Skip to content

FastAPI instrumentation: errors in hooks not handled properly #3642

@alexmojaki

Description

@alexmojaki

Example script:

from typing import Any

import uvicorn
from fastapi import FastAPI, Request
from fastapi.responses import JSONResponse
from opentelemetry import trace
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExporter
from opentelemetry.trace import Span

tracer_provider = TracerProvider()
trace.set_tracer_provider(tracer_provider)
exporter = ConsoleSpanExporter()
span_processor = BatchSpanProcessor(exporter)
tracer_provider.add_span_processor(span_processor)


def server_request_hook(span: Span, scope: dict[str, Any]):
    raise Exception('Hook Exception')


app = FastAPI()
FastAPIInstrumentor.instrument_app(app, server_request_hook=server_request_hook)


@app.exception_handler(Exception)
async def exception_handler(request: Request, exc: Exception):
    return JSONResponse(
        status_code=200,
        content={'message': 'Oops!'},
    )


@app.get('/')
async def index():
    raise Exception('Index Exception')


uvicorn.run(app)

Output after visiting http://127.0.0.1:8000/:

INFO:     127.0.0.1:55312 - "GET / HTTP/1.1" 500 Internal Server Error
ERROR:    Exception in ASGI application
Traceback (most recent call last):
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 403, in run_asgi
    result = await app(  # type: ignore[func-returns-value]
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 60, in __call__
    return await self.app(scope, receive, send)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/fastapi/applications.py", line 1054, in __call__
    await super().__call__(scope, receive, send)
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/starlette/applications.py", line 113, in __call__
    await self.middleware_stack(scope, receive, send)
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/starlette/middleware/errors.py", line 186, in __call__
    raise exc
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/starlette/middleware/errors.py", line 164, in __call__
    await self.app(scope, receive, _send)
  File "/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/opentelemetry/instrumentation/asgi/__init__.py", line 754, in __call__
    self.server_request_hook(current_span, scope)
  File "/Users/alex/Library/Application Support/JetBrains/PyCharm2025.1/scratches/scratch_1842.py", line 20, in server_request_hook
    raise Exception('Hook Exception')
Exception: Hook Exception
{
    "name": "GET /",
    "context": {
        "trace_id": "0xf2635a292d6a5396c9914909957f3be6",
        "span_id": "0x0760d24d07d2a667",
        "trace_state": "[]"
    },
    "kind": "SpanKind.SERVER",
    "parent_id": null,
    "start_time": "2025-07-16T13:20:32.289554Z",
    "end_time": "2025-07-16T13:20:32.292083Z",
    "status": {
        "status_code": "ERROR",
        "description": "Exception: Hook Exception"
    },
    "attributes": {
        "http.scheme": "http",
        "http.host": "127.0.0.1:8000",
        "net.host.port": 8000,
        "http.flavor": "1.1",
        "http.target": "/",
        "http.url": "http://127.0.0.1:8000/",
        "http.method": "GET",
        "http.server_name": "127.0.0.1:8000",
        "http.user_agent": "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/138.0.0.0 Safari/537.36",
        "net.peer.ip": "127.0.0.1",
        "net.peer.port": 55312,
        "http.route": "/"
    },
    "events": [
        {
            "name": "exception",
            "timestamp": "2025-07-16T13:20:32.292002Z",
            "attributes": {
                "exception.type": "Exception",
                "exception.message": "Hook Exception",
                "exception.stacktrace": "Traceback (most recent call last):\n  File \"/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/opentelemetry/trace/__init__.py\", line 589, in use_span\n    yield span\n  File \"/Users/alex/work/logfire/.venv/lib/python3.12/site-packages/opentelemetry/instrumentation/asgi/__init__.py\", line 754, in __call__\n    self.server_request_hook(current_span, scope)\n  File \"/Users/alex/Library/Application Support/JetBrains/PyCharm2025.1/scratches/scratch_1842.py\", line 20, in server_request_hook\n    raise Exception('Hook Exception')\nException: Hook Exception\n",
                "exception.escaped": "False"
            }
        }
    ],
    "links": [],
    "resource": {
        "attributes": {
            "telemetry.sdk.language": "python",
            "telemetry.sdk.name": "opentelemetry",
            "telemetry.sdk.version": "1.35.0",
            "service.name": "unknown_service"
        },
        "schema_url": ""
    }
}

Problems:

  1. Errors in hooks probably shouldn't cause the whole request to fail
  2. Even if they should, the exception_handler handler isn't used in this case, i.e. the response is 500 instead of 200. This is because of the decision made at the end of fastapi: fix wrapping of middlewares #3012 to not pass user defined error handlers to the outer server middleware. The reasoning was to avoid executing side effects in an error handler twice. On that note, see https://github.com/open-telemetry/opentelemetry-python-contrib/pull/3012/files#r2210430687
  3. Also, the 500 status code isn't even recorded on the span.

By contrast, if the server request hook doesn't raise an exception, things work as expected, i.e. error handling inside the route is correct.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions