Uvicorn错误日志无法从OpenTelemetry获取trace_id（trace_id=0）

问题现象 #

访问FastAPI应用的/throws端点时，自定义异常处理器输出的日志包含有效的trace_id和span_id，但Uvicorn生成的Exception in ASGI application错误日志中，trace_id和span_id始终为0。

当前配置代码 #

FastAPI应用代码（main.py） #

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)

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"]

日志配置（log-format.yaml） #

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

解决方案 #

问题根源在于重复的OpenTelemetry instrumentation和中间件顺序错误，导致Uvicorn处理ASGI异常时无法进入有效的Trace上下文。以下是修复步骤：

1. 移除重复的FastAPI Instrumentation #

FastAPIInstrumentor().instrument_app(app)内部已经会自动添加OpenTelemetry相关处理逻辑，和手动添加的OpenTelemetryMiddleware会造成上下文冲突，直接移除这一行。

2. 调整OpenTelemetry中间件包裹方式 #

确保OpenTelemetryMiddleware直接包裹原始FastAPI app，作为Uvicorn启动的入口ASGI应用，这样整个请求链从Uvicorn接收请求开始就会被Trace上下文覆盖。

3. 优化日志Instrumentation初始化 #

在初始化LoggingInstrumentor时，显式设置set_logging_format=True，确保日志上下文能正确关联Trace信息（自定义日志格式已包含otel字段时，此设置可兼容）。

修改后的完整代码 #

from fastapi import FastAPI, Request
from opentelemetry.exporter.otlp.proto.grpc.trace_exporter import OTLPSpanExporter
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.instrumentation.logging import LoggingInstrumentor
from opentelemetry.instrumentation.requests import RequestsInstrumentor
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))
)

# 初始化日志Instrumentation，确保上下文关联
LoggingInstrumentor().instrument(set_logging_format=True)
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)

# 直接用OpenTelemetryMiddleware包裹原始app，作为Uvicorn启动的ASGI应用
asgi_app = OpenTelemetryMiddleware(app, tracer_provider=trace_provider)

额外说明 #

• 确保所有OpenTelemetry相关包版本兼容，比如opentelemetry-instrumentation-asgi、opentelemetry-instrumentation-fastapi和uvicorn的版本匹配
• 如果日志格式仍未正确显示Trace ID，检查LoggingInstrumentor是否正确注入了日志过滤器，确保otelTraceID、otelSpanID等字段能被日志格式化器正确提取

内容的提问来源于stack exchange，提问作者Tom McLean