Wie man Logging in Python 3 verwendet

Einführung

Das logging Modul ist Teil der Standard-Python-Bibliothek und bietet die Verfolgung von Ereignissen, die während des Softwarebetriebs auftreten. Sie können Logging-Aufrufe zu Ihrem Code hinzufügen, um anzuzeigen, welche Ereignisse stattgefunden haben.

Das logging Modul ermöglicht sowohl diagnostisches Logging, das Ereignisse im Zusammenhang mit dem Betrieb einer Anwendung aufzeichnet, als auch Audit-Logging, das die Ereignisse der Transaktionen eines Benutzers zur Analyse aufzeichnet. Es wird insbesondere verwendet, um Ereignisse in einer Datei aufzuzeichnen.

Voraussetzungen

Sie sollten Python 3 installiert und eine Programmierumgebung auf Ihrem Computer oder Server eingerichtet haben. Wenn Sie keine Programmierumgebung eingerichtet haben, können Sie auf die Installations- und Einrichtungsanleitungen für eine lokale Programmierumgebung oder für eine Programmierumgebung auf Ihrem Server verweisen, die für Ihr Betriebssystem (Ubuntu, CentOS, Debian usw.) geeignet ist.

Warum das logging Modul verwenden

Das logging-Modul hält eine Aufzeichnung der Ereignisse, die in einem Programm auftreten, sodass es möglich ist, Ausgaben im Zusammenhang mit den Ereignissen zu sehen, die während der Laufzeit eines Softwarestücks auftreten.

Sie sind möglicherweise vertrauter damit, zu überprüfen, ob Ereignisse eintreten, indem Sie die print()-Anweisung in Ihrem Code verwenden. Die print()-Anweisung bietet eine grundlegende Möglichkeit, um Ihren Code zu debuggen und Probleme zu lösen. Während das Einfügen von print()-Anweisungen in Ihrem Code den Ausführungsfluss und den aktuellen Zustand Ihres Programms verfolgt, erweist sich diese Lösung aus mehreren Gründen als weniger wartbar als die Verwendung des logging-Moduls:

• Es wird schwierig, zwischen Debugging-Ausgaben und normaler Programmausgabe zu unterscheiden, da die beiden vermischt sind.
• Wenn man print()-Anweisungen, die über den Code verteilt sind, verwendet, gibt es keine effiziente Möglichkeit, die Anweisungen zu deaktivieren, die Debugging-Ausgaben liefern.
• Es wird schwierig, alle print()-Anweisungen zu entfernen, wenn Sie mit dem Debuggen fertig sind.
• Es gibt keinen Protokolleintrag, der leicht verfügbare Diagnoseinformationen enthält.

Es ist eine gute Idee, sich daran zu gewöhnen, das logging-Modul in Ihrem Code zu verwenden, da dies für Anwendungen, die über kleine Python-Skripte hinauswachsen, geeigneter ist und einen nachhaltigen Ansatz für das Debugging bietet.

Da Protokolle Ihnen Verhalten und Fehler im Laufe der Zeit zeigen können, geben sie Ihnen auch ein besseres Gesamtbild davon, was in Ihrem Anwendungsentwicklungsprozess vor sich geht.

Debug-Nachrichten in die Konsole drucken

Wenn Sie es gewohnt sind, die print()-Anweisung zu verwenden, um zu sehen, was in einem Programm passiert, sind Sie möglicherweise daran gewöhnt, ein Programm zu sehen, das eine Klasse definiert und Objekte instanziiert, die etwas wie dies generiert:

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

Der oben stehende Code hat eine __init__-Methode, um den name und den price eines Objekts der Klasse Pizza zu definieren. Dann gibt es zwei Methoden, eine namens make() zum Pizzabacken und eine namens eat() zum Pizzaessen. Diese beiden Methoden nehmen den Parameter quantity entgegen, der auf 1 initialisiert wird.

Jetzt lassen Sie uns das Programm ausführen:

python pizza.py

Wir werden die folgende Ausgabe erhalten:

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)

Während die print()-Anweisung es uns ermöglicht, zu sehen, dass der Code funktioniert, können wir stattdessen das logging-Modul verwenden.

