Comment utiliser la journalisation en Python 3

Introduction

Le module logging fait partie de la bibliothèque standard de Python et fournit un suivi des événements qui se produisent pendant l'exécution du logiciel. Vous pouvez ajouter des appels de journalisation à votre code pour indiquer quels événements se sont produits.

Le module logging permet à la fois la journalisation de diagnostic qui enregistre des événements liés au fonctionnement d'une application, ainsi que la journalisation d'audit qui enregistre les événements des transactions d'un utilisateur pour analyse. Il est particulièrement utilisé pour enregistrer des événements dans un fichier.

Conditions préalables

Vous devez avoir Python 3 installé et un environnement de programmation configuré sur votre ordinateur ou serveur. Si vous n'avez pas d'environnement de programmation configuré, vous pouvez consulter les guides d'installation et de configuration pour un environnement de programmation local ou pour un environnement de programmation sur votre serveur, approprié à votre système d'exploitation (Ubuntu, CentOS, Debian, etc.).

Pourquoi utiliser le module logging

Le module logging garde une trace des événements qui se produisent dans un programme, ce qui permet de voir la sortie liée à chacun des événements qui se produisent pendant l'exécution d'un logiciel.

Vous êtes peut-être plus familier avec le fait de vérifier que des événements se produisent en utilisant l'instruction print() dans votre code. L'instruction print() offre un moyen basique pour déboguer votre code afin de résoudre des problèmes. Bien que l'intégration d'instructions print() dans votre code puisse suivre le flux d'exécution et l'état actuel de votre programme, cette solution s'avère moins maintenable que l'utilisation du module logging pour plusieurs raisons :

• Il devient difficile de distinguer entre la sortie de débogage et la sortie normale du programme car les deux sont mélangés.
• Lors de l'utilisation des instructions print() dispersées dans le code, il n'y a pas de moyen efficace de désactiver celles qui fournissent une sortie de débogage.
• Il devient difficile de supprimer toutes les instructions print() lorsque vous avez terminé le débogage.
• Il n'y a aucun enregistrement de journal contenant des informations de diagnostic facilement accessibles.

C'est une bonne idée de prendre l'habitude d'utiliser le module logging dans votre code, car il est plus adapté aux applications qui dépassent le cadre des petits scripts Python et offre une approche durable du débogage.

Parce que les journaux peuvent montrer des comportements et des erreurs au fil du temps, ils peuvent également vous donner une meilleure vue d'ensemble de ce qui se passe dans votre processus de développement d'application.

Impression de messages de débogage dans la console

Si vous avez l'habitude d'utiliser l'instruction print() pour voir ce qui se passe dans un programme, vous êtes peut-être habitué à voir un programme qui définit une classe et instancie des objets qui génèrent quelque chose comme ceci :

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()

Le code ci-dessus a une méthode __init__ pour définir le nom et le prix d'un objet de la classe Pizza. Il comporte ensuite deux méthodes, l'une appelée make() pour faire des pizzas, et l'autre appelée eat() pour manger des pizzas. Ces deux méthodes prennent en paramètre quantity, qui est initialisé à 1.

Maintenant, exécutons le programme :

python pizza.py

Nous allons recevoir la sortie suivante :

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)

Bien que l'instruction print() nous permette de voir que le code fonctionne, nous pouvons utiliser le module logging pour faire cela à la place.

Retirons ou commentons les instructions print() dans tout le code, et ajoutons import logging en haut du fichier:

import logging


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

Le module logging a un niveau par défaut de WARNING, qui est un niveau supérieur à DEBUG. Comme nous allons utiliser le module logging pour le débogage dans cet exemple, nous devons modifier la configuration afin que le niveau de logging.DEBUG renvoie des informations à la console pour nous. Nous pouvons le faire en ajoutant la ligne suivante sous la déclaration d'importation :

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

Ce niveau de logging.DEBUG fait référence à une valeur entière constante que nous utilisons dans le code ci-dessus pour définir un seuil. Le niveau de DEBUG est 10.

Maintenant, nous allons remplacer toutes les instructions print() par des instructions logging.debug() à la place. Contrairement à logging.DEBUG qui est une constante, logging.debug() est une méthode du module logging. En travaillant avec cette méthode, nous pouvons utiliser la même chaîne passée à print(), comme montré ci-dessous :

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()

À ce stade, lorsque nous exécutons le programme avec la commande python pizza.py, nous recevrons cette sortie :

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)

Les messages de journal ont le niveau de sévérité DEBUG ainsi que le mot root qui y est intégré, ce qui fait référence au niveau de votre module Python. Le module logging peut être utilisé avec une hiérarchie de journaliseurs ayant des noms différents, afin que vous puissiez utiliser un journaliseur différent pour chacun de vos modules.

Par exemple, vous pouvez attribuer des enregistreurs à des enregistreurs différents qui ont des noms différents et des sorties différentes :

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

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

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

Maintenant que nous comprenons comment utiliser le module logging pour imprimer des messages dans la console, passons à l'utilisation du module logging pour imprimer des messages dans un fichier.

Journaliser des messages dans un fichier

Le but principal du module logging est de journaliser des messages dans un fichier plutôt que dans une console. Garder un fichier de messages vous fournit des données au fil du temps que vous pouvez consulter et quantifier afin de voir quels changements doivent être apportés à votre code.

