Python logging tutorial

ultima modifica 6 luglio 2020

Python logging tutorial mostra come fare logging in Python con il loggingmodule.

Logging

Logging è il processo di scrittura di informazioni in file di log. I file di log contengono informazioni su vari eventi accaduti nel sistema operativo, nel software o nella comunicazione.

Scopo del logging

Il logging viene fatto per i seguenti scopi:

• Raccolta di informazioni
• Risoluzione dei problemi
• Generazione di statistiche
• Auditing
• Profiling

Il logging non si limita a identificare errori nello sviluppo del software. È anche usato per rilevare incidenti di sicurezza, monitorare le violazioni delle politiche, fornire informazioni in caso di problemi, trovare colli di bottiglia nell’applicazione o generare dati sull’utilizzo.

Quali eventi registrare

Gli eventi che dovrebbero essere registrati includono fallimenti nella validazione degli input, fallimenti nell’autenticazione e nell’autorizzazione, errori nell’applicazione, cambiamenti nella configurazione e avvio e chiusura dell’applicazione.

Quali eventi non registrare

Gli eventi che non dovrebbero essere registrati includono il codice sorgente dell’applicazione, i valori di identificazione della sessione, i token di accesso, i dati personali sensibili, le password, le stringhe di connessione al database, le chiavi di crittografia, i dati del conto bancario e del titolare della carta di credito.

Le migliori pratiche di log

Le seguenti sono alcune buone pratiche per fare i log:

• Il log dovrebbe essere significativo.
• Il log dovrebbe contenere il contesto.
• Il log dovrebbe essere strutturato e fatto a diversi livelli.
• Il log dovrebbe essere bilanciato; non dovrebbe includere troppe o troppo poche informazioni.
• I messaggi di log dovrebbero essere comprensibili agli umani e analizzabili dalle macchine.
• Il log in applicazioni più complesse dovrebbe essere fatto in diversi file di log.
• Il logging dovrebbe essere adattato allo sviluppo e alla produzione.

Il modulo di logging

Il modulo di logging di Python definisce funzioni e classi che implementano un sistema flessibile di registrazione degli eventi per applicazioni e librerie.

I componenti del modulo di logging

Il modulo di logging ha quattro componenti principali: loggers, handlers, filtri e formattatori. I logger espongono l’interfaccia che il codice dell’applicazione usa direttamente.I gestori inviano i record di log (creati dai logger) alla destinazione appropriata.I filtri forniscono una struttura a grana più fine per determinare quali record di log emettere.I formattatori specificano la disposizione dei record di log nell’output finale.

Gerarchia di log in Python

I logger di Python formano una gerarchia. Un logger chiamato main è un parente di main.new.

I logger figli propagano i messaggi fino ai gestori associati ai loro antenati. Per questo motivo, non è necessario definire e configurare gestori per tutti i logger nell’applicazione. È efficiente configurare gestori per un logger di primo livello e creare logger figli secondo necessità.

Livelli di log di Python

I livelli sono usati per identificare la gravità di un evento. Ci sono sei livelli di registrazione:

• CRITICAL
• ERROR
• WARNING
• INFO
• DEBUG
• NOTSET

Se il livello di log è impostato su WARNING, tutti i messaggi WARNINGERROR, e CRITICAL vengono scritti nel file di log o nella console. Se è impostato su ERROR, solo i messaggi ERROR eCRITICAL vengono registrati.

I logger hanno un concetto di livello effettivo. Se un livello non è esplicitamente impostato su un logger, il livello del suo genitore è usato invece come livello effettivo. Se il genitore non ha un livello esplicitamente impostato, viene esaminato il suo genitore, e così via – tutti gli antenati vengono cercati finché non viene trovato un livello esplicitamente impostato.

Quando il logger viene creato con getLogger(), il livello è impostato aNOTSET. Se il livello di registrazione non è impostato esplicitamente con setLevel(), i messaggi vengono propagati ai genitori del logger. La catena di logger antenati viene attraversata fino a quando non viene trovato un antenato con un livello diverso da NOTSET, oppure viene raggiunto il root. Il logger principale ha un livello predefinito WARNING impostato.

Logger principale

Tutti i logger sono discendenti del logger principale. Ogni logger passa i messaggi di log al suo genitore. I nuovi logger vengono creati con il metodo getLogger(name). Chiamando la funzione senza un nome (getLogger()) viene restituito il logger radice.

