Python, dalle fondamenta Lezione 11 / 60

logging: log strutturati, livelli, e i pattern che funzionano in produzione

Perché print() non scala, il problema di reputazione del modulo logging, e la configurazione che lo rende davvero piacevole da usare.

print() va bene. Per uno script che esegui una volta sul tuo portatile, è perfetto. Il problema è che nel momento in cui un pezzo di codice diventa qualcosa di diverso, un servizio, una libreria, un job schedulato, qualsiasi cosa che qualcun altro gestisce, print() inizia a costarti.

Non c’è livello (è un errore o un aggiornamento di stato?), niente timestamp (quando è successo?), niente nome del modulo (quale file ha prodotto questo?), nessun modo di silenziare un modulo rumoroso senza silenziare tutto, e nessun modo per chi lo gestisce di redirigere a un file, a syslog o a un aggregatore di log nel cloud senza modificare il tuo codice sorgente.

Il modulo logging di Python risolve tutti questi problemi. Ha anche una reputazione di essere sgradevole, soprattutto perché i tutorial ufficiali mostrano per primi i pezzi più profondi dell’API. La versione semplice è davvero semplice. Questa lezione è la versione semplice, poi la versione da produzione, poi il piccolo insieme di trabocchetti che vale la pena conoscere.

La versione semplice

Due righe in cima a ogni modulo:

import logging
logger: logging.Logger = logging.getLogger(__name__)

Poi ovunque in quel modulo:

logger.debug("starting calculation with input=%s", payload)
logger.info("processed %d records", len(records))
logger.warning("rate limit at %d%% — backing off", pct)
logger.error("failed to fetch %s: %s", url, exc)
logger.critical("database connection lost")

Ecco fatto. Cinque livelli di severità, in ordine crescente: DEBUG, INFO, WARNING, ERROR, CRITICAL. Il livello di default è WARNING, il che significa che le chiamate debug e info vengono silenziosamente scartate finché non alzi il livello.

Per il punto di ingresso di uno script, una sola chiamata configura tutto:

import logging

logging.basicConfig(
    level=logging.INFO,
    format="%(asctime)s %(levelname)-8s %(name)s: %(message)s",
)

basicConfig imposta un handler che scrive su stderr con il formato che specifichi. Esegui il tuo script e ottieni gratis output con timestamp, livello e tag del modulo.

getLogger(name): l’unica regola

L’abitudine più importante di tutte: usa sempre logging.getLogger(__name__) in cima a ogni modulo, mai logging.info(...) direttamente.

La ragione è la gerarchia dei logger. I nomi dei logger sono percorsi puntati, e formano un albero basato su quei punti. Un modulo chiamato myapp.payments.stripe produce un logger di nome myapp.payments.stripe, che è figlio di myapp.payments, che è figlio di myapp, che è figlio del logger root.

Perché conta? Perché la configurazione cascade lungo l’albero. Se imposti il logger root su INFO, ogni modulo eredita INFO. Ma puoi sovrascrivere per sotto-albero:

logging.getLogger("myapp").setLevel(logging.INFO)         # la maggior parte dell'app
logging.getLogger("myapp.payments").setLevel(logging.DEBUG)  # solo questo sottosistema
logging.getLogger("urllib3").setLevel(logging.WARNING)    # silenzia una dipendenza rumorosa

Questa è l’intera ragione per cui logging esiste come gerarchia e non solo come una collezione di print-con-livelli. Puoi alzare la verbosità per una parte del sistema mentre tieni il resto silenzioso, senza toccare i punti di chiamata.

Se chiami logging.info(...) direttamente, stai usando il logger root e hai buttato via quella capacità. Usa getLogger(__name__).

Stringhe di formato: cosa metterci

L’argomento format di basicConfig è un template stile % con campi nominati. Quelli utili:

  • %(asctime)s, timestamp formattato, con %(msecs)d per i millisecondi.
  • %(levelname)s, DEBUG, INFO, ecc. La larghezza -8s ti dà allineamento con padding.
  • %(name)s, il nome del logger, che è il percorso del modulo se hai usato __name__.
  • %(message)s, il messaggio stesso, dopo la sostituzione degli argomenti.
  • %(module)s, %(funcName)s, %(lineno)d, info sul punto di chiamata, utili in sviluppo.
  • %(process)d, %(thread)d, utili quando ne hai più di uno.

Un formato ragionevole per la produzione:

"%(asctime)s.%(msecs)03d %(levelname)-8s %(name)s [%(process)d]: %(message)s"

Un formato ragionevole per lo sviluppo:

"%(asctime)s %(levelname)-8s %(name)s:%(lineno)d %(message)s"

Aggiungi lineno e funcName quando vuoi fare grep su “da dove viene questo”.

dictConfig: la versione da produzione