Pour commencer à enregistrer dans un fichier, nous pouvons modifier la méthode logging.basicConfig() pour inclure un paramètre filename. Dans ce cas, appelons le nom du fichier 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()

Le code ci-dessus est le même que dans la section précédente, sauf que maintenant nous avons ajouté le nom du fichier pour l'enregistrement à imprimer. Une fois que nous exécuterons le code avec la commande python pizza.py, nous devrions avoir un nouveau fichier dans notre répertoire appelé test.log.

Ouvrons le fichier test.log avec nano (ou l'éditeur de texte de votre choix) :

nano test.log

Lorsque le fichier s'ouvre, nous recevrons ce qui suit :

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)

Ceci est similaire à la sortie de la console que nous avons rencontrée dans la section précédente, sauf qu'elle se trouve maintenant dans le fichier test.log.

Fermons le fichier avec CTRL + x et retournons dans le fichier pizza.py afin que nous puissions modifier le code.

Nous garderons une grande partie du code identique, mais nous modifierons les paramètres dans les deux instances de pizza, pizza_01 et 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))

Modify the parameters of the pizza_01 object
pizza_01 = Pizza("Sicilian", 18)
pizza_01.make(5)
pizza_01.eat(4)

Modify the parameters of the pizza_02 object
pizza_02 = Pizza("quattro formaggi", 16)
pizza_02.make(2)
pizza_02.eat(2)

Avec ces changements, exécutons à nouveau le programme avec la commande python pizza.py.

Une fois que le programme a été exécuté, nous pouvons ouvrir à nouveau notre fichier test.log avec nano :

nano test.log

Lorsque nous examinons le fichier, nous verrons que plusieurs nouvelles lignes ont été ajoutées, et que les lignes précédentes de la dernière fois que le programme a été exécuté ont été conservées :

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)

Bien que ces informations soient certainement utiles, nous pouvons rendre le journal plus informatif en ajoutant des attributs LogRecord supplémentaires. Principalement, nous aimerions ajouter un horodatage lisible par l'homme qui nous indique quand le LogRecord a été créé.

Nous pouvons ajouter cet attribut à un paramètre appelé format, le référencer comme indiqué dans le tableau avec la chaîne %(asctime)s. De plus, pour conserver le nom du niveau DEBUG, nous devrons inclure la chaîne %(levelname)s et pour conserver le message chaîne que nous demandons au logger d'imprimer, nous inclurons %(message)s. Chacun de ces attributs sera séparé par un deux-points, comme montré dans le code ajouté :

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)

Lorsque nous exécutons le code ci-dessus avec les attributs ajoutés à l'aide de la commande python pizza.py, nous obtiendrons de nouvelles lignes ajoutées à notre fichier test.log qui incluent l'horodatage lisible par l'homme en plus du nom de niveau DEBUG et des messages associés qui sont passés au logger en tant que chaînes.

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)

En fonction de vos besoins, vous voudrez peut-être utiliser des attributs LogRecord supplémentaires dans votre code afin de rendre les journaux de vos fichiers de programme pertinents pour vous.

Enregistrer des messages de débogage et d'autres messages dans des fichiers séparés vous donne une compréhension globale de votre programme Python au fil du temps, vous offrant l'opportunité de résoudre des problèmes et de modifier votre code d'une manière éclairée par le travail historique effectué sur le programme, ainsi que par les événements et transactions qui se produisent.

Table des niveaux de journalisation

En tant que développeur, vous pouvez attribuer un niveau d'importance à l'événement capturé dans le journal en ajoutant un niveau de gravité. Les niveaux de gravité sont affichés dans le tableau ci-dessous.

Les niveaux de journalisation sont techniquement des entiers (une constante), et ils sont tous en incréments de 10, en commençant par NOTSET qui initialise le journaliseur à la valeur numérique de 0.

Vous pouvez également définir vos propres niveaux par rapport aux niveaux prédéfinis. Si vous définissez un niveau avec la même valeur numérique, vous écraserez le nom associé à cette valeur.

Le tableau suivant montre les différents noms de niveaux, leur valeur numérique, quelle fonction vous pouvez utiliser pour appeler le niveau, et à quoi sert ce niveau.

CRITICAL

logging.critical()

ERROR

logging.error()

WARNING

logging.warning()

INFO

logging.info()

DEBUG

logging.debug()

Le module logging définit le niveau par défaut à WARNING, donc WARNING, ERROR et CRITICAL seront tous enregistrés par défaut. Dans l'exemple ci-dessus, nous avons modifié la configuration pour inclure le niveau DEBUG avec le code suivant :

logging.basicConfig(level=logging.DEBUG)

Vous pouvez en savoir plus sur les commandes et le travail avec le débogueur dans la documentation officielle de logging.

Conclusion

Le débogage est une étape importante de tout projet de développement logiciel. Le module logging fait partie de la bibliothèque standard de Python, fournit un suivi des événements qui se produisent pendant l'exécution du logiciel et peut enregistrer ces événements dans un fichier journal séparé pour vous permettre de suivre ce qui se passe pendant l'exécution de votre code. Cela vous offre l'opportunité de déboguer votre code en comprenant les divers événements qui se produisent lors de l'exécution de votre programme au fil du temps.