Il logger radice ha sempre un livello esplicito impostato, che è WARNINGdi default.

Il logger radice si trova in cima alla gerarchia ed è sempre presente, anche se non configurato. In generale, il programma o la libreria non dovrebbero registrare direttamente sul logger di root. Invece dovrebbe essere configurato un logger specifico per il programma. Root logger può essere usato per attivare e disattivare facilmente tutti i logger di tutte le librerie.

Python logging semplice esempio

Il modulo logging ha metodi semplici che possono essere usati subito senza alcuna configurazione. Questo può essere usato per un semplice logging.

#!/usr/bin/env pythonimport logginglogging.debug('This is a debug message')logging.info('This is an info message')logging.warning('This is a warning message')logging.error('This is an error message')logging.critical('This is a critical message')

L’esempio chiama cinque metodi del modulo logging I messaggi vengono scritti nella console.

$ simple.pyWARNING:root:This is a warning messageERROR:root:This is an error messageCRITICAL:root:This is a critical message

Nota che viene usato il logger root e che sono stati scritti solo tre messaggi, perché per default vengono scritti solo i messaggi di livello warning e superiori.

Python imposta il livello di logging

Il livello di logging viene impostato con setLevel().Imposta la soglia per questo logger a lvl.I messaggi di registrazione che sono meno gravi di lvl saranno ignorati.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.DEBUG)logger.debug('This is a debug message')logger.info('This is an info message')logger.warning('This is a warning message')logger.error('This is an error message')logger.critical('This is a critical message')

Nell’esempio, cambiamo il livello di registrazione a DEBUG.

logger = logging.getLogger('dev')

Il getLogger() restituisce un logger con il nome specificato; se il nome è None, restituisce il logger principale. Il nome può essere una stringa separata da punti che definisce la gerarchia dei log; per esempio’a’, ‘a.b’, o ‘a.b.c’. Si noti che c’è un nome di root implicito, che non viene mostrato.

$ set_level.pyThis is a warning messageThis is an error messageThis is a critical message

Ora tutti i messaggi sono stati scritti.

Livello effettivo di registrazione di Python

Il livello effettivo di registrazione è il livello impostato esplicitamente o determinato dai genitori del logger.

#!/usr/bin/env pythonimport loggingmain_logger = logging.getLogger('main')main_logger.setLevel(5)dev_logger = logging.getLogger('main.dev')print(main_logger.getEffectiveLevel())print(dev_logger.getEffectiveLevel())

Nell’esempio, esaminiamo il livello di log effettivo di due logger.

dev_logger = logging.getLogger('main.dev')

Il livello del dev_logger non è impostato; viene quindi utilizzato il livello del suo genitore.

$ effective_level.py55

Questo è l’output.

Gestori di log in Python

Handler è un oggetto responsabile dell’invio dei messaggi di log appropriati (basati sulla gravità dei messaggi di log) alla destinazione specificata dal gestore.

I gestori sono propagati come i livelli. Se il logger non ha un handler impostato, la sua catena di antenati cerca un handler.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.INFO)fileHandler = logging.FileHandler('test.log')fileHandler.setLevel(logging.INFO)consoleHandler = logging.StreamHandler()consoleHandler.setLevel(logging.INFO)logger.addHandler(fileHandler)logger.addHandler(consoleHandler)logger.info('information message')

L’esempio crea due handler per un logger: un handler file e un handler console.

fileHandler = logging.FileHandler('test.log')

FileHandler invia i record di log al test.logfile.

consoleHandler = logging.StreamHandler()

StreamHandler invia i record di log ad uno stream.Se lo stream non è specificato, viene usato il sys.stderr.

logger.addHandler(fileHandler)

Il gestore viene aggiunto al logger con addHandler().

Python logging formatters

Formatter è un oggetto che configura l’ordine finale, la struttura e il contenuto del record di log. Oltre alla stringa del messaggio, i record di log includono anche la data e l’ora, i nomi dei log e la severità del livello di log.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger('dev')logger.setLevel(logging.INFO)consoleHandler = logging.StreamHandler()consoleHandler.setLevel(logging.INFO)logger.addHandler(consoleHandler)formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')consoleHandler.setFormatter(formatter)logger.info('information message')

