Adding context: extra, adapters, filters

logging · Advanced · 13 min

Without per-request context, logs from concurrent requests are impossible to untangle.

Three ways to add fields to log records:

`extra=` on a single call: log.info("paid", extra={"order_id": 42}) adds attributes to the record, usable in formats as %(order_id)s. A format that references a field will fail on records that lack it, and keys must not clash with built-in attributes such as message or asctime.

`LoggerAdapter` wraps a logger and injects the same extra into every call: LoggerAdapter(log, {"user": "ada"}). Since 3.13, merge_extra=True merges per-call extra with the adapter's instead of discarding it.

A filter is any callable or object with filter(record) added to a logger or handler. Return False to drop the record; or modify it and return True. Returning a (possibly new) LogRecord is also allowed since 3.12. Filters on a handler see all records reaching it, including propagated ones, so a handler filter that reads a contextvars.ContextVar holding the current request ID stamps every line, from any module, with no changes at call sites. Context vars are per-thread and per-asyncio-task, so this works with concurrency.

Filters on a logger only run for records created by that exact logger, not its children.

Example

import logging, sys, contextvars
request_id = contextvars.ContextVar("request_id", default="-")

class RequestIdFilter(logging.Filter):
    def filter(self, record):
        record.request_id = request_id.get()
        return True                          # keep the record

h = logging.StreamHandler(sys.stdout)
h.addFilter(RequestIdFilter())
h.setFormatter(logging.Formatter("[%(request_id)s] %(name)s %(message)s"))
logging.basicConfig(level=logging.INFO, handlers=[h])

def handle(rid):
    request_id.set(rid)
    logging.getLogger("app.db").info("query")

handle("req-1")                              # [req-1] app.db query
base = logging.LoggerAdapter(logging.getLogger("app"), {"user": "ada"})
base.info("hi %s", base.extra["user"])       # [req-1] app hi ada

Remember

  • extra={...} adds fields to one record
  • LoggerAdapter adds fixed context to every call
  • A handler filter reading a ContextVar stamps request IDs everywhere

Watch out for

  • Putting a filter on a parent logger and expecting it to run for child loggers' records.

Check yourself

  1. A filter is attached to logger 'app'. A record from 'app.db' propagates up. Does the filter run?

Sign in to answer, see the explanations, and get this lesson back as a quick review later.

Official docs: docs.python.org/3/howto/logging-cookbook.html#adding-contextual-information-to-your-logging-output