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

Opentelemetrymiddleware: Background task duration is recorded in metrics

Open
#3,591 1 comment 0 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
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:
https://github.com/open-telemetry/opentelemetry-python-contrib/blob/c4347e027c745ab7e1b9468ad75c37bed535ca26/instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/__init__.py#L767

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: https://github.com/trallnag/prometheus-fastapi-instrumentator/issues/275

This is actually the same bug as in traces: https://github.com/open-telemetry/opentelemetry-python-contrib/issues/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: https://github.com/open-telemetry/opentelemetry-python-contrib/blob/c4347e027c745ab7e1b9468ad75c37bed535ca26/instrumentation/opentelemetry-instrumentation-fastapi/src/opentelemetry/instrumentation/fastapi/__init__.py#L202

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.

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

Reproduce the FastAPI background-task route, then inspect instrumentation/opentelemetry-instrumentation-asgi/src/opentelemetry/instrumentation/asgi/init.py around line 767. Compare the metrics behavior with issue #1684 and review the FastAPI middleware entry point at instrumentation/opentelemetry-instrumentation-fastapi/src/opentelemetry/instrumentation/fastapi/init.py around line 202. Done means metrics record user-facing duration without background-task time and do not emit an empty measurement.

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
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.