Logging in Python Tutorial

Wenn du gerade erst mit Python startest und mehr lernen möchtest, besuche DataCamps Kurs Introduction to Data Science in Python.

Im Allgemeinen ist Logging eine Möglichkeit, ein von einem Computerprogramm erzeugtes Protokoll zu führen. Eine Logdatei enthält in der Regel eine Reihe von Einträgen über Ereignisse, die in deinem Code (zum Beispiel in einem Python-Skript) oder in einem Betriebssystem auftreten. Diese Ereignisse oder Nachrichten werden in eine Logdatei geschrieben; eine Nachricht oder ein Ereignis kann auch eine Kommunikation zwischen verschiedenen Nutzenden sein.

Wie Logs erzeugt werden, hängt meist von den Entwicklerinnen und Entwicklern ab. Vielleicht sollen alle Aktionen einer Anwendung protokolliert werden, nur Fehlerfälle, oder gezielt wichtige Aktionen von Nutzenden. Eine wichtige Aktion kann zum Beispiel sein, nachzuvollziehen, welcher Endnutzer bzw. welche IP-Adresse auf die Anwendung oder den Server zugegriffen hat. Bei einem fehlgeschlagenen Versuch liefern die Logs oft bessere Einblicke als ein bloßer Stacktrace.

Ein anschauliches Beispiel: Du versuchst unter Linux eine Installation mit sudo-Rechten durchzuführen, hast diese Rechte aber nicht. Dann erscheint die Meldung "Xyz is not in the sudoers file. This incident will be reported", die in eine Logdatei geschrieben wird.

Die gute Nachricht: Python bringt ein integriertes Logging-Modul mit, das du ohne zusätzliche Installation sofort nutzen kannst.

Worin unterscheidet sich Logging von print?

Logging ähnelt in der Idee der print-Funktion. Allerdings fehlen bei print viele für Entwicklerinnen und Entwickler nützliche Informationen. Logging kann dagegen Zeitstempel und die Zeilennummer erfassen, an der der Fehler aufgetreten ist. Es kann Fehler oder beliebige Informationen in Dateien, an Sockets usw. schreiben und bietet fünf Schweregrade, anhand derer du dein Logging differenzieren kannst.

Die fünf Logging-Level, wie hier gezeigt, sind:

• Debug (10): Nützlich, um Probleme im Code zu diagnostizieren.

• Info (20): Kann als Bestätigung dienen, dass der Code fehlerfrei läuft. Ein gutes Beispiel für Info-Logs ist der Trainingsfortschritt eines Machine-Learning-Modells.

• Warning (30): Weist auf ein mögliches zukünftiges Problem hin. Zum Beispiel eine Warnung zu einem Modul, das künftig eingestellt wird, oder wenig verfügbarer RAM.

• Error (40): Ein schwerwiegender Fehler im Code, z. B. ein Syntaxfehler, Out-of-Memory-Fehler oder Exceptions.

• Critical (50): Ein Fehler, durch den das Programm nicht mehr funktioniert oder abrupt beendet wird.

Genug Theorie, oder?

Schauen wir uns an, wie du Logging in Python-Code einsetzt.

Doch vorher ein Blick auf die Tabelle mit Logging-Attributen. Einige davon wirst du in diesem Tutorial verwenden.

import logging

Jetzt rufst du die Methode basicConfig() auf. Sie hilft dir, eine Grundkonfiguration einzurichten, damit das Loggingsystem reibungslos läuft.

Du kannst damit Folgendes festlegen:

• den Schweregrad fürs Logging: die fünf Logging-Level.
• Schreiben der Ereignisse in eine Datei.
• Nur aktuelle Logs speichern, indem alte über filemode überschrieben werden.
• das Format, in dem Logs gespeichert werden.

Denk daran: Die Methode basicConfig() ist optional und kann entfallen.

logging.basicConfig()

Lass uns nun die fünf Schweregrade ausgeben.

