Python, de la zero Lecția 11 / 60

logging: log-uri structurate, niveluri si pattern-urile care merg in productie

De ce print() nu scaleaza, problema de reputatie a modulului logging si configurarea care il face cu adevarat placut de folosit.

print() e în regulă. Pentru un script pe care-l rulezi o dată pe laptop, e perfect. Problema apare în clipa în care o bucată de cod devine altceva: un serviciu, o bibliotecă, un job programat, orice operează altcineva. Atunci print() începe să te coste.

Nu există nivel (e o eroare sau un update de status?), nu există timestamp (când s-a întâmplat asta?), nu există nume de modul (ce fișier a produs asta?), nu există un mod de a reduce zgomotul unui modul fără a reduce totul, și nu există un mod prin care operatorul să redirecționeze către un fișier, un syslog sau un agregator de loguri din cloud fără să-ți editeze codul sursă.

Modulul logging din Python rezolvă toate aceste probleme. Are și o reputație de neplăcut, ceea ce vine în mare parte din faptul că tutorialele oficiale arată întâi partea cea mai adâncă a API-ului. Versiunea simplă e cu adevărat simplă. Lecția asta e versiunea simplă, apoi versiunea pentru producție, apoi setul mic de capcane care merită cunoscute.

Versiunea simplă

Două linii la începutul fiecărui modul:

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

Apoi oriunde în acel modul:

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")

Atât. Cinci niveluri de severitate, în ordine crescătoare: DEBUG, INFO, WARNING, ERROR, CRITICAL. Nivelul implicit e WARNING, ceea ce înseamnă că apelurile debug și info sunt aruncate în tăcere până ridici nivelul.

Pentru punctul de intrare al unui script, un singur apel configurează totul:

import logging

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

basicConfig configurează un handler care scrie în stderr cu formatul pe care-l specifici. Rulează-ți scriptul și primești output cu timestamp, nivel și etichetă de modul, gratis.

getLogger(name): singura regulă

Cel mai important obicei: folosește mereu logging.getLogger(__name__) la începutul fiecărui modul, niciodată logging.info(...) direct.

Motivul e ierarhia de logger-i. Numele logger-ilor sunt căi separate prin puncte, iar acele puncte formează un arbore. Un modul numit myapp.payments.stripe produce un logger numit myapp.payments.stripe, care e copilul lui myapp.payments, care e copilul lui myapp, care e copilul logger-ului rădăcină.

De ce contează? Pentru că configurarea cascadează în jos pe arbore. Dacă setezi logger-ul rădăcină pe INFO, fiecare modul moștenește INFO. Dar poți suprascrie pe sub-arbore:

logging.getLogger("myapp").setLevel(logging.INFO)         # cea mai mare parte din aplicatie
logging.getLogger("myapp.payments").setLevel(logging.DEBUG)  # doar acest subsistem
logging.getLogger("urllib3").setLevel(logging.WARNING)    # taie din zgomotul unei dependinte galagioase

Ăsta e motivul pentru care logging există ca ierarhie și nu doar ca o colecție de print-uri cu niveluri. Poți crește verbozitatea pentru o parte a sistemului ținând restul liniștit, fără să atingi locurile de apel.

Dacă apelezi logging.info(...) direct, folosești logger-ul rădăcină și ai aruncat la gunoi acea capacitate. Folosește getLogger(__name__).

Format strings: ce să pui în ele

Argumentul format din basicConfig e un șablon în stil % cu câmpuri denumite. Cele utile:

  • %(asctime)s — timestamp formatat, cu %(msecs)d pentru milisecunde.
  • %(levelname)s — DEBUG, INFO etc. Lățimea -8s îți dă aliniere cu padding.
  • %(name)s — numele logger-ului, care e calea modulului dacă ai folosit __name__.
  • %(message)s — mesajul în sine, după substituția de argumente.
  • %(module)s, %(funcName)s, %(lineno)d — info despre locul apelului, util în dezvoltare.
  • %(process)d, %(thread)d — utile când ai mai mult de unul din oricare.

