Python Logging – Guida più semplice con codice completo ed esempi

Il modulo di logging ti permette di monitorare l’esecuzione del tuo codice in modo che quando il codice va in crash puoi controllare i log e identificare la causa. I messaggi di log hanno una gerarchia incorporata – a partire dai messaggi di debug, informativi, di avvertimento, di errore e critici. È possibile includere anche informazioni di traceback. È progettato per progetti python da piccoli a grandi con più moduli ed è altamente raccomandato per qualsiasi programmazione modulare python. Questo post è una spiegazione semplice e chiara di come usare il modulo di logging.

Logging in Python – Guida semplificata con codice completo ed esempi. Foto di Andrea Reiman.

Contenuto

1. 1. Perché loggare?
   2. Un esempio di log di base
   3. I 5 livelli di log
   4. Come loggare su un file invece che sulla console
   5. Come cambiare il formato di log
   6. Perché lavorare con il logger di root per tutti i moduli non è la migliore idea
   7. Come creare un nuovo logger?
   8. Come includere informazioni di traceback nei messaggi registrati
   9. Esercizi
   10. Conclusione

Perché registrare?

Immaginate di stare eseguendo uno script python, e di voler sapere quale parte dello script è stata eseguita, a che ora e in certi casi controllare quali valori tengono le variabili.

Di solito, potete semplicemente ‘print()‘ fuori i messaggi significativi in modo da poterli vedere nella console. E questo probabilmente è tutto ciò di cui avete bisogno quando state sviluppando piccoli programmi.

Il problema è: quando usate questo approccio su progetti più grandi contenenti molti moduli volete un approccio più strutturato e robusto.

Perché?

Perché, il codice potrebbe passare attraverso diversi stadi come nello sviluppo, debug, revisione, test o va in produzione, vuoi vedere diversi livelli di dettagli nei messaggi stampati.

Il tipo di messaggi che vuoi stampare durante lo sviluppo o il debug può essere molto diverso da quello che vuoi vedere una volta che va in produzione. A seconda dello scopo, volete che il codice stampi diversi tipi di messaggi.

Immaginate di fare tutto questo con solo if else e print dichiarazioni.

Inoltre, c’è un certo livello di gerarchia necessario nei messaggi stampati.

Ovvero, durante una certa esecuzione di ‘test’, si vogliono vedere solo avvisi e messaggi di errore. Mentre durante il ‘debug’, sono necessari messaggi più dettagliati che aiutino il debug. Inoltre, se si vuole stampare su quale modulo e a che ora è stato eseguito il codice, lo script python diventa disordinato.

Tutti questi problemi sono ben affrontati dal modulo logging.

Utilizzando il logging, è possibile:

1. controllare il livello dei messaggi per registrare solo quelli necessari
2. controllare dove mostrare o salvare i log
3. controllare come formattare i log con i modelli di messaggio integrati
5. controllare come formattare i log con i modelli di messaggio integrati
6. .nei template dei messaggi
7. Sapere da quale modulo provengono i messaggi

Potreste dire ‘Vedo che logging può essere utile ma sembra troppo tecnico e sembra essere un po’ difficile da capire’. Beh, sì, logging richiede un po’ di curva di apprendimento, ma è per questo che questo post è qui: rendere il log facile da imparare.

Senza ulteriori indugi, entriamo subito in argomento.

Un esempio di log di base

Python fornisce un modulo integrato logging che fa parte della libreria standard di Python. Quindi non c’è bisogno di installare nulla.

Per usare la registrazione, tutto quello che dovete fare è impostare la configurazione di base usando logging.basicConfig(). In realtà, anche questo è opzionale. Lo vedremo presto.

Poi, invece di print(), si chiama logging.{level}(message) per mostrare il messaggio in console.

import logginglogging.basicConfig(level=logging.INFO)def hypotenuse(a, b): """Compute the hypotenuse""" return (a**2 + b**2)**0.5logging.info("Hypotenuse of {a}, {b} is {c}".format(a=3, b=4, c=hypotenuse(a,b)))#> INFO:root:Hypotenuse of 3, 4 is 5.0

