Osservabilità: Log Strutturati, Metriche e Tracing in Produzione

Quando un'applicazione gira solo sul tuo portatile, capire cosa succede è banale: apri il terminale e leggi. In produzione la situazione cambia di colpo. Il servizio risponde lento solo per certi utenti, un job notturno fallisce due volte a settimana, un errore compare senza che nessuno sappia da dove arriva. La differenza tra un'ora di debugging e tre giorni persi raramente è la bravura: è la qualità delle informazioni che l'applicazione produce mentre lavora.

Questo è il campo dell'osservabilità: la capacità di rispondere a domande che non avevi previsto quando hai scritto il codice. Non è un tool da installare, è una decisione su cosa registrare e come — sapendo che ogni cosa registrata ha un costo.

Tre strumenti, tre domande diverse

Log, metriche e trace vengono spesso confusi, ma rispondono a domande differenti e hanno costi differenti.

L'errore più comune è usare un solo strumento per tutto. Chi mette tutto nei log finisce con gigabyte di testo che nessuno legge. Chi mette tutto nelle metriche si ritrova a fissare un grafico che dice "la latenza è alta" senza sapere perché.

Da print a eventi strutturati

Un classico anti-pattern:

print("Errore nell'ordine " + str(order_id))

Questa riga ha almeno cinque problemi: non ha un livello di severità, non ha un timestamp affidabile, non ha un formato parsabile, non dice chi era l'utente e — soprattutto — per estrarne le informazioni devi sperare che il testo non cambi mai.

La versione strutturata registra un evento, cioè un oggetto con campi nominati. Con la libreria standard di Python puoi farlo senza dipendenze esterne:

import json, logging, time

class JsonFormatter(logging.Formatter):
    EXTRA = ("request_id", "user_id", "duration_ms", "status", "route")

    def format(self, record):
        payload = {
            "ts": time.strftime("%Y-%m-%dT%H:%M:%S", time.gmtime(record.created)),
            "level": record.levelname,
            "logger": record.name,
            "msg": record.getMessage(),
        }
        for key in self.EXTRA:
            value = getattr(record, key, None)
            if value is not None:
                payload[key] = value
        if record.exc_info:
            payload["exc"] = self.formatException(record.exc_info)
        return json.dumps(payload, ensure_ascii=False)

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])

L'uso è quasi identico a prima, ma ora i dati sono interrogabili:

log = logging.getLogger("api")
log.info(
    "ordine creato",
    extra={"request_id": rid, "user_id": uid, "duration_ms": 42, "route": "/orders"},
)

Scrivi su stdout, una riga JSON per evento, e lascia che sia l'infrastruttura a raccogliere e ruotare i file. Questo mantiene l'applicazione semplice e la rende compatibile con qualunque sistema di raccolta.

Livelli, contesto e ID di correlazione

I livelli servono a decidere cosa guardare ora e cosa guardare quando serve. Usarli male significa avere migliaia di righe di rumore in mezzo a un errore.

Il secondo ingrediente è il contesto. Senza un identificativo di correlazione, dieci richieste concorrenti producono log indistricabili. In Python i contextvars risolvono il problema senza passare l'ID a ogni funzione:

import contextvars, logging, uuid

request_id = contextvars.ContextVar("request_id", default="-")

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

# all'ingresso della richiesta
request_id.set(str(uuid.uuid4()))

Con un filtro agganciato all'handler, ogni riga di log porta con sé lo stesso request_id: basta una ricerca per ricostruire l'intera storia di una richiesta. In un sistema distribuito lo stesso ID va propagato via header tra i servizi, e va affiancato al trace_id generato dallo strumento di tracing.

Cosa non deve finire nei log

Un log è un archivio che resta lì per mesi, spesso su sistemi con accessi più larghi di quelli del database di produzione. Trattarlo come una discarica è un rischio concreto.

Da non registrare mai:

• password, token, cookie, header Authorization;
• dati personali non necessari (email, telefono, indirizzo, IBAN, numeri di carta);
• body completi di richieste e risposte;
• query SQL con i parametri reali già interpolati.

Una funzione di mascheramento applicata prima della serializzazione è il minimo:

SENSITIVE = {"password", "token", "authorization", "card_number", "email"}

def scrub(payload: dict) -> dict:
    return {
        k: ("***" if k.lower() in SENSITIVE else v)
        for k, v in payload.items()
    }

Vale anche per le eccezioni: un traceback può contenere l'intera query o il contenuto di una variabile. Meglio registrare il tipo di errore e un messaggio controllato, non l'oggetto grezzo.

Metriche: contatori, istogrammi e cardinalità

Le metriche sono numeri aggregati nel tempo. Sono economiche e perfette per gli alert. Le tre tipologie che coprono quasi tutto:

• Counter: solo crescente (richieste totali, errori totali);
• Gauge: valore istantaneo (connessioni aperte, coda in attesa);
• Histogram: distribuzione di valori (latenza, dimensione delle risposte).

Per i servizi si usa spesso il metodo RED: Rate (richieste al secondo), Errors (tasso di errore), Duration (latenza). Per le risorse — CPU, disco, memoria — si usa USE: Utilization, Saturation, Errors.

from prometheus_client import Counter, Histogram

REQUESTS = Counter("http_requests_total", "Richieste", ["method", "route", "status"])
LATENCY = Histogram("http_request_seconds", "Latenza", ["method", "route"])

