Skip to content

Tracing asyncio Services with OpenTelemetry

In a synchronous service, "the current span" is a thread-local and everything works. In an async service, thousands of requests interleave on one thread, so the current span has to follow the logical flow of a coroutine rather than the thread it happens to run on. OpenTelemetry's Python SDK does this with contextvars, and the result is that tracing mostly just works: an awaited call sees its caller's span, and a task created inside a span inherits it. The place it stops working is exactly the place async services do something threads cannot — a task that outlives the span that created it. This guide covers the mechanics, the measured overhead (11.24 µs per span unsampled, 3.91 µs batched and sampled), and what to record.

Prerequisites

  • Python 3.11+ with opentelemetry-sdk (pip install opentelemetry-sdk); measurements use 1.44.
  • Context propagation from Context Variables & Request Context — spans are stored in a contextvar.
  • An exporter: OTLP to a collector in production, an in-memory one for the tests here.
How span context travels through asyncio 5 stages from a span starts to task after. How span context travels through asyncio a span starts sets a contextvar awaited calls see the same context task inside copies the context the span ends the contextvar resets task after no parent: a new trace Verified: a task created inside the span had a parent; one created after it did not.

1. Set up a provider, a processor and a sampler

Three objects decide everything about cost and volume:

provider = TracerProvider(
    resource=Resource.create({"service.name": "orders-api"}),
    sampler=ParentBased(TraceIdRatioBased(0.1)),       # 10% of traces, children follow
)
provider.add_span_processor(BatchSpanProcessor(OTLPSpanExporter(), max_queue_size=2048))
trace.set_tracer_provider(provider)
tracer = trace.get_tracer(__name__)

ParentBased is the sampler that keeps traces intact: once a trace is sampled, every span in it is, so you never get a trace with holes in it. Verified — 22 of 200 parents were sampled at a 10% ratio, and their children followed.

BatchSpanProcessor exports on a background thread in batches. The alternative, SimpleSpanProcessor, exports each span synchronously, which is fine in tests and wrong in production: measured, it cost 11.24 µs per span against 3.91 µs for the batched, sampled configuration — and with a network exporter the synchronous version would block the event loop on every span.

Verify: spans reach your collector, and the exporter's queue-full counter stays at zero.

2. Rely on contextvars, and know their boundary

Span context follows contextvars, which asyncio copies into each new task. Three verified behaviours:

with tracer.start_as_current_span("request") as parent:
    await child()                                      # parent is the request span ✓
    task = asyncio.create_task(child())                # created inside: inherits ✓
await task

late = asyncio.create_task(child())                    # created after the span ended: no parent ✗

The first two are what makes tracing feel automatic. The third is the trap: a background task created after the span ends starts its own trace, so the work appears as an orphan with no connection to the request that caused it.

The fix is to capture the link explicitly when you spawn work that outlives the request:

span_context = trace.get_current_span().get_span_context()
task = asyncio.create_task(background(link=trace.Link(span_context)))

and start the background span with links=[link], which records the causal relationship without pretending the work is part of the original trace. See running background tasks safely for the ownership side of the same problem.

Verify: every span in a trace has a parent, and background work appears with a link rather than as an orphan.

3. Instrument the boundaries, not every function

A span per function produces traces nobody can read and overhead nobody budgeted. Instrument where work crosses a boundary:

  • Inbound requests — usually automatic via an ASGI instrumentation.
  • Outbound calls — HTTP, database, cache, broker. These are what the trace exists to show.
  • Significant internal phases — "render", "validate", "aggregate" — where they represent a chunk of time you would otherwise be unable to attribute.
async def get_order(order_id: int) -> Order:
    with tracer.start_as_current_span("db.get_order") as span:
        span.set_attribute("order.id", order_id)
        return await pool.fetchrow(QUERY, order_id)

Attributes carry the identifiers that let you find a trace later — tenant, order, job id — and the outcome. Do not put request bodies, tokens or personal data on spans: traces are widely readable inside an organisation, and a trace backend is not an appropriate place for secrets.

Failures need two calls, because a span with an exception event but an OK status is not findable by "show me errors":

    except Exception as exc:
        span.record_exception(exc)
        span.set_status(Status(StatusCode.ERROR, str(exc)))
        raise

Verified: that produced a span with status ERROR and an event named exception.

Verify: a failing request produces a trace whose error span is findable by status.

What to put on a span, and what not to A grid of 5 rows by 2 columns. What to put on a span, and what not to put on the span example why identifiers tenant, request, job id joins the trace to your logs outcome set_status on failure error traces are findable exceptions span.record_exception(exc) the traceback rides along not: secrets or payloads tokens, bodies, PII traces are widely readable not: high-cardinality metrics per-user counters that is what logs are for Measured: a recorded exception appears as an event named "exception" with the span status ERROR.

