structlog Processors and Pipelines
A structlog configuration is a list of functions, and almost every problem with one is an ordering problem: a field missing because it was read before it was added, a drop that fires too late to save any work, a renderer that is not actually last. This guide is for engineers who have structlog running and now need the chain to be deliberate. It is part of the modern Python logging libraries deep dive section, and it builds on structlog architecture and setup.
The contract is small enough to state in one line: a processor takes (logger, method_name, event_dict) and returns an event_dict — except the last one, which returns something the underlying logger can be called with.
Prerequisites
pip install "structlog>=24.1.0,<26.0.0" \
"orjson>=3.10.0,<4.0.0"
export LOG_RENDERER=json # json in production, console in development
Concept and architecture
structlog splits the work into three layers, and knowing which layer a problem lives in resolves most confusion.
The bound logger is what your code holds. structlog.get_logger() returns a lazy proxy; the first call resolves the configuration and, with cache_logger_on_first_use=True, freezes it onto that logger. log.bind(order_id=8812) returns a new bound logger carrying that key — binding is immutable, which is why a bound value cannot leak between requests unless you deliberately share the logger object.
The processor chain is the list you configure. Each entry is called in order with the event dict, and the dict it returns is what the next one sees. Processors are ordinary functions: there is no registry, no decorator, no base class.
The renderer is the final processor and behaves differently: it returns a string (or an (args, kwargs) pair) that is passed to the wrapped logger — PrintLogger, a stdlib logger through structlog.stdlib.LoggerFactory, or anything else. Once it has run, the record is no longer a dict.
That last point explains the most common structural mistake. A processor appended after the renderer never runs, and structlog cannot warn you about it, because a renderer is just a processor that happens to return a string.
Step-by-step implementation
Step 1 — Order the chain by what each processor needs to see. Enrichment first, filtering after the fields it filters on, rendering last.
import logging
import structlog
structlog.configure(
processors=[
structlog.contextvars.merge_contextvars, # request/trace ids first
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level, # 'level' must exist before any filter
structlog.processors.TimeStamper(fmt="iso", utc=True),
structlog.processors.StackInfoRenderer(),
structlog.processors.format_exc_info, # exc_info -> 'exception' string
drop_health_checks, # a filter, after the fields it reads
structlog.processors.EventRenderer if False else structlog.processors.JSONRenderer(),
],
wrapper_class=structlog.make_filtering_bound_logger(logging.INFO),
logger_factory=structlog.PrintLoggerFactory(),
cache_logger_on_first_use=True,
)
make_filtering_bound_logger is worth understanding separately: it discards below-level calls before the chain runs at all, which is far cheaper than a processor that raises DropEvent halfway through. Use it for level filtering and reserve DropEvent for decisions that depend on the event's content.
Step 2 — Write processors that respect the contract. Three arguments, return the dict. Raise DropEvent to discard.
import structlog
def drop_health_checks(logger, method_name: str, event_dict: dict) -> dict:
"""Discard the access records for probe endpoints — they are pure volume."""
if event_dict.get("route") in {"/healthz", "/readyz"} and event_dict.get("status") == 200:
raise structlog.DropEvent
return event_dict
def add_service_metadata(logger, method_name: str, event_dict: dict) -> dict:
event_dict.setdefault("service", "checkout-api")
event_dict.setdefault("version", "2026.8.1")
return event_dict
setdefault rather than assignment is deliberate: a caller who bound an explicit service value should win over the default. Processors that overwrite what the call site provided are a recurring source of confusion.
Step 3 — Converge stdlib records onto the same renderer. Your dependencies use logging. ProcessorFormatter is a stdlib Formatter that runs a structlog chain, so both worlds end in the same JSON shape.
import logging.config
import structlog
shared = [ # runs for BOTH structlog and stdlib records
structlog.contextvars.merge_contextvars,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt="iso", utc=True),
]
structlog.configure(
processors=shared + [structlog.stdlib.ProcessorFormatter.wrap_for_formatter],
logger_factory=structlog.stdlib.LoggerFactory(),
cache_logger_on_first_use=True,
)
formatter = structlog.stdlib.ProcessorFormatter(
foreign_pre_chain=shared, # applied to records that came from logging
processors=[
structlog.stdlib.ProcessorFormatter.remove_processors_meta,
structlog.processors.JSONRenderer(),
],
)
handler = logging.StreamHandler()
handler.setFormatter(formatter)
logging.getLogger().addHandler(handler)
logging.getLogger().setLevel(logging.INFO)
The two halves have to agree. wrap_for_formatter ends the structlog chain by packaging the event dict for the formatter instead of rendering it; foreign_pre_chain gives records that originated in logging the same enrichment before they meet the shared renderer. Miss the second and library records arrive without timestamps or levels while your own records have both.
foreign_pre_chain, those records reach the renderer with none of the fields your queries assume.Step 4 — Bind context where it belongs. structlog.contextvars holds ambient values that survive await boundaries; bind() holds values on a specific logger object. Use the first for request-scoped identity and the second for a value that belongs to one code path.
import structlog
structlog.contextvars.clear_contextvars() # start of request
structlog.contextvars.bind_contextvars(request_id="r-9f3c") # visible to every log call
log = structlog.get_logger(__name__).bind(component="checkout") # this code path only
log.info("order accepted", order_id=8812)
Clearing at the start of each request is not optional under a threaded or pooled server: contextvars persist for the life of the context, and a worker thread reused by the next request will otherwise carry the previous one's identity.
Configuration reference
| Setting | Type | Default | Production value |
|---|---|---|---|
processors |
list | console-oriented default | enrichment → filters → renderer |
wrapper_class |
class | BoundLogger |
make_filtering_bound_logger(INFO) |
logger_factory |
callable | PrintLoggerFactory |
stdlib.LoggerFactory when sharing with logging |
cache_logger_on_first_use |
bool |
False |
True |
TimeStamper(fmt=…) |
str | none | "iso" with utc=True |
format_exc_info |
processor | absent | present, before the renderer |
foreign_pre_chain |
list | none | the shared enrichment list |
JSONRenderer(serializer=…) |
callable | json.dumps |
orjson.dumps at volume |
Async and concurrency considerations
structlog.contextvars is backed by contextvars, so it behaves exactly like the standard-library mechanism described in using contextvars for request tracing: a task created with create_task inherits a copy of the context at creation time, and values set afterwards do not reach it.
The processor chain itself is synchronous and runs on the calling thread, which means the renderer and the underlying write happen there too. Under asyncio, that puts a slow sink on the event loop, and the fix is the same as for the standard library — a queue in front. With stdlib.LoggerFactory, that is just a QueueHandler, which is one more argument for routing structlog through logging rather than around it.
Binding is thread-safe because it is immutable: bind() returns a new logger and never mutates the one you called it on. bind_contextvars, by contrast, mutates the current context, which is exactly what you want per request and exactly what you must clear between requests.
Production code examples
A complete configuration for a service that emits JSON in production and readable output in development, with both structlog and stdlib records sharing the pipeline.
# observability/log.py
import logging
import logging.config
import os
import orjson
import structlog
def _orjson_dumps(obj, default) -> str:
return orjson.dumps(obj, default=default).decode()
SHARED = [
structlog.contextvars.merge_contextvars,
structlog.stdlib.add_logger_name,
structlog.stdlib.add_log_level,
structlog.processors.TimeStamper(fmt="iso", utc=True),
structlog.processors.StackInfoRenderer(),
structlog.processors.format_exc_info,
]
def configure() -> None:
dev = os.environ.get("LOG_RENDERER", "json") == "console"
renderer = (
structlog.dev.ConsoleRenderer(colors=True) if dev
else structlog.processors.JSONRenderer(serializer=_orjson_dumps)
)
structlog.configure(
processors=SHARED + [structlog.stdlib.ProcessorFormatter.wrap_for_formatter],
logger_factory=structlog.stdlib.LoggerFactory(),
wrapper_class=structlog.make_filtering_bound_logger(logging.INFO),
cache_logger_on_first_use=True,
)
logging.config.dictConfig({
"version": 1,
"disable_existing_loggers": False,
"formatters": {
"structlog": {
"()": structlog.stdlib.ProcessorFormatter,
"foreign_pre_chain": SHARED,
"processors": [
structlog.stdlib.ProcessorFormatter.remove_processors_meta,
renderer,
],
},
},
"handlers": {"stdout": {"class": "logging.StreamHandler", "formatter": "structlog"}},
"root": {"handlers": ["stdout"], "level": "INFO"},
})
Driving it:
configure()
structlog.contextvars.bind_contextvars(request_id="r-9f3c")
structlog.get_logger("checkout").info("order accepted", order_id=8812)
logging.getLogger("urllib3").warning("retrying connection")
Expected Output:
{"request_id": "r-9f3c", "logger": "checkout", "level": "info", "timestamp": "2026-08-02T13:07:44Z", "event": "order accepted", "order_id": 8812}
{"request_id": "r-9f3c", "logger": "urllib3", "level": "warning", "timestamp": "2026-08-02T13:07:44Z", "event": "retrying connection"}
Two records, two libraries, one shape — including the request ID on the urllib3 record, which knows nothing about any of this.
Common mistakes
A processor added after the renderer. It never runs, and there is no error, because a renderer is just a processor whose return type is different. Keep the renderer as the last element and assert it in a test if the list is assembled dynamically.
Filtering before the fields exist. A DropEvent condition that reads route must run after whatever sets route. The failure is silent: the condition simply never matches.
Returning None to drop an event. The next processor receives None and raises an AttributeError from inside the logging call. raise structlog.DropEvent is the only supported way.
Forgetting foreign_pre_chain. Library records reach the renderer with no level, no timestamp and no context, producing a log where half the lines are queryable and half are not.
Configuring inside a request handler. With cache_logger_on_first_use=True, loggers created before the reconfiguration keep the old chain, so the service ends up with two behaviours depending on when a module was imported. Configure once, at startup.
Not clearing contextvars between requests. A pooled worker thread carries the previous request's identity into the next one, which is worse than having no request ID at all — the records are attributed to the wrong request.
Migrating an existing chain
Most services do not build a chain from nothing; they inherit one from a tutorial and outgrow it. Four changes, in this order, take a default configuration to a production one without a step where logging is broken.
Step one: pin the renderer to the environment. The single most common inherited problem is ConsoleRenderer in production, which produces coloured, human-oriented output that a log backend stores as unparsed text. Swapping it for JSONRenderer behind an environment check is a one-line change with a large effect, and it is safe to do before anything else because nothing else in the chain depends on which renderer runs last.
Step two: add the enrichment the backend needs. Level, logger name and timestamp are the three fields every query assumes. structlog's defaults include some of them depending on how the chain was assembled, and it is worth making all three explicit rather than relying on that: add_log_level, add_logger_name, and a TimeStamper with fmt="iso" and utc=True. ISO-8601 in UTC removes an entire class of confusion around local time in a distributed system.
Step three: bring the standard library in. Until ProcessorFormatter is configured, half the process's records — every dependency — bypass the chain entirely. This is the step that most often gets deferred and most often causes the "half our logs are JSON" report weeks later. Do it as its own change, because it touches the logging configuration as well as the structlog one and is the step most likely to produce duplicates while you get the propagation right.
Step four: add the policy processors. Redaction, sampling, filtering. These go last because each one needs the fields the earlier steps added, and because they are the ones that discard data — a mistake here is silent, so they deserve their own change and their own tests.
| Step | Change | Risk if it goes wrong | Reversible? |
|---|---|---|---|
| 1 | renderer per environment | output shape changes | yes, immediately |
| 2 | explicit enrichment | duplicate fields, wrong timestamps | yes |
| 3 | ProcessorFormatter |
duplicate records, or library records lost | yes |
| 4 | policy processors | records silently discarded | yes, but the data is gone |
Performance characteristics
The chain is a list of Python function calls per record, which puts a floor on what an emitted record costs. Ten processors is roughly ten function calls plus a dictionary mutation each — a few microseconds, which is comparable to what the standard library spends building a LogRecord. The renderer dominates: json.dumps over a dozen keys is the largest single cost in the chain, and swapping it for orjson is the one optimisation that reliably shows up in a benchmark.
Two structural choices matter more than the processor count. cache_logger_on_first_use=True removes a configuration lookup per call, and make_filtering_bound_logger discards below-level calls before the chain runs at all — which means a DEBUG call in a hot loop costs a level comparison rather than ten function calls plus a render. Both are the default in a well-assembled configuration and both are absent from most inherited ones.
structlog.configure(
processors=SHARED + [structlog.processors.JSONRenderer(serializer=orjson_dumps)],
wrapper_class=structlog.make_filtering_bound_logger(logging.INFO), # filters first
cache_logger_on_first_use=True, # resolve once
)
The measurement technique for confirming any of this on your own workload — and the reason a published benchmark of these libraries is usually measuring something else — is in benchmarking Python logging libraries.
What the chain should not do
The chain is flexible enough to hold anything, and it runs on the calling thread for every record, which is why it is worth being deliberate about what stays out of it.
Two things belong outside it, and putting them in is a common source of trouble that the chain's flexibility invites.
Level filtering belongs in the wrapper class rather than in a processor, because make_filtering_bound_logger discards a below-level call before the chain is entered at all — a level comparison instead of ten function calls and a render. A processor that raises DropEvent for low-level records works and is strictly more expensive on the path that matters most, which is the hot path where the record is discarded.
And delivery belongs in the logger factory or in the standard library's handlers, not in a processor that writes somewhere as a side effect. A processor that posts to a webhook, appends to a file or increments a counter is doing I/O on the calling thread inside a log call, which is the same mistake as a synchronous handler and has the same remedy: put it behind a queue, on the standard library side, where the infrastructure for that already exists.
Two chains, one process
A service occasionally needs two different renderings of the same records — JSON to a collector and human-readable output to a console during a deploy, or a full stream to one destination and a redacted subset to another. structlog's chain is per-configuration and there is only one configuration, so the second rendering has to come from the standard library side rather than from a second structlog chain.
The arrangement that works is ProcessorFormatter twice: the structlog chain ends with wrap_for_formatter, and two handlers each carry their own ProcessorFormatter with a different final renderer. Every record then passes through the shared chain once and is rendered twice, which is both correct and the cheaper of the two orderings — the enrichment, redaction and sampling happen once regardless of how many destinations there are.
json_handler = logging.StreamHandler(sys.stdout)
json_handler.setFormatter(structlog.stdlib.ProcessorFormatter(
foreign_pre_chain=SHARED,
processors=[structlog.stdlib.ProcessorFormatter.remove_processors_meta,
structlog.processors.JSONRenderer()],
))
console_handler = logging.StreamHandler(sys.stderr)
console_handler.setLevel(logging.WARNING) # only the loud ones
console_handler.setFormatter(structlog.stdlib.ProcessorFormatter(
foreign_pre_chain=SHARED,
processors=[structlog.stdlib.ProcessorFormatter.remove_processors_meta,
structlog.dev.ConsoleRenderer(colors=False)],
))
The setLevel on the second handler is what keeps this affordable: the console copy exists for the records a human might glance at, so restricting it to WARNING and above means the duplication applies to a small fraction of the stream rather than all of it.
Keeping the chain reviewable
A processor list is code that runs on every record in the process, and it is worth treating with the same care as any other hot path. Three habits help: keep the list in one module so a reviewer can see the whole order at once, name each custom processor for what it does rather than for what it operates on (drop_probe_traffic, not route_filter), and write a test that asserts the renderer is last. The third one sounds trivial and catches the failure that produces no error at all.
Related
- Modern Python logging libraries deep dive — the parent section: structlog, Loguru, and the standard library compared.
- structlog architecture and setup — the configuration this guide takes apart.
- Writing custom structlog processors — the processor contract in depth, with redaction and sampling examples.
- Testing structlog output with pytest — capturing events without rendering them.
- structlog in Celery workers — configuring the chain in a process that forks.
- Binding context variables in structlog — bind versus contextvars in detail.
Frequently Asked Questions
What exactly is a structlog processor?
A callable taking three arguments — the logger, the method name such as info, and the event dictionary — and returning an event dictionary for the next processor. Only the last one is different: a renderer returns a string (or a tuple of args and kwargs) that the underlying logger is called with. Anything that respects that contract is a processor, including a plain function or a class with __call__.
Does processor order matter?
It is the whole design. A processor can only see what earlier processors have put in the event dict, so a filter that drops on a field must run after whatever adds that field, and the renderer must run last because it stops returning a dict. Most structlog problems that look like missing data are really an ordering mistake.
How do I drop an event from inside a processor?
Raise structlog.DropEvent. structlog catches it and discards the record without calling the rest of the chain or the underlying logger. Returning None is not the way to do it — the next processor will simply receive None and fail.
When do I need ProcessorFormatter?
Whenever standard-library records need to end up in the same output as structlog records, which is almost always in a real service, since your dependencies use logging. ProcessorFormatter is a stdlib Formatter that runs a structlog chain, so records from both worlds converge on one renderer and one JSON shape.
Is the processor chain a performance concern?
Rarely, but it is measurable. Each processor is a Python function call per record, and a chain of ten costs a few microseconds before the renderer runs. That matters only at high volume; when it does, drop early — put the cheapest filtering processor near the front so discarded records never reach the expensive ones.
What is cache_logger_on_first_use actually caching?
The bound logger's method resolution: after the first call, structlog freezes the configured chain onto that logger so subsequent calls skip the configuration lookup. The trade is that later calls to structlog.configure will not affect loggers already created, which is why configuration belongs at startup and not in a request handler.