OpenTelemetry FastAPI and Requests #1940
Description
How do you use Sentry?
Sentry Saas (sentry.io)
Version
1.16.0
Steps to Reproduce
- Manually instrument a FastAPI application using requests as an HTTP client using the following code snippet:
sentry_sdk.init(
dsn=get_sentry_dsn(),
traces_sample_rate=traces_sample_rate,
instrumenter="otel",
environment=get_environment(),
)
tracer_provider = TracerProvider(resource=resource)
tracer_provider.add_span_processor(SentrySpanProcessor())
trace.set_tracer_provider(tracer_provider)
set_global_textmap(SentryPropagator())
...
RequestsInstrumentor().instrument(tracer_provider=tracer_provider)
...
FastAPIInstrumentor.instrument_app(app, tracer_provider=trace.get_tracer_provider())
- Create two instances of the Application
- Using the requests library, In the first instance, call the second instance in a way to cause an error, in this case the first instance endpoint calls with an invalid auth token, resulting in a 403
- Review sentry trace in sentry.io
Expected Result
A single trace with both requests
Actual Result
Multiple traces with each request
Additional Info
I spent a day or two debugging this issue, and it seems to boil down to how the trace-id is extracted in the propagator. I believe the ASGI middleware is generating a span somewhere that I haven't been able to find, since the scope here already has the new span somewhere, see a sample below.
Because of the asgi middleware, the sentry_trace = getter.get(carrier, SENTRY_TRACE_HEADER_NAME) becomes sentry_trace: [['ecf45d41418a4ab8a5723e6c24b598d3-9cdd27733f0c0d37-', 'bd345b67708c6000341cdd61eeeb5583-3b4d0fe494390136-1']], which means sentry uses the first trace id to then send to sentry, causing the behaviour above. I tried changing the selection to select the last element, which works, but I'm not sure how this would impact usage in other places, otherwise I would open a PR. I believe there is no issue with the outgoing request because looking at the sentry span in inject in the propagator, the current span seems to be correct, see below for more info.
asgi carrier info
carrier: [{'type': 'http', 'asgi': {'version': '3.0', 'spec_version': '2.3'}, 'http_version': '1.1', 'server': ('127.0.0.1', 8081), 'client': ('127.0.0.1', 59687), 'scheme': 'http', 'method': 'GET', 'root_path': '', 'path': '/api/v1/example/test2', 'raw_path': b'/api/v1/example/test2', 'query_string': b'', 'headers': [(b'host', b'localhost:8081'), (b'sentry-trace', b'ecf45d41418a4ab8a5723e6c24b598d3-9cdd27733f0c0d37-'), (b'user-agent', b'python-requests/2.28.2'), (b'accept-encoding', b'gzip, deflate'), (b'accept', b'*/*'), (b'connection', b'keep-alive'), (b'content-type', b'application/json'), (b'authorization', b'Bearer token'), (b'sentry-trace', b'bd345b67708c6000341cdd61eeeb5583-3b4d0fe494390136-1'), (b'baggage', b'sentry-trace_id=bd345b67708c6000341cdd61eeeb5583,sentry-environment=dev,sentry-release=<sentry_release>,sentry-public_key=<public_key>,sentry-transaction=/api/v1,sentry-sample_rate=1.0')], 'app': <fastapi.applications.FastAPI object at 0x106070fa0>}]
sentry span in propagator inject
sentry_span: <Span(op=None, description:'HTTP GET', trace_id='bd345b67708c6000341cdd61eeeb5583', span_id='3b4d0fe494390136', parent_span_id='46cb3b9f78354054', sampled=True)>