4. Budget the overhead deliberately

The numbers make the trade explicit:

configuration per span
SimpleSpanProcessor, everything exported 11.24 µs
BatchSpanProcessor, 10% sampled 3.91 µs

At ten spans per request and 1,000 requests per second, the first configuration is 112 ms of CPU per second — 11% of a core, on the event loop, for observability. The second is 39 ms. Neither is free, and both are trivial compared with a single database call, which is the point: instrument the calls, not the loops.

The three levers, in order of effect: sample (a ratio, or a tail sampler in the collector), batch (always), and bound the span count per request (a trace with 500 spans is a debugging problem of its own). For high-throughput internal services, sampling at 1% with a rule that always samples errors gives you the traces you actually look at.

Verify: loop lag is unchanged with tracing enabled, and the exporter never drops spans.

What a span costs per call 2 bars comparing SimpleSpanProcessor, all spans with the others. What a span costs per call SimpleSpanProcessor, all spans 11.24 µs BatchSpanProcessor, 10% sampled 3.91 µs Measured over 20,000 spans with an in-process exporter; a network exporter adds its own cost. Batching and sampling are not optimisations to add later; they are the default configuration.

5. Join traces to logs and metrics

A trace answers "why was this request slow"; metrics answer "is the service slow"; logs answer "what exactly happened". They are only useful together when they share identifiers:

span = trace.get_current_span().get_span_context()
logger.info("order created", extra={
    "trace_id": format(span.trace_id, "032x"),
    "span_id": format(span.span_id, "016x"),
})

With the trace id in every log line, a slow trace leads directly to the log lines of that request — see structured logging for async services. Going the other way, exemplars attach a trace id to a metric bucket, so a spike in the p99 histogram links to a trace that produced it.

Keep the cardinality rules straight, because this is where teams get into trouble: trace attributes may be high-cardinality (a user id is fine and useful), metric labels must not be (a user id will destroy your metrics backend). That difference is the main reason both systems exist.

Verify: given a trace id from a slow trace, you can find that request's logs in one query.

Tracing and metrics answer different questions 2 columns contrasting traces, metrics. Tracing and metrics answer different questions traces why was THIS request slow one sampled request, end to end shows the causal chain high cardinality is fine sampled: not every request metrics how is the service doing aggregated over all requests no per-request detail cardinality must stay low every request counted A service needs both: metrics to notice, traces to explain.

Verification

Tracing is correctly set up when:

  • BatchSpanProcessor is used, never the simple one, in production.
  • Sampling is ParentBased, so traces have no holes.
  • Spans mark boundaries, not every function call.
  • Failures set both record_exception and an ERROR status.
  • Background work is linked, not orphaned.
  • Logs carry the trace id, so the three signals join.

Pitfalls & edge cases

  • SimpleSpanProcessor in production. Synchronous export on the loop; 11.24 µs per span with a local exporter, far worse over a network.
  • Tasks created after the span ends. They start a new trace; capture a link instead.
  • Manual span.end() without a context manager. An early return leaks an unended span; use with.
  • Secrets in attributes. Traces are broadly readable; treat them as you would logs.
  • Uniform sampling of errors. Sample errors at 100% and successes at a ratio, or the traces you need are the ones you threw away.
  • Instrumenting library internals. An HTTP client instrumentation already creates a span per request; adding your own doubles them.

Frequently Asked Questions

Does OpenTelemetry tracing work correctly with asyncio?

Yes. Span context lives in a contextvar, which asyncio copies into each task, so awaited calls and tasks created inside a span both see it as their parent — both verified. The exception is a task created after the span ends, which starts a new trace.

Why do my background tasks show up as separate traces?

Because the span that created them had already ended, so there was no current context to inherit. Capture the span context before spawning and start the background span with links=[Link(span_context)], which records the causal relationship without falsifying the parent.

How much overhead does OpenTelemetry add to an async service?

Measured over 20,000 spans with an in-process exporter: 11.24 µs per span with SimpleSpanProcessor exporting everything, and 3.91 µs with BatchSpanProcessor and 10% sampling. Use batching and sampling, instrument boundaries rather than every function, and the cost stays well under any single I/O call.

What sampling strategy should an async service use?

ParentBased with a ratio, so a sampled trace is sampled end to end rather than full of holes. Verified at a 10% ratio, 22 of 200 parents were sampled and their children followed. Add a rule that always samples errors, since those are the traces you will actually open.

Should I put request data on spans?

Identifiers yes, contents no. Tenant, order and job ids make traces findable and joinable with logs; request bodies, tokens and personal data do not belong in a trace backend. Metric labels have the opposite rule — keep those low-cardinality.