Exclude background tasks from request duration in ASGI middleware

[marpulli]

Is your feature request related to a problem?
The duration of a request span in FastAPI includes the duration of evaluating background tasks. There is no span whose duration represents the time bewteen receiving a request and sending the response. An example:

import asyncio
from typing import TypedDict

from fastapi import BackgroundTasks, Depends, FastAPI
from opentelemetry import trace
from opentelemetry.instrumentation.fastapi import FastAPIInstrumentor
from opentelemetry.sdk.trace import TracerProvider
from opentelemetry.sdk.trace.export import BatchSpanProcessor, ConsoleSpanExporter

app = FastAPI()
exporter = ConsoleSpanExporter()
provider = TracerProvider()
processor = BatchSpanProcessor(exporter)
provider.add_span_processor(processor)
trace.set_tracer_provider(provider)
FastAPIInstrumentor.instrument_app(app)


def get_context(
    background_tasks: BackgroundTasks,
):
    return Context(background_tasks=background_tasks)


async def some_background_task():
    await asyncio.sleep(10)


class Context(TypedDict):
    background_tasks: BackgroundTasks


@app.get("/")
async def main(context=Depends(get_context)):
    print(context.keys())
    context["background_tasks"].add_task(some_background_task)
    return None

Describe the solution you'd like
Either end the server span after we have sent the response (this is how dd-trace solve it in DataDog/dd-trace-py#3799)

OR create a new span that stops after the response has been sent.

Additional context
This is important to calculation latency metrics using the FastAPI instrumentation

[macieyng]

Thanks for reporting! We'll try to reproduce the issue.

I agree that there should be two new spans - producer (because FastAPI is producing the task) and consumer (because FastAPI is consuming the task, similarly to how celery instrumentation behaves). Is that what you had in mind?

[marpulli]

Thanks for the reply! Let me explain in a bit more detail. Let's say we are calling the endpoint foo. We currently get spans that look like this:

/foo                  <----------------->
... other stuff
http send                          <->
background task execution             <->

i.e. the /foo span does not end until the background task has finished executing, even though the client has the response. There is no span that currently represents the time from receiving the request to the time sending it.

The celery implementation might do this if the consumer span is not a parent of the request span? We'd then have a whole different trace for the background task execution?