Python Observability

structlog in asyncio Services

structlog's bound context is what makes it pleasant — bind a request identifier once, and every event in that request carries it. Under asyncio, where hundreds of requests interleave on one thread, that context has to follow each task rather than the thread, and output has to stay off the event loop. This page covers the contextvars integration that makes context task-local, the reset that keeps it from leaking between requests, the output arrangement that never blocks the loop, and when structlog's async methods are worth using. It is a task article under structlog architecture and setup, part of the modern Python logging libraries deep dive section, and it builds on binding context variables in structlog.

Context that follows the task, not the thread Three requests are handled concurrently on a single event loop thread, their coroutines interleaving as each awaits I/O. In the first arrangement, bound context is stored per thread. Request A binds its request identifier; while A awaits a database call, request B runs on the same thread and binds its own identifier, overwriting A's. When A resumes and logs, its record carries B's identifier. Every record is attributed to whichever request most recently bound context, which is effectively random. In the second arrangement, context is stored in context variables, which asyncio copies per task. Each request's task has its own context, so A's records carry A's identifier regardless of how the coroutines interleave, and a child task spawned by A inherits a copy of A's context. The note records that the thread-local version produces records that look correct and are wrong, which is worse than missing context. three requests interleaving on one loop thread context per thread A binds B binds C binds A logs → says C every record carries whoever bound last — plausible-looking and wrong context per task (contextvars) A binds B binds C binds A logs → says A each task has its own copy; child tasks inherit a snapshot of their parent's wrong context is worse than missing context — it sends an investigation to the wrong request
Under asyncio the thread is shared by every request. Context has to belong to the task, which is exactly what context variables provide.

Prerequisites

pip install "structlog>=24.1.0,<26.0.0"

Implementation

Step 1 — Configure the processor chain with merge_contextvars first. structlog's contextvars integration stores bound fields in a context variable, which asyncio copies for every task. Putting the merge processor first in the chain means every event picks up whatever the current task has bound, before any other processor sees it.

import logging
import structlog

structlog.configure(
    processors=[
        structlog.contextvars.merge_contextvars,          # 1. task-local context first
        structlog.stdlib.add_log_level,
        structlog.stdlib.add_logger_name,
        structlog.processors.TimeStamper(fmt="iso", utc=True),
        structlog.processors.StackInfoRenderer(),
        structlog.processors.format_exc_info,
        structlog.stdlib.ProcessorFormatter.wrap_for_formatter,
    ],
    logger_factory=structlog.stdlib.LoggerFactory(),
    wrapper_class=structlog.stdlib.BoundLogger,
    cache_logger_on_first_use=True,
)

Step 2 — Bind and clear at the request boundary. Middleware binds request-scoped fields at the start of each request, after clearing anything left over. The clear matters because some servers reuse tasks or run requests in contexts that are copied from a long-lived parent; without it, a field bound in one request can be visible in the next.

import uuid
from starlette.middleware.base import BaseHTTPMiddleware

class StructlogContextMiddleware(BaseHTTPMiddleware):
    async def dispatch(self, request, call_next):
        structlog.contextvars.clear_contextvars()          # 2. nothing from before
        structlog.contextvars.bind_contextvars(
            request_id=request.headers.get("x-request-id") or uuid.uuid4().hex,
            route=request.scope.get("route").path if request.scope.get("route") else request.url.path,
            method=request.method,
        )
        return await call_next(request)

Step 3 — Rely on inheritance for child tasks. A task created inside a request handler gets a copy of the context as it was at creation. Fields bound in the child stay in the child. This is what makes fan-out with asyncio.gather or a TaskGroup produce correctly attributed records without any extra work, and it is also why binding a field in the parent after creating a child does not reach the child.

log = structlog.get_logger("quotes")

async def fetch_price(sku: str):
    structlog.contextvars.bind_contextvars(sku=sku)        # child-only
    log.info("price fetched")

async def build_quote(skus: list[str]):
    log.info("building quote", item_count=len(skus))
    async with asyncio.TaskGroup() as tg:
        for sku in skus:
            tg.create_task(fetch_price(sku))

Expected Output: each child's records carry the request's context and their own field.

{"event": "building quote", "item_count": 2, "request_id": "9c1f4e7a", "route": "/quotes", "method": "POST", "level": "info"}
{"event": "price fetched", "sku": "A1", "request_id": "9c1f4e7a", "route": "/quotes", "method": "POST", "level": "info"}
{"event": "price fetched", "sku": "B7", "request_id": "9c1f4e7a", "route": "/quotes", "method": "POST", "level": "info"}