def record(method, route, status, seconds):
    REQUESTS.labels(method, route, str(status)).inc()
    LATENCY.labels(method, route).observe(seconds)

La regola d'oro: mai etichette ad alta cardinalità. route va bene se è il template (/orders/{id}), non l'URL reale. user_id o order_id come label sono un disastro: ogni valore distinto crea una serie temporale separata e la memoria del sistema di metriche esplode. Con un esempio, se hai 10.000 ordini e 5 route, passi da 5 serie a 50.000.

Altro punto spesso sottovalutato: la media mente. Se metà delle richieste risponde in 20 ms e metà in 2 secondi, la media è circa 1 secondo — un valore che nessun utente ha mai sperimentato. Guarda i percentili: p50, p95, p99. Il p99 racconta l'esperienza del tuo utente più sfortunato, che spesso è anche quello che paga di più.

Tracing: seguire una richiesta attraverso i servizi

Un trace è un albero di span: ogni span rappresenta un'operazione con inizio, fine, attributi ed eventuali errori. Serve quando il problema non è cosa è fallito ma dove si perde tempo lungo la catena.

from opentelemetry import trace

tracer = trace.get_tracer("orders")

def calcola_totale(order_id, items):
    with tracer.start_as_current_span("calcola_totale") as span:
        span.set_attribute("order.items", len(items))
        with tracer.start_as_current_span("db.query"):
            righe = carica_prezzi(items)
        return somma(righe)

Il valore aggiunto arriva quando gli span di servizi diversi condividono lo stesso contesto: vedi la richiesta HTTP che entra, la query che occupa 800 ms, la chiamata al servizio di pagamento che ne occupa altri 300. Senza tracing, quel percorso lo ricostruisci a mano leggendo log di tre applicazioni diverse e sperando che i timestamp siano allineati.

Il tracing si può campionare: registrare una percentuale delle richieste, oppure tutte quelle lente e una frazione di quelle veloci. Nel secondo caso si parla di campionamento in coda (tail sampling) e richiede di bufferizzare gli span finché la richiesta non è conclusa. Anche negli attributi degli span valgono le stesse regole dei log: niente dati sensibili, niente valori ad altissima cardinalità.

Dal sintomo alla causa: un percorso tipo

Immagina un'API che gestisce ordini e un grafico che mostra il p95 in salita (esempio illustrativo). Il percorso di indagine è quasi sempre lo stesso:

1. Metrica — l'alert scatta sulla latenza p95, non su una causa specifica.
2. Dashboard — errori e throughput: gli errori sono stabili, quindi non è un guasto ma un rallentamento.
3. Trace — si aprono le richieste più lente e si vede che il tempo è concentrato in una query.
4. Log — filtrando per request_id di una di quelle richieste si recuperano i parametri e il contesto.

Con log in JSON, l'indagine diventa una riga di jq:

# gli errori più frequenti\.
jq -r 'select(.level == "ERROR") | .msg' app.log | sort | uniq -c | sort -rn | head

# le richieste lente, con il loro request_id\.
jq 'select(.duration_ms > 1000) | {ts, route, request_id, duration_ms}' app.log

Loggare non è gratis

Facciamo un esempio di ordine di grandezza: 100 richieste al secondo con 1 KB di log ciascuna fanno circa 8,6 GB al giorno. Moltiplicato per trenta giorni di retention, sono centinaia di gigabyte da archiviare, indicizzare e — soprattutto — pagare.

Qualche contromisura concreta:

• Campiona l'INFO, tieni tutto l'ERROR e il WARNING.
• Non loggare dentro i cicli: un log per batch, con il conteggio finale.
• Retention a livelli: pochi giorni di ricerca rapida, archivi compressi per il resto.
• Scritture non bloccanti: un handler sincrono su disco lento può rallentare l'applicazione; meglio stdout o scritture asincrone.
• Verifica il comportamento quando il backend dei log è irraggiungibile: l'applicazione deve continuare a funzionare, non bloccarsi.

Errori comuni

• Messaggi concatenati come stringhe, impossibili da interrogare.
• Dati sensibili nei log perchè "tanto sono interni".
• Nessun ID di correlazione: impossibile seguire una singola richiesta.
• Metriche con user_id, session_id o URL completi come etichette.
• Alert basati su cause ipotizzate invece che su sintomi misurabili.
• DEBUG attivo in produzione, che annega le informazioni utili.
• Dashboard costruite una volta e mai più riviste, mentre il sistema cambia.

Conclusione: cosa portarsi a casa

• Log, metriche e trace non sono alternative: coprono domande diverse. Parti dalle metriche per gli alert, usa i trace per localizzare il collo di bottiglia, scava nei log per il dettaglio.
• Log strutturati in JSON su stdout, con un ID di correlazione su ogni riga: è il singolo cambiamento che migliora di più il debugging.
• Maschera i dati sensibili alla fonte, non a valle: i log vivono a lungo e su sistemi accessibili a molte persone.
• Cura la cardinalità delle metriche e guarda i percentili, non le medie.
• Ogni riga che registri ha un costo di spazio, denaro e rumore: campiona, definisci la retention e rivedi periodicamente cosa stai davvero usando.
• L'obiettivo non è avere più dati, ma poter rispondere in pochi minuti alla prossima domanda imprevista.

Foto di copertina di Tyler su Unsplash.