Python Logging die echt helpt

Het meeste advies stopt bij 'gebruik gestructureerde logs'. Het lastigere deel is bepalen wat het waard is om op te schrijven, voordat een incident dat voor je beslist.

Ik heb veel logs gelezen die me vertelden dat een job faalde en verder niets. De oplossing was bijna nooit een nieuwe library. Het was vooraf beslissen wie deze regel leest en wat diegene ermee moet doen.

Schrijf voor wie gebeld wordt

Elke regel kost later leeswerk, dus beantwoord voordat je er een toevoegt voor wie hij is: jij die lokaal debugt, een auditor over een half jaar, of wie er vannacht dienst heeft. Die drie willen verschillende dingen, en een regel die alle drie probeert te bedienen bedient er geen. Debugregels mogen breedsprakig zijn. Dienstregels moeten zeggen wat stukging en wat je vervolgens controleert.

Gestructureerd, maar niet overal JSON

De standaardbibliotheek geeft je al extra, en een JSON-formatter daarbovenop levert doorzoekbare velden zonder één call site aan te raken: log.info('batch loaded', extra={'table': 'orders_silver', 'rows': 41233, 'run_id': run_id}). Houd het lokaal wel gewoon platte tekst. Niemand wil zijn unittests door jq halen.

Context wint van events

Een regel die Load failed zegt is een doodlopend pad. Diezelfde regel met een run id, de bronpartitie en het aantal rijen dat erdoorheen kwam vertelt je waar je moet kijken zonder de pipelinecode te openen. LoggerAdapter of contextvars duwen die context de stack in, zodat je geen run_id-argument door negen functies hoeft te rijgen.

import contextvars
import logging

# Set once per run; every log line below picks it up without passing it around.
run_id = contextvars.ContextVar("run_id", default="-")


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


handler = logging.StreamHandler()
handler.addFilter(RunContext())
handler.setFormatter(logging.Formatter("%(levelname)s run=%(run_id)s %(message)s"))

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


def load_partition(table, partition):
    rows = 41233  # whatever the load actually returned
    # A JSON formatter would turn these extra fields into queryable columns.
    log.info("batch loaded", extra={"table": table, "partition": partition, "rows": rows})


run_id.set("2026-05-05T04:00")
load_partition("orders_silver", "2026-05-04")
# INFO run=2026-05-05T04:00 batch loaded
Illustratief voorbeeld, geen productiecode.

Niveaus werken alleen als je ze verdedigt

WARNING kruipt omhoog. Iets ziet er één keer vreemd uit, iemand zet het voor de zekerheid hoger, en een jaar later is de warning-stroom vierhonderd regels per uur die iedereen wegfiltert. Elke paar maanden opruimen loont: waar niemand ooit op gehandeld heeft gaat omlaag of eruit. En retries horen op DEBUG tot de laatste faalt.