Un format rezonabil pentru producție:

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

Un format rezonabil pentru dezvoltare:

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

Adaugă lineno și funcName când vrei să poți face grep după „de unde a venit asta”.

dictConfig: versiunea pentru producție

Pentru orice trece dincolo de un basicConfig cu un singur script, unealta potrivită e logging.config.dictConfig. Primește un dict declarativ (sau YAML/JSON încărcat într-un dict) care descrie handlere, formattere și niveluri 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",  # mai linistit decat restul
        },
        "urllib3": {
            "level": "WARNING",
        },
    },
    "root": {
        "level": "WARNING",
        "handlers": ["console"],
    },
}

logging.config.dictConfig(CONFIG)

Câteva lucruri de reținut:

  • disable_existing_loggers: False e aproape mereu ce vrei. Implicit True reduce la tăcere orice a fost creat înainte de apelul dictConfig, ceea ce e o capcană.
  • Fiecare handler are propriul nivel. Consola poate fi pe INFO în timp ce fișierul primește DEBUG.
  • RotatingFileHandler rotește fișierele la un prag de dimensiune, ca log-urile să nu umple discul.
  • propagate: False pe un logger îl oprește să mai scrie și în handler-ele strămoșilor. Util când ai atașat un handler atât la nivel de pachet, cât și la cel de rădăcină, și nu vrei linii duplicate.

În aplicații reale, această configurație trăiește de obicei într-un fișier YAML încărcat la pornire, ca operatorii să poată schimba nivelurile fără un redeploy.

Formatare leneșă: singura greșeală mare

Compară-le pe acestea două:

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

Produc același output. Nu sunt echivalente.

Prima trece string-ul de format și argumentele separat. Logger-ul verifică nivelul și, dacă INFO e dezactivat, string-ul de format nu e niciodată evaluat și len(items) nu e niciodată apelat. Leneș.

A doua construiește f-string-ul înainte ca info să fie măcar apelat. Munca de formatare se întâmplă necondiționat, cu sau fără filtrare pe nivel. Pentru o linie de log de tipul "processing user X", e în regulă. Pentru ceva cu un calcul costisitor în f-string, f"state: {dump_full_state()}", tocmai ai plătit serializarea la fiecare apel, chiar și când DEBUG e oprit.

Obicei: folosește placeholdere în stil % în apelurile logger.*. Folosește f-string-uri peste tot în altă parte. Linter-ul pylint o prinde; ruff are și o regulă G004 pentru asta.

Excepția care merită știută: extra={...} e în regulă să fie construit cu orice formatare de string-uri, pentru că valorile lui nu se expandează în string-ul mesajului, ci se atașează ca atribute pentru handlere structurate.

Excepții: loghează stack trace-ul

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

logger.exception(msg) e logger.error(msg) plus stack trace-ul curent atașat. Apelează-l doar din interiorul unui bloc except. Pentru căi care nu sunt erori, unde vrei să atașezi un obiect excepție pe care deja îl ai, folosește cuvântul cheie exc_info:

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

Nu pune repr(exc) manual în mesaj. Tratarea stack trace-ului de către logger e mai bună decât ce ai asambla cu formatare de string-uri.

Logging structurat: extra și mai departe

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

Cuvântul cheie extra adaugă câmpuri la înregistrarea de log fără să le pună în mesaj. Un formatter JSON (cum e python-json-logger) le emite ca pe câmpuri structurate. Un formatter text simplu le ignoră, în afară de cazul în care le referențiezi după nume în string-ul de format.

Pentru logging structurat mai serios, două opțiuni terțe domină în 2026:

  • structlog — explicit, compunabil, bazat pe pipeline de procesoare. Industrial. Se asociază curat cu logging, deci poți să-l adopți fără să rescrii apelurile de log existente.
  • loguru — opinionat, cu bateriile incluse, output implicit drăguț. Un singur import și ai log-uri colorate, structurate. Bun pentru scripturi și servicii mici.

