Using contextvars for Request Tracing in Python

Every log line a request produces should carry the same correlation ID - across await points, spawned tasks, and offloaded work - without that ID being threaded through every function signature. This page is for backend engineers and SREs running an async Python service who need request-scoped tracing that survives an event loop multiplexing hundreds of requests onto one OS thread. It implements that with contextvars, the only standard-library primitive that stays correct under that concurrency model. It is a focused task within the context variables and thread safety reference and part of the Python Logging Fundamentals and Structured Data guide.

One slot written once at the boundary, read by everything downstream An inbound request carrying a traceparent or X-Trace-ID header enters TraceMiddleware, which resolves an identifier and writes it into trace_id_ctx, a single module-level ContextVar, keeping the returned token. Three readers draw from that same slot: the awaited handler, a task spawned with asyncio.create_task that receives a copy of the context, and TraceFilter, which copies the value onto every LogRecord. The resulting log lines all carry the same identifier. On teardown the middleware's finally block resets the variable with its token, restoring the previous value so nothing bleeds into the next request. Inbound request traceparent · X-Trace-ID TraceMiddleware token = trace_id_ctx.set(id) finally: reset(token) writes once restores previous trace_id_ctx — one module-level ContextVar, one value per context current value: 4bf92f3577b34da6a3ce929d0e0e4736 await handler(...) same context, same value across every await point asyncio.create_task() child gets a context copy taken at creation time TraceFilter.filter() record.trace_id = get() once per LogRecord [4bf92f3577b34da6a3ce929d0e0e4736] order accepted · payment authorised handler, spawned task and third-party records all share the one identifier
Middleware writes the trace ID into one slot; every reader downstream — including the filter that stamps library records — pulls from that same slot until teardown resets it.

Prerequisites

contextvars is standard library from Python 3.7, so there is nothing to install for the primitive itself; the examples target Python 3.11 or newer, where asyncio.to_thread and PEP 604 type unions are both available. Only the middleware example needs a third-party package, and it should be pinned rather than installed bare:

pip install "starlette>=0.37.0,<1.0.0"
# pyproject.toml — the same pin, expressed for a real service
[project]
name = "orders-api"
requires-python = ">=3.11,<3.14"
dependencies = [
  "starlette>=0.37.0,<1.0.0",   # only for the ASGI middleware example
]                                # contextvars and logging are stdlib

Two environment inputs are worth wiring up front: a service name, so downstream tooling can label the records, and the header name your edge proxy uses for an explicit identifier, so the middleware is not hard-coded to one deployment.

export OTEL_SERVICE_NAME="orders-api"
export TRACE_HEADER="X-Trace-ID"      # explicit override; traceparent is still honoured

Implementation

The flow has four steps: declare the slot, seed it at the request boundary, read it in a filter, and reset it on teardown.

  1. Declare one module-level ContextVar. Define it once with a None default so every module that imports it shares the same slot and the filter can detect a missing value. Declaring it inside a request handler would create a fresh slot per call and defeat propagation entirely, and a ContextVar created in a loop also leaks, because the runtime never garbage-collects context variable slots.

  2. Seed the value in ASGI middleware. Middleware owns the whole request lifecycle, so it is the right place to extract the inbound identifier and to guarantee the matching reset. Prefer an explicit X-Trace-ID header, then the trace-id segment of a W3C traceparent, and finally a generated UUID so a request is never untraceable.

  3. Read the value in a logging filter. The filter runs once per record, resolves the active value, and attaches it as a LogRecord attribute that the formatter consumes with a %(trace_id)s placeholder. Attach the filter to the handler, not to one logger, so records emitted by third-party libraries through the same handler are tagged too.

  4. Reset on teardown. Reset the variable in a finally block so its value never survives into the next request the worker handles.

The header precedence in step two is deliberate. An explicit X-Trace-ID lets an upstream proxy or test harness pin a known value; the W3C traceparent carries the trace ID propagated by an instrumented caller, sitting in the second hyphen-delimited segment of a 00-<trace-id>-<span-id>-<flags> string; and the UUID fallback guarantees that even an uninstrumented client produces a correlatable request. Preserving an inbound trace ID rather than minting a fresh one is what keeps a single logical operation stitched together as it crosses service boundaries - the same rule that governs context propagation and baggage on the tracing side, applied here to logs.

The middleware seeds and resets the context:

import contextvars
import uuid
from starlette.middleware.base import BaseHTTPMiddleware
from starlette.requests import Request
from starlette.responses import Response