Il messaggio di log stampato ha il seguente formato predefinito: {LEVEL}:{LOGGER}:{MESSAGE}.

Nel caso precedente, il livello è info, perché, ho chiamato logging.info().

Il logger si chiama root, perché è il logger di default e non ne ho ancora creato uno nuovo.

Un logger è come un’entità che puoi creare e configurare per registrare diversi tipi e formati di messaggi.

Puoi configurare un logger che stampa sulla console e un altro logger che invia i log a un file, ha un diverso livello di registrazione ed è specifico per un dato modulo. Altre spiegazioni ed esempi sono in arrivo.

Infine, il messaggio è la stringa che ho passato a logging.info().

Ora, cosa sarebbe successo se non avessi configurato logging.basicConfig(level=logging.INFO)? Il log non sarebbe stato stampato.

Perché?

Per saperlo capiamo i livelli di log.

I 5 livelli di log

logging ha 5 diversi livelli gerarchici di log che un dato logger può essere configurato.

Vediamo cosa dicono i documenti di python su ogni livello:

1. DEBUG: Informazioni dettagliate, per la diagnosi dei problemi. Valore=10.
2. INFO: Conferma che le cose stanno funzionando come previsto. Valore=20.
3. WARNING: È successo qualcosa di inaspettato, o indicativo di qualche problema. Ma il software funziona ancora come previsto. Valore=30.
4. ERROR: Problema più serio, il software non è in grado di eseguire qualche funzione. Valore=40
5. CRITICO: Un errore grave, il programma stesso potrebbe non essere in grado di continuare a funzionare. Valore=50

Ora, tornando alla domanda precedente su cosa sarebbe successo se non aveste impostato logging.basicConfig(level=logging.INFO) nell’esempio precedente.

La risposta è: il log non sarebbe stato stampato perché, il logger di default è ‘root’ e il suo livello basicConfig di default è ‘WARNING’. Ciò significa che solo i messaggi da logging.warning() e livelli superiori saranno registrati.

Quindi, il messaggio di logging.info() non sarebbe stato stampato. Ed è per questo che la configurazione di base era impostata come INFO inizialmente (in logging.basicConfig(level=logging.INFO)).

Se avessi impostato il livello come logging.ERROR invece, solo il messaggio da logging.error e logging.critical sarà registrato. Chiaro?

import logginglogging.basicConfig(level=logging.WARNING)def hypotenuse(a, b): """Compute the hypotenuse""" return (a**2 + b**2)**0.5kwargs = {'a':3, 'b':4, 'c':hypotenuse(3, 4)}logging.debug("a = {a}, b = {b}".format(**kwargs))logging.info("Hypotenuse of {a}, {b} is {c}".format(**kwargs))logging.warning("a={a} and b={b} are equal".format(**kwargs))logging.error("a={a} and b={b} cannot be negative".format(**kwargs))logging.critical("Hypotenuse of {a}, {b} is {c}".format(**kwargs))#> WARNING:root:a=3 and b=3 are equal#> ERROR:root:a=-1 and b=4 cannot be negative#> CRITICAL:root:Hypotenuse of a, b is 5.0

Come loggare su un file invece che sulla console

Per inviare i messaggi di log a un file dal logger root, è necessario impostare l’argomento file in logging.basicConfig()

import logginglogging.basicConfig(level=logging.INFO, file='sample.log')

Ora tutti i messaggi di log successivi andranno direttamente al file ‘sample.log’ nella vostra directory di lavoro corrente. Se volete inviarli ad un file in una directory diversa, indicate il percorso completo del file.

Come cambiare il formato di log

Il modulo di log fornisce degli shorthands per aggiungere vari dettagli ai messaggi registrati. L’immagine sottostante, tratta dai documenti di Python, mostra la lista.

