Come Utilizzare il Logging in Python 3

Introduzione

Il modulo logging fa parte della libreria standard di Python e fornisce il tracciamento degli eventi che si verificano durante l’esecuzione del software. Puoi aggiungere chiamate di logging al tuo codice per indicare quali eventi sono accaduti.

Il modulo logging consente sia il logging diagnostico che registra gli eventi relativi al funzionamento di un’applicazione, sia il logging di audit che registra gli eventi delle transazioni di un utente per l’analisi. Viene utilizzato soprattutto per registrare gli eventi su un file.

Prerequisiti

Dovresti avere Python 3 installato e un ambiente di programmazione configurato sul tuo computer o server. Se non hai un ambiente di programmazione configurato, puoi fare riferimento alle guide di installazione e configurazione per un ambiente di programmazione locale o per un ambiente di programmazione sul tuo server appropriato per il tuo sistema operativo (Ubuntu, CentOS, Debian, ecc.).

Perché utilizzare il modulo logging

Il modulo logging tiene traccia degli eventi che si verificano all’interno di un programma, rendendo possibile visualizzare l’output relativo a ciascuno degli eventi che si verificano durante l’esecuzione di un pezzo di software.

Potresti essere più familiare con il controllo degli eventi che si verificano utilizzando l’istruzione print() all’interno del tuo codice. L’istruzione print() fornisce un modo basilare per eseguire il debug del tuo codice per risolvere problemi. Anche se l’inserimento di istruzioni print() in tutto il codice può tracciare il flusso di esecuzione e lo stato attuale del tuo programma, questa soluzione si dimostra meno manutenibile rispetto all’utilizzo del modulo logging per alcune ragioni:

• Diventa difficile distinguere tra output di debug e output normale del programma perché i due sono mescolati
• Quando si utilizzano le istruzioni print() sparse nel codice, non c’è un modo efficiente per disabilitare quelle che forniscono output di debug
• Diventa difficile rimuovere tutte le istruzioni print() quando hai finito il debug
• Non c’è un record di log che contenga informazioni diagnostiche facilmente disponibili

È una buona idea abituarsi ad utilizzare il modulo logging nel tuo codice poiché questo è più adatto per applicazioni che vanno oltre i piccoli script Python e fornisce un approccio sostenibile al debug.

Poiché i log possono mostrare il comportamento e gli errori nel tempo, possono anche fornire un’immagine complessiva migliore di ciò che sta accadendo nel processo di sviluppo dell’applicazione.

Stampa dei messaggi di debug sulla console

Se sei abituato a utilizzare l’istruzione print() per vedere cosa sta accadendo in un programma, potresti essere abituato a vedere un programma che definisce una classe e istanzia oggetti che generano qualcosa di simile a questo:

