Skip to content

Correlating Logs and Traces with Request IDs

When two requests interleave on one event loop, their log lines interleave too, and without an identifier on each line there is no way to tell them apart. A request id and a trace id on every log record — set once at the start of the request, read by a logging filter — fixes that and links each line to its trace. Context variables make it work across awaits and tasks, with exceptions that matter. Tested with two concurrent requests, a contextvars.ContextVar for the request id and an OpenTelemetry span: log lines from the handler, from a child task, from asyncio.to_thread and from a call_soon callback all carried the right request id and trace id; lines from loop.run_in_executor and from a plain threading.Thread carried none. This guide wires up the ids, makes them survive every boundary, and links logs to traces in the backend.

Prerequisites

1. Put the ids in context, and read them in a logging filter

Set the request id once, at the edge of the request, in a context variable; a logging filter copies it — and the current trace id — onto every record:

import contextvars
import logging

from opentelemetry import trace

request_id: contextvars.ContextVar[str] = contextvars.ContextVar("request_id", default="-")


class ContextFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id.get()
        ctx = trace.get_current_span().get_span_context()
        record.trace_id = format(ctx.trace_id, "032x") if ctx.is_valid else "-"
        record.span_id = format(ctx.span_id, "016x") if ctx.is_valid else "-"
        return True


handler = logging.StreamHandler()
handler.addFilter(ContextFilter())
handler.setFormatter(logging.Formatter(
    "%(asctime)s %(levelname)s request_id=%(request_id)s trace_id=%(trace_id)s %(message)s"))
logging.getLogger().addHandler(handler)

Attach the filter to the handler, not a logger, so records from every library's logger get the ids. OpenTelemetry stores the current span in a context variable too, so both ids follow the same rules. Tested: two interleaved requests' handler lines each carried their own request id and trace id.

Verify: under concurrent load, grepping logs for one request id returns a complete, coherent request with no lines from others.

2. Set the request id at the boundary

The edge of the request — ASGI middleware, a message consumer's per-message handler — sets the id, preferring one supplied by the caller so ids join up across services:

class RequestIdMiddleware:
    def __init__(self, app) -> None:
        self.app = app

    async def __call__(self, scope, receive, send) -> None:
        if scope["type"] != "http":
            return await self.app(scope, receive, send)
        incoming = dict(scope["headers"]).get(b"x-request-id", b"").decode()
        rid = incoming if 0 < len(incoming) <= 64 and incoming.isprintable() else uuid.uuid4().hex
        token = request_id.set(rid)
        try:
            await self.app(scope, receive, send)
        finally:
            request_id.reset(token)

Validate incoming ids — length and characters — before putting them into every log line. Resetting with the token keeps the variable correct for anything that runs after the request in the same task. When tracing is enabled, the trace id already identifies the request across services; the request id remains useful for systems without tracing and for humans quoting an id from an error page. The middleware pattern is in writing pure ASGI middleware.

Verify: a request sent with X-Request-ID: abc123 produces log lines with request_id=abc123, and one without gets a generated id.

Does the request id reach this code? A grid of 6 rows by 3 columns. Does the request id reach this code? where the log line was written request id trace id handler coroutine correct correct child task (create_task) correct correct asyncio.to_thread(...) correct correct loop.call_soon callback correct correct loop.run_in_executor(...) missing missing threading.Thread(...) missing missing Python 3.14, two interleaved requests; to_thread copies context, run_in_executor does not.

3. Carry context across thread boundaries

Tasks copy the current context when they are created, and so do asyncio.to_thread and loop callbacks. loop.run_in_executor and threads you start yourself do not:

import contextvars
import functools

# Loses context (tested): no request id in the worker's log lines
await loop.run_in_executor(executor, render_report, params)

# Keeps context: to_thread copies it for you (default executor only)
await asyncio.to_thread(render_report, params)

# Keeps context with a custom executor: run inside a copy of the current context
ctx = contextvars.copy_context()
await loop.run_in_executor(executor, functools.partial(ctx.run, render_report, params))