Cambiamo il formato del messaggio di log per mostrare l’ORA, il LIVELLO e il MESSAGGIO. Per farlo basta aggiungere il formato all’argomento format di logging.basiconfig().

import logginglogging.basicConfig(level=logging.INFO, format='%(asctime)s :: %(levelname)s :: %(message)s')logging.info("Just like that!")#> 2019-02-17 11:40:38,254 :: INFO :: Just like that!

6. Perché lavorare con il logger root per tutti i moduli non è l’idea migliore

Perché tutti condivideranno lo stesso logger ‘root’.

Ma perché è un male?

Guardiamo il codice seguente:

# 1. code inside myprojectmodule.pyimport logginglogging.basicConfig(file='module.log')#-----------------------------# 2. code inside main.py (imports the code from myprojectmodule.py)import loggingimport myprojectmodule # This runs the code in myprojectmodule.pylogging.basicConfig(file='main.log') # No effect, because!

Immaginate di avere uno o più moduli nel vostro progetto. E che questi moduli usino il modulo root di base. Quindi, quando si importa il modulo (‘myprojectmodule.py‘), tutto il codice di quel modulo verrà eseguito e il logger verrà configurato.

Una volta configurato, il logger root nel file principale (che ha importato il modulo ‘myprojectmodule‘) non sarà più in grado di modificare le impostazioni del logger root. Perché, il logging.basicConfig() una volta impostato non può essere cambiato.

Questo significa che se volete registrare i messaggi da myprojectmodule in un file e i log dal modulo principale in un altro file, il logger di root non può farlo.

Per fare ciò è necessario creare un nuovo logger.

Come creare un nuovo logger?

È possibile creare un nuovo logger utilizzando il metodo ‘logger.getLogger(name)‘. Se esiste un logger con lo stesso nome, verrà usato quello.

Sebbene si possa dare praticamente qualsiasi nome al logger, la convenzione è di usare la variabile __name__ come questa:

logger = logging.getLogger(__name__)logger.info('my logging message')

Ma perché usare __name__ come nome del logger, invece di codificare un nome?

Perché la variabile __name__ conterrà il nome del modulo (file python) che ha chiamato il codice. Quindi, quando viene usato all’interno di un modulo, creerà un logger con il valore fornito dall’attributo __name__ del modulo.

Facendo così, se si finisce per cambiare il nome del modulo (nome del file) in futuro, non è necessario modificare il codice interno.

Ora, una volta creato un nuovo logger, dovreste ricordarvi di registrare tutti i vostri messaggi usando il nuovo logger.info() invece del metodo logging.info() della root.

Un altro aspetto da notare è che tutti i logger hanno una gerarchia incorporata.

Che cosa intendo con questo?

Per esempio, se avete configurato il logger di root per registrare i messaggi in un particolare file. Hai anche un logger personalizzato per il quale non hai configurato il gestore di file per inviare messaggi a console o a un altro file di log.

In questo caso, il logger personalizzato farà fallback e scriverà sul file impostato dal logger root stesso. Finché e a meno che non si configuri il file di log del proprio logger personalizzato.

Cos’è dunque un gestore di file e come impostarlo?

Cos’è e come impostare un gestore di file e un formattatore?

Le classi FileHandler() e Formatter() sono usate per impostare il file di output e il formato dei messaggi per i logger diversi da quello principale.

Ricordate come abbiamo impostato il nome del file e il formato del messaggio nel logger principale (dentro logging.basicConfig()) prima?

Abbiamo semplicemente specificato i parametri filename e format in logging.basicConfig() e tutti i log successivi andavano in quel file.

Tuttavia, quando si crea un logger separato, è necessario impostarli individualmente usando gli oggetti logging.FileHandler() e logging.Formatter().

Un FileHandler viene usato per fare in modo che il logger personalizzato faccia il log in un file diverso. Allo stesso modo, un Formatter è usato per cambiare il formato dei messaggi registrati.

