Python Logging: un tutorial aprofundat

Publicat: 2022-03-11

Pe măsură ce aplicațiile devin mai complexe, a avea jurnale bune poate fi foarte utilă, nu numai la depanare, ci și pentru a oferi informații despre problemele/performanța aplicațiilor.

Biblioteca standard Python vine cu un modul de înregistrare care oferă majoritatea caracteristicilor de bază de înregistrare. Prin configurarea corectă a acestuia, un mesaj de jurnal poate aduce o mulțime de informații utile despre când și unde este declanșat jurnalul, precum și contextul jurnalului, cum ar fi procesul/thread-ul care rulează.

În ciuda avantajelor, modulul de înregistrare este adesea trecut cu vederea, deoarece este nevoie de ceva timp pentru a fi configurat corect și, deși complet, în opinia mea, documentul oficial de înregistrare la https://docs.python.org/3/library/logging.html nu oferă cu adevărat cele mai bune practici de logare și nu evidențiază unele surprize de înregistrare.

Acest tutorial de înregistrare în jurnal Python nu este menit să fie un document complet despre modulul de înregistrare, ci mai degrabă un ghid de „începere” care introduce câteva concepte de înregistrare în jurnal, precum și câteva „probleme” de care trebuie să aveți grijă. Postarea se va încheia cu cele mai bune practici și va conține câteva indicații către subiecte de logare mai avansate.

Vă rugăm să rețineți că toate fragmentele de cod din postare presupun că ați importat deja modulul de înregistrare:

 import logging

Concepte pentru Python Logging

Această secțiune oferă o privire de ansamblu asupra unor concepte care sunt adesea întâlnite în modulul de înregistrare.

Niveluri de înregistrare Python

Nivelul jurnalului corespunde „importanței” acordate unui jurnal: un jurnal de „erori” ar trebui să fie mai urgent decât jurnalul de „avertizare”, în timp ce un jurnal de „depanare” ar trebui să fie util doar la depanarea aplicației.

Există șase niveluri de jurnal în Python; fiecare nivel este asociat cu un număr întreg care indică severitatea jurnalului: NOTSET=0, DEBUG=10, INFO=20, WARN=30, ERROR=40 și CRITICAL=50.

Nivelurile de jurnal ale Python Logging

Toate nivelurile sunt destul de simple (DEBUG < INFO < WARN ) cu excepția NOTSET, a cărui particularitate va fi abordată în continuare.

Formatare Python Logging

Formatatorul de jurnal îmbogățește practic un mesaj de jurnal adăugându-i informații de context. Poate fi util să știți când este trimis jurnalul, unde (fișier Python, număr de linie, metodă etc.) și context suplimentar, cum ar fi firul și procesul (poate fi extrem de util când depanați o aplicație multithreaded).

De exemplu, când un jurnal „hello world” este trimis printr-un formatator de jurnal:

 "%(asctime)s — %(name)s — %(levelname)s — %(funcName)s:%(lineno)d — %(message)s"

va deveni

 2018-02-07 19:47:41,864 - abc - WARNING - <module>:1 - hello world

Formatarea mesajelor de jurnal Python

Handler Python Logging

Managerul de jurnal este componenta care scrie/afișează efectiv un jurnal: Afișează-l în consolă (prin StreamHandler), într-un fișier (prin FileHandler) sau chiar trimițându-ți un e-mail prin SMTPHandler etc.

Fiecare handler de jurnal are 2 câmpuri importante:

  • Un formatator care adaugă informații de context într-un jurnal.
  • Un nivel de jurnal care filtrează jurnalele ale căror niveluri sunt inferioare. Deci un handler de jurnal cu nivelul INFO nu va gestiona jurnalele DEBUG.

Managerul de înregistrare Python

Biblioteca standard oferă o mână de handlere care ar trebui să fie suficiente pentru cazuri de utilizare obișnuite: https://docs.python.org/3/library/logging.handlers.html#module-logging.handlers. Cele mai comune sunt StreamHandler și FileHandler:

 console_handler = logging.StreamHandler() file_handler = logging.FileHandler("filename")