L’esempio crea un logger per console e aggiunge un formatter al suo gestore.

formatter = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')

Il formatter viene creato. Include la data e l’ora, il nome del logger, il nome del livello di registrazione e il messaggio di log.

consoleHandler.setFormatter(formatter)

Il formatter viene impostato al gestore con setFormatter().

$ formatter.py2019-03-28 14:53:27,446 dev INFO: information message

Il messaggio con il formato definito viene mostrato nella console.

Python logging basicConfig

Il basicConfig() configura il logger root. Fa la basicconfiguration per il sistema di logging creando un gestore di stream con un defaultformatter. Il debug()info()warning()error() e critical() chiamanobasicConfig() automaticamente se non sono definiti gestori per il logger root.

#!/usr/bin/env pythonimport logginglogging.basicConfig(filename='test.log', format='%(filename)s: %(message)s', level=logging.DEBUG)logging.debug('This is a debug message')logging.info('This is an info message')logging.warning('This is a warning message')logging.error('This is an error message')logging.critical('This is a critical message')

L’esempio configura il logger root con basicConfig.

logging.basicConfig(filename='test.log', format='%(filename)s: %(message)s', level=logging.DEBUG)

Con filename, impostiamo il file in cui scrivere i messaggi di log. Il format determina cosa viene registrato nel file; abbiamo il nome del file e il messaggio. Con level, impostiamo la soglia di log.

$ basic_config.py$ cat test.logbasic_config.py: This is a debug messagebasic_config.py: This is an info messagebasic_config.py: This is a warning messagebasic_config.py: This is an error messagebasic_config.py: This is a critical message

Dopo aver eseguito il programma, abbiamo cinque messaggi scritti nel filetest.log.

Python logging fileConfig

Il fileConfig() legge la configurazione di log dal file in formato configparser.

keys=root,devkeys=consoleHandlerkeys=extend,simplelevel=INFOhandlers=consoleHandlerlevel=INFOhandlers=consoleHandlerqualname=devpropagate=0class=StreamHandlerlevel=INFOformatter=extendargs=(sys.stdout,)format=%(asctime)s - %(name)s - %(levelname)s - %(message)sformat=%(asctime)s - %(message)s

Il log.conf definisce un logger, un gestore e un formattatore.

#!/usr/bin/env pythonimport loggingimport logging.configlogging.config.fileConfig(fname='log.conf')logger = logging.getLogger('dev')logger.info('This is an information message')

L’esempio legge il file di configurazione dei log dal log.conf.

$ file_config.py2019-03-28 15:26:31,137 - dev - INFO - This is an information message

Questo è l’output.

Variabile di log di Python

I dati dinamici sono registrati usando la formattazione delle stringhe.

#!/usr/bin/env pythonimport loggingroot = logging.getLogger()root.setLevel(logging.INFO)log_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format)# incident happenserror_message = 'authentication failed'root.error(f'error: {error_message}')

L’esempio scrive dati personalizzati nel messaggio di log.

2019-03-21 14:17:23,196 log_variable.py: error: authentication failed

Questo è il messaggio di log.

Python logging formato datetime

Il datetime è incluso nel messaggio di log con il asctime record di log. Con l’opzione di configurazione datefmt, possiamo formattare la stringa datetime.

#!/usr/bin/env pythonimport logginglogger = logging.getLogger()logger.setLevel(logging.DEBUG)log_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format, datefmt='%Y-%m-%d %H:%M:%S')logger.info("information message")

L’esempio formatta il datetime del messaggio di log.

log_format = '%(asctime)s %(filename)s: %(message)s'

Includiamo la stringa datetime nel log con asctime.

logging.basicConfig(filename="test.log", format=log_format, datefmt='%Y-%m-%d %H:%M:%S')

L’opzione datefmt formatta la stringa datetime.

2019-03-21 14:17:23,196 log_variable.py: error: authentication failed2019-03-21 14:23:33 date_time.py: information message

Nota la differenza nel formato della stringa datetime.

Python logging stack trace

Lo stack trace è uno stack di chiamate di funzioni che sono state eseguite fino al punto di un’eccezione lanciata. Lo stack trace è incluso con l’opzione exc_info.

#!/usr/bin/env pythonimport logginglog_format = '%(asctime)s %(filename)s: %(message)s'logging.basicConfig(filename="test.log", format=log_format)vals = try: print(vals)except Exception as e: logging.error("exception occurred", exc_info=True)