# Declared once, at import time — every module shares this one slot.
trace_id_ctx: contextvars.ContextVar[str | None] = contextvars.ContextVar(
    "trace_id", default=None
)


class TraceMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request: Request, call_next) -> Response:
        # Prefer explicit header, then traceparent's trace-id, then generate.
        traceparent = request.headers.get("traceparent", "")
        parts = traceparent.split("-")            # 00-<trace-id>-<span-id>-<flags>
        inbound = request.headers.get("X-Trace-ID") or (
            parts[1] if len(parts) > 1 else None
        )
        token = trace_id_ctx.set(inbound or uuid.uuid4().hex)  # keep the token
        try:
            return await call_next(request)
        finally:
            trace_id_ctx.reset(token)             # runs on success or exception

Expected behaviour: every request resolves trace_id_ctx to a 32-character W3C trace ID or a generated UUID hex, and teardown unconditionally restores the previous value so no identifier bleeds into the next request.

The reset matters most under connection reuse: a keep-alive worker that skips it starts the next request with the previous request's trace ID still active, and the leak is invisible until two unrelated requests share an ID in your dashboards. Because reset restores the exact prior state rather than clearing the slot, nesting is safe - an inner scope that overrides the trace ID for a sub-operation returns the outer request's value on exit.

The filter stamps that value onto every record, with a fallback for code that runs outside a request:

import logging

# trace_id_ctx is imported from the module above.


class TraceFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        # Resolved per record, so it reflects the coroutine actually emitting.
        record.trace_id = trace_id_ctx.get() or "no-trace"
        return True                                # never drop the record


logger = logging.getLogger("app")
logger.setLevel(logging.INFO)
_handler = logging.StreamHandler()
_handler.setFormatter(logging.Formatter("[%(trace_id)s] %(message)s"))
_handler.addFilter(TraceFilter())                  # on the handler, not the logger
logger.addHandler(_handler)

logger.info("processing step")

Expected Output:

[no-trace] processing step

Inside a request the same line would read [4bf92f3577b34da6a3ce929d0e0e4736] processing step. The no-trace fallback fires only for code emitting outside any request scope, which makes orphaned log lines easy to spot. Attaching the filter to the handler rather than to the app logger is what extends the tag to library records - a database driver or HTTP client logging through the same handler is stamped with the same trace ID, which is exactly what you want when reconstructing a request from mixed sources. The formatter above is deliberately minimal; in production the field belongs in a JSON payload, following the conventions in structured logging with the standard library, and the whole handler/filter wiring can be declared as data via configuring logging with dictConfig.

One request, from set(token) to reset(token) Time runs downward across four participants. ASGI middleware captures a token from trace_id_ctx.set and awaits call_next. The request handler logs the first record, then awaits a task created with create_task, which receives a copy of the context. The worker task logs the second record under the same trace ID and returns. The handler logs a third record and returns the response. The middleware's finally block then calls reset with the captured token, so trace_id_ctx is back to None before the worker picks up the next request. All three records reach the log stream already carrying the same identifier, stamped by TraceFilter. ASGI middleware owns set and reset request handler the request coroutine worker() task spawned mid-request log stream TraceFilter stamps trace_id token = ctx.set('4bf9…') await call_next(request) logger.info('accepted') record 1 · [4bf92f35…4736] await create_task(worker) context copied logger.info('worker') record 2 · [4bf92f35…4736] task returns logger.info('done') record 3 · [4bf92f35…4736] response returned finally: reset(token) trace_id_ctx is back to None before this worker accepts the next request
The token is captured and reset in the same scope; everything between the two reads one value, including the task spawned halfway through.

Coroutines spawned during the request inherit the value with no extra work, because asyncio copies the context when it creates a task:

import asyncio
import logging

# trace_id_ctx and the configured logger from above.


async def worker() -> None:
    logging.getLogger("app").info("inside spawned task")


async def main() -> None:
    trace_id_ctx.set("req-abc-123")
    await asyncio.create_task(worker())  # task inherits the context snapshot


if __name__ == "__main__":
    asyncio.run(main())

Expected Output:

[req-abc-123] inside spawned task

The copy is one-directional and shallow: the child task sees the parent's values at creation time, but a set() inside the task is invisible to the parent, and a value set in the parent after the task was created never reaches it. Seed the trace ID before you fan out, never after.

Crossing thread, executor, and process boundaries

The automatic copy is a property of asyncio.Task creation, not of concurrency in general, so every other boundary needs an explicit decision.

