opentelemetry-python-contrib icon indicating copy to clipboard operation
opentelemetry-python-contrib copied to clipboard

GRPC traces called twice when result evaluates to false

Open kevmodo opened this issue 8 months ago • 0 comments
trafficstars

Describe your environment

OS: MacOS Python version: 3.12.9 Package version: commit a5474c3b290f5fcd7b5e8f9953ae8b2891c374c0 google-cloud-pubsub 2.28.0

What happened?

When instrumenting Google Cloud PubSub, I see a lot of log messages Calling end() on an ended span..

This appears to happen whenever no messages are available after a PubSub call:

...
GrpcInstrumentorClient().instrument()

subscriber = pubsub_v1.SubscriberClient()
subscription_path = subscriber.subscription_path(env.pubsub_project_id, env.subscription_id)
with subscriber:
    while True:
        response = subscriber.pull(
            subscription=subscription_path,
            max_messages=1,
            retry=retry.Retry(timeout=env.timeout),
        )
       ...

This appears to be due to https://github.com/open-telemetry/opentelemetry-python-contrib/blob/a5474c3b290f5fcd7b5e8f9953ae8b2891c374c0/instrumentation/opentelemetry-instrumentation-grpc/src/opentelemetry/instrumentation/grpc/_client.py#L168-L169

which ends the span when result evaluates falsy.

But then since there was no exception, program flow continues to https://github.com/open-telemetry/opentelemetry-python-contrib/blob/a5474c3b290f5fcd7b5e8f9953ae8b2891c374c0/instrumentation/opentelemetry-instrumentation-grpc/src/opentelemetry/instrumentation/grpc/_client.py#L122, where it calls span.end().

My interpretation of the if not result: is that it's mainly acting as an indication that there was an exception; at any rate, in my simple use case, spans seem to start and end correctly if I change it to if result is None:.

Steps to Reproduce

...
GrpcInstrumentorClient().instrument()

subscriber = pubsub_v1.SubscriberClient()
subscription_path = subscriber.subscription_path(env.pubsub_project_id, env.subscription_id)
with subscriber:
    while True:
        response = subscriber.pull(
            subscription=subscription_path,
            max_messages=1,
            retry=retry.Retry(timeout=env.timeout),
        )
       ...

(This relies on an empty queue. I'm not familiar enough with gRPC to create a fully standalone test at this point)

Expected Result

Only a single span.end() call for each span created.

Actual Result

span.end() is called twice when result contains no messages.

Additional context

No response

Would you like to implement a fix?

Yes

kevmodo avatar Mar 21 '25 07:03 kevmodo