Python ist eine beliebte, ob­jekt­ori­en­tier­te Pro­gram­mier­spra­che. Viele Ent­wick­ler schätzen Python, da man mit der Skript­spra­che Programme schneller er­ar­bei­ten kann als mit kom­pi­lie­ren­den Sprachen wie Java. Gegenüber „tra­di­tio­nel­len“ pro­ze­du­ra­len Pro­gram­mier­spra­chen wie Perl hat Python hingegen den Vorteil, gut lesbar zu sein und sich leicht warten zu lassen. Ob künst­li­che In­tel­li­genz, grafische Be­nut­zer­ober­flä­che oder Sys­tem­ver­wal­tung: Python lässt sich für eine Vielzahl von Aufgaben verwenden. Doch je häufiger eine Pro­gram­mier­spra­che genutzt wird, desto wichtiger ist auch eine gute Feh­ler­kul­tur. Logging sollte von der ersten Ent­wick­lungs­pha­se bis zum tat­säch­li­chen Einsatz durch den Nutzer statt­fin­den.

In der Python-Bi­blio­thek existiert ein prak­ti­sches Logging-Modul. Sowohl beim einfachen Debugging als auch beim zentralen Logging aus un­ter­schied­li­chen Servern kann dies Python-Logging-Modul Ent­wick­lern und Ope­ra­to­ren die Arbeit erheblich er­leich­tern.

Was ist Logging?

Logging kommt vom Eng­li­schen Begriff „log“ und be­zeich­net in diesem Zu­sam­men­hang ein Protokoll. Ähnlich einem Logbuch enthält es alle wichtigen Auf­zeich­nun­gen über den Er­eig­nis­ver­lauf. Abhängig davon, was un­ter­sucht werden soll, werden entweder nur bestimmte Aktionen oder Er­eig­nis­se in einem Prozess erfasst oder es wird jede einzelne Aktion geprüft.

Wer eine neue Pro­gram­mier­spra­che lernt, macht un­wei­ger­lich einige Fehler. Auch wenn Python für jene, die bereits Pro­gram­mier­spra­chen wie C++ oder Java kennen, aufgrund ähnlicher Struk­tu­ren ver­ständ­lich ist (zum Beispiel die Form der Schleifen), so hat doch jede Sprache ihre Be­son­der­hei­ten. Python bei­spiels­wei­se stellt Hier­ar­chien durch Ein­rü­ckun­gen dar. Übersieht man im Eifer des Gefechts ein fehlendes Leer­zei­chen, funk­tio­niert selbst die simpelste Anwendung nicht. Ein Feh­ler­pro­to­koll weist un­er­fah­re­ne Ent­wick­ler beim Debugging auf die ent­spre­chen­de Zeile und den Fehler „un­ex­pec­ted In­den­ta­ti­on“ hin. In diesem Fall pro­to­kol­liert das Python-Logging einfache Skript­feh­ler und gibt eine Nachricht aus. Aber Logging kann noch mehr. Ent­wick­ler nutzen Logging in Pro­gram­men für ganz un­ter­schied­li­che An­wen­dungs­be­rei­che:

  • Debugging: Der ganze Quellcode wird auf Fehler un­ter­sucht, um einen rei­bungs­lo­sen Ablauf des fertigen Programms zu ge­währ­leis­ten.
     
  • Auffinden und Beheben von Si­cher­heits­lü­cken: Mögliche Risiken werden präventiv ermittelt und behoben.
     
  • IT-Forensik: Durch sie kann man bei kri­ti­schen Vorfällen wie Hacker-Angriffen anhand der Log-Datei die Ursache ermitteln.
     
  • IT-Audit: Diese Über­prü­fung stellt fest, ob Da­ten­si­cher­heit und-in­te­gri­tät ge­währ­leis­tet sind, sie ver­gleicht Ziele des je­wei­li­gen Un­ter­neh­mens mit den vor­han­de­nen IT-Struk­tu­ren auf deren Ver­ein­bar­keit und ana­ly­siert die Effizienz der Programme und Be­triebs­sys­te­me.
     
  • Vergleich ver­schie­de­ner Versionen von Da­ten­sät­zen: Indem für jeden Durchlauf eine eigene Log-Datei angelegt wird, ist ein Vergleich möglich.