A raw ThreadPoolExecutor.submit or loop.run_in_executor runs the callable under whatever context the worker thread already had - usually empty - so the trace ID silently becomes no-trace. There are two correct fixes. asyncio.to_thread copies the caller's context for you and is the right default in async code. When you are outside a loop, or need the same snapshot for several submissions, take it yourself:

import contextvars
from concurrent.futures import ThreadPoolExecutor


def blocking_work() -> str | None:
    return trace_id_ctx.get()          # reads the snapshot, not the thread's own context


def offload(pool: ThreadPoolExecutor) -> str | None:
    ctx = contextvars.copy_context()   # snapshot taken in the calling context
    return pool.submit(ctx.run, blocking_work).result()

Expected Output: offload returns the caller's trace ID; replacing ctx.run with a bare pool.submit(blocking_work) returns None, which the filter then renders as no-trace.

Generators and async generators capture context at the point they are resumed, not where they were defined, so a generator built inside one request and consumed inside another logs under the consumer's trace ID. Materialise the values, or bind the ID explicitly into the payload, before handing a generator across a request boundary.

Processes inherit nothing at all: neither fork nor spawn keeps a live link to the parent's context, so the identifier has to travel as an argument and be re-established in the child, as covered in thread-safe logging in multiprocessing. The same reasoning applies to background workers - schedulers, queue consumers, retry loops - which have no request to inherit from and should set their own trace ID at the start of each unit of work and reset it when that unit finishes. Relying on the no-trace default there produces a stream of uncorrelatable log lines exactly when an incident makes correlation most valuable.

For synchronous WSGI servers the principle holds but the finally lives in different machinery: wrap the application callable so the set happens before dispatch and the reset happens in a finally around the response iterator, or register a teardown callback the framework guarantees to run before the worker returns to the pool.

Which boundaries carry the context, and which need an explicit snapshot Five branches from one question about where the offloaded work runs. An asyncio task created with create_task or a TaskGroup gets the context copied automatically at creation. asyncio.to_thread also runs the call in a copy of the caller's context. A raw ThreadPoolExecutor submit or run_in_executor copies nothing, so the callable must be submitted as ctx.run from a contextvars.copy_context snapshot or its records fall back to no-trace. A generator resumed in another request or task reads context at resume time rather than at definition, so the identifier must be rebound or materialised first. A process or queue boundary such as fork, spawn, Celery or cron inherits nothing at all, so the trace ID has to travel as an argument and be set again in the child. Work leaves the current coroutine — how? the answer decides whether the trace ID follows asyncio task create_task() TaskGroup asyncio.to_thread the default way to offload blocking work executor.submit run_in_executor or a raw thread pool generator resumed in another request or task process or queue fork, spawn, Celery, RQ, cron worker Copied asyncio snapshots the context when it creates the task Copied to_thread runs the call inside a copy of the caller's context Not copied submit ctx.run from copy_context(), else records read no-trace Bound too late context is read where it resumes — rebind or materialise first Nothing inherits pass the trace ID as an argument and set it again in the child
Only the two asyncio-owned boundaries copy context for you; the other three need the identifier carried across by hand.

Configuration options

Decision Option Recommended Reason
Default value None vs sentinel string None Lets the filter detect a miss and substitute a fallback
Identifier source header vs generated header first, UUID fallback Preserves an upstream trace, never leaves a request untagged
Read site filter vs formatter filter Decouples context resolution from output format, reusable across handlers
Filter attachment logger vs handler handler Tags third-party records that share the handler, not just your own
Reset site finally vs none finally Guarantees reset on exception, prevents cross-request bleed
Thread pool raw submit vs copy_context() copy_context() or asyncio.to_thread Thread pools do not inherit the caller's context

Verification

Confirm propagation with a test that asserts a spawned task observes the parent's trace ID and that teardown clears it:

import asyncio
import contextvars

trace_id_ctx: contextvars.ContextVar[str | None] = contextvars.ContextVar(
    "trace_id", default=None
)


async def child() -> str | None:
    return trace_id_ctx.get()


async def main() -> None:
    token = trace_id_ctx.set("req-abc-123")
    try:
        seen = await asyncio.create_task(child())
        assert seen == "req-abc-123", seen          # inheritance across task creation
    finally:
        trace_id_ctx.reset(token)
    assert trace_id_ctx.get() is None               # teardown restored the default
    print("propagation OK")


if __name__ == "__main__":
    asyncio.run(main())

Expected Output:

propagation OK

