skip to content

How do you get a transcript id onto every logging.LogRecord without passing it through every function?

level: seniorimportance: should knowfreq 38%

answer

  1. Do not widen every signature
  2. Ambient value, one declaration
  3. The record can be decorated in flight
  4. Handler-level, not logger-level
  5. Unwind the scope in finally

basics

~20 s

Declare a module-level contextvars.ContextVar with a safe default, set it at the job entry point and reset the token in a finally, then attach a logging.Filter to the handler that copies the value onto each record.

solid answer

~50 s

Three pieces. A module-level `contextvars.ContextVar("transcript_id", default="-")` holds the ambient value. A `logging.Filter` subclass whose `filter(record)` does `record.transcript_id = transcript_id.get()` and returns `True` copies it onto every `logging.LogRecord` — filters are allowed to mutate records, and returning `True` keeps the record. The formatter then references `%(transcript_id)s`. Attach the filter to the **handler**, not to one logger: a logger's filters only see records logged through that logger, while a handler's filters see everything that reaches it, including records propagated up from library loggers. The default matters because the filter runs for records emitted outside any job; a formatter referencing an attribute the record lacks makes logging drop the record and print to stderr. At the entry point, `set()` the id and `reset(token)` in a `finally` so the next job on a reused worker does not inherit it.

code

python · 32 lines
python
import contextvars
import logging
import sys

transcript_id = contextvars.ContextVar("transcript_id", default="-")


class TranscriptFilter(logging.Filter):
    def filter(self, record):
        record.transcript_id = transcript_id.get()
        return True


handler = logging.StreamHandler(sys.stdout)
handler.setFormatter(logging.Formatter("[%(transcript_id)s] %(message)s"))
handler.addFilter(TranscriptFilter())  # on the handler, not one logger

log = logging.getLogger("archiver")
log.addHandler(handler)
log.setLevel(logging.INFO)

log.info("worker idle")
token = transcript_id.set("chat-4821")
try:
    log.info("archiving transcript for a 4-person team")
finally:
    transcript_id.reset(token)
log.info("worker idle")

# [-] worker idle
# [chat-4821] archiving transcript for a 4-person team
# [-] worker idle

go deeper

for a junior

Know that a log record can be enriched centrally instead of by adding a parameter to every function, and that the value comes from a variable declared once at module level with a safe default.

for a middle

Be able to write the three pieces: the ContextVar, the Filter that sets an attribute and returns True, and the format string that names it. Explain why set() must be paired with reset().

for a senior

Show the production judgment: filter on the handler so propagated records are covered, a default so unstamped paths cannot make logging drop lines, and a reset in finally so a reused worker never attributes one job's records to another.

for a principal

Own the observability contract — which ambient fields exist, who sets them, whether they are emitted as structured fields, and how the same values reach metrics and traces without every service inventing its own filter.

