Python-Logging: So machen Sie mit dem Python-Logging-Modul Skriptfehler ausfindig

Python ist eine beliebte, objektorientierte Programmiersprache. Viele Entwickler schätzen Python, da man mit der Skriptsprache Programme schneller erarbeiten kann als mit kompilierenden Sprachen wie Java. Gegenüber „traditionellen“ prozeduralen Programmiersprachen wie Perl hat Python hingegen den Vorteil, gut lesbar zu sein und sich leicht warten zu lassen. Ob künstliche Intelligenz, grafische Benutzeroberfläche oder Systemverwaltung: Python lässt sich für eine Vielzahl von Aufgaben verwenden. Doch je häufiger eine Programmiersprache genutzt wird, desto wichtiger ist auch eine gute Fehlerkultur. Logging sollte von der ersten Entwicklungsphase bis zum tatsächlichen Einsatz durch den Nutzer stattfinden.

In der Python-Bibliothek existiert ein praktisches Logging-Modul. Sowohl beim einfachen Debugging als auch beim zentralen Logging aus unterschiedlichen Servern kann dies Python-Logging-Modul Entwicklern und Operatoren die Arbeit erheblich erleichtern.

Inhaltsverzeichnis

Was ist Logging?
Fehleranalyse mit Python-Logging: 5 Level der Log-Priorisierung
Das Python-Logging-Modul
1. Logger
2. Handler
3. Formatter
4. Filter
Das Python-Logging-Modul an einem Beispiel
1. Python-Logging-Level ändern
2. Python-Logging in einer Datei ablegen

Was ist Logging?

Logging kommt vom Englischen Begriff „log“ und bezeichnet in diesem Zusammenhang ein Protokoll. Ähnlich einem Logbuch enthält es alle wichtigen Aufzeichnungen über den Ereignisverlauf. Abhängig davon, was untersucht werden soll, werden entweder nur bestimmte Aktionen oder Ereignisse in einem Prozess erfasst oder es wird jede einzelne Aktion geprüft.

Wer eine neue Programmiersprache lernt, macht unweigerlich einige Fehler. Auch wenn Python für jene, die bereits Programmiersprachen wie C++ oder Java kennen, aufgrund ähnlicher Strukturen verständlich ist (zum Beispiel die Form der Schleifen), so hat doch jede Sprache ihre Besonderheiten. Python beispielsweise stellt Hierarchien durch Einrückungen dar. Übersieht man im Eifer des Gefechts ein fehlendes Leerzeichen, funktioniert selbst die simpelste Anwendung nicht. Ein Fehlerprotokoll weist unerfahrene Entwickler beim Debugging auf die entsprechende Zeile und den Fehler „unexpected Indentation“ hin. In diesem Fall protokolliert das Python-Logging einfache Skriptfehler und gibt eine Nachricht aus. Aber Logging kann noch mehr. Entwickler nutzen Logging in Programmen für ganz unterschiedliche Anwendungsbereiche:

Debugging: Der ganze Quellcode wird auf Fehler untersucht, um einen reibungslosen Ablauf des fertigen Programms zu gewährleisten.
Auffinden und Beheben von Sicherheitslücken: Mögliche Risiken werden präventiv ermittelt und behoben.
IT-Forensik: Durch sie kann man bei kritischen Vorfällen wie Hacker-Angriffen anhand der Log-Datei die Ursache ermitteln.
IT-Audit: Diese Überprüfung stellt fest, ob Datensicherheit und-integrität gewährleistet sind, sie vergleicht Ziele des jeweiligen Unternehmens mit den vorhandenen IT-Strukturen auf deren Vereinbarkeit und analysiert die Effizienz der Programme und Betriebssysteme.
Vergleich verschiedener Versionen von Datensätzen: Indem für jeden Durchlauf eine eigene Log-Datei angelegt wird, ist ein Vergleich möglich.

Beim Logging können sehr viele Daten anfallen, insbesondere, wenn man mit Python eine komplexe Anwendung schreibt. Mit Python-Logging-to-File (also einer Log-Datei, die durch das Python-Logging-Modul erstellt und über einen Handler mit den Logging-Informationen bestückt wird) sammeln Entwickler diese Daten. Wichtig dabei ist, dass die Log-Datei asynchron arbeitet. Andernfalls blockiert das Logging in Python womöglich die Ausführung des Skripts.

Fehleranalyse mit Python-Logging: 5 Level der Log-Priorisierung

