Python Logging Basics

Questo articolo copre le basi dell’uso del modulo di log standard che viene fornito con tutte le distribuzioni Python. Dopo averlo letto, dovresti essere in grado di integrare facilmente il logging nella tua applicazione Python.

Modulo di log della libreria standard

Python è dotato di un modulo di log nella libreria standard che fornisce una struttura flessibile per emettere messaggi di log dai programmi Python. Questo modulo è ampiamente usato dalle librerie ed è il primo punto di riferimento per la maggior parte degli sviluppatori quando si tratta di logging.

Il modulo fornisce un modo per le applicazioni di configurare diversi gestori di log e un modo per indirizzare i messaggi di log a questi gestori. Questo permette una configurazione altamente flessibile che può affrontare un sacco di casi d’uso diversi.

Per emettere un messaggio di log, un chiamante richiede prima un logger nominato. Il nome può essere usato dall’applicazione per configurare diverse regole per diversi logger. Questo logger poi può essere usato per emettere messaggi semplicemente formattati a diversi livelli di log (DEBUG, INFO, ERROR, ecc.), che di nuovo possono essere usati dall’applicazione per gestire messaggi di priorità più alta rispetto a quelli di priorità più bassa. Anche se potrebbe sembrare complicato, può essere semplice come questo:

import logginglog = logging.getLogger("my-logger")log.info("Hello, world")

Internamente, il messaggio viene trasformato in un oggetto LogRecord e indirizzato a un oggetto Handler registrato per questo logger. L’handler userà poi un Formatter per trasformare il LogRecord in una stringa ed emetterla.

Fortunatamente, la maggior parte delle volte gli sviluppatori non devono essere a conoscenza dei dettagli. La documentazione di Python contiene un eccellente articolo sul modulo di log e su come tutto funziona insieme. Il resto di questo articolo si concentrerà sulle migliori pratiche invece che su tutti i possibili modi di usare questo modulo.

Livelli di log

Non tutti i messaggi di log sono creati uguali. I livelli di log sono elencati qui nella documentazione di Python; li includeremo qui per riferimento. Quando impostate un livello di log in Python usando il modulo standard, state dicendo alla libreria che volete gestire tutti gli eventi da quel livello in su. Se impostate il livello di log su INFO, esso includerà i messaggi INFO, WARNING, ERROR e CRITICAL. I messaggi NOTSET e DEBUG non saranno inclusi.

Logging dai moduli

Un’applicazione Python ben organizzataben organizzata applicazione Python è probabilmente composta da molti moduli. A volte questi moduli sono destinati ad essere usati da altri programmi, ma a meno che non stiate intenzionalmente sviluppando moduli riutilizzabili all’interno della vostra applicazione, è probabile che stiate usando moduli disponibili da pypi e moduli che voi stessi scrivete specificamente per la vostra applicazione.

In generale, un modulo dovrebbe emettere messaggi di log come migliore pratica e non dovrebbe configurare come tali messaggi sono gestiti. Questa è la responsabilità dell’applicazione.

L’unica responsabilità dei moduli è quella di rendere facile per l’applicazione instradare i propri messaggi di log. Per questa ragione, è una convenzione per ogni modulo usare semplicemente un logger con il nome del modulo stesso. Questo rende facile per l’applicazione instradare diversi moduli in modo diverso, mantenendo allo stesso tempo semplice il codice di log nel modulo. Il modulo ha bisogno solo di due righe per impostare il logging, e poi usare il logger nominato:

import logginglog = logging.getLogger(__name__)def do_something(): log.debug("Doing something!")

Questo è tutto quello che c’è da fare. In Python, __name__ contiene il nome completo del modulo corrente, quindi questo funzionerà semplicemente in qualsiasi modulo. Il modulo di log di Python fornisce un gran numero di modi per mettere a punto questo, ma per quasi tutte le applicazioni, la configurazione può essere molto semplice.