Beim Logging können sehr viele Daten anfallen, ins­be­son­de­re, 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-In­for­ma­tio­nen bestückt wird) sammeln Ent­wick­ler diese Daten. Wichtig dabei ist, dass die Log-Datei asynchron arbeitet. An­dern­falls blockiert das Logging in Python womöglich die Aus­füh­rung des Skripts.

Feh­ler­ana­ly­se mit Python-Logging: 5 Level der Log-Prio­ri­sie­rung

Einige Ent­wick­ler nutzen die print-Ausgabe, um ihr Skript auf Fehler zu über­prü­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 nach­träg­lich den gesamten Code durch­ge­hen müssen, um den Befehl aus­zu­kom­men­tie­ren oder zu löschen. An­dern­falls erscheint der Ausgabe-Text womöglich, wenn Anwender das Programm nutzen. Zudem wirkt der Quellcode damit sehr un­auf­ge­räumt.

Mit einfachem Logging erspart man sich die zu­sätz­li­che Arbeit und nutzt eine ele­gan­te­re Lösung der Feh­ler­ana­ly­se. Python-Logging kennt fünf un­ter­schied­li­che Fehler-Schwe­re­gra­de – im Original: Level of Severity. Wer seine eignen Log-Filter anlegen will, kann dies natürlich tun. Das in­klu­dier­te Python-Logging-Modul von Vinay Sajip bietet bereits eine Abstufung der Schwe­re­gra­de, die uns sinnvoll erscheint:

Logging-Level-Name Nutzung Mögliche Nach­rich­ten­aus­ga­be
Debug Pro­blem­dia­gno­se, sehr de­tail­liert Un­er­war­te­te Ein­rü­ckung in Zeile XY
Info Gibt Rück­mel­dung, dass das System ord­nungs­ge­mäß läuft Funktion 1*1 wird aus­ge­führt
Warning Die Anwendung arbeitet wei­test­ge­hend ord­nungs­ge­mäß, aber eine un­er­war­te­te Situation ist auf­ge­tre­ten oder es wird vor einem zu­künf­ti­gen Problem gewarnt Der Spei­cher­platz wird knapp
Error Eine Funktion konnte nicht aus­ge­führt werden, weil ein Problem auf­ge­tre­ten ist. Ein Fehler ist auf­ge­tre­ten und die Aktion wurde ab­ge­bro­chen
Critical Ein schwer­wie­gen­des Problem ist auf­ge­tre­ten. Mög­li­cher­wei­se muss die ganze Anwendung gestoppt werden Schwer­wie­gen­der Fehler: Das Programm kann nicht auf diesen Service zugreifen und muss beendet werden.

Die un­ter­schied­li­chen Level stellen jeweils In­for­ma­tio­nen über Er­eig­nis­se mit wach­sen­der Wich­tig­keit dar. Python-Logging-Level sind statische Funk­tio­nen. In der ob­jekt­ori­en­tier­ten Pro­gram­mie­rung sind diese Funk­tio­nen Inhalte einer Klasse. Für jede Instanz der Klasse innerhalb eines Objekts sind statische Funk­tio­nen immer gleich. Sie verändern sich nicht und sie sind auch vorhanden, wenn keine Instanz auf­ge­ru­fen wird. Error bei­spiels­wei­se ist in jeder Instanz eine Error-Meldung. Wird sie im gleichen Aus­füh­rungs­ob­jekt auf­ge­ru­fen, bleibt die as­so­zi­ier­te Feh­ler­mel­dung dieselbe. Für andere Aktionen kann eine andere Feh­ler­mel­dung fest­ge­legt werden.

Debug ist das nied­rigs­te Level, weshalb auch In­for­ma­tio­nen mit niedriger Priorität aus­ge­ge­ben werden. Das heißt aber nicht, dass der Schwe­re­grad 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-Bi­blio­thek. Die Logging-Schnitt­stel­le in­ter­agiert daher nicht nur flüssig mit dem rest­li­chen Quellcode, sondern ist auch immer ein­satz­be­reit. Einfaches Logging und das Versenden der In­for­ma­tio­nen an eine Datei ist mithilfe des Handlers schnell in den be­stehen­den Code eingebaut. Das Python-Logging-Modul verfügt über weitere Funk­tio­nen, mit denen Sie das Tool anpassen können. Das sind die Haupt­be­stand­tei­le des Logging-Moduls:

  • Logger
  • Handler
  • Filter
  • Formatter