Einige Entwickler nutzen die print-Ausgabe, um ihr Skript auf Fehler zu überprüfen. Dafür setzen sie den Befehl an allen Stellen, von denen sie vermuten, dass von dort ein Fehler herrührt. Andere nutzen print sogar präventiv in ihrem Skript. Ein Problem dieser Methode ist, dass sie nachträglich den gesamten Code durchgehen müssen, um den Befehl auszukommentieren oder zu löschen. Andernfalls erscheint der Ausgabe-Text womöglich, wenn Anwender das Programm nutzen. Zudem wirkt der Quellcode damit sehr unaufgeräumt.

Mit einfachem Logging erspart man sich die zusätzliche Arbeit und nutzt eine elegantere Lösung der Fehleranalyse. Python-Logging kennt fünf unterschiedliche Fehler-Schweregrade – im Original: Level of Severity. Wer seine eignen Log-Filter anlegen will, kann dies natürlich tun. Das inkludierte Python-Logging-Modul von Vinay Sajip bietet bereits eine Abstufung der Schweregrade, die uns sinnvoll erscheint:

Logging-Level-Name	Nutzung	Mögliche Nachrichtenausgabe
Debug	Problemdiagnose, sehr detailliert	Unerwartete Einrückung in Zeile XY
Info	Gibt Rückmeldung, dass das System ordnungsgemäß läuft	Funktion 1*1 wird ausgeführt
Warning	Die Anwendung arbeitet weitestgehend ordnungsgemäß, aber eine unerwartete Situation ist aufgetreten oder es wird vor einem zukünftigen Problem gewarnt	Der Speicherplatz wird knapp
Error	Eine Funktion konnte nicht ausgeführt werden, weil ein Problem aufgetreten ist.	Ein Fehler ist aufgetreten und die Aktion wurde abgebrochen
Critical	Ein schwerwiegendes Problem ist aufgetreten. Möglicherweise muss die ganze Anwendung gestoppt werden	Schwerwiegender Fehler: Das Programm kann nicht auf diesen Service zugreifen und muss beendet werden.

Die unterschiedlichen Level stellen jeweils Informationen über Ereignisse mit wachsender Wichtigkeit dar. Python-Logging-Level sind statische Funktionen. In der objektorientierten Programmierung sind diese Funktionen Inhalte einer Klasse. Für jede Instanz der Klasse innerhalb eines Objekts sind statische Funktionen immer gleich. Sie verändern sich nicht und sie sind auch vorhanden, wenn keine Instanz aufgerufen wird. Error beispielsweise ist in jeder Instanz eine Error-Meldung. Wird sie im gleichen Ausführungsobjekt aufgerufen, bleibt die assoziierte Fehlermeldung dieselbe. Für andere Aktionen kann eine andere Fehlermeldung festgelegt werden.

Debug ist das niedrigste Level, weshalb auch Informationen mit niedriger Priorität ausgegeben werden. Das heißt aber nicht, dass der Schweregrad eines Fehlers höher ist als bei Critical. Debug umfasst alle anderen Level und gibt somit alle Meldungen bis hin zum Critical Error aus.

Das Python-Logging-Modul

Das Python-Logging-Modul ist Teil der Python-Bibliothek. Die Logging-Schnittstelle interagiert daher nicht nur flüssig mit dem restlichen Quellcode, sondern ist auch immer einsatzbereit. Einfaches Logging und das Versenden der Informationen an eine Datei ist mithilfe des Handlers schnell in den bestehenden Code eingebaut. Das Python-Logging-Modul verfügt über weitere Funktionen, mit denen Sie das Tool anpassen können. Das sind die Hauptbestandteile des Logging-Moduls:

Logger
Handler
Filter
Formatter

Die Instanzen sind zusammengefasst in der LogRecord-Instanz und tauschen sich innerhalb der Instanz aus.

Logger

Logger zeichnen die Aktionen während eines Programmdurchlaufs auf. Sie treten nicht direkt als Instanz auf, sondern man ruft sie mit der Funktion logging.getLogger(Loggername) auf. Weisen Sie dem Logger einen Namen zu, um beispielsweise Hierarchien strukturiert darzustellen. In Python stellen Sie Kinder von Paketen getrennt durch einen Punkt dar. Das Paket log kann also die untergeordneten Pakete log.bam oder log.bar.loco besitzen. Analog dazu funktionieren die Logger, sodass das Objekt „log“ die Informationen seiner Kinder „log.bam“ und „log.bar.loco“ erhält.

Handler

Handler nehmen die Informationen der Logger auf und senden sie weiter. Der Handler ist eine Grundlagenklasse, die festlegt, wie die Schnittstelle der Handler-Instanzen agiert. Mit der jeweiligen Handler-Klasse legen Sie das Ziel fest. Der StreamHandler sendet die Informationen an Streams, der FileHandler sendet sie an Dateien. Für ein Programm können Sie mehrere Handler nutzen, die Nachrichten desselben Loggers versenden. Dies ist sinnvoll, wenn man beispielsweise Debugging-Informationen in der Konsole und wichtige Fehlermeldungen in einer gesonderten Datei ausspielen möchte.

