[Python] Uvicorn not getting trace id from otel in error logs (trace_id=0)

I have a test FastAPI application:

from fastapi import FastAPI, Request
from opentelemetry.exporter.otlp.proto.grpc import trace_exporter
from opentelemetry.instrumentation.asgi import OpenTelemetryMiddleware
from opentelemetry.sdk.resources import Resource
from opentelemetry import trace
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
from opentelemetry.instrumentation.logging import LoggingInstrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
from starlette.responses import JSONResponse
import logging, os

# Setup OpenTelemetry
resource = Resource.create(attributes={"service.name": os.environ["SERVICE_NAME"]})
trace_provider = TracerProvider(resource=resource)
trace.set_tracer_provider(trace_provider)
trace_provider.add_span_processor(
BatchSpanProcessor(OTLPSpanExporter(insecure=True))
)

LoggingInstrumentor().instrument()
RequestsInstrumentor().instrument()

# Define FastAPI app
app = FastAPI()

@app.get("/throws")
async def throws():
raise ValueError("Oops!")

@app.get("/ok")
async def ok():
return {"message": "Fine"}

@app.exception_handler(Exception)
async def handle_all_exceptions(request: Request, exc: Exception):
logging.exception("Handled exception", exc_info=exc)
return JSONResponse(content={"detail": "Internal Server Error"}, status_code=500)

FastAPIInstrumentor().instrument_app(app)
asgi_app = OpenTelemetryMiddleware(app, tracer_provider=trace_provider)


If I go to the /throws endpoint, I can see one log message from the custom exception handler with the trace id, then another exception message from uvicorn without the trace id:

fastapi-app-1 | 2025-07-31 08:10:22,886 INFO [uvicorn.error] [server.py:84] [trace_id=0 span_id=0 resource.service.name=fastapi-app-1] - Started server process [1]
fastapi-app-1 | 2025-07-31 08:10:22,887 INFO [uvicorn.error] [on.py:48] [trace_id=0 span_id=0 resource.service.name=fastapi-app-1] - Waiting for application startup.
fastapi-app-1 | 2025-07-31 08:10:22,887 INFO [uvicorn.error] [on.py:62] [trace_id=0 span_id=0 resource.service.name=fastapi-app-1] - Application startup complete.
fastapi-app-1 | 2025-07-31 08:10:22,887 INFO [uvicorn.error] [server.py:216] [trace_id=0 span_id=0 resource.service.name=fastapi-app-1] - Uvicorn running on http://0.0.0.0:8000 (Press CTRL+C to quit)
fastapi-app-1 | 2025-07-31 08:10:24,315 ERROR [root] [main.py:41] [trace_id=01475de07b3933590da528898e0d14a9 span_id=355c87a166b5f480 resource.service.name=fastapi-app-1] - Handled exception
fastapi-app-1 | Traceback (most recent call last):
fastapi-app-1 | File "/usr/local/lib/python3.11/site-
....
fastapi-app-1 | File "/app/main.py", line 33, in throws
fastapi-app-1 | raise ValueError("Oops!")
fastapi-app-1 | ValueError: Oops!
fastapi-app-1 | 2025-07-31 08:10:24,318 INFO [uvicorn.access] [h11_impl.py:473] [trace_id=01475de07b3933590da528898e0d14a9 span_id=355c87a166b5f480 resource.service.name=fastapi-app-1] - 192.168.97.1:38576 - "GET /throws HTTP/1.1" 500
fastapi-app-1 | 2025-07-31 08:10:24,319 ERROR [uvicorn.error] [h11_impl.py:408] [trace_id=0 span_id=0 resource.service.name=fastapi-app-1] - Exception in ASGI application
fastapi-app-1 | Traceback (most recent call last):
fastapi-app-1 | File "/usr/local/lib/python3.11/site-packages/uvicorn/protocols/http/h11_impl.py", line 403, in run_asgi
...
fastapi-app-1 | File "/app/main.py", line 33, in throws
fastapi-app-1 | raise ValueError("Oops!")
fastapi-app-1 | ValueError: Oops!


My app was created with Docker with this Dockerfile:

FROM python:3.11

WORKDIR /app

COPY ./requirements.txt ./
RUN pip install --no-cache-dir -r requirements.txt

COPY ./main.py ./
COPY ./log-format.yaml ./

CMD ["uvicorn", "main:asgi_app", "--host", "0.0.0.0", "--port", "8000", "--log-config", "log-format.yaml"]


and this logging config:

version: 1
formatters:
default:
format: "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s resource.service.name=%(otelServiceName)s] - %(message)s"
use_colors: true
access:
format: "%(asctime)s %(levelname)s [%(name)s] [%(filename)s:%(lineno)d] [trace_id=%(otelTraceID)s span_id=%(otelSpanID)s resource.service.name=%(otelServiceName)s] - %(message)s"
handlers:
default:
class: logging.StreamHandler
formatter: default
stream: ext://sys.stderr
access:
class: logging.StreamHandler
formatter: access
stream: ext://sys.stdout
loggers:
uvicorn.error:
level: INFO
handlers:
- default
propagate: no
uvicorn.access:
level: INFO
handlers:
- access
propagate: no
root:
level: DEBUG
handlers:
- default
propagate: no


According to this GitHub discussion the fix (which I have in my example) is to do:

app.add_middleware(
OpenTelemetryMiddleware,
default_span_details=_get_default_span_details,
excluded_urls=_excluded_urls_from_env,
)


or to do:

app = OpenTelemetryMiddleware(app)


But neither of those two options has added the trace id to the exception logs.

How can I fix this?

Continue reading...