Lass uns die print()-Anweisungen im gesamten Code entfernen oder auskommentieren und import logging an den Anfang der Datei hinzufügen:

import logging


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

Das logging Modul hat ein standardmäßiges Level von WARNING, welches über dem Level DEBUG liegt. Da wir das logging Modul in diesem Beispiel zum Debugging verwenden werden, müssen wir die Konfiguration ändern, sodass das Level logging.DEBUG Informationen an die Konsole zurückgibt. Das können wir tun, indem wir die folgende Zeile unter der Import-Anweisung hinzufügen:

import logging

logging.basicConfig(level=logging.DEBUG)


class Pizza():
...

Dieses Niveau von logging.DEBUG bezieht sich auf einen konstanten ganzzahligen Wert, den wir im obigen Code verwenden, um einen Schwellenwert festzulegen. Das Niveau von DEBUG beträgt 10.

Jetzt werden wir alle print() Anweisungen durch logging.debug() Anweisungen ersetzen. Im Gegensatz zu logging.DEBUG, das eine Konstante ist, ist logging.debug() eine Methode des logging Moduls. Wenn wir mit dieser Methode arbeiten, können wir den gleichen String verwenden, der an print() übergeben wurde, wie im Folgenden gezeigt:

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

An diesem Punkt, wenn wir das Programm mit dem Befehl python pizza.py ausführen, erhalten wir diese Ausgabe:

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)

Die Protokollnachrichten haben die Schweregradstufe DEBUG sowie das Wort root, das sich auf die Ebene Ihres Python-Moduls bezieht. Das logging-Modul kann mit einer Hierarchie von Loggern verwendet werden, die unterschiedliche Namen haben, sodass Sie für jedes Ihrer Module einen anderen Logger verwenden können.

Zum Beispiel können Sie Logger verschiedenen Loggern zuweisen, die unterschiedliche Namen und unterschiedliche Ausgaben haben:

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

Jetzt, da wir verstanden haben, wie man das logging-Modul verwendet, um Nachrichten in die Konsole zu drucken, lassen Sie uns zum Drucken von Nachrichten in eine Datei mit dem logging-Modul übergehen.

Protokollierung von Nachrichten in eine Datei

Der Hauptzweck des logging-Moduls besteht darin, Nachrichten in eine Datei zu protokollieren, anstatt in eine Konsole. Eine Datei mit Nachrichten zu führen, gibt Ihnen über die Zeit Daten, die Sie konsultieren und quantifizieren können, um zu sehen, welche Änderungen an Ihrem Code vorgenommen werden müssen.

Um mit dem Protokollieren in eine Datei zu beginnen, können wir die Methode logging.basicConfig() modifizieren, um einen filename-Parameter einzuschließen. In diesem Fall nennen wir die Datei 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()

Der obige Code ist derselbe wie im vorherigen Abschnitt, mit dem Unterschied, dass wir jetzt den Dateinamen für das Protokoll hinzugefügt haben, in das geschrieben werden soll. Nachdem wir den Code mit dem python pizza.py-Befehl ausgeführt haben, sollten wir eine neue Datei in unserem Verzeichnis mit dem Namen test.log haben.

Lass uns die test.log Datei mit nano (oder dem Texteditor deiner Wahl) öffnen:

nano test.log

Wenn die Datei geöffnet wird, erhalten wir Folgendes:

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)

Dies ist ähnlich der Konsolenausgabe, die wir im vorherigen Abschnitt getroffen haben, nur dass sie sich jetzt in der test.log Datei befindet.

Lass uns die Datei mit CTRL + x schließen und in die pizza.py Datei zurückkehren, damit wir den Code ändern können.

Wir werden einen Großteil des Codes gleich lassen, aber die Parameter in den beiden Pizza-Instanzen, pizza_01 und pizza_02, ändern:

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)

Mit diesen Änderungen lassen Sie das Programm erneut mit dem Befehl python pizza.py ausführen.

Sobald das Programm ausgeführt wurde, können wir unsere test.log Datei erneut mit nano öffnen:

nano test.log

Wenn wir die Datei überprüfen, werden wir sehen, dass mehrere neue Zeilen hinzugefügt wurden und dass die vorherigen Zeilen von der letzten Ausführung des Programms beibehalten wurden:

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)

