Logging and config: the dot-name logger tree, JSON output, and settings that fail at boot

One tree, configured once

logging.getLogger("app.api.orders") does not create an isolated logger — it creates (or returns, it is a registry of singletons) a node in a tree keyed by dot-name: app.api.orders is a child of app.api, which is a child of app, which hangs off the root. A record emitted at a node first passes that node’s level gate, then propagates up the tree and is offered to every ancestor’s handlers — ancestor levels are not re-checked, only their handlers fire. That asymmetry is the whole configuration contract: handlers belong at the root, configured once, at the process entrypoint; everything else just emits.

# main.py — the ONLY place in the process that configures logging
import logging.config

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": False,   # keep library loggers alive
    "formatters": {
        "json": {"()": "pythonjsonlogger.json.JsonFormatter",
                 "format": "%(asctime)s %(levelname)s %(name)s %(message)s"},
    },
    "handlers": {"stdout": {"class": "logging.StreamHandler", "formatter": "json"}},
    "root": {"level": "INFO", "handlers": ["stdout"]},
})

# every other module — app code and libraries alike
import logging
logger = logging.getLogger(__name__)     # a tree node; attach NOTHING to it

Libraries call getLogger(__name__) and add nothing — at most a NullHandler to silence the “no handlers found” warning. The classic violation: a library author “helpfully” attaches a StreamHandler at import time. Now every record is emitted by that handler and, after propagation, by the root handler — every line appears twice, and ops spends a week grepping duplicates before someone reads the library source. Per-module verbosity is still cheap when you need it: set loggers: {"app.api": {"level": "DEBUG"}} in the same dictConfig and only that subtree gets noisy.

Structured JSON and the correlation id

Prose logs can only be grepped; JSON logs can be queried — filter by level, group by logger, aggregate duration_ms percentiles, join on request_id. That last field is the one that turns fifty interleaved request streams into one readable story, and in async services it must come from contextvars, not threading.local — hundreds of tasks interleave on one thread, and a ContextVar is copied per task, so each request sees its own value (the same middleware seam you built in the python/06 request lifecycle):

import logging
from contextvars import ContextVar

request_id: ContextVar[str] = ContextVar("request_id", default="-")

class RequestIdFilter(logging.Filter):
    def filter(self, record: logging.LogRecord) -> bool:
        record.request_id = request_id.get()   # stamped onto EVERY record
        return True

# ASGI middleware sets it once per request
async def correlation(request, call_next):
    request_id.set(request.headers.get("x-request-id") or new_id())
    return await call_next(request)

Two honest routes to JSON: python-json-logger is a formatter swap — five lines of dictConfig, stdlib semantics untouched. structlog is a second logging worldview — bound loggers carry context (log = log.bind(user_id=...)) through call chains without filters, which is genuinely better ergonomics, but adopting it halfway leaves two formats in one stream and a team confused about which import to use. Pick one posture and migrate whole services, not files.

Levels discipline and the lazy-formatting rule

logger.info("user %s rebalanced %d", uid, n) is not style — it is a deferral contract. The logging call first checks isEnabledFor(INFO) (roughly a hundred nanoseconds); only if the record will actually be emitted are the args formatted into the template. logger.debug(f"user {user!r}") inverts that: the f-string evaluates before the call, every time, even with DEBUG disabled — and a repr of a fat ORM object costs microseconds to milliseconds. At a few million hot-path calls per hour that is real CPU, and it was the silent three-week tax in the Hook. The %s form has a second payoff: the message template stays constant, so a log pipeline can group by template and graph “this line started firing 100x more” — f-strings produce a unique message per call and kill that aggregation.

Levels are a paging contract, not a severity vibe: ERROR means a human should act — if nobody should be woken, it is WARNING (degraded, self-healing, worth a morning look) or INFO (state changes: startup, config loaded, connection pool sized). Teams that log handled retries at ERROR train on-call to ignore ERROR, and the one real page drowns. DEBUG stays off in prod by default; when you need it, enable it for one dot-name subtree via dictConfig, never at root.

Settings that fail at boot

The config half of the discipline has one rule: a misconfigured service must refuse to start. pydantic-settings gives the mechanism — a typed class whose fields load from the environment and validate at construction:

from pydantic import PostgresDsn, SecretStr
from pydantic_settings import BaseSettings

class Settings(BaseSettings):
    model_config = {"env_prefix": "APP_"}
    database_url: PostgresDsn        # REQUIRED — no default, boot fails without it
    api_key: SecretStr               # repr and logs show '**********'
    log_level: str = "INFO"          # a default is fine when the default is the SAFE one

settings = Settings()                # raises ValidationError AT BOOT, not at 3am

The config-drift failure this kills: a “sensible default” like database_url = "postgres://staging-db/app" means a prod deploy that forgets the env var boots green and quietly runs production traffic against staging — no crash, no page, just wrong data until an audit notices. Required fields must be required; the crash at deploy time is the feature. SecretStr closes the other leak: secrets never appear in repr, tracebacks, or the settings dump you log at startup (log the dump — it is the cheapest incident tool you will ever ship — but log it with secrets masked). One image, env-per-deployment: staging and prod differ only in environment variables, never in code paths.