Per qualsiasi cosa oltre un singolo basicConfig di script, lo strumento giusto è logging.config.dictConfig. Prende un dict dichiarativo (o YAML/JSON caricato in un dict) che descrive handler, formatter e livelli per logger.

import logging.config

CONFIG: dict = {
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "standard": {
            "format": "%(asctime)s %(levelname)-8s %(name)s: %(message)s",
        },
        "json": {
            "()": "pythonjsonlogger.jsonlogger.JsonFormatter",
            "format": "%(asctime)s %(levelname)s %(name)s %(message)s",
        },
    },
    "handlers": {
        "console": {
            "class": "logging.StreamHandler",
            "level": "INFO",
            "formatter": "standard",
        },
        "file": {
            "class": "logging.handlers.RotatingFileHandler",
            "level": "DEBUG",
            "formatter": "json",
            "filename": "/var/log/myapp/app.log",
            "maxBytes": 50_000_000,
            "backupCount": 5,
        },
    },
    "loggers": {
        "myapp": {
            "level": "DEBUG",
            "handlers": ["console", "file"],
            "propagate": False,
        },
        "myapp.payments": {
            "level": "INFO",  # più silenzioso del resto
        },
        "urllib3": {
            "level": "WARNING",
        },
    },
    "root": {
        "level": "WARNING",
        "handlers": ["console"],
    },
}

logging.config.dictConfig(CONFIG)

Cose da notare:

  • disable_existing_loggers: False è quasi sempre quello che vuoi. Il default True silenzia qualsiasi cosa creata prima della chiamata di dictConfig, che è una trappola.
  • Ogni handler ha il suo livello. La console può essere INFO mentre il file riceve DEBUG.
  • Il RotatingFileHandler ruota i file a una soglia di dimensione così che i log non possano riempire il disco.
  • propagate: False su un logger gli impedisce di scrivere anche sugli handler degli antenati. Utile quando hai attaccato un handler sia a livello di pacchetto sia di root e non vuoi righe duplicate.

Nelle app reali questa config di solito vive in un file YAML caricato all’avvio, così le ops possono cambiare i livelli senza un redeploy.

Lazy formatting: il grande errore

Confronta queste due:

logger.info("processing user %s with %d items", user_id, len(items))      # corretto
logger.info(f"processing user {user_id} with {len(items)} items")          # sbagliato

Producono lo stesso output. Non sono equivalenti.

La prima passa la stringa di formato e gli argomenti separatamente. Il logger controlla il livello, e se INFO è disabilitato, la stringa di formato non viene mai valutata e len(items) non viene mai chiamata. Lazy.

La seconda costruisce l’f-string prima ancora che info venga chiamata. Il lavoro di formattazione avviene incondizionatamente, indipendentemente dal filtraggio del livello. Per una riga di log "processing user X" va bene. Per qualcosa con un calcolo costoso nell’f-string, f"state: {dump_full_state()}", hai appena pagato per la serializzazione a ogni chiamata, anche quando DEBUG è spento.

Abitudine: usa segnaposto stile % nelle chiamate logger.*. Usa f-string ovunque altro. Il linter pylint lo rileva; anche ruff ha una regola G004 per questo.

L’eccezione che vale la pena conoscere: extra={...} va bene costruirlo con qualsiasi formattazione di stringhe perché i suoi valori non vengono espansi nella stringa del messaggio, sono attaccati come attributi per gli handler strutturati.

Eccezioni: logga il traceback

try:
    risky()
except Exception:
    logger.exception("risky() failed")

logger.exception(msg) è logger.error(msg) più il traceback corrente attaccato. Chiamalo solo dall’interno di un blocco except. Per percorsi non di errore in cui vuoi attaccare un oggetto eccezione che hai già, usa il keyword exc_info:

logger.warning("retry %d failed", attempt, exc_info=exc)

Non fare repr(exc) manualmente nel tuo messaggio. La gestione del traceback del logger è migliore di quello che assembleresti con la formattazione di stringhe.

Logging strutturato: extra e oltre

logger.info(
    "user_action",
    extra={"user_id": user_id, "action": "checkout", "cart_total": 49.99},
)

Il keyword extra aggiunge campi al log record senza metterli nel messaggio. Un formatter JSON (come python-json-logger) li emette come campi strutturati. Un formatter di testo semplice li ignora a meno che tu non li referenzi per nome nella stringa di formato.

Per logging strutturato più serio, due opzioni di terze parti dominano nel 2026:

  • structlog, esplicito, componibile, basato su pipeline di processor. Industriale. Si abbina pulitamente con logging così puoi adottarlo senza riscrivere le chiamate di log esistenti.
  • loguru, opinato, batteries-included, output di default carino. Un singolo import e hai log colorati e strutturati. Buono per script e piccoli servizi.

Entrambe sono scelte ragionevoli. structlog è quello che vedrai in codebase più grandi che si preoccupano della forma dei log. loguru è quello che vedrai nei repository dove qualcuno voleva log carini in cinque minuti.

