Logging & config — a record's path through the gates, and the layer that wins

In Java you add SLF4J and Logback, a logback.xml ships with the starter, and log.info(...) just shows up. Python's logging is the same design — PEP 282 took it from log4j: loggers named in a dotted tree, levels, handlers, formatters — but it ships with no configuration at all. The root logger sits at WARNING with no handler of yours, so the first log.info(...) you write goes nowhere, and nothing tells you. This page follows one record through every gate it has to pass, then does the same for the other thing every service needs on day one: which of three config layers set model_name.

logger treelevels as gates handlers & formattersJSON lines env > file > default

One record, three gates, as many exits as there are handlers

The call is logging.getLogger("app.db").info("pool ready: %d connections", 5), made inside a request whose id is 7f3a9c01. getLogger returns one object per name and the dots make a tree: app.db's parent is app, whose parent is the root logger. The record meets three kinds of gate:

  1. The logger gate — once, at app.db. INFO is 20; the record goes on only if 20 ≥ the logger's effective level — its own level, or, while that is NOTSET, the first level set on the way up. Nobody set one? Root's default is WARNING (30), and the record dies here.
  2. The climb. A record that passed is handed to every handler on app.db, then on app, then on root — unless a logger on the way has propagate = False, which ends the climb there. The levels of app and root are not consulted on the way up. Only handlers are.
  3. Each handler's own gate. A handler has a level too (default NOTSET: everything passes). Its formatter is the stamp that turns the record into bytes — plain text, or one JSON object per line.

Pick the levels and the handler layout. Every emitted line below was printed by a real run of Python 3.12.3's logging, with the record's clock pinned to 2026-09-10 09:30:00.250 UTC so the timestamps stay put; the gate verdicts are that run's getEffectiveLevel(), isEnabledFor() and handler levels.

Follow the record from log.info(...) to the terminal


    

The run behind the fourth level option is the one worth rereading: root at ERROR, and the INFO line still comes out of root's handler. The effective level was decided at app.db (it inherited INFO from app); root's own level is only ever the gate for records logged on root. To silence everything below a level, set it on the handler.

The request id in the JSON line is not an argument anyone passed. It lives in a contextvars.ContextVar that the request sets on the way in; the formatter reads it when it stamps the line. A ContextVar holds one value per thread and per asyncio task, so two requests in flight never stamp each other's lines — which is exactly what a module-level global does. (That is one of the three traps in the py-09 exercise.)

Config: three layers, and the top one that defines a key wins

Spring Boot taught you the rule already: command-line arguments beat environment variables, which beat application.properties, which beats the defaults in code. A Python service wants the same thing and the standard library does not hand it to you — you write a twenty-line load_config(defaults, path, env). Default is the dict in the code; file is askcli.toml (read with tomllib, in the standard library since 3.11); env is ASKCLI_MODEL_NAME and friends. Precedence is per key: the environment can override model_name and leave the file's timeout_s standing. A key in the file that is not a field is a typo, and a typo that is silently ignored is a bug that ships. Each result below is what the py-09 reference load_config returned for those three layers.

Which layer set model_name?

Takeaways: a missing log line was dropped at one of three places — the logger gate at the logger that made the record (its effective level, inherited from the nearest ancestor that set one), a handler's own level, or a climb cut short by propagate = False. Ancestor loggers' levels are never consulted on the way up, so root at ERROR silences nothing below it; a handler's level does. A line printed twice is two handlers on one path. Config is the same kind of lookup: for each key, the highest layer that defines it wins — env over file over default — and a key nobody recognises is an error, not a no-op.