Tested: run_in_executor and a plain threading.Thread both logged without ids, while to_thread logged them correctly. Wrapping the callable in copy_context().run is the general fix for custom executors and threads. Process pools are a harder boundary — context variables are not pickled — so pass the ids explicitly as arguments and set them in the worker.

Verify: a log line written inside each kind of offloaded work carries the request id, checked in a test that runs two requests concurrently.

With the trace id on every line, a logging backend can jump from a log line to its trace and from a span to its logs. Emit structured logs so the ids are fields, not text:

import json


class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        return json.dumps({
            "ts": self.formatTime(record),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
            "request_id": getattr(record, "request_id", "-"),
            "trace_id": getattr(record, "trace_id", "-"),
            "span_id": getattr(record, "span_id", "-"),
        })

Field names matter: most backends recognise trace_id and span_id (or the OpenTelemetry trace_id attribute when logs are exported through the OpenTelemetry logs pipeline) and build the cross-links from them. The opentelemetry-instrumentation-logging package injects the same fields automatically if you prefer not to maintain the filter. Structured logging setup is covered in structured logging for async services.

Verify: from a log line in the backend, the "view trace" link opens the request's trace, and the trace view lists that request's logs.

From incoming request to correlated log line A flow of 5 stages. From incoming request to correlated log line middleware set request_id contextvar tracing span in context tasks, to_thread context copied logging filter ids onto every record backend log <-> trace links Set once, read everywhere, preserved across every boundary you control.

5. Propagate ids to downstream calls

Correlation across services needs the ids on outgoing requests as well. With OpenTelemetry instrumentation, trace context is injected automatically; add the request id header yourself:

import httpx


async def add_request_id(request: httpx.Request) -> None:
    request.headers.setdefault("X-Request-ID", request_id.get())


client = httpx.AsyncClient(event_hooks={"request": [add_request_id]})

The event hook runs inside the calling task's context, so it sees the current request's id. Downstream services set their own context from the header, and a single id then appears in the logs of every service a request touched. Automatic trace-context injection for httpx and aiohttp is covered in instrumenting httpx and aiohttp with OpenTelemetry.

Verify: one request id from the edge appears in the logs of every downstream service it called.

How does context reach this code path? A decision on Where does the code run with 4 outcomes. How does context reach this code path? Where does the code run? same task or child task automatic context copied at create_task asyncio.to_thread automatic copies context run_in_executor / Thread copy_context().run otherwise lost process pool, other service pass ids explicitly args or headers Context follows asyncio's own scheduling; everything else needs help.

Verification

Logs and traces are correlated when:

  • Every log record carries request and trace ids from a handler-level filter.
  • Ids are set at the boundary from validated incoming headers or generated.
  • Thread and process boundaries preserve ids through to_thread, copy_context().run or arguments.
  • Outgoing calls propagate ids, and the backend links logs and traces.

Diagnostic Hook: measure the share of log lines with request_id="-" during request handling. A non-zero share points at code paths that lost context — most often run_in_executor or a thread started by a library — and the lines themselves show which code path it is.

Pitfalls & edge cases

  • run_in_executor without copy_context. Tested: ids missing.
  • Filters on loggers instead of handlers. Third-party loggers' records miss the ids.
  • Untrusted incoming ids. Validate length and characters.
  • Text-only log formats. Backends cannot link what they cannot parse as fields.

Frequently Asked Questions

How do I add a request ID to every log line in asyncio?

Store it in a contextvars.ContextVar at the start of each request and add a logging.Filter to your handler that copies it onto every record. Tasks created during the request inherit it.

Why is the request ID missing in logs from run_in_executor?

loop.run_in_executor does not copy the context into the worker thread; asyncio.to_thread does. In testing, run_in_executor lines had no ids. Wrap the call in contextvars.copy_context().run.

How do I add the OpenTelemetry trace ID to Python logs?

In a logging filter, read trace.get_current_span().get_span_context() and format trace_id and span_id onto the record, or use opentelemetry-instrumentation-logging.

How do I pass a request ID to downstream services?

Add an X-Request-ID header from the context variable in an httpx event hook or aiohttp trace hook; OpenTelemetry instrumentation propagates the trace context separately.