class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        print("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        print("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        print("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Il codice sopra ha un metodo __init__ per definire il nome e il prezzo di un oggetto della classe Pizza. Ha quindi due metodi, uno chiamato make() per fare le pizze e uno chiamato eat() per mangiare le pizze. Questi due metodi prendono come parametro quantità, inizializzata a 1.

Ora eseguiamo il programma:

python pizza.py

Riceveremo l’output seguente:

Output
Pizza created: artichoke ($15)
Made 1 artichoke pizza(s)
Ate 1 pizza(s)
Pizza created: margherita ($12)
Made 2 margherita pizza(s)
Ate 1 pizza(s)

Mentre l’istruzione print() ci permette di vedere che il codice sta funzionando, possiamo usare il modulo logging per fare questo invece.

Eliminiamo o commentiamo le istruzioni print() in tutto il codice e aggiungiamo import logging all’inizio del file:

import logging


class Pizza():
    def __init__(self, name, value):
        self.name = name
        self.value = value
...

Il modulo logging ha un livello predefinito di WARNING, che è un livello superiore a DEBUG. Poiché useremo il modulo logging per il debug in questo esempio, dobbiamo modificare la configurazione in modo che il livello di logging.DEBUG ci restituisca informazioni sulla console. Possiamo farlo aggiungendo la seguente riga sotto l’istruzione di importazione:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

Questo livello di logging.DEBUG si riferisce a un valore intero costante che riferiamo nel codice sopra per impostare una soglia. Il livello di DEBUG è 10.

Ora sostituiremo tutte le istruzioni print() con istruzioni logging.debug(). A differenza di logging.DEBUG che è una costante, logging.debug() è un metodo del modulo logging. Quando lavoriamo con questo metodo, possiamo utilizzare lo stesso stringa passata a print(), come mostrato nel seguente esempio:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

A questo punto, quando eseguiamo il programma con il comando python pizza.py, riceveremo questo output:

Output
DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

I messaggi di log hanno livello di gravità DEBUG così come la parola root incorporata in essi, che si riferisce al livello del tuo modulo Python. Il modulo logging può essere utilizzato con una gerarchia di registri che hanno nomi diversi, in modo che tu possa utilizzare un registro diverso per ciascuno dei tuoi moduli.

Ad esempio, puoi impostare registri uguali a diversi registri che hanno nomi e output diversi:

logger1 = logging.getLogger("module_1")
logger2 = logging.getLogger("module_2")

logger1.debug("Module 1 debugger")
logger2.debug("Module 2 debugger")

Output
DEBUG:module_1:Module 1 debugger
DEBUG:module_2:Module 2 debugger

Ora che abbiamo compreso come utilizzare il modulo logging per stampare messaggi sulla console, passiamo all’utilizzo del modulo logging per stampare messaggi su un file.

Registrazione dei messaggi su un file

Il principale scopo del modulo logging è registrare messaggi su un file anziché su una console. Mantenere un file di messaggi fornisce dati nel tempo che puoi consultare e quantificare in modo da poter vedere quali modifiche devono essere apportate al tuo codice.

Per iniziare a registrare su un file, possiamo modificare il metodo logging.basicConfig() per includere un parametro filename. In questo caso, chiamiamo il file test.log:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("artichoke", 15)
pizza_01.make()
pizza_01.eat()

pizza_02 = Pizza("margherita", 12)
pizza_02.make(2)
pizza_02.eat()

Il codice sopra è lo stesso di quello nella sezione precedente, tranne che ora abbiamo aggiunto il nome del file per il log da stampare. Una volta eseguito il codice con il comando python pizza.py, dovremmo avere un nuovo file nella nostra directory chiamato test.log.

Apriamo il file test.log con nano (o l’editor di testo che preferisci):

nano test.log

Quando il file si apre, riceveremo quanto segue:

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)

Questo è simile all’output della console che abbiamo incontrato nella sezione precedente, tranne che ora è nel file test.log.

Chiudiamo il file con CTRL + x e torniamo al file pizza.py in modo da poter modificare il codice.

Manteniamo gran parte del codice lo stesso, ma modifichiamo i parametri nelle due istanze di pizza, pizza_01 e pizza_02:

import logging

logging.basicConfig(filename="test.log", level=logging.DEBUG)


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

# Modifica i parametri dell'oggetto pizza_01
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

# Modifica i parametri dell'oggetto pizza_02
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Con queste modifiche, eseguiamo nuovamente il programma con il comando python pizza.py.

Una volta eseguito il programma, possiamo aprire di nuovo il nostro file test.log con nano:

nano test.log

Quando esaminiamo il file, vedremo che sono state aggiunte diverse nuove righe e che le righe precedenti dall’ultima volta che il programma è stato eseguito sono state conservate:

DEBUG:root:Pizza created: artichoke ($15)
DEBUG:root:Made 1 artichoke pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: margherita ($12)
DEBUG:root:Made 2 margherita pizza(s)
DEBUG:root:Ate 1 pizza(s)
DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)

Pur essendo queste informazioni sicuramente utili, possiamo rendere il registro più informativo aggiungendo ulteriori attributi di LogRecord. Principalmente, vorremmo aggiungere un timestamp leggibile dall’utente che ci dica quando è stato creato il LogRecord.