Run the mirror-image assertion for offloaded work: a ThreadPoolExecutor task must read the caller's value after an explicit copy_context() and must read None without one. Asserting both directions is what stops the test from passing for the wrong reason on a single-worker pool that happened to reuse the calling thread.

What a dropped context looks like in the log stream Two stdout excerpts from the same request. On the left, the offloaded work was run through asyncio.to_thread or ctx.run, so all four records — request accepted, db query, the pool worker's pdf render, and the response — carry the identifier 4bf92f35 through 4736. On the right, the same work was handed to a bare pool.submit call, so the third record reads no-trace while the other three still carry the trace ID, leaving one orphaned line that no dashboard can join back to the request. asyncio.to_thread(...) — the ID survives pool.submit(fn) — the ID is lost stdout — one request, four records [4bf92f35…4736] request accepted [4bf92f35…4736] db query 12ms [4bf92f35…4736] pdf render (pool) [4bf92f35…4736] response 200 the pool worker ran inside a copy of the caller's context, so the filter still resolves it stdout — same request, raw executor [4bf92f35…4736] request accepted [4bf92f35…4736] db query 12ms [no-trace] pdf render (pool) [4bf92f35…4736] response 200 one orphaned line: the sentinel inside a request is the precise signal that a boundary was crossed
The sentinel is the assertion: a no-trace record emitted inside a request names both the bug and the boundary that caused it.

A cheap continuous check is to assert in CI that no log line escapes with the no-trace sentinel during a request-path test. Pipe the structured output through a parser and fail the test if any record produced inside a simulated request carries the fallback value. Because the fallback only appears outside request scope, its presence inside one is a precise signal that a boundary was crossed without propagation - a missing middleware, a thread pool without copy_context(), or a generator that captured context too early. Treating the sentinel as a test assertion rather than just a log convenience turns propagation bugs into build failures instead of incident-time surprises. The same trace ID should also appear on the trace side of your pipeline; if it does not, reconcile the mapping described in adding trace IDs to log records before trusting either signal.

Common mistakes

  • Error signature: ValueError: <Token ...> was created in a different Context, raised from the reset call. Root cause: the token was captured in one context and reset in another - typically a set() whose return value was discarded and reconstructed later, or a reset performed after an await moved execution into a different task. Remediation: capture the token in the same scope as the set and reset it in that scope's finally; never pass a token across a task boundary, and never store one on a shared object.

  • Error signature: trace IDs mismatch between concurrent requests, with one request's ID appearing on another's log lines. Root cause: request state was stored in threading.local(), which has one slot per OS thread while asyncio multiplexes many requests onto a single thread. Remediation: replace every threading.local() in the request path with a ContextVar; the read cost is comparable and correctness under a shared event loop is restored.

  • Error signature: log lines from the first few requests after a restart look fine, then every subsequent request logs under a stale identifier. Root cause: the middleware set the variable but skipped the reset, so a keep-alive worker began the next request with the previous request's value still active. Remediation: wrap the mutation in try/finally in the middleware itself, and add the teardown assertion from the verification section so the leak fails a test rather than a dashboard.

  • Error signature: records emitted from a run_in_executor call, or from a blocking database driver, carry the no-trace sentinel while the surrounding request is tagged correctly. Root cause: the executor boundary was crossed without a context snapshot. Remediation: switch to asyncio.to_thread, or submit ctx.run from a contextvars.copy_context() snapshot as shown above. If the offloaded work is only slow because of logging I/O, moving the handler behind non-blocking logging with QueueHandler removes the need to offload it at all.

Frequently Asked Questions

Does contextvars work with ThreadPoolExecutor?

Yes, but not automatically. Asyncio copies context for tasks it creates, but a thread pool does not. Snapshot the active context with copy_context() and run the offloaded callable through ctx.run() so the worker thread reads the caller's trace ID.

How do I handle a missing trace ID in a background task?

Give the ContextVar a None default and have the logging filter substitute a deterministic fallback such as a generated UUID when it reads None. Background workers that start outside any request should set their own trace ID at task entry rather than inheriting one.

Is there performance overhead compared with threading.local?

It is negligible for reads. A ContextVar get() is an O(1) lookup against an immutable mapping and adds well under a microsecond, with no GIL-contention penalty. The set() call is the costlier operation, so set once per request rather than per log line.

Should I read the trace ID in the formatter or in a filter?

Use a filter. The filter runs once per record and attaches the value as a LogRecord attribute that the formatter string then consumes with a placeholder. Reading context directly in the formatter couples context resolution to output formatting and breaks reuse across handlers.