Die Instanzen sind zu­sam­men­ge­fasst in der LogRecord-Instanz und tauschen sich innerhalb der Instanz aus.

Logger

Logger zeichnen die Aktionen während eines Pro­gramm­durch­laufs auf. Sie treten nicht direkt als Instanz auf, sondern man ruft sie mit der Funktion logging.getLogger(Log­ger­na­me) auf. Weisen Sie dem Logger einen Namen zu, um bei­spiels­wei­se Hier­ar­chien struk­tu­riert dar­zu­stel­len. In Python stellen Sie Kinder von Paketen getrennt durch einen Punkt dar. Das Paket log kann also die un­ter­ge­ord­ne­ten Pakete log.bam oder log.bar.loco besitzen. Analog dazu funk­tio­nie­ren die Logger, sodass das Objekt „log“ die In­for­ma­tio­nen seiner Kinder „log.bam“ und „log.bar.loco“ erhält.

Handler

Handler nehmen die In­for­ma­tio­nen der Logger auf und senden sie weiter. Der Handler ist eine Grund­la­gen­klas­se, die festlegt, wie die Schnitt­stel­le der Handler-Instanzen agiert. Mit der je­wei­li­gen Handler-Klasse legen Sie das Ziel fest. Der Stream­Hand­ler sendet die In­for­ma­tio­nen an Streams, der Fi­le­Hand­ler sendet sie an Dateien. Für ein Programm können Sie mehrere Handler nutzen, die Nach­rich­ten desselben Loggers versenden. Dies ist sinnvoll, wenn man bei­spiels­wei­se Debugging-In­for­ma­tio­nen in der Konsole und wichtige Feh­ler­mel­dun­gen in einer ge­son­der­ten Datei aus­spie­len möchte.

Mithilfe der Methode setLevel() legen Sie den ge­rings­ten Schwe­re­grad fest, den eine Log­nach­richt benötigt, um an diesem Handler wei­ter­ge­sen­det zu werden. Statt logger.setLevel (welches das Logging-Level bestimmt) heißt die Methode dann [hand­ler­na­me].setLevel (siehe Code-Vorlage Zeile 5: fh.setLevel).

Formatter

Formatter (For­ma­tie­rungs­ob­jek­te) lassen sich im Gegensatz zu Handlern direkt als Instanz im An­wen­dungs­code einsetzen. Mit diesen Instanzen legen Sie das Format fest, in dem Ihre Be­nach­rich­ti­gung in der Log-Datei aus­ge­ge­ben wird. Nutzen Sie keine For­ma­tie­rung, erscheint lediglich die fest­ge­leg­te Nachricht des Loggers. Mit der folgenden Funktion rufen Sie den Formatter auf und legen Nach­rich­ten- und Da­tums­for­mat fest:

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

Spe­zi­fi­zie­ren Sie kein Da­tums­for­mat im Attribut, gibt der Formatter die ame­ri­ka­ni­sche Form und Zeit­an­ga­be vor: „Jahr-Monat-Tag Stunden:Minuten:Sekunden“.

Filter

Filter er­mög­li­chen noch genauere Fest­le­gun­gen für die aus­ge­ge­be­nen Nach­rich­ten. Filter de­fi­nie­ren Sie zuerst und fügen sie dann dem ent­spre­chen­den Handler oder Logger mit der Methode addFilter() hinzu. Ist der Wert eines Filters aufgrund der Nach­rich­ten­ei­gen­schaf­ten false, reicht er die Nachricht nicht weiter. Nutzen Sie die Funktion logging.Filter(name=fh), wobei das Attribut fh für einen be­lie­bi­gen Log­ger­na­men steht, um die Log-Daten eines be­stimm­ten Loggers zu­zu­las­sen und alle anderen Logger zu blo­ckie­ren.

Das Python-Logging-Modul an einem Beispiel

Python stellt Ent­wick­lern das Zei­chen­tool Turtle zur Verfügung, um grund­le­gen­de Befehle am Beispiel zu erproben. Im Folgenden nutzt der Bei­spiel­nut­zer Turtle. Das Zei­chen­tool soll auf einem grünen Hin­ter­grund geradeaus laufen, sich nach links drehen, wei­ter­lau­fen und dann einen Kreis be­schrei­ben. 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.')

