La registrazione delle eccezioni in Python

Aaron Maxwell è autore di Powerful Python.

Le eccezioni capitano. E come sviluppatori, dobbiamo semplicemente averci a che fare. Anche quando scriviamo software per aiutarci a trovare i burritos.

Aspettate, sto andando avanti… ci torneremo. Come dicevo: Il modo in cui trattiamo le eccezioni dipende dal linguaggio. E per il software che opera in scala, il logging è uno degli strumenti più potenti e preziosi che abbiamo per trattare le condizioni di errore. Diamo un’occhiata ad alcuni modi in cui questi funzionano insieme.

Lo schema “Big Tarp”

Partiamo da un estremo:

try: main_loop()except Exception: logger.exception("Fatal error in main loop")

Questo è un ampio catch-all. È adatto per alcuni percorsi di codice dove sapete che il blocco di codice (cioè main_loop()) può sollevare un certo numero di eccezioni che potreste non prevedere. E piuttosto che permettere al programma di terminare, decidete che è preferibile registrare le informazioni di errore, e continuare da lì.

La magia qui è con il metodo exception. (logger è l’oggetto logger della vostra applicazione, qualcosa che è stato restituito da logging.getLogger(), per esempio). Questo meraviglioso metodo cattura l’intero stack trace nel contesto del blocco except, e lo scrive per intero.

Nota che non devi passare l’oggetto eccezione qui. Dovete passare una stringa di messaggio. Questo registrerà l’intero stack trace, ma aggiungerà una riga con il vostro messaggio. Quindi il messaggio multilinea che appare nel vostro log potrebbe assomigliare a questo:

Fatal error in main loopTraceback (most recent call last): File "bigtarp.py", line 14, in main_loop() File "bigtarp.py", line 9, in main_loop print(foo(x)) File "bigtarp.py", line 4, in foo return 10 // n ZeroDivisionError: integer division or modulo by zero

I dettagli dello stack trace non hanno importanza – questo è un esempio giocattolo che illustra una soluzione adulta ad un problema del mondo reale. Notate solo che la prima linea è il messaggio che avete passato a logger.exception(), e le linee successive sono l’intero stack trace, incluso il tipo di eccezione (ZeroDivisionError in questo caso). In questo modo cattura e registra qualsiasi tipo di errore.

Di default, logger.exception usa il livello di log ERROR. In alternativa, puoi usare i normali metodi di log – logger.debug(), logger.info(), logger.warn(), ecc. – e passare il parametro exc_info, impostandolo su True:

while True: try: main_loop() except Exception: logger.error("Fatal error in main loop", exc_info=True)

Impostare exc_info su True farà sì che il log includa l’intero stack trace…. esattamente come fa logger.exception(). L’unica differenza è che si può facilmente cambiare il livello di log in qualcosa di diverso da errore: Basta sostituire logger.error con logger.warn, per esempio.

Fatto divertente: il pattern Big Tarp ha una controparte quasi diabolica, che leggerete di seguito.

Il pattern “Pinpoint”

Ora guardiamo l’altro estremo. Immaginate di lavorare con OpenBurrito SDK, una libreria che risolve il problema cruciale di trovare un burrito a tarda notte vicino alla vostra posizione attuale. Supponiamo che abbia una funzione chiamata find_burrito_joints() che normalmente restituisce una lista di ristoranti adatti. Ma in alcune rare circostanze, potrebbe sollevare un’eccezione chiamata BurritoCriteriaConflict.

from openburrito import find_burrito_joints, BurritoCriteriaConflict# "criteria" is an object defining the kind of burritos you want.try: places = find_burrito_joints(criteria)except BurritoCriteriaConflict as err: logger.warn("Cannot resolve conflicting burrito criteria: {}".format(err.message)) places = list()

Lo schema qui è di eseguire ottimisticamente del codice – la chiamata a find_burrito_joints(), in questo caso – all’interno di un blocco try. Nel caso in cui venga sollevato uno specifico tipo di eccezione, si registra un messaggio, si affronta la situazione e si va avanti.

La differenza chiave è la clausola except. Con il Big Tarp, state fondamentalmente catturando e registrando ogni possibile eccezione. Con Pinpoint, state catturando un tipo di eccezione molto specifico, che ha rilevanza semantica in quel particolare punto del codice.