Python Logger

Logger este probabil cel care va fi folosit direct cel mai des în cod și care este și cel mai complicat. Un nou logger poate fi obținut prin:

 toto_logger = logging.getLogger("toto")

Un logger are trei câmpuri principale:

  • Propagare: decide dacă un jurnal ar trebui să fie propagat la părintele loggerului. În mod implicit, valoarea sa este True.
  • Un nivel: ca și nivelul de gestionare a jurnalelor, nivelul de înregistrare este utilizat pentru a filtra jurnalele „mai puțin importante”. Cu excepția, spre deosebire de gestionarea jurnalului, nivelul este verificat doar la loggerul „copil”; odată ce jurnalul este propagat către părinții săi, nivelul nu va fi verificat. Acesta este mai degrabă un comportament neintuitiv.
  • Handlers: Lista de handler la care va fi trimis un jurnal atunci când ajunge la un logger. Acest lucru permite o gestionare flexibilă a jurnalelor - de exemplu, puteți avea un handler de jurnal de fișiere care înregistrează toate jurnalele DEBUG și un handler de jurnal de e-mail care va fi utilizat numai pentru jurnalele CRITICE. În această privință, relația logger-handler este similară cu cea editor-consumator: un jurnal va fi difuzat tuturor gestionarilor odată ce trece de verificarea nivelului de logger.

Procesul de înregistrare Python

Un logger este unic după nume, ceea ce înseamnă că, dacă a fost creat un logger cu numele „toto”, apelurile ulterioare ale logging.getLogger("toto") vor returna același obiect:

 assert id(logging.getLogger("toto")) == id(logging.getLogger("toto"))

După cum probabil ați ghicit, loggerii au o ierarhie. În partea de sus a ierarhiei se află loggerul rădăcină, care poate fi accesat prin logging.root. Acest logger este apelat atunci când sunt utilizate metode precum logging.debug() . În mod implicit, nivelul jurnalului rădăcină este WARN, astfel încât fiecare jurnal cu un nivel inferior (de exemplu prin logging.info("info") ) va fi ignorat. O altă particularitate a logger-ului rădăcină este că handlerul său implicit va fi creat prima dată când este înregistrat un jurnal cu un nivel mai mare decât WARN. Utilizarea loggerului rădăcină direct sau indirect prin metode precum logging.debug() nu este, în general, recomandată.

În mod implicit, atunci când este creat un nou logger, părintele său va fi setat la loggerul rădăcină:

 lab = logging.getLogger("ab") assert lab.parent == logging.root # lab's parent is indeed the root logger

Cu toate acestea, loggerul folosește „notația cu puncte”, ceea ce înseamnă că un logger cu numele „ab” va fi copilul „a”. Cu toate acestea, acest lucru este adevărat numai dacă a fost creat loggerul „a”, altfel părintele „ab” este încă rădăcina.

 la = logging.getLogger("a") assert lab.parent == la # lab's parent is now la instead of root

Când un logger decide dacă un jurnal trebuie să treacă conform verificării nivelului (de exemplu, dacă nivelul jurnalului este mai mic decât nivelul loggerului, jurnalul va fi ignorat), el folosește „nivelul efectiv” în loc de nivelul actual. Nivelul efectiv este același cu nivelul loggerului dacă nivelul nu este NOTSET, adică toate valorile de la DEBUG până la CRITICAL; totuși, dacă nivelul loggerului este NOTSET, atunci nivelul efectiv va fi primul nivel strămoș care are un nivel non-NOTSET.