Ambele sunt alegeri rezonabile. structlog e ce vei vedea în codebase-uri mai mari, care țin la forma log-urilor. loguru e ce vei vedea în repo-uri unde cineva a vrut log-uri drăguțe în cinci minute.

Agregatoare de log-uri din cloud: povestea integrării

În producție aproape niciodată nu citești log-urile de pe disc. Le expediezi către unul dintre acestea:

  • CloudWatch Logs (AWS) — preia stdout/stderr de la runtime-urile de containere; log-urile structurate funcționează cel mai bine ca JSON.
  • Cloud Logging / Stackdriver (GCP) — aceeași formă; biblioteca client Python expune un handler care adaugă câmpuri specifice GCP.
  • Datadog, Splunk, Honeycomb, Grafana Loki — același pattern general, SDK-uri diferite.

Strategia portabilă: log-uri JSON la stdout, lasă runtime-ul să le expedieze, lasă agregatorul să le parseze. De-asta handler-ul json din dictConfig de mai sus e mai util în producție decât cel pentru oameni.

# Output JSON minim doar cu 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)

Pentru majoritatea proiectelor, instalează în schimb python-json-logger și evită întreținerea celor de mai sus.

Un exemplu real: bibliotecă + aplicație

Împărțirea pe care majoritatea o nimerește greșit: o bibliotecă nu ar trebui să configureze niciodată logging-ul. Ar trebui doar să apeleze logging.getLogger(__name__) și să emită. Aplicația care importă biblioteca e cea care decide unde se duc log-urile și la ce nivel.

Un fișier de bibliotecă:

# 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 punct de intrare al aplicației:

# 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"},          # biblioteca: info si peste
        "mylib.payments": {"level": "DEBUG"}, # cu exceptia acestui submodul
    },
    "root": {"level": "WARNING", "handlers": ["console"]},
})

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

Pentru că biblioteca folosește __name__, aplicația poate să intervină și să crească verbozitatea unui submodul fără nicio cooperare din partea autorului bibliotecii. Asta e răsplata.

Greșeli frecvente de evitat

  • Logging la nivelul greșit. error pentru lucruri care nu sunt erori creează oboseala pagerului. info pentru lucruri care ar trebui să fie debug creează zgomot care îngroapă semnalul real. Calibrează: ERROR e „un om va trebui până la urmă să se uite la asta”, WARNING e „potențial îngrijorător, poate fi normal”, INFO e „evenimente jalon pe care operatorul vrea să le vadă”, DEBUG e „tot restul, oprit implicit”.
  • Logging în interiorul buclelor fierbinți. Chiar și la niveluri suprimate există overhead. Mută apelurile de log în afara buclelor interioare sau pune o gardă cu if logger.isEnabledFor(logging.DEBUG): pentru cele cu adevărat costisitoare.
  • Logging de secrete. Token-uri, parole, corpuri întregi de cereri. Odată ajunse în pipeline-ul de log-uri sunt greu de retras. Redactează la sursă.
  • Apelarea logging.basicConfig() de mai multe ori. E un no-op după primul apel (cu excepția cazului în care treci force=True în 3.8+). Pentru configurări complexe, folosește în schimb dictConfig.

Când să alegi ce

Pentru un script unic: basicConfig și getLogger(__name__).

Pentru un serviciu mic: dictConfig dintr-un fișier YAML la pornire, formatter JSON la stdout, lasă platforma să se ocupe de rotația fișierelor.

Pentru orice mai mare: la fel ca mai sus, plus structlog pentru câmpuri structurate, plus un handler de cloud dacă nu primești stdout-ul expediat automat.

Lucrul de internalizat: logging-ul e canalul între tine cel viitor (sau colegul tău viitor, sau inginerul de gardă la 3 dimineața) și sistemul așa cum a rulat. Costul unei linii de log gândite cu cap e o linie de cod. Costul de a nu o avea când ai nevoie e debugging doar dintr-un stack trace. Cheltuie linia.


Referințe: logging — Logging facility for Python, logging.config, logging.handlers, Logging HOWTO, structlog, loguru. Consultat 2026-05-01.

Caută