Nota anche che uso logger.warn() piuttosto che logger.exception(). (In questo articolo, ovunque vediate warn(), potete sostituire info(), o error(), ecc.) In altre parole, registro un messaggio ad una particolare gravità invece di registrare l’intero stack trace.

Perché sto buttando via le informazioni dello stack trace? Perché non è così utile in questo contesto, dove sto catturando un tipo specifico di eccezione, che ha un chiaro significato nella logica del codice. Per esempio, in questo frammento:

characters = {"hero": "Homer", "villain": "Mr. Burns"}# Insert some code here that may or may not add a key called# "sidekick" to the characters dictionary.try: sidekick = charactersexcept KeyError: sidekick = "Milhouse"

Qui, il KeyError non è un errore qualsiasi. Quando viene sollevato, significa che si è verificata una situazione specifica, vale a dire che non c’è un ruolo “sidekick” definito nel mio cast di personaggi, quindi devo ripiegare su un default. Riempire il log con uno stack trace non è utile in questo tipo di situazione. Ed è qui che userete Pinpoint.

Lo schema “Transformer”

Qui, state catturando un’eccezione, la registrate, poi sollevate un’altra eccezione. Per prima cosa, ecco come funziona in Python 3:

try: something()except SomeError as err: logger.warn("...") raise DifferentError() from err

In Python 2, dovete abbandonare il “from err”:

try: something()except SomeError as err: logger.warn("...") raise DifferentError()

(Questo ha grosse implicazioni. Ne parleremo tra un momento). Questo si verifica spesso intorno ai confini della libreria.

Per esempio, immaginate di usare l’SDK openburrito per la vostra app killer che permette alle persone di trovare locali per burrito a tarda notte. La funzione find_burrito_joints() può sollevare BurritoCriteriaConflict se siamo troppo esigenti. Questa è l’API esposta dall’SDK, ma non corrisponde convenientemente alla logica di livello superiore della vostra applicazione. Una soluzione migliore a questo punto del codice è un’eccezione che avete definito, chiamata NoMatchingRestaurants.

In questa situazione, applicherete lo schema in questo modo (per Python 3):

from myexceptions import NoMatchingRestaurantstry: places = find_burrito_joints(criteria)except BurritoCriteriaConflict as err: logger.warn("Cannot resolve conflicting burrito criteria: {}".format(err.message)) raise NoMatchingRestaurants(criteria) from err

Questo causa una singola linea di output nel vostro log, e innesca una nuova eccezione. Se non viene mai catturata, l’output di errore dell’eccezione assomiglia a questo:

Traceback (most recent call last): File "transformerB3.py", line 8, in places = find_burrito_joints(criteria) File "/Users/amax/python-exception-logging-patterns/openburrito.py", line 7, in find_burrito_joints raise BurritoCriteriaConflictopenburrito.BurritoCriteriaConflictThe above exception was the direct cause of the following exception:Traceback (most recent call last): File "transformerB3.py", line 11, in raise NoMatchingRestaurants(criteria) from errmyexceptions.NoMatchingRestaurants: {'region': 'Chiapas'}

Ora questo è interessante. L’output include la traccia dello stack per NoMatchingRestaurants. E riporta anche il BurritoCriteriaConflict istigatore… specificando chiaramente quale fosse l’originale.

In Python 3, le eccezioni possono ora essere concatenate. La sintassi raise ... from ... lo prevede. Quando dite raise NoMatchingRestaurants(criteria) da err, questo solleva un’eccezione di typeNoMatchingRestaurants. Questa eccezione sollevata ha un attributo chiamato __cause__, il cui valore è l’eccezione istigatrice. Python 3 fa uso di questo internamente quando riporta le informazioni sull’errore.

Come si fa in Python 2? Beh, non si può. Questa è una di quelle chicche che devi solo aggiornare per avere. In Python 2, la sintassi “raise … from” non è supportata, quindi il vostro output di eccezione includerà solo lo stack trace per NoMatchingRestaurants. Il pattern Transformer è ancora perfettamente utile, naturalmente.

Il pattern “Message and Raise”

In questo pattern, registrate che un’eccezione si verifica in un particolare punto, ma poi permettete che si propaghi e venga gestita ad un livello superiore:

try: something()except SomeError: logger.warn("...") raise