Aggregatori di log nel cloud: la storia dell’integrazione

In produzione quasi mai leggi i log dal disco. Li spedisci a uno tra:

  • CloudWatch Logs (AWS), prende stdout/stderr dai container runtime; i log strutturati funzionano meglio come JSON.
  • Cloud Logging / Stackdriver (GCP), stessa forma; la libreria client Python espone un handler che aggiunge campi specifici di GCP.
  • Datadog, Splunk, Honeycomb, Grafana Loki, stesso pattern generale, SDK diversi.

La strategia portabile: logga JSON su stdout, lascia che il runtime lo spedisca, lascia che l’aggregatore lo parsi. Ecco perché l’handler json nel dictConfig sopra è più utile in produzione di quello leggibile dall’umano.

# Output JSON minimale solo con stdlib
import json
import logging

class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        payload: dict = {
            "ts": self.formatTime(record),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        if record.exc_info:
            payload["exc"] = self.formatException(record.exc_info)
        # extras
        for k, v in record.__dict__.items():
            if k not in logging.LogRecord("", 0, "", 0, "", None, None).__dict__:
                payload[k] = v
        return json.dumps(payload)

Per la maggior parte dei progetti, installa invece python-json-logger ed evita di mantenere quanto sopra.

Un esempio reale: libreria + applicazione

La separazione che la maggior parte sbaglia: una libreria non dovrebbe mai configurare il logging. Dovrebbe solo chiamare logging.getLogger(__name__) ed emettere. L’applicazione che importa la libreria è quella che decide dove vanno i log e a quale livello.

Un file di libreria:

# mylib/payments.py
import logging

logger: logging.Logger = logging.getLogger(__name__)

def charge(card: str, amount: float) -> str:
    logger.debug("charging card ending %s for %.2f", card[-4:], amount)
    try:
        token: str = _stripe_call(card, amount)
    except Exception:
        logger.exception("stripe call failed for amount=%.2f", amount)
        raise
    logger.info("charged %.2f, token=%s", amount, token)
    return token

Un punto di ingresso dell’applicazione:

# app/main.py
import logging.config

logging.config.dictConfig({
    "version": 1,
    "disable_existing_loggers": False,
    "formatters": {
        "std": {"format": "%(asctime)s %(levelname)-8s %(name)s: %(message)s"},
    },
    "handlers": {
        "console": {"class": "logging.StreamHandler", "formatter": "std"},
    },
    "loggers": {
        "mylib": {"level": "INFO"},          # libreria: info e oltre
        "mylib.payments": {"level": "DEBUG"}, # tranne questo sottomodulo
    },
    "root": {"level": "WARNING", "handlers": ["console"]},
})

from mylib.payments import charge
charge("4242 4242 4242 4242", 49.99)

Poiché la libreria usa __name__, l’applicazione può intervenire e alzare la verbosità di un sottomodulo senza alcuna cooperazione dall’autore della libreria. Quello è il guadagno.

Errori comuni da evitare

  • Loggare al livello sbagliato. error per cose che non sono errori crea pager fatigue. info per cose che dovrebbero essere debug crea rumore che seppellisce il segnale reale. Calibra: ERROR è “un umano dovrà eventualmente guardarlo”, WARNING è “potenzialmente preoccupante, può essere normale”, INFO è “eventi milestone che chi gestisce vuole vedere”, DEBUG è “tutto il resto, spento di default”.
  • Loggare dentro hot loop. Anche a livelli soppressi c’è overhead. Sposta le chiamate di log fuori dai loop interni, o proteggi con if logger.isEnabledFor(logging.DEBUG): per quelle davvero costose.
  • Loggare segreti. Token, password, body completi delle richieste. Una volta nella pipeline dei log sono difficili da richiamare. Redirigi alla sorgente.
  • Chiamare logging.basicConfig() più di una volta. È un no-op dopo la prima chiamata (a meno che non passi force=True in 3.8+). Per setup complessi, usa invece dictConfig.

Quando scegliere cosa

Per uno script una tantum: basicConfig e getLogger(__name__).

Per un piccolo servizio: dictConfig da un file YAML all’avvio, formatter JSON su stdout, lascia che la piattaforma gestisca la rotazione dei file.

Per qualcosa di più grande: come sopra, più structlog per i campi strutturati, più un handler cloud se non ti viene già spedito stdout automaticamente.

La cosa da interiorizzare: il logging è il canale tra il tuo io futuro (o il tuo collega futuro, o l’ingegnere on-call alle 3 di notte) e il sistema mentre girava. Il costo di una riga di log pensata è una riga di codice. Il costo di non averla quando ti serve è il debug solo da uno stack trace. Spendi la riga.


References: logging — Logging facility for Python, logging.config, logging.handlers, Logging HOWTO, structlog, loguru. Retrieved 2026-05-01.

Cerca