In generale, una configurazione consiste nell’aggiungere un Formatter e un Handler al logger principale. Poiché questo è così comune, il modulo di logging fornisce una funzione di utilità chiamata basicConfig che gestisce la maggior parte dei casi d’uso.

Le applicazioni dovrebbero configurare il logging il prima possibile, preferibilmente come prima cosa nell’applicazione, in modo che i messaggi di log non si perdano durante l’avvio.

Infine, le applicazioni dovrebbero avvolgere un blocco try/except intorno al codice principale dell’applicazione per inviare qualsiasi eccezione attraverso l’interfaccia di logging invece che solo a stderr. Questo è conosciuto come un gestore globale try catch. Non dovrebbe essere il luogo in cui si gestisce tutta la registrazione delle eccezioni, si dovrebbe continuare a pianificare le eccezioni nei blocchi try catch nei punti necessari del codice come regola empirica.

Esempio 1 – Registrazione su Standard Output per Systemd

Questa è la più semplice e probabilmente la migliore opzione per configurare la registrazione in questi giorni. Quando si usa systemd per eseguire un demone, le applicazioni possono semplicemente inviare messaggi di log a stdout o stderr e avere systemd che inoltra i messaggi a journald e syslog. Come ulteriore vantaggio, questo non richiede nemmeno di catturare le eccezioni, poiché Python le scrive già su errore standard. Detto questo, seguite le giuste convenzioni e gestite le vostre eccezioni.

Nel caso di esecuzione di Python in container come Docker, il logging su standard output è spesso la mossa più semplice, poiché questo output può essere gestito direttamente e facilmente dal container stesso.

import loggingimport oslogging.basicConfig(level=os.environ.get("LOGLEVEL", "INFO"))exit(main())

Ecco fatto. L’applicazione ora registrerà tutti i messaggi con livello INFO o superiore su stderr, usando un formato semplice:

ERROR:the.module.name:The log message

L’applicazione può anche essere configurata per includere messaggi DEBUG, o magari solo ERROR, impostando la variabile d’ambiente LOGLEVEL.

L’unico problema con questa soluzione è che le eccezioni sono registrate come linee multiple, il che può causare problemi per le analisi successive. Purtroppo, configurare Python per inviare eccezioni multi-linea come una singola linea non è così semplice, ma certamente possibile. Notate l’implementazione qui sotto, chiamando logging.exception è equivalente a logging.error(..., exc_info=True).

import loggingimport os class OneLineExceptionFormatter(logging.Formatter): def formatException(self, exc_info): result = super().formatException(exc_info) return repr(result) def format(self, record): result = super().format(record) if record.exc_text: result = result.replace("\n", "") return result handler = logging.StreamHandler()formatter = OneLineExceptionFormatter(logging.BASIC_FORMAT)handler.setFormatter(formatter)root = logging.getLogger()root.setLevel(os.environ.get("LOGLEVEL", "INFO"))root.addHandler(handler) try: exit(main())except Exception: logging.exception("Exception in main(): ") exit(1)

Esempio 2 – Syslog

L’alternativa è inviare direttamente a syslog. Questo è ottimo per i vecchi sistemi operativi che non hanno systemd. In un mondo ideale questo dovrebbe essere semplice, ma purtroppo, Python richiede una configurazione un po’ più elaborata per essere in grado di inviare messaggi di log unicode. Ecco un esempio di implementazione.

import loggingimport logging.handlersimport os class SyslogBOMFormatter(logging.Formatter): def format(self, record): result = super().format(record) return "ufeff" + result handler = logging.handlers.SysLogHandler('/dev/log')formatter = SyslogBOMFormatter(logging.BASIC_FORMAT)handler.setFormatter(formatter)root = logging.getLogger()root.setLevel(os.environ.get("LOGLEVEL", "INFO"))root.addHandler(handler) try: exit(main())except Exception: logging.exception("Exception in main()") exit(1)

Esempio 3 – File di log