logging.debug("A Debug Logging Message")

logging.info("A Info Logging Message")

logging.warning("A Warning Logging Message")

WARNING:root:A Warning Logging Message

logging.error("An Error Logging Message")

ERROR:root:An Error Logging Message

logging.critical("A Critical Logging Message")

CRITICAL:root:A Critical Logging Message

Wie du an den Ausgaben siehst, wurden standardmäßig nur Meldungen mit einem Schweregrad größer als 20 geloggt. Das ist die Default-Konfiguration des Python-Loggings.

Wie oben erwähnt, kannst du die Schwelle über basicConfig() anpassen. Hier setzen wir sie auf 20, das heißt, alle Logging-Level mit einem Schweregrad größer als 10 werden geloggt.

Hinweis: Starte den Kernel neu, bevor du die folgenden Zellen ausführst, damit die Ausgabe korrekt ist.

import logging

logging.basicConfig(level=logging.INFO)

logging.debug("A Debug Logging Message")

logging.info("A Info Logging Message")

INFO:root:A Info Logging Message

logging.warning("A Warning Logging Message")

WARNING:root:A Warning Logging Message

logging.error("An Error Logging Message")

ERROR:root:An Error Logging Message

logging.critical("A Critical Logging Message")

CRITICAL:root:A Critical Logging Message

Jetzt schreiben wir die obigen Ausgaben in eine Logdatei. Dafür nutzt du erneut basicConfig().

import logging

logging.basicConfig(level = logging.INFO, filename = 'datacamp.log')

logging.debug("A Debug Logging Message")

logging.info("A Info Logging Message")

logging.warning("A Warning Logging Message")

logging.error("An Error Logging Message")

logging.critical("A Critical Logging Message")

Wie du siehst, werden die Logs nun in die Datei datacamp.log geschrieben. Führst du die obigen Zellen mehrfach aus, werden die Einträge entsprechend oft angehängt. Standardmäßig ist die Datei im append-Modus.

Mit dem Schlüsselwort filemode kannst du verhindern, dass die Logdatei mehrfach identische Einträge enthält, also den Append-Modus deaktivieren. Setzt du filemode auf write, werden frühere Logs überschrieben und nur die aktuellen gespeichert. Da filemode hier auf w steht, wird die Logdatei bei jedem Aufruf von basicConfig() im Write-Modus geöffnet und dadurch überschrieben.

Die Dateimodus-Funktionalität beim Logging entspricht dem üblichen Datei-Handling in Python.

import logging

logging.basicConfig(level = logging.INFO, filename = 'datacamp.log', filemode = 'w')

logging.debug("A Debug Logging Message")
logging.info("A Info Logging Message")
logging.warning("A Warning Logging Message")
logging.error("An Error Logging Message")
logging.critical("A Critical Logging Message")

Führe die obigen Zeilen nun mehrfach aus. Du wirst sehen, dass diesmal nur die aktuellen Logeinträge gespeichert werden und die vorherigen überschrieben werden, wie unten gezeigt.

Als Nächstes schauen wir uns weitere Logging-Attribute an, etwa Datum, Uhrzeit und die Zeilennummer, an der eine Warnung oder ein Fehler erzeugt wurde. Du wirst zustimmen: Das sind klare Vorteile gegenüber einer einfachen print-Funktion.

Dafür übergibst du die Logging-Attribute asctime und lineno. Außerdem das Attribut message als Platzhalter für die eigentliche Lognachricht. Alle diese Attribute werden im Parameter format angegeben.

import logging

logging.basicConfig(format='Date-Time : %(asctime)s : Line No. : %(lineno)d - %(message)s', \
                    level = logging.DEBUG)

logging.debug("A Debug Logging Message")
logging.info("A Info Logging Message")
logging.warning("A Warning Logging Message")
logging.error("An Error Logging Message")
logging.critical("A Critical Logging Message")