În mod implicit, un nou logger are nivelul NOTSET și, deoarece loggerul rădăcină are un nivel WARN, nivelul efectiv al loggerului va fi WARN. Deci, chiar dacă un nou logger are atașați niște handlere, acești handler nu vor fi apelați decât dacă nivelul jurnalului depășește WARN:

 toto_logger = logging.getLogger("toto") assert toto_logger.level == logging.NOTSET # new logger has NOTSET level assert toto_logger.getEffectiveLevel() == logging.WARN # and its effective level is the root logger level, ie WARN # attach a console handler to toto_logger console_handler = logging.StreamHandler() toto_logger.addHandler(console_handler) toto_logger.debug("debug") # nothing is displayed as the log level DEBUG is smaller than toto effective level toto_logger.setLevel(logging.DEBUG) toto_logger.debug("debug message") # now you should see "debug message" on screen

În mod implicit, nivelul loggerului va fi utilizat pentru a decide despre trecerile unui jurnal: Dacă nivelul jurnalului este mai mic decât nivelul loggerului, jurnalul va fi ignorat.

Cele mai bune practici de înregistrare Python

Modulul de logare este într-adevăr foarte la îndemână, dar conține câteva ciudații care pot cauza ore lungi de durere de cap chiar și pentru cei mai buni dezvoltatori Python. Iată cele mai bune practici pentru utilizarea acestui modul în opinia mea:

  • Configurați loggerul rădăcină, dar nu îl utilizați niciodată în codul dvs. - de exemplu, nu apelați niciodată o funcție precum logging.info() , care de fapt apelează logger-ul rădăcină în spatele scenei. Dacă doriți să capturați mesaje de eroare din bibliotecile pe care le utilizați, asigurați-vă că ați configurat loggerul rădăcină să scrie într-un fișier, de exemplu, pentru a ușura depanarea. În mod implicit, logger-ul rădăcină iese numai în stderr , astfel încât jurnalul se poate pierde cu ușurință.
  • Pentru a utiliza înregistrarea, asigurați-vă că ați creat un nou logger utilizând logging.getLogger(logger name) . De obicei folosesc __name__ ca nume de înregistrare, dar orice poate fi folosit, atâta timp cât este consecvent. Pentru a adăuga mai mulți handlere, am de obicei o metodă care returnează un logger (puteți găsi esenta pe https://gist.github.com/nguyenkims/e92df0f8bd49973f0c94bddf36ed7fd0).
 import logging import sys from logging.handlers import TimedRotatingFileHandler FORMATTER = logging.Formatter("%(asctime)s — %(name)s — %(levelname)s — %(message)s") LOG_FILE = "my_app.log" def get_console_handler(): console_handler = logging.StreamHandler(sys.stdout) console_handler.setFormatter(FORMATTER) return console_handler def get_file_handler(): file_handler = TimedRotatingFileHandler(LOG_FILE, when='midnight') file_handler.setFormatter(FORMATTER) return file_handler def get_logger(logger_name): logger = logging.getLogger(logger_name) logger.setLevel(logging.DEBUG) # better to have too much log than not enough logger.addHandler(get_console_handler()) logger.addHandler(get_file_handler()) # with this pattern, it's rarely necessary to propagate the error up to parent logger.propagate = False return logger

După ce puteți crea un nou logger și îl puteți utiliza:

 my_logger = get_logger("my module name") my_logger.debug("a debug message")
  • Utilizați clasele RotatingFileHandler, cum ar fi TimedRotatingFileHandler folosit în exemplu în loc de FileHandler, deoarece va roti fișierul în mod automat atunci când fișierul atinge o limită de dimensiune sau o va face în fiecare zi.
  • Utilizați instrumente precum Sentry, Airbrake, Raygun etc., pentru a captura automat jurnalele de erori pentru dvs. Acest lucru este util mai ales în contextul unei aplicații web, unde jurnalul poate fi foarte pronunțat și jurnalele de erori se pot pierde cu ușurință. Un alt avantaj al utilizării acestor instrumente este că puteți obține detalii despre valorile variabilelor din eroare, astfel încât să puteți ști ce adresă URL declanșează eroarea, ce utilizator este în cauză etc.

Dacă sunteți interesat de mai multe bune practici, citiți Cele mai frecvente 10 greșeli pe care le fac dezvoltatorii Python de la colegul Toptaler Martin Chikilian.