Skip to content

Opentelemetrymiddleware: Background task duration is recorded in metrics #3591

Open
@david-gang

Description

@david-gang

Describe your environment

OS: Ubuntu
Python version: 3.12
Package version: [v0.55b1]

What happened?

I use otel metrics. We have routes which use background tasks and when looking at the http_server_duration_milliseconds_bucket metrics we see that the time of the background task is included.
I am just interested in user facing time and not in the background task stuff.

Steps to Reproduce

Create a fastapi route

from fastapi import APIRouter, Request,BackgroundTasks
import asyncio
@router.get("/healthz-with-background-task")
async def healthz_with_background_task(background_tasks: BackgroundTasks) -> dict[str, str]:
    background_tasks.add_task(sleep_background_task)
    return {"status": "ok", "message": "Background task started"}
async def sleep_background_task() -> None:
    """Background task that sleeps for 10 seconds asynchronously."""
    await asyncio.sleep(10)
    # You could add logging here to confirm the task completed
    # logger.info("Background sleep task completed")

Then at this line add a print:

print(f"duration_s: {duration_attrs_new} {duration_s}")

interestingly you get two prints:
The first one with the real duration but without attributes! duration_s: {} 0.0012163339997641742
The second one with attributes but with the duration of the background task included: duration_s: {'http.route': '/healthz-with-background-task'} 10.00230166700203

Expected Result

I should get the user facing duration and not background task including.

Actual Result

I get the duration with background task including and get one empty!

Additional context

This is a severe bug which is a blocker from using the metrics implementation. Interestingly this also exist in prometheus fastapi: trallnag/prometheus-fastapi-instrumentator#275

This is actually the same bug as in traces: #1684
but here it is metrics

After rethinking the issue i would say that it may be problematic that fastapi uses the opentelemetry middleware of asgi as background tasks are not part of the asgi spec, so that asgi have no reason to support this scenario:

Would you like to implement a fix?

In order to create a fix it would be important to have the guidance of starlette/ fastapi core developers as they understand more how they hook into the asgi framework.

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions