open-telemetry / open-telemetry/opentelemetry-python-contrib

FastAPI: fail to reset trace_id with large (multi-chunk) request payload

Open
#3,700 3 comments 5 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

bug
Dominant language
Python
Stars
1.1k
Forks
1.1k
Avg merge
4d 15h
Merged PRs (30d)
16

Description

Describe your environment

OS: Ubuntu 22
Python version: Python 3.10.12
Package version: 0.57b0
opentelemetry-instrumentation==0.57b0
opentelemetry-instrumentation-fastapi==0.57b0
opentelemetry-sdk==1.36.0
fastapi==0.116.1
starlette==0.47.2

What happened?

When enable tracing on FastApi request with large incoming payload (which gets streamed as multiple chunks), the trace_id does not get reset for the next Request coming over the same http connection (keep-alive).

It looks like trace context gets leaked and doesn't get reset/close properly and gets attached to the http connection, as long as the connection is kept alive, any subsequent request would get the same trace_id as first request.

Steps to Reproduce

Below is a minimal runnable example with two python files: app.py and test_app.py

app.py:

import asyncio
import logging
from fastapi import FastAPI, Request
from opentelemetry import trace
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import ConsoleSpanExporter, SimpleSpanProcessor

# Set up logging to see the trace IDs
logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

# --- OpenTelemetry Setup ---
# A simple tracer provider to print traces to the console
provider = TracerProvider()
processor = SimpleSpanProcessor(ConsoleSpanExporter())
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)

app = FastAPI()
# Instrument the app. This middleware sets up tracing for each request.
FastAPIInstrumentor.instrument_app(app)

@app.post("/predict")
async def predict(request: Request):
    """
    This endpoint manually reads the request body, which triggers the bug
    when the payload is sent in multiple chunks.
    """
    logger.info("Handling /predict request...")
    
    # Manually reading the body to reproduce the issue
    request_bytes = await request.body()
    
    logger.info("Received payload of %d bytes", len(request_bytes))
    
    # Simulate some processing
    await asyncio.sleep(0.5)
    
    # Get the current trace ID and print it
    current_span = trace.get_current_span()
    trace_id = format(current_span.get_span_context().trace_id, 'x')
    logger.info("Trace ID for /predict: %s", trace_id)
    
    return {"status": "ok", "message": "Payload received", "trace_id": trace_id}

@app.get("/test")
async def test_trace_id():
    """
    This endpoint is used to check if the trace ID has been reset.
    """
    logger.info("Handling /test request...")
    
    # Get the current trace ID and print it
    current_span = trace.get_current_span()
    trace_id = format(current_span.get_span_context().trace_id, 'x')
    logger.info("Trace ID for /test: %s", trace_id)
    
    return {"status": "ok", "message": "Trace ID checked", "trace_id": trace_id}

test_app.py:

import asyncio
import httpx
import logging

logging.basicConfig(level=logging.INFO)
logger = logging.getLogger(__name__)

async def run_test():
    # A large payload (10MB) to ensure it's sent in multiple chunks
    large_payload = b'A' * 1024 * 1024 * 10
    
    # Use httpx.AsyncClient as a context manager to maintain a keep-alive connection
    async with httpx.AsyncClient(base_url="http://localhost:8000") as client:
        logger.info("--- Sending first request to /predict with large payload ---")
        try:
            response1 = await client.post(
                "/predict",
                content=large_payload,
                headers={"Content-Type": "application/octet-stream"}
            )
            response1.raise_for_status()
            logger.info("First request successful: %s", response1.json())
        except httpx.HTTPStatusError as e:
            logger.error("Request 1 failed: %s", e.response.text)
        
        # Add a short delay to ensure the server is ready for the next request
        await asyncio.sleep(1)

        logger.info("\n--- Sending second request to /test on the same connection ---")
        try:
            response2 = await client.get("/test")
            response2.raise_for_status()
            logger.info("Second request successful: %s", response2.json())
        except httpx.HTTPStatusError as e:
            logger.error("Request 2 failed: %s", e.response.text)

if __name__ == "__main__":
    asyncio.run(run_test())

Run above two scripts in separate process:

uvicorn app:app &
python test_app.py
Expected Result

second request GET /test gets a new trace id (different than the first request POST /predict)

Actual Result

second request gets the same trace id as first request

INFO:__main__:--- Sending first request to /predict with large payload ---
INFO:httpx:HTTP Request: POST http://localhost:8000/predict "HTTP/1.1 200 OK"
INFO:__main__:First request successful: {'status': 'ok', 'message': 'Payload received', 'trace_id': '5c2d0e099c31993a72d823959aaf52d2'}
INFO:__main__:
--- Sending second request to /test on the same connection ---
INFO:httpx:HTTP Request: GET http://localhost:8000/test "HTTP/1.1 200 OK"
INFO:__main__:Second request successful: {'status': 'ok', 'message': 'Trace ID checked', 'trace_id': '5c2d0e099c31993a72d823959aaf52d2'}
Additional context

If we make request payload small enough (to be sent in 1 chunk), the second request would get a new trace id as expected

Would you like to implement a fix?

None

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Run the app.py and test_app.py reproduction with the versions listed, focusing on FastAPIInstrumentor.instrument_app and the large multi-chunk request. Trace the request context across the keep-alive connection and compare the two returned trace IDs. Done means the subsequent GET /test receives a different trace ID from the preceding large POST /predict request.

Written by the indexing model from the issue text.

Assessment

Tech stack
fastapi, python
Domain
backend, observability
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Quiet
Clarity
Mostly clear
Newbie friendliness
52/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.