Date-Time : 2020-03-18 23:58:12,429 : Line No. : 1 - A Debug Logging Message
Date-Time : 2020-03-18 23:58:12,436 : Line No. : 2 - A Info Logging Message
Date-Time : 2020-03-18 23:58:12,437 : Line No. : 3 - A Warning Logging Message
Date-Time : 2020-03-18 23:58:12,440 : Line No. : 4 - An Error Logging Message
Date-Time : 2020-03-18 23:58:12,441 : Line No. : 5 - A Critical Logging Message

Hier sind die Definitionen der einzelnen Attribute direkt aus dieser Tabelle:

• asctime: Menschlich lesbare Zeit, zu der der LogRecord erzeugt wurde. Standardformat: 2020-03-18 22:24:42,670 (die Zahl nach dem Komma sind Millisekunden). Da dieses Attribut ein String ist, folgt darauf das Schlüsselwort s.

• lineno: Quellzeilennummer, an der der Logging-Aufruf erfolgt ist. Da dieses Attribut ein Integer ist, folgt darauf das Schlüsselwort d.

• message: Die geloggte Nachricht, berechnet als msg % args. Sie wird gesetzt, wenn Formatter.format() aufgerufen wird. Wenn du dieses Attribut im Parameter format() nicht angibst, werden die gewünschten Nachrichten nicht ausgegeben. Auch hier verwendest du s, da es sich um einen String handelt.

• funcName: Gibt das Modul oder den Funktionsnamen aus, in dem das Log erzeugt wurde. Nützlich, wenn dein Code viele Funktionen enthält und du Logs nach Funktion oder Methode trennen möchtest.

Zum Schluss ein einfaches Beispiel, wie du die Logging-Debug-Funktion anstelle von print einsetzen kannst.

import logging

logging.basicConfig(format='%(asctime)s :: %(levelname)s :: %(funcName)s :: %(lineno)d \
:: %(message)s', level = logging.INFO)

def addition(x, y):
    add = x + y
    return add


def subtract(x, y):
    sub = x - y
    return sub


def multiply(x, y):
    mul = x * y
    return mul


def divide(x, y):
    div = x / y
    return div

def exponent(x, y):
    exp = x ** y
    return exp


num1 = 20
num2 = 2

def main():
    add_result = addition(num1, num2)
    logging.info('Add: {} + {} = {}'.format(num1, num2, add_result))

    sub_result = subtract(num1, num2)
    logging.info('Sub: {} - {} = {}'.format(num1, num2, sub_result))

    mul_result = multiply(num1, num2)
    logging.info('Mul: {} * {} = {}'.format(num1, num2, mul_result))

    div_result = divide(num1, num2)
    logging.info('Div: {} / {} = {}'.format(num1, num2, div_result))

    exp_result = exponent(num1, num2)
    logging.info('Exp: {} ** {} = {}'.format(num1, num2, exp_result))


main()

2020-03-19 00:01:27,372 :: INFO :: main :: 35 :: Add: 20 + 2 = 22
2020-03-19 00:01:27,376 :: INFO :: main :: 38 :: Sub: 20 - 2 = 18
2020-03-19 00:01:27,377 :: INFO :: main :: 41 :: Mul: 20 * 2 = 40
2020-03-19 00:01:27,378 :: INFO :: main :: 44 :: Div: 20 / 2 = 10.0
2020-03-19 00:01:27,379 :: INFO :: main :: 47 :: Exp: 20 ** 2 = 400

Fazit

Glückwunsch, du hast das Tutorial abgeschlossen.

Probier gern weitere Logging-Attribute aus und schau, wie du sie in deinem Code sinnvoll einsetzt.

Stell Fragen zu diesem Tutorial jederzeit unten in den Kommentaren.

Wenn du gerade erst mit Python startest und mehr lernen möchtest, besuche DataCamps Kurs Introduction to Data Science in Python.