Possiamo aggiungere quell’attributo a un parametro chiamato format, facendo riferimento ad esso come mostrato nella tabella con la stringa %(asctime)s. Inoltre, per mantenere il nome del livello DEBUG, sarà necessario includere la stringa %(levelname)s e per mantenere la stringa del messaggio che chiediamo al registro di stampare includeremo %(message)s. Ogni uno di questi attributi sarà separato da due punti, come mostrato nel codice aggiunto:

import logging

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


class Pizza():
    def __init__(self, name, price):
        self.name = name
        self.price = price
        logging.debug("Pizza created: {} (${})".format(self.name, self.price))

    def make(self, quantity=1):
        logging.debug("Made {} {} pizza(s)".format(quantity, self.name))

    def eat(self, quantity=1):
        logging.debug("Ate {} pizza(s)".format(quantity, self.name))

pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Quando eseguiamo il codice sopra con gli attributi aggiunti con il comando python pizza.py, otterremo nuove righe aggiunte al nostro file test.log che includono il timestamp leggibile dall’essere umano oltre al nome del livello DEBUG e ai messaggi associati che vengono passati al registro come stringhe.

DEBUG:root:Pizza created: Sicilian ($18)
DEBUG:root:Made 5 Sicilian pizza(s)
DEBUG:root:Ate 4 pizza(s)
DEBUG:root:Pizza created: quattro formaggi ($16)
DEBUG:root:Made 2 quattro formaggi pizza(s)
DEBUG:root:Ate 2 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: Sicilian ($18)
2021-08-19 23:31:34,484:DEBUG:Made 5 Sicilian pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 4 pizza(s)
2021-08-19 23:31:34,484:DEBUG:Pizza created: quattro formaggi ($16)
2021-08-19 23:31:34,484:DEBUG:Made 2 quattro formaggi pizza(s)
2021-08-19 23:31:34,484:DEBUG:Ate 2 pizza(s)

A seconda delle tue esigenze, potresti voler fare uso di ulteriori attributi di LogRecord nel tuo codice per rendere i log dei file del programma rilevanti per te.

Registrare messaggi di debug e altri messaggi in file separati ti fornisce una comprensione olistica del tuo programma Python nel tempo, offrendoti l’opportunità di risolvere i problemi e modificare il tuo codice in modo informato dal lavoro storico svolto nel programma, così come dagli eventi e dalle transazioni che si verificano.

Tabella dei Livelli di Registrazione

Come sviluppatore, puoi assegnare un livello di importanza all’evento catturato nel registro tramite l’aggiunta di un livello di gravità. I livelli di gravità sono mostrati nella tabella qui sotto.

I livelli di registrazione sono tecnicamente interi (una costante), e sono tutti in incrementi di 10, a partire da NOTSET che inizializza il registro al valore numerico 0.

Puoi anche definire i tuoi livelli relativi ai livelli predefiniti. Se definisci un livello con lo stesso valore numerico, sovrascriverai il nome associato a quel valore.

La seguente tabella mostra i vari nomi di livello, il loro valore numerico, quale funzione puoi utilizzare per chiamare il livello, e a cosa serve quel livello.

Il modulo logging imposta il livello predefinito a WARNING, quindi WARNING, ERROR, e CRITICAL saranno tutti registrati per impostazione predefinita. Nell’esempio sopra, abbiamo modificato la configurazione per includere il livello DEBUG con il seguente codice:

logging.basicConfig(level=logging.DEBUG)

Puoi leggere ulteriori informazioni sui comandi e sul lavoro con il debugger dalla documentazione ufficiale di logging.

Conclusione

Il debug è un passaggio importante di qualsiasi progetto di sviluppo software. Il modulo logging fa parte della libreria standard di Python, fornisce il tracciamento degli eventi che si verificano durante l’esecuzione del software e può produrre in output questi eventi in un file di log separato per consentirti di tenere traccia di ciò che accade mentre il tuo codice viene eseguito. Questo ti offre l’opportunità di eseguire il debug del tuo codice basandoti sulla comprensione dei vari eventi che si verificano durante l’esecuzione del programma nel tempo.