Im obigen Bild sehen Sie, wie das Ergebnis aussieht. Das Turtle-Modul (linkes Fenster) hat die Befehle an­ge­nom­men und läuft wie vor­ge­schrie­ben. Im rechten Fenster umfasst der Code neben den Turtle-Befehlen auch Logging-Befehle vom Level INFO und ERROR. Die typische Aus­ga­be­form einer Log-Meldung ist folgende: [Schwe­re­grad]:[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 schief­ge­lau­fen.

Das liegt daran, dass die Grund­ein­stel­lung des Python-Logging-Moduls auf WARNING steht. Alle de­tail­lier­te­ren Angaben lässt das Modul aus, solange diese Ein­stel­lun­gen nicht geändert werden.

Python-Logging-Level ändern

Mit folgendem Befehl ändern Sie die Ein­stel­lung 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 Auf­zeich­nun­gen. Damit Sie den Überblick über Ihre Logging-Daten behalten, sollten Sie eine Log-Datei nutzen. Diese Praxis nennt sich im Eng­li­schen Logging to File, also Log-Auf­zeich­nun­gen in einer Datei ablegen.

Python-Logging in einer Datei ablegen

Python-Logging-to-File funk­tio­niert über zwei Wege. Entweder Sie erstellen eine Log-Datei über die Grund­ein­stel­lun­gen oder Sie nutzen den Handler. Legen Sie kein Ziel fest, legt Python-Logging die In­for­ma­tio­nen 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 Fi­le­Hand­ler 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 Fi­le­Hand­ler exis­tie­ren im Logging-Modul der Python-Bi­blio­thek weitere Logging-Handler – wie der Stream­Hand­ler und der Null­Hand­ler. Zum nach­träg­li­chen Auswerten von Logging-Daten ist jedoch eine Log-Datei emp­feh­lens­wert.

So erstellen Sie einen Fi­le­Hand­ler, der Debug-Meldungen in einer Datei ablegt:

Im obigen Bild ruft der Befehl logging.getLogger() das Python-Logging-Modul auf. „fh“ wird als Fi­le­Hand­ler definiert, der das Attribut „debug.log“ besitzt. Damit erstellt fh die Log-Datei „debug.log“ und über­sen­det die auf­tre­ten­den Log-Nach­rich­ten an Sie. Die Methode ad­dHa­nd­ler() weist dem Logger den ent­spre­chen­den Handler zu. Die Log-Datei benennen Sie ganz nach Wunsch.

Folgende Funk­tio­nen können Sie nutzen, um es selber aus­zu­pro­bie­ren:

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, hilf­rei­che In­for­ma­tio­nen für bestimmte Tasks liefern, reichen einfache Meldungen mitunter nicht aus. Ein Timestamp und der Name des Loggers helfen, die Hinweise besser ein­zu­ord­nen. Im folgenden Bild sehen Sie ein Beispiel, wie Sie das Format durch Formatter-Attribute festlegen können. Im Notepad-Fenster debug.log gibt die Text­aus­ga­be die Log-Nach­rich­ten mit Datum, Uhrzeit, Log­ger­na­me, Log-Level und Nachricht an.

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 prak­ti­sches Tool zur Feh­ler­prä­ven­ti­on, zur Kontrolle nach Hacker-Angriffen oder einfach für die Analyse. Während andere Pro­gram­mier­spra­chen das Logging aus zweiter Hand hin­zu­fü­gen, gehört das Logging-Modul bei Python zur Stan­dard­bi­blio­thek. Fügen Sie die Methode in Ihren Code ein, werden Log-Nach­rich­ten un­ter­schied­li­cher Level erstellt: sowohl in Dateien als auch auf der Konsole. Die For­ma­tie­rung und Filter sowie Handler lassen eine be­nut­zer­ge­rech­te Ein­stel­lung zu. Achten Sie dabei unbedingt auf schnell zu­zu­ord­nen­de Namen für Ihre Logger und deren Kinder, um sich die Arbeit mit Log-Dateien unter Python zu ver­ein­fa­chen.

Zum Hauptmenü