Step 4 — Keep the write off the loop. The processor chain runs on the calling task, and so does the final write unless something moves it. Routing structlog through the standard library — as the configuration above does with wrap_for_formatter — and giving the standard library a queue handler means the loop only enqueues, and a slow sink stalls a listener thread instead of every coroutine. The mechanics are in logging from asyncio tasks without blocking.

import queue
from logging.handlers import QueueHandler, QueueListener

formatter = structlog.stdlib.ProcessorFormatter(processor=structlog.processors.JSONRenderer())
out = logging.StreamHandler(); out.setFormatter(formatter)

q: "queue.Queue[logging.LogRecord]" = queue.Queue(maxsize=10_000)
QueueListener(q, out, respect_handler_level=True).start()
logging.getLogger().handlers = [QueueHandler(q)]
logging.getLogger().setLevel(logging.INFO)

Step 5 — Use the async methods selectively. structlog offers awaitable logging methods — await log.ainfo(...) — that run the processor chain in a thread pool. They are useful when processors are genuinely expensive: a redaction pass over large payloads, a lookup in a slow structure. For an ordinary chain they add thread-pool scheduling to every log call, which costs more than the chain itself. The default should be the synchronous methods with a queue handler behind them.

What runs on the loop A structlog call in an async handler is broken into three parts. The processor chain — merging context, adding the level and timestamp, formatting exceptions — runs on the calling task, on the loop thread, and typically costs a few microseconds. Handing the event to the standard library and enqueueing it in a QueueHandler also runs on the loop and costs microseconds. Rendering to JSON and writing to the sink runs on the listener thread, where a slow sink stalls only that thread. A second row shows the same call with a plain StreamHandler, where the rendering and the write both happen on the loop thread, so a stalled pipe blocks every coroutine in the process. A third row shows the async method, where the processor chain moves to a thread pool at the cost of scheduling overhead that exceeds the chain's own cost for typical processors. where each part of a log call runs queue handler processors enqueue render + write — listener thread loop: µs only plain StreamHandler processors render + write — on the loop a slow pipe stalls all await log.ainfo() thread handoff processors worth it only for expensive processors the default: synchronous calls, cheap processors, a queue handler behind them the loop pays microseconds per call, and nothing the sink does can stall it
The queue moves the one potentially slow step off the loop. The async methods move the cheap steps off it, which usually costs more than it saves.

Context that must cross a boundary

Context variables follow tasks automatically. They do not follow work to places asyncio does not manage, and three such boundaries come up regularly.

Thread pools. asyncio.to_thread copies the current context into the worker thread, so structlog's bound fields are present in records logged from the function it runs. A plain ThreadPoolExecutor.submit does not; records logged there have no request context unless it is captured at submission and attached inside the worker, as described in propagating context across thread and process pools.

Callbacks scheduled outside a task. Callbacks registered with loop.call_soon or loop.call_later run with the context that was current when they were scheduled, which is usually what is wanted. Callbacks registered by libraries on long-lived objects — a connection's close handler, a pool's eviction callback — run with whatever context was current when the library registered them, which may be a different request or none. Records from those callbacks should carry context explicitly rather than relying on bound fields.

Background tasks that outlive the request. A task created during a request and left running after it returns keeps a copy of the request's context. That is correct for work genuinely belonging to the request, such as an audit write, and wrong for work that becomes independent, such as a cache refresh triggered by the request. Clearing context at the start of such a task, and binding what actually describes it, prevents its records being attributed to a request that finished long ago.

In each case the principle is the same as for any context propagation: bound fields describe the current unit of work, and whenever work crosses into something with a different lifetime, the context should be set deliberately for the new unit rather than inherited by accident.

Adding trace context alongside bound fields

A structlog service that is also traced benefits from carrying the trace and span identifiers on every event, and the processor chain is the natural place to add them.

A small processor that reads the current span and adds its identifiers to the event dictionary does the job. Because it runs on the calling task, it sees the span that is current for that task, which under asyncio is exactly the request's span — the same property that makes context variables work for bound fields. Placing it after merge_contextvars and before rendering means every event, from every coroutine, carries the identifiers of the span it was logged in.

from opentelemetry import trace