Mithilfe der Methode setLevel() legen Sie den geringsten Schweregrad fest, den eine Lognachricht benötigt, um an diesem Handler weitergesendet zu werden. Statt logger.setLevel (welches das Logging-Level bestimmt) heißt die Methode dann [handlername].setLevel (siehe Code-Vorlage Zeile 5: fh.setLevel).

Formatter

Formatter (Formatierungsobjekte) lassen sich im Gegensatz zu Handlern direkt als Instanz im Anwendungscode einsetzen. Mit diesen Instanzen legen Sie das Format fest, in dem Ihre Benachrichtigung in der Log-Datei ausgegeben wird. Nutzen Sie keine Formatierung, erscheint lediglich die festgelegte Nachricht des Loggers. Mit der folgenden Funktion rufen Sie den Formatter auf und legen Nachrichten- und Datumsformat fest:

logging.Formatter.__init__(fmt=[Nachrichtenformat], datefmt=[Datumsformat])
#oder auch:
logging.Formatter.__init__(fmt=None, datefmt=None)

Spezifizieren Sie kein Datumsformat im Attribut, gibt der Formatter die amerikanische Form und Zeitangabe vor: „Jahr-Monat-Tag Stunden:Minuten:Sekunden“.

Filter

Filter ermöglichen noch genauere Festlegungen für die ausgegebenen Nachrichten. Filter definieren Sie zuerst und fügen sie dann dem entsprechenden Handler oder Logger mit der Methode addFilter() hinzu. Ist der Wert eines Filters aufgrund der Nachrichteneigenschaften false, reicht er die Nachricht nicht weiter. Nutzen Sie die Funktion logging.Filter(name=fh), wobei das Attribut fh für einen beliebigen Loggernamen steht, um die Log-Daten eines bestimmten Loggers zuzulassen und alle anderen Logger zu blockieren.

Das Python-Logging-Modul an einem Beispiel

Python stellt Entwicklern das Zeichentool Turtle zur Verfügung, um grundlegende Befehle am Beispiel zu erproben. Im Folgenden nutzt der Beispielnutzer Turtle. Das Zeichentool soll auf einem grünen Hintergrund geradeaus laufen, sich nach links drehen, weiterlaufen und dann einen Kreis beschreiben. In das Beispiel bauen wir die Python-Logging-Befehle Info und Error ein:

# -*- coding: UTF-8 -*-
import turtle
import logging
turtle.bgcolor("green")
turtle.fd(30)
turtle.lt(90)
turtle.fd(50)
logging.info('Läuft bei Dir.')
turtle.circle(50)
logging.error('Upps, da ist etwas schiefgelaufen.')

Python-Logging-Funktionen zwischen simplen Turtle-Befehlen mit grafischer Ausgabe der Befehle und Logging-Aufzeichnung in der Konsole — Die Konsole zeigt das Logging-Level ERROR an, gibt aber nicht die Mitteilung des Levels INFO aus.

Im obigen Bild sehen Sie, wie das Ergebnis aussieht. Das Turtle-Modul (linkes Fenster) hat die Befehle angenommen und läuft wie vorgeschrieben. Im rechten Fenster umfasst der Code neben den Turtle-Befehlen auch Logging-Befehle vom Level INFO und ERROR. Die typische Ausgabeform einer Log-Meldung ist folgende: [Schweregrad]:[Herkunft der Meldung]:[Nachricht der Meldung]

Die Konsole (Console 1/A) gibt im Beispiel jedoch nur die Python-Logging-Meldung ERROR an: Error:root:Upps, da ist etwas schiefgelaufen.

Das liegt daran, dass die Grundeinstellung des Python-Logging-Moduls auf WARNING steht. Alle detaillierteren Angaben lässt das Modul aus, solange diese Einstellungen nicht geändert werden.

Python-Logging-Level ändern

Mit folgendem Befehl ändern Sie die Einstellung auf das Level DEBUG:

logging.basicConfig(level=logging.DEBUG)

Im Bild oben zeigt die Konsole für jeden neuen Aufruf das Logging an. Stoppt man das Programm, löscht die Konsole alle Aufzeichnungen. Damit Sie den Überblick über Ihre Logging-Daten behalten, sollten Sie eine Log-Datei nutzen. Diese Praxis nennt sich im Englischen Logging to File, also Log-Aufzeichnungen in einer Datei ablegen.