L’ultima opzione è quella di registrare i messaggi direttamente su un file. Questo è raramente utile al giorno d’oggi, poiché gli amministratori possono configurare syslog per scrivere certi messaggi in file specifici, o se si distribuisce all’interno di container, questo è un anti-pattern. Inoltre, se si usa il logging centralizzato, avere a che fare con file di log aggiuntivi è una preoccupazione in più. Ma è un’opzione ancora disponibile.

Quando si fa il log su file, la cosa principale di cui fare attenzione è che i file di log devono essere ruotati regolarmente. L’applicazione deve rilevare il file di log che viene rinominato e gestire questa situazione. Mentre Python fornisce il proprio gestore di rotazione dei file, è meglio lasciare la rotazione dei log a strumenti dedicati come logrotate. Il WatchedFileHandler terrà traccia del file di log e lo riaprirà se viene ruotato, facendolo funzionare bene con logrotate senza richiedere alcun segnale specifico.

Ecco un’implementazione di esempio.

import loggingimport logging.handlersimport os handler = logging.handlers.WatchedFileHandler( os.environ.get("LOGFILE", "/var/log/yourapp.log"))formatter = logging.Formatter(logging.BASIC_FORMAT)handler.setFormatter(formatter)root = logging.getLogger()root.setLevel(os.environ.get("LOGLEVEL", "INFO"))root.addHandler(handler) try: exit(main())except Exception: logging.exception("Exception in main()") exit(1)

Altre destinazioni

È possibile utilizzare altre destinazioni di log, e alcuni framework ne fanno uso (es, Django può inviare certi messaggi di log come email). Il HTTPHandler potrebbe essere utile quando si è in esecuzione in un PaaS e non si ha accesso diretto all’host per impostare syslog o si è dietro un firewall che blocca il syslog in uscita, e può essere utilizzato per registrare direttamente a sistemi di log centralizzati come SolarWinds® Loggly®.

Molti dei gestori di log più elaborati nella libreria di log possono facilmente bloccare l’applicazione, causando interruzioni semplicemente perché l’infrastruttura di log non risponde. Per queste ragioni, è meglio mantenere la configurazione dei log di un’applicazione il più semplice possibile.

Una tendenza crescente nei log in generale è quella di separarli il più possibile dalle funzionalità di base della vostra applicazione. In questo modo si può avere un comportamento diverso in diversi ambienti o contesti di distribuzione. Usare l’HTTPHandler con un sistema come Loggly è un modo semplice per raggiungere facilmente questo obiettivo direttamente nella propria applicazione.

Quando si fa il deploy su container, cercare di mantenere le cose il più semplici possibile. Fate il log su out/err standard e affidatevi al vostro container host o alla vostra piattaforma di orchestrazione per capire cosa fare con i log. È ancora possibile utilizzare servizi di centralizzazione dei log, ma con un approccio sidecar o log shipper.

Se è desiderabile una configurazione a grana fine, il modulo di log fornisce anche la possibilità di caricare la configurazione dei log da un file di configurazione. Questo è abbastanza potente, ma raramente necessario. Quando si carica la configurazione di log da un file, specificare disable_existing_loggers=False. L’impostazione predefinita, che è lì solo per compatibilità all’indietro, disabiliterà qualsiasi logger creato dai moduli. Questo rompe molti moduli, quindi usatelo con cautela.

Summario

Il logging in Python è semplice e ben standardizzato, grazie ad un potente framework di logging proprio nella libreria standard.

I moduli dovrebbero semplicemente registrare tutto in un’istanza di logger per il nome del loro modulo. Questo rende facile per l’applicazione instradare i messaggi di log di diversi moduli in posti diversi, se necessario.

Le applicazioni hanno poi diverse opzioni per configurare il logging. In un’infrastruttura moderna, tuttavia, seguire le migliori pratiche semplifica molto questo aspetto. A meno che non sia specificamente necessario, loggare semplicemente su stdoutstderr e lasciare che system o il vostro contenitore gestisca i messaggi di log è sufficiente e rappresenta l’approccio migliore.