def add_trace_context(logger, method_name, event_dict):
    ctx = trace.get_current_span().get_span_context()
    if ctx.is_valid:
        event_dict["trace_id"] = f"{ctx.trace_id:032x}"
        event_dict["span_id"] = f"{ctx.span_id:016x}"
    return event_dict

There is a subtle ordering benefit. Because this processor runs before the event is enqueued, the identifiers are captured on the loop at the moment of the call, not later on the listener thread where the current span would be different or absent. That is the same reason bound context is merged first. Any processor that reads task-local state must run before the handoff to the queue, and only the rendering and writing should happen after it.

The same pattern extends to anything else that lives in the task's context: a tenant identifier from baggage, a feature flag evaluated for the request, a deadline. Reading them in a processor before the queue keeps them correctly attributed without any call site needing to pass them.

Where bound context survives A table of places code runs in an asyncio service and whether structlog context bound with bind_contextvars is visible there. In the request's own coroutine: yes. In tasks created with asyncio.create_task during the request: yes, because the task copies the context at creation. In asyncio.to_thread calls: yes, the context is copied into the thread. In a run_in_executor call on a thread pool: no, unless the callable is wrapped with copy_context().run. In a background task created at startup, before any request: no, it carries only the startup context. The note says context follows task creation, so work created outside the request never sees request fields. where the code runs sees request context? the request coroutine yes create_task during the request yes · copied at creation asyncio.to_thread yes · copied into the thread loop.run_in_executor no · wrap with copy_context().run task started at startup no · has startup context only context follows task creation — work created outside the request never sees it
Context variables are copied when a task is created. Anything started before the request, or handed to a plain executor, misses it.

Configuration options

Setting Value Why
First processor merge_contextvars every event gets the task's context
Binding bind_contextvars in middleware request fields on every event
Reset clear_contextvars at request start no leakage between requests
Child tasks inherit a copy automatically fan-out records attributed correctly
Output stdlib QueueHandler the sink never blocks the loop
Async methods only for expensive processors scheduling overhead otherwise
cache_logger_on_first_use True avoids rebuilding loggers per call

Verification

Run two concurrent requests that interleave and confirm each record carries its own request's context.

import asyncio, structlog
from structlog.testing import capture_logs

async def request(rid: str):
    structlog.contextvars.clear_contextvars()
    structlog.contextvars.bind_contextvars(request_id=rid)
    await asyncio.sleep(0)                 # force interleaving
    structlog.get_logger().info("step")

async def main():
    with capture_logs(processors=[structlog.contextvars.merge_contextvars]) as logs:
        await asyncio.gather(request("A"), request("B"))
    return {entry["request_id"] for entry in logs}

print(asyncio.run(main()))

Expected Output: each request's record carries its own identifier.

{'A', 'B'}

A result of {'B'} means context is being stored somewhere shared rather than per task.

Common mistakes

Thread-local context under asyncio. Error signature: records attributed to the wrong request. Root cause: context stored per thread, and every request shares the loop thread. Remediation: use the contextvars integration.

No reset at request start. Error signature: fields from a previous request appearing in a new one. Root cause: context carried across by a reused task. Remediation: clear at the start of each request.

A synchronous handler on the loop. Error signature: every endpoint slowing when the log sink slows. Root cause: rendering and writing on the loop thread. Remediation: a queue handler.

Async methods by default. Error signature: logging overhead higher than expected. Root cause: thread-pool scheduling on every call for a cheap chain. Remediation: synchronous methods unless processors are expensive.

Binding in the parent after creating children. Error signature: a field missing from child task records. Root cause: children copy context at creation. Remediation: bind before creating the tasks that need it.

Frequently Asked Questions

Is structlog safe to use in asyncio?

Yes, provided bound context is stored in context variables rather than in thread-local storage or a shared logger instance. The contextvars integration does exactly that, and each asyncio task gets its own copy of the context.

Do child tasks inherit bound context?

They inherit a copy of the context as it was when the task was created. Fields bound in the child do not affect the parent, and fields bound in the parent after the child was created do not appear in the child.

Can structlog block the event loop?

The processor chain runs on the calling task, so expensive processors cost loop time, and the final write blocks if the sink is slow. Routing output through a standard library queue handler removes the write from the loop; keeping processors cheap handles the rest.

Should I use the async logging methods?

Only when the processor chain itself is expensive enough to matter. They run the chain in a thread pool and await it, which adds scheduling overhead to every call. For a typical chain of timestamping, context merging and rendering, the synchronous methods with a queue handler are faster.

Related Guides