Python-Logging in einer Datei ablegen

Python-Logging-to-File funktioniert über zwei Wege. Entweder Sie erstellen eine Log-Datei über die Grundeinstellungen oder Sie nutzen den Handler. Legen Sie kein Ziel fest, legt Python-Logging die Informationen temporär in der Konsole ab.

So erstellen Sie eine Datei für Ihr Python-Logging:

import logging
logging.basicConfig( level=logging.DEBUG, filename='example.log')

Der FileHandler ist eine Instanz der Logging-Klasse. Sie agiert zusammen mit der Logging-Instanz. Sie ist dafür zuständig, wohin welche Logging-Daten in welcher Form gesendet werden. Neben dem FileHandler existieren im Logging-Modul der Python-Bibliothek weitere Logging-Handler – wie der StreamHandler und der NullHandler. Zum nachträglichen Auswerten von Logging-Daten ist jedoch eine Log-Datei empfehlenswert.

So erstellen Sie einen FileHandler, der Debug-Meldungen in einer Datei ablegt:

Python-Editor mit Logging-Funktionen und Log-Datei mit Log der Nachrichten verschiedener Melde-Level — Der FileHandler „fh“ mit dem Attribut debug.log erstellt die als Attribut angegebene Datei und sendet die Nachrichten der Logger als einfache Textausgabe.

Im obigen Bild ruft der Befehl logging.getLogger() das Python-Logging-Modul auf. „fh“ wird als FileHandler definiert, der das Attribut „debug.log“ besitzt. Damit erstellt fh die Log-Datei „debug.log“ und übersendet die auftretenden Log-Nachrichten an Sie. Die Methode addHandler() weist dem Logger den entsprechenden Handler zu. Die Log-Datei benennen Sie ganz nach Wunsch.

Folgende Funktionen können Sie nutzen, um es selber auszuprobieren:

import logging
logger = logging.getLogger('Beispiel_Log')
logger.setLevel(logging.DEBUG)
fh = logging.FileHandler('debug.log')
fh.setLevel(logging.DEBUG)
logger.addHandler(fh)
logger.debug('Debug-Nachricht')
logger.info('Info-Nachricht')
logger.warning('Warnhinweis')
logger.error('Fehlermeldung')
logger.critical('Schwerer Fehler')

Soll die Log-Datei, die Sie mit Python-Logging-to-File erstellen, hilfreiche Informationen für bestimmte Tasks liefern, reichen einfache Meldungen mitunter nicht aus. Ein Timestamp und der Name des Loggers helfen, die Hinweise besser einzuordnen. Im folgenden Bild sehen Sie ein Beispiel, wie Sie das Format durch Formatter-Attribute festlegen können. Im Notepad-Fenster debug.log gibt die Textausgabe die Log-Nachrichten mit Datum, Uhrzeit, Loggername, Log-Level und Nachricht an.

Python-Editor mit Logger-Methoden und Formatattributen sowie die Textausgabe in der Log-Datei mit den formatierten Nachrichten — Der Formatter im Python-Logging-Modul ermöglicht hilfreiche, menschenlesbare Angaben, die bei der Fehlerkorrektur oder Analyse weiterhelfen.

Hier noch einmal der Code, um es selber zu probieren:

import logging
logger = logging.getLogger('Beispiel_Log')
logger.setLevel(logging.DEBUG)
fh = logging.FileHandler('debug.log')
fh.setLevel(logging.DEBUG)
logger.addHandler(fh)
formatter = logging.Formatter('%(asctime)s - %(name)s - %(levelname)s - %(message)s')
fh.setFormatter(formatter)
logger.addHandler(fh)
logger.debug('Debug-Nachricht')
logger.info('Info-Nachricht')
logger.warning('Warnhinweis')
logger.error('Fehlermeldung')
logger.critical('Schwerer Fehler')

Fazit

Python-Logging ist ein praktisches Tool zur Fehlerprävention, zur Kontrolle nach Hacker-Angriffen oder einfach für die Analyse. Während andere Programmiersprachen das Logging aus zweiter Hand hinzufügen, gehört das Logging-Modul bei Python zur Standardbibliothek. Fügen Sie die Methode in Ihren Code ein, werden Log-Nachrichten unterschiedlicher Level erstellt: sowohl in Dateien als auch auf der Konsole. Die Formatierung und Filter sowie Handler lassen eine benutzergerechte Einstellung zu. Achten Sie dabei unbedingt auf schnell zuzuordnende Namen für Ihre Logger und deren Kinder, um sich die Arbeit mit Log-Dateien unter Python zu vereinfachen.