Skip to content

← The Edge of the System step 7 of 12

Hard Framework

Structured logging: events, not sentences

You cannot alert on a sentence. logger.info(f"Order {order_id} failed after {n} retries") produces a line that a human can read and a machine cannot group, count, threshold or correlate. The same event as structured data — {"event": "order.failed", "order_id": 17, "retries": 3} — is queryable the moment it lands.

There is still no JSON formatter in the standard library through 3.15. You write the payload builder, or you take a dependency. This is that builder.

def build_log_payload(record_fields: Mapping[str, object],
                      reserved: frozenset[str],
                      context: Mapping[str, object]) -> dict[str, object]: ...

Rules

  1. Promote every caller field to the top level of the payload.
  2. Drop any field whose name is in reserved, or is one of your own envelope keys (ENVELOPE_KEYS = {"context", "_dropped"}), and record the name in a sorted "_dropped" list.
  3. Nest the request context under "context" — omitted entirely when empty.
  4. Sanitise every value, recursively, so the result is JSON-encodable. Anything that is not becomes repr(value).
  5. Omit "_dropped" entirely when nothing was dropped.

The reserved-key collision trap

extra= looks like a free-form dictionary. It is not. Logger.makeRecord checks each key against the LogRecord‘s own attributes and raises:

KeyError: "Attempt to overwrite 'module' in LogRecord"

The list includes name, msg, args, levelname, levelno, pathname, filename, module, exc_info, lineno, funcName, created, thread, process — plus message and asctime, which are not even attributes yet at that point. So extra={"module": "billing"} in a request handler is an exception thrown from a logging call: the observability code takes down the request it was supposed to describe. That is why this function refuses the key and records the refusal, rather than passing it through or raising.

%-style formatting is not legacy

logger.info("processed %s orders", n)     # correct
logger.info(f"processed {n} orders")      # ruff G004

The stdlib contract is that arguments are not formatted if the record is filtered out. An f-string is evaluated at the call site, unconditionally, so a logger.debug(f"...{expensive()}...") in a hot loop pays full price on a production system running at INFO. A blanket “migrate everything to f-strings” sweep is a performance regression in exactly the code you least want to slow down.

Where this sits in a real handler chain

  • contextvars carries request-scoped values (request id, tenant, user) without threading them through every function signature. That is where the context argument comes from.
  • QueueHandler + QueueListener move the actual write off the request path. A synchronous file or network handler is a latency bug that only appears under load, which is precisely the load at which you need the logs. Since 3.12 dictConfig can wire both up and expose the listener via getHandlerByName(); since 3.14 QueueListener is a context manager.
  • logger.exception() inside an except block, never logger.error(str(exc)) — you want the traceback.

The typing that matters

Build the payload as dict[str, object], not dict[str, Any]. Any would let a Decimal reach json.dumps with the checker’s blessing; object forces you to narrow every value, which is exactly the pass that finds the unserialisable one. And if you subclass logging.Formatter, def format(self, record: logging.LogRecord) -> str must match the supertype signature exactly — --strict checks the override, and an inverted parameter order here is a silent breakage in whichever handler happens to call you.

The ecosystem choice

Stdlib-only (this function, plus a Formatter subclass) — no dependency, and libraries that use plain logging are already integrated. python-json-logger — the same thing, maintained. structlog — a processor pipeline and structlog.contextvars, which is nicer to use, at the cost of a second logging concept in your process and a bridging configuration for every library that logs through the stdlib. All three are defensible. Sentences are not.

Loading visualization…