Nell’esempio, registriamo l’eccezione che viene lanciata quando si cerca di accedere ad un indice di lista inesistente.

logging.error("exception occurred", exc_info=True)

La traccia dello stack è inclusa nel log impostando il exc_info a True.

2019-03-21 14:56:21,313 stack_trace.py: exception occurredTraceback (most recent call last): File "C:\Users\Jano\Documents\pyprogs\pylog\stack_trace.py", line 11, in <module> print(vals)IndexError: list index out of range

Lo stack trace è incluso nel log.

Python logging getLogger

Il getLogger() restituisce un logger con il nome specificato. È una pratica comune mettere il nome del modulo con __name__.

Tutte le chiamate a questa funzione con un dato nome restituiscono la stessa istanza di logger, il che significa che le istanze di logger non hanno mai bisogno di essere passate tra diverse parti di un’applicazione.

#!/usr/bin/env pythonimport loggingimport sysmain = logging.getLogger('main')main.setLevel(logging.DEBUG)handler = logging.FileHandler('my.log')format = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')handler.setFormatter(format)main.addHandler(handler)main.info('info message')main.critical('critical message')main.debug('debug message')main.warning('warning message')main.error('error message')

L’esempio crea un nuovo logger con getLogger().

main = logging.getLogger('main')main.setLevel(logging.DEBUG)

Viene creato un logger chiamato main; impostiamo il livello di registrazione a DEBUG.

handler = logging.FileHandler('my.log')

Viene creato un gestore di file. I messaggi saranno scritti nelmy.log file.

format = logging.Formatter('%(asctime)s %(name)s %(levelname)s: %(message)s')handler.setFormatter(format)

Viene creato un formattatore. Esso include l’ora, il nome del logger, il livello di registrazione e il messaggio da registrare. Il formattatore viene aggiunto al gestore con setFormatter().

main.addHandler(handler)

Il gestore viene aggiunto al logger con addHandler().

$ cat my.log2019-03-21 14:15:45,439 main INFO: info message2019-03-21 14:15:45,439 main CRITICAL: critical message2019-03-21 14:15:45,439 main DEBUG: debug message2019-03-21 14:15:45,439 main WARNING: warning message2019-03-21 14:15:45,439 main ERROR: error message

Questi sono i messaggi di log scritti.

Configurazione YAML del logging di Python

I dettagli del logging possono essere definiti in un file di configurazione YAML. È comunemente usato per i file di configurazione.

$ pip install pyyaml

Abbiamo bisogno di installare il modulo pyyaml.

version: 1formatters: simple: format: "%(asctime)s %(name)s: %(message)s" extended: format: "%(asctime)s %(name)s %(levelname)s: %(message)s"handlers: console: class: logging.StreamHandler level: INFO formatter: simple file_handler: class: logging.FileHandler level: INFO filename: test.log formatter: extended propagate: falseloggers: dev: handlers: test: handlers: root: handlers: 

Nel file di configurazione, abbiamo definito vari formattatori, gestori e logger. L’opzione propagate impedisce la propagazione dei messaggi di log ai logger genitori; nel nostro caso, al logger principale, altrimenti i messaggi verrebbero duplicati.

#!/usr/bin/env pythonimport loggingimport logging.configimport yamlwith open('config.yaml', 'r') as f: log_cfg = yaml.safe_load(f.read())logging.config.dictConfig(log_cfg)logger = logging.getLogger('dev')logger.setLevel(logging.INFO)logger.info('This is an info message')logger.error('This is an error message')

Nell’esempio, leggiamo il file di configurazione e usiamo il dev logger.

$ log_yaml.py2019-03-28 11:36:54,854 dev: This is an info message2019-03-28 11:36:54,855 dev: This is an error message

Quando eseguiamo il programma, ci sono due messaggi nella console.I gestori della console usano il formattatore semplice con meno informazioni.

...2019-03-28 11:36:54,854 dev INFO: This is an info message2019-03-28 11:36:54,855 dev ERROR: This is an error message

Ci sono messaggi di log all’interno del file test.log.Sono prodotti dal formattatore esteso con più informazioni.

In questo tutorial, abbiamo lavorato con la libreria di log di Python.

Elenco di tutti i tutorial di Python.