The requirement — every log line carries the identifier of the work in progress — is the canonical use of a `contextvars.ContextVar`, and the interview value is in wiring it to `logging` correctly rather than in the variable itself. **The scenario.** A chat-transcript archiver processes transcripts one at a time on a small pool of long-lived workers, for a 4-person team whose conversations interleave. When a transcript gets archived twice, the operators' first question is "which transcript, and which run" — and log lines that carry no identifier cannot answer it. Threading a `transcript_id` parameter down through the parser, the redactor and the writer is the alternative, and it is exactly what nobody wants: every helper's signature grows a parameter it does not use, and any code path that forgets it logs anonymously. **Piece one: the variable.** Declare it once at module level, with a default: ```python transcript_id = contextvars.ContextVar("transcript_id", default="-") ``` The default is load-bearing, not decoration. The filter you are about to write runs for *every* record the handler sees — start-up lines, third-party library chatter, shutdown messages — most of which happen outside any archive job. A bare `get()` there would raise `LookupError` inside the logging machinery. **Piece two: the filter.** `logging.Filter` is not only for dropping records; its `filter()` hook is the supported place to *decorate* one. Subclass it, set the attribute, return `True`: ```python class TranscriptFilter(logging.Filter): def filter(self, record): record.transcript_id = transcript_id.get() return True ``` Choose an attribute name that does not collide with `LogRecord`'s own — `name`, `msg`, `args`, `levelname`, `module` and friends are already taken, and overwriting one corrupts formatting for every handler. Then the formatter can name it: `logging.Formatter("[%(transcript_id)s] %(message)s")`. **Piece three: where the filter is attached.** This is the detail that separates candidates. Filters attached to a `Logger` run only for records logged *through that logger* — `Logger.handle` applies the logger's filters before dispatch, and records propagated up from child or library loggers are already past that check. Filters attached to a `Handler` run for every record the handler is about to emit, whatever logger created it. Since the goal is "every record in the output carries the id", attach the filter to the handler. In a `logging.config.dictConfig` this is the difference between listing the filter under a logger and listing it under the handler. **Piece four: the scope.** At the entry point of each job: ```python token = transcript_id.set(chat_id) try: archive(chat_id) finally: transcript_id.reset(token) ``` The `finally` is the operationally important half. Workers are reused: if an exception skips the reset, the *next* transcript is logged under the previous id. The symptom is grim precisely because it is plausible — the logs show one transcript apparently written twice and another never touched, so the duplicated side effect is chased in the archiver's write path when the real defect is in the logging scope. On Python 3.14 the same pairing is `with transcript_id.set(chat_id):`, since the token is now a context manager. **What goes wrong without the default.** If a record reaches the handler with no `transcript_id` attribute, the formatter's percent-interpolation fails. `logging` catches that inside `Handler.emit`, calls `handleError`, and prints a traceback to stderr — the record itself is dropped. So one unstamped code path costs you the very log line you were trying to enrich. Either the filter is on the handler and always sets the attribute, or the formatter must tolerate its absence. **Alternatives worth naming.** `logging`'s `extra=` keyword does the same decoration per call: `log.info("...", extra={"transcript_id": chat_id})`. It works, but it puts the burden back on every call site — the problem you set out to solve — and it refuses keys that clash with reserved `LogRecord` attributes. `logging.setLogRecordFactory` can wrap the factory so every record is born with the attribute, which is a reasonable process-wide alternative to a handler filter; the filter is usually preferred because it is scoped to the handler you control rather than to the whole process. Creating a child logger per transcript is the wrong answer: loggers are cached forever in the logging manager, so a per-transcript logger name is an unbounded, uncollectable registry. **Structured output.** Once the attribute exists on the record, a JSON formatter can emit it as a field rather than baking it into the message text, which is what makes the id filterable in a log store. That is the real payoff over appending the id to every message string by hand.

  • Why attach the logging.Filter to the handler rather than to one logger?
    A logger's filters run only for records logged through that logger; records propagated up from child or library loggers never see them. A handler's filters run for every record the handler is about to emit. Since the goal is that every emitted line carries the id, the handler is the right attachment point.
  • What happens if a logging.Formatter names an attribute a record does not have?
    Interpolation fails inside `Handler.emit`; logging catches it, calls `handleError`, prints a traceback to stderr and drops that record. So the enrichment must be total — either the filter always sets the attribute, or the format string does not depend on it. A module-level default on the ContextVar is what makes the filter total.
  • Why not create a child logger named after each transcript instead?
    Loggers are interned by name in the logging manager and effectively live for the process lifetime, so a logger per transcript is an unbounded registry that is never collected. Identifiers belong on the record as data, not in the logger hierarchy.

saying these in an interview costs you the question

  • Threads the id through every function signature
  • Attaches the filter to one logger and expects propagated records stamped
  • Reads the ContextVar with no default inside the filter
  • Forgets the reset, leaking the id into the next job
  • Thinks logging.Filter can only drop records, not decorate them
  • Overwrites a reserved LogRecord attribute such as name or msg

context