import logging# Gets or creates a loggerlogger = logging.getLogger(__name__) # set log levellogger.setLevel(logging.WARNING)# define file handler and set formatterfile_handler = logging.FileHandler('logfile.log')formatter = logging.Formatter('%(asctime)s : %(levelname)s : %(name)s : %(message)s')file_handler.setFormatter(formatter)# add file handler to loggerlogger.addHandler(file_handler)# Logslogger.debug('A debug message')logger.info('An info message')logger.warning('Something is not right.')logger.error('A Major error has happened.')logger.critical('Fatal error. Cannot continue')

Nota come abbiamo impostato il formattatore sul ‘file_handler‘ e non il ‘logger‘ direttamente.

Assumendo che il codice di cui sopra venga eseguito dal programma principale, se si guarda all’interno della directory di lavoro, verrà creato un file chiamato logfile.log se non esiste e conterrà i seguenti messaggi.

#> 2019-02-17 12:40:14,797 : WARNING : __main__ : Something is not right.#> 2019-02-17 12:40:14,798 : ERROR : __main__ : A Major error has happened.#> 2019-02-17 12:40:14,798 : CRITICAL : __main__ : Fatal error. Cannot continue

Nota ancora, il Formatter è impostato sull’oggetto FileHandler e non direttamente sul logger. Qualcosa a cui si potrebbe voler fare l’abitudine.

Come includere informazioni di traceback nei messaggi registrati

Oltre a ‘debuginfowarningerror‘, e ‘critical‘, è possibile registrare le eccezioni che includeranno tutte le informazioni di traceback associate.

Con logger.exception, si possono registrare informazioni di traceback nel caso in cui il codice incontri qualche errore. logger.exception registrerà il messaggio fornito nei suoi argomenti così come le informazioni di traceback del messaggio di errore.

Di seguito un bell’esempio.

import logging# Create or get the loggerlogger = logging.getLogger(__name__) # set log levellogger.setLevel(logging.INFO)def divide(x, y): try: out = x / y except ZeroDivisionError: logger.exception("Division by zero problem") else: return out# Logslogger.error("Divide {x} / {y} = {c}".format(x=10, y=0, c=divide(10,0)))#> ERROR:__main__:Division by zero problem#> Traceback (most recent call last):#> File "<ipython-input-16-a010a44fdc0a>", line 12, in divide#> out = x / y#> ZeroDivisionError: division by zero#> ERROR:__main__:None

Esercizi

1. Crea una nuova directory di progetto e un nuovo file python chiamato ‘example.py‘. Importate il modulo di logging e configurate il logger di root al livello di messaggi ‘debug’. Registra un messaggio ‘info’ con il testo “Questo è il messaggio di log di root!”.
2. Configurare il logger di root per formattare il messaggio “Questo è il messaggio di log di root!” come segue:

#> 2019-03-03 17:18:32,703 :: INFO :: Module <stdin> :: Line No 1 :: This is root logger's logging message!

Mostra soluzione

import logginglogging.basicConfig(level=logging.INFO, format='%(asctime)s :: %(levelname)s :: Module %(module)s :: Line No %(lineno)s :: %(message)s')logging.info("This is root logger's logging mesage!")

1. Creare un altro file python nella stessa directory chiamato ‘mymod.py‘ e creare un nuovo logger con il nome del modulo. Configuratelo al livello dei messaggi di ‘errore’ e fategli inviare gli output del log a un file chiamato “mymod_{current_date}.log”.
2. Dal logger ‘mymod’ creato sopra, registrate il seguente messaggio ‘critico’ nel suddetto file di log: “Questo è un messaggio critico. Non ignorarlo”.

Conclusione

Molte congratulazioni se sei stato in grado di risolvere gli esercizi!

È stato abbastanza utile e diretto, vero?

Il log è un grande strumento ma non è popolare nei flussi di lavoro della scienza dei dati come dovrebbe essere. Spero che i concetti di logging siano chiari e la prossima volta che lavorerete su un progetto basato su python, la mia gentile richiesta è di ricordarvi di dare al modulo logging una possibilità.

Felice logging!