skip to content

What does logging's extra= dict add to a LogRecord, and when does it raise KeyError?

level: middleimportance: must knowfreq 55%

answer

  1. It is not stored in a nested dict
  2. The record is just an object
  3. Some names are already taken
  4. makeRecord checks before it writes
  5. message and asctime are reserved too

basics

~20 s

Each key in the extra mapping becomes an attribute on the LogRecord itself, so a formatter can emit it as a field. Logger.makeRecord raises KeyError if a key collides with an existing record attribute or with message or asctime.

solid answer

~40 s

`logger.info("thumbnail written", extra={"job_id": "j-914"})` hands the dict to `Logger.makeRecord`, which copies every key straight into the record's `__dict__` — so it becomes `record.job_id`, not a nested `record.extra`. That is what makes stdlib structured logging possible: a formatter can read arbitrary attributes off the record. The guard is deliberate: `makeRecord` raises `KeyError("Attempt to overwrite ...")` when the key already exists on the record or is `message`/`asctime`, so `extra={"module": ...}`, `{"name": ...}`, `{"args": ...}` or `{"process": ...}` blow up at the call site rather than silently corrupting the record for every handler. Two practical consequences: namespace your fields, because CPython adds record attributes over time (`taskName` arrived in 3.12 and instantly reserved that name); and remember `extra` is per-call, so a `%(job_id)s` in a shared format string breaks every record that lacks it.

code

python · 12 lines
python
import logging, sys

logging.basicConfig(
    stream=sys.stdout, level=logging.INFO, format="%(levelname)s %(job_id)s %(message)s"
)
log = logging.getLogger("thumbnails")
log.info("thumbnail written", extra={"job_id": "j-914"})

try:
    log.info("thumbnail written", extra={"module": "clash"})
except KeyError as exc:
    print("rejected:", exc)

go deeper

for a junior

Know that extra takes a dictionary and that its keys become fields you can print with a %(key)s placeholder. Be ready to say what it is for and to show one call using it.

for a middle

Explain that makeRecord copies the keys into the record's own dict and rejects collisions with a KeyError, and name several reserved attributes such as name, module, args and message.

for a senior

Show how you keep this safe in a running service: namespaced field names, a formatter that discovers attributes instead of a rigid format string, and a rule that no secret or personal datum ever rides in extra.

for a principal

Own the convention. Decide which field names belong to the platform, how a team adds a new one, and treat an unguarded extra key as a schema change that a future interpreter upgrade can turn into a runtime error.