Während diese Informationen sicherlich nützlich sind, können wir das Protokoll informativer gestalten, indem wir zusätzliche LogRecord-Attribute hinzufügen. Vor allem möchten wir einen menschenlesbaren Zeitstempel hinzufügen, der uns sagt, wann der LogRecord erstellt wurde.

Wir können dieses Attribut zu einem Parameter namens format hinzufügen und es wie in der Tabelle mit der Zeichenfolge %(asctime)s referenzieren. Zusätzlich, um den Namen der DEBUG Ebene beizubehalten, müssen wir die Zeichenfolge %(levelname)s einfügen, und um die Zeichenfolge Nachricht, die wir den Logger bitten, auszugeben, beizubehalten, fügen wir %(message)s hinzu. Jedes dieser Attribute wird durch einen Doppelpunkt getrennt, wie im hinzugefügten Code gezeigt:

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)

Wenn wir den obigen Code mit den hinzugefügten Attributen mit dem Befehl python pizza.py ausführen, werden neue Zeilen zu unserer test.log Datei hinzugefügt, die den menschenlesbaren Zeitstempel sowie den Levelnamen DEBUG und die zugehörigen Nachrichten enthalten, die als Strings an den Logger übergeben werden.

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)

Je nach Ihren Bedürfnissen möchten Sie möglicherweise zusätzliche LogRecord-Attribute in Ihrem Code verwenden, um die Protokolle Ihrer Programmdateien für Sie relevant zu machen.

Das Protokollieren von Debug- und anderen Nachrichten in separaten Dateien gibt Ihnen im Laufe der Zeit ein ganzheitliches Verständnis Ihres Python-Programms, wodurch Sie die Möglichkeit haben, Ihren Code auf eine Weise zu beheben und zu ändern, die durch die in das Programm investierte historische Arbeit sowie durch die eintretenden Ereignisse und Transaktionen informiert ist.

Tabelle der Protokollierungsstufen

Als Entwickler können Sie dem Ereignis, das im Logger erfasst wird, einen Grad der Wichtigkeit zuordnen, indem Sie ein Schweregradniveau hinzufügen. Die Schweregrade sind in der folgenden Tabelle angegeben.

Die Protokollierungsstufen sind technisch gesehen ganze Zahlen (eine Konstante), und sie sind alle in Schritten von 10 angeordnet, beginnend mit NOTSET, das den Logger mit dem numerischen Wert 0 initialisiert.

Sie können auch Ihre eigenen Ebenen in Bezug auf die vordefinierten Ebenen festlegen. Wenn Sie eine Ebene mit demselben numerischen Wert definieren, überschreiben Sie den Namen, der mit diesem Wert verknüpft ist.

Die folgende Tabelle zeigt die verschiedenen Ebenennamen, ihren numerischen Wert, welche Funktion Sie verwenden können, um die Ebene aufzurufen, und wofür diese Ebene verwendet wird.

CRITICAL

logging.critical()

ERROR

logging.error()

WARNING

logging.warning()

INFO

logging.info()

DEBUG

logging.debug()

Das logging Modul setzt das Standardniveau auf WARNING, sodass WARNING, ERROR und CRITICAL standardmäßig protokolliert werden. Im obigen Beispiel haben wir die Konfiguration geändert, um das DEBUG Niveau mit folgendem Code einzuschließen:

logging.basicConfig(level=logging.DEBUG)

Sie können mehr über die Befehle und die Arbeit mit dem Debugger in der offiziellen logging Dokumentation lesen.

Schlussfolgerung

Debugging ist ein wichtiger Schritt jedes Softwareentwicklungsprojekts. Das logging Modul ist Teil der standardmäßigen Python-Bibliothek, bietet die Nachverfolgung von Ereignissen, die während der Ausführung von Software auftreten, und kann diese Ereignisse in eine separate Protokolldatei ausgeben, um Ihnen zu ermöglichen, nachzuvollziehen, was während der Ausführung Ihres Codes passiert. Dies gibt Ihnen die Möglichkeit, Ihren Code zu debuggen, indem Sie die verschiedenen Ereignisse verstehen, die beim Ausführen Ihres Programms im Laufe der Zeit auftreten.