Non state effettivamente gestendo l’eccezione. State solo interrompendo temporaneamente il flusso per registrare un evento. Lo farete quando avete specificamente un gestore di livello superiore per l’errore, e volete ricadere su quello, ma volete anche registrare che l’errore si è verificato, o il suo significato, in un certo punto del codice.

Questo può essere più utile nella risoluzione dei problemi, quando state ottenendo un’eccezione, ma cercando di capire meglio il contesto chiamante. Puoi inserire questa dichiarazione di log per fornire informazioni utili, e anche distribuire in sicurezza in produzione se hai bisogno di osservare i risultati in condizioni realistiche.

L’antipattern “Messaggio Criptico”

Ora rivolgiamo la nostra attenzione ad alcuni anti-pattern… cose che non dovresti fare nel tuo codice.

try: something()except Exception: logger.error("...")

Supponiamo che tu o qualcuno della tua squadra scriva questo codice, e poi sei mesi dopo, vedi uno strano messaggio nel tuo log. Qualcosa come:

ERROR: something bad happened

Ora spero e prego che non vediate le parole “è successo qualcosa di brutto” nel vostro log attuale. Tuttavia, il testo attuale del log che vedete potrebbe essere altrettanto sconcertante. Cosa fare dopo?

Bene, la prima cosa è capire dove nel codice base viene registrato questo vago messaggio. Se siete fortunati, sarete in grado di cercare rapidamente nel codice e trovare esattamente una possibilità. Se non siete fortunati, potreste trovare il messaggio di log in diversi percorsi di codice completamente diversi. Il che vi lascerà con diverse domande:

  • Quale di essi sta causando l’errore?
  • O sono diversi? O TUTTI?
  • Quale voce nel log corrisponde a quale posto?

A volte, però, non è nemmeno possibile fare un grep o una ricerca nel codice per trovare dove sta succedendo, perché il testo del log viene generato. Considerate:

 what = "something" quality = "bad" event = "happened" logger.error("%s %s %s", what, quality, event)

Come fareste a cercarlo? Potreste anche non pensarci, a meno che non abbiate cercato prima la frase completa e non abbiate ottenuto alcun risultato. E se hai ottenuto un riscontro, potrebbe facilmente essere un falso positivo.

La soluzione ideale è passare l’argomento exc_info:

try: something()except Exception: logger.error("something bad happened", exc_info=True)

Quando fai questo, una traccia completa dello stack è inclusa nei log dell’applicazione. Questo vi dice esattamente quale linea in quale file sta causando il problema, chi l’ha invocato, ecc… tutte le informazioni di cui avete bisogno per iniziare il debugging.

Il più diabolico antipattern di Python

Se vi vedrò mai fare questo, verrò a casa vostra a confiscare i vostri computer, poi entrerò nel vostro account github e cancellerò tutti i vostri repo:

try: something()except Exception: pass

Nella mia newsletter, mi riferisco a questo come “Il più diabolico antipattern di Python”. Notate come questo non solo non riesce a darvi alcuna informazione utile sulle eccezioni. Riesce anche a nascondere completamente il fatto che qualcosa è sbagliato in primo luogo. Potreste non sapere mai che avete sbagliato a digitare il nome di una variabile – sì, questo maschera effettivamente NameError – fino a quando non venite chiamati alle 2 di notte perché la produzione è rotta, in un modo che richiede fino all’alba per essere capito, perché tutte le possibili informazioni per la risoluzione dei problemi sono state soppresse.

Solo non fatelo. Se sentite di dover semplicemente catturare ed ignorare tutti gli errori, almeno gettateci sotto un grande telo (cioè usate logger.exception() invece di pass).

Altri modelli di registrazione delle eccezioni

Ci sono molti altri modelli per registrare le informazioni sulle eccezioni in Python, con diversi compromessi, pro e contro. Quali modelli avete trovato utili, o no? Fatelo sapere a tutti nei commenti.

Per saperne di più su Python Logging Basics.

I marchi registrati, i marchi di servizio e i loghi Loggly e SolarWinds sono di proprietà esclusiva di SolarWinds Worldwide, LLC o delle sue affiliate. Tutti gli altri marchi commerciali sono di proprietà dei rispettivi proprietari.

.

Lascia un commento

Il tuo indirizzo email non sarà pubblicato.