## Where `extra` actually goes Every `logger.info(...)` call ends up in `Logger._log`, which asks `Logger.makeRecord` to build the `LogRecord` object that handlers will later format. `makeRecord` takes the `extra` mapping and copies each key/value pair directly into the new record's instance dictionary — roughly: ```python if extra is not None: for key in extra: if (key in ["message", "asctime"]) or (key in rv.__dict__): raise KeyError("Attempt to overwrite %r in LogRecord" % key) rv.__dict__[key] = extra[key] ``` So `extra={"job_id": "j-914"}` does **not** create a nested container; it creates `record.job_id`. That single line is the whole foundation of structured logging with the standard library: because the record is an ordinary object with an ordinary `__dict__`, a formatter can walk it and emit whatever fields it finds. ## The collision guard, and why it raises The `LogRecord` constructor already sets a fixed set of attributes: `name`, `msg`, `args`, `levelname`, `levelno`, `pathname`, `filename`, `module`, `exc_info`, `exc_text`, `stack_info`, `lineno`, `funcName`, `created`, `msecs`, `relativeCreated`, `thread`, `threadName`, `processName`, `process`, and — since 3.12 — `taskName`, which carries the running asyncio task's name. `message` and `asctime` are checked explicitly because they do not exist yet at record-creation time: `Formatter.format` sets `record.message` from `getMessage()`, and `formatTime` sets `asctime`. Reserving them keeps a caller from poisoning fields the formatting machinery is about to write. Raising rather than overwriting is the right call. A silent overwrite of `record.levelno` or `record.exc_info` would corrupt the record for *every* handler attached anywhere up the tree, and the failure would surface far from the log call that caused it. A `KeyError` at the call site is loud and local. The upgrade hazard is worth stating plainly: this set grows. Code that happily logged `extra={"taskName": worker}` on 3.11 started raising `KeyError` on 3.12 at every such call site. Since a logging call is usually inside an `except` block or a hot loop, that is exactly where you least want a new exception. Namespacing (`app_task`, or nesting everything under one key such as `ctx`) makes your fields immune to whatever CPython adds next. ## Getting the field into the output Setting an attribute is only half the job — something must read it. Two consumers exist. A `%`-style format string such as `"%(job_id)s %(message)s"` reads it by name. But a record that lacks `job_id` then fails to format, and the failure is handled inside `Handler.emit`, which calls `Handler.handleError`: a traceback is printed to `sys.stderr`, that one record is dropped, and the application keeps running (unless `logging.raiseExceptions` has been set to `False`, which silences even that). Losing records to a stderr traceback nobody reads is a classic production paper cut, so per-call fields and a rigid format string are a poor pair. A custom `Formatter` that discovers attributes is the robust option: it emits whatever fields are present and omits the rest. Alternatively, a `Filter` can inject a default value for the field onto every record, so the format string always finds it. ## When `extra` is the wrong tool: `LoggerAdapter` For a value that is constant across a scope rather than per call, `logging.LoggerAdapter(logger, {"job_id": "j-914"})` binds it once and every call through the adapter carries it. The catch is the default `LoggerAdapter.process`, which *replaces* `kwargs["extra"]` with the adapter's own dict — silently discarding a call-site `extra`. Python 3.13 added a `merge_extra` keyword: with `merge_extra=True` the two dicts are merged and call-site keys win on conflict. Before 3.13 the standard workaround was to override `process` yourself. The adapter also proxies `isEnabledFor`, `setLevel` and the level methods, and adapters can wrap adapters. ## Choosing between the three - **`extra=`** for facts specific to one event: a duration, a size, an outcome. - **`LoggerAdapter`** for facts fixed over an explicit scope you already thread through the code. - **A `Filter` reading a context variable** for ambient facts nobody wants to pass at all, such as a request or job id. ## Rules that survive review 1. Namespace field names, or nest them, so a future CPython attribute cannot collide with them. 2. Keep values JSON-friendly, or make the formatter tolerate them (`json.dumps(..., default=str)`); a value that fails to serialize costs you the record. 3. Never put credentials or personal data in `extra` — structured fields are indexed, retained and widely readable, which is worse than the same secret buried in prose. 4. Do not assume the field reaches the output; a formatter or format string has to ask for it.

  • Without merge_extra, what does logging.LoggerAdapter do with an extra dict passed at the call site?
    It throws it away. The default `process` sets `kwargs["extra"] = self.extra`, so the adapter's dict wins wholesale and the per-call fields never reach the record — silently, with no error. On 3.13+ pass `merge_extra=True` and the dicts are merged with call-site keys taking precedence; before that you override `process` and merge by hand.
  • A format string contains %(job_id)s but a library logs a record without it. What actually happens?
    The formatter raises, `Handler.emit` catches it and calls `Handler.handleError`, which prints a traceback to stderr and drops that record. The application does not crash and the log line is simply gone — which is why per-call fields belong in a formatter that reads what is present, or get a default injected by a Filter, rather than in a shared format string.
  • Does a collision in extra raise even when the message is below the logger's effective level?
    No. `Logger.info` checks `isEnabledFor` before it calls `makeRecord`, so a suppressed call never builds the record and never validates the keys. A bad `extra` key can therefore sit dormant in a DEBUG call and raise the day someone turns DEBUG on — a good argument for testing log calls at the level you may need in an incident.

The extra dict is not an envelope stapled to the record — its contents are poured into the record's own pockets, which is why a pocket that is already full makes the call refuse.

saying these in an interview costs you the question

  • Says extra values live in a separate record.extra dictionary
  • Believes any key name is safe to pass in extra
  • Thinks a colliding key just overwrites the record attribute
  • Assumes extra fields appear in output without a formatter change
  • Claims extra sticks to the logger for later calls
  • Puts tokens or personal data in extra because it is not the message

context