Aaron Maxwell ist Autor von Powerful Python.
Ausnahmen passieren. Und als Entwickler müssen wir einfach mit ihnen umgehen. Selbst wenn wir Software schreiben, die uns hilft, Burritos zu finden.
Warten Sie, ich greife mir selbst vor… wir kommen darauf zurück. Wie ich schon sagte: Wie wir mit Ausnahmen umgehen, hängt von der Sprache ab. Und für Software, die in großem Umfang betrieben wird, ist die Protokollierung eines der mächtigsten und wertvollsten Werkzeuge, die wir für den Umgang mit Fehlerbedingungen haben. Schauen wir uns einige Möglichkeiten an, wie diese zusammenarbeiten.
Das „Big Tarp“-Muster
Wir fangen mit einem Extrem an:
try: main_loop()except Exception: logger.exception("Fatal error in main loop")
Dies ist ein breiter Auffangtopf. Er eignet sich für einige Codepfade, bei denen Sie wissen, dass der Codeblock (d.h. main_loop()) eine Reihe von Ausnahmen auslösen kann, die Sie nicht erwarten. Und anstatt das Programm abzubrechen, entscheiden Sie, dass es besser ist, die Fehlerinformationen zu protokollieren und von dort aus weiterzumachen.
Die Magie liegt hier in der exception-Methode. (logger ist das Logger-Objekt Ihrer Anwendung – etwas, das zum Beispiel von logging.getLogger() zurückgegeben wurde.) Diese wunderbare Methode erfasst den vollständigen Stack-Trace im Kontext des Except-Blocks und schreibt ihn vollständig aus.
Beachten Sie, dass Sie hier nicht das Exception-Objekt übergeben müssen. Sie übergeben einen Message-String. Dies protokolliert den vollständigen Stack-Trace, stellt aber eine Zeile mit Ihrer Nachricht voran. Die mehrzeilige Meldung, die in Ihrem Protokoll erscheint, könnte also so aussehen:
Fatal error in main loopTraceback (most recent call last): File "bigtarp.py", line 14, in main_loop() File "bigtarp.py", line 9, in main_loop print(foo(x)) File "bigtarp.py", line 4, in foo return 10 // n ZeroDivisionError: integer division or modulo by zero
Die Details des Stacktrace sind nicht wichtig – dies ist ein Spielzeugbeispiel, das eine erwachsene Lösung für ein reales Problem illustriert. Beachten Sie einfach, dass die erste Zeile die Nachricht ist, die Sie an logger.exception() übergeben haben, und dass die folgenden Zeilen die vollständige Stapelverfolgung sind, einschließlich des Ausnahmetyps (in diesem Fall ZeroDivisionError). Auf diese Weise wird jede Art von Fehler abgefangen und protokolliert.
Standardmäßig verwendet logger.exception die Protokollstufe ERROR. Alternativ können Sie die regulären Protokollierungsmethoden – logger.debug(), logger.info(), logger.warn() usw. – verwenden und den Parameter exc_info übergeben, indem Sie ihn auf True setzen:
while True: try: main_loop() except Exception: logger.error("Fatal error in main loop", exc_info=True)
Wenn Sie exc_info auf True setzen, wird die Protokollierung den vollständigen Stack-Trace…. genau wie bei logger.exception() einschließen. Der einzige Unterschied besteht darin, dass Sie die Protokollierungsebene leicht auf etwas anderes als Fehler ändern können: Ersetzen Sie einfach logger.error mit logger.warn, zum Beispiel.
Spaßige Tatsache: Das Big Tarp-Muster hat ein fast teuflisches Gegenstück, über das Sie weiter unten lesen werden.
Das „Pinpoint“-Muster
Werfen wir nun einen Blick auf das andere Extrem. Stellen Sie sich vor, Sie arbeiten mit dem OpenBurrito SDK, einer Bibliothek, die das entscheidende Problem löst, eine Burrito-Bude in der Nähe Ihres aktuellen Standorts zu finden. Nehmen wir an, es gibt eine Funktion mit dem Namen find_burrito_joints(), die normalerweise eine Liste von geeigneten Restaurants zurückgibt. Aber unter bestimmten seltenen Umständen kann sie eine Ausnahme namens BurritoCriteriaConflict auslösen.
from openburrito import find_burrito_joints, BurritoCriteriaConflict# "criteria" is an object defining the kind of burritos you want.try: places = find_burrito_joints(criteria)except BurritoCriteriaConflict as err: logger.warn("Cannot resolve conflicting burrito criteria: {}".format(err.message)) places = list()
Das Muster hier ist, optimistisch etwas Code auszuführen – in diesem Fall den Aufruf von find_burrito_joints() – innerhalb eines Try-Blocks. Wenn ein bestimmter Ausnahmetyp ausgelöst wird, protokollieren Sie eine Meldung, kümmern sich um die Situation und machen weiter.
Der entscheidende Unterschied ist die except-Klausel. Mit dem Big Tarp fangen Sie im Grunde jede mögliche Ausnahme ab und protokollieren sie. Mit Pinpoint fangen Sie einen ganz bestimmten Ausnahmetyp ab, der an dieser bestimmten Stelle im Code semantische Bedeutung hat.
Beachten Sie auch, dass ich logger.warn() statt logger.exception() verwende. (Wo immer Sie in diesem Artikel warn() sehen, können Sie info() oder error() usw. ersetzen.) Mit anderen Worten, ich protokolliere eine Meldung mit einem bestimmten Schweregrad, anstatt den gesamten Stack-Trace zu protokollieren.
Warum werfe ich die Stack-Trace-Informationen weg? Weil sie in diesem Kontext, in dem ich einen bestimmten Ausnahmetyp abfange, der in der Logik des Codes eine klare Bedeutung hat, nicht so nützlich ist. Zum Beispiel in diesem Ausschnitt:
characters = {"hero": "Homer", "villain": "Mr. Burns"}# Insert some code here that may or may not add a key called# "sidekick" to the characters dictionary.try: sidekick = charactersexcept KeyError: sidekick = "Milhouse"
Hier ist der KeyError nicht irgendein Fehler. Wenn er ausgelöst wird, bedeutet das, dass eine bestimmte Situation eingetreten ist – nämlich, dass es in meiner Rollenbesetzung keine „Sidekick“-Rolle gibt, so dass ich auf einen Standard zurückgreifen muss. Das Protokoll mit einem Stack-Trace zu füllen, ist in einer solchen Situation nicht sinnvoll. Und hier kommt Pinpoint zum Einsatz.
Das „Transformer“-Muster
Hier fängt man eine Ausnahme ab, protokolliert sie und löst dann eine andere Ausnahme aus. Zunächst einmal, wie es in Python 3 funktioniert:
try: something()except SomeError as err: logger.warn("...") raise DifferentError() from err
In Python 2 müssen Sie das „from err“ weglassen:
try: something()except SomeError as err: logger.warn("...") raise DifferentError()
(Das hat große Auswirkungen, dazu gleich mehr.) Sie werden dieses Muster verwenden wollen, wenn eine Ausnahme ausgelöst wird, die nicht gut zur Logik Ihrer Anwendung passt. Dies geschieht oft an Bibliotheksgrenzen.
Stellen Sie sich zum Beispiel vor, Sie verwenden das openburrito SDK für Ihre Killer-App, mit der man spätabends Burrito-Lokale finden kann. Die Funktion find_burrito_joints() könnte BurritoCriteriaConflict auslösen, wenn wir zu wählerisch sind. Dies ist die API, die vom SDK zur Verfügung gestellt wird, aber sie lässt sich nicht so einfach auf die übergeordnete Logik Ihrer Anwendung abbilden. Besser geeignet ist an dieser Stelle des Codes eine von Ihnen definierte Ausnahme mit der Bezeichnung NoMatchingRestaurants.
In dieser Situation wenden Sie das Muster wie folgt an (für Python 3):
from myexceptions import NoMatchingRestaurantstry: places = find_burrito_joints(criteria)except BurritoCriteriaConflict as err: logger.warn("Cannot resolve conflicting burrito criteria: {}".format(err.message)) raise NoMatchingRestaurants(criteria) from err
Das führt zu einer einzigen Ausgabezeile in Ihrem Protokoll und löst eine neue Ausnahme aus. Wenn sie nicht abgefangen wird, sieht die Fehlerausgabe dieser Ausnahme wie folgt aus:
Traceback (most recent call last): File "transformerB3.py", line 8, in places = find_burrito_joints(criteria) File "/Users/amax/python-exception-logging-patterns/openburrito.py", line 7, in find_burrito_joints raise BurritoCriteriaConflictopenburrito.BurritoCriteriaConflictThe above exception was the direct cause of the following exception:Traceback (most recent call last): File "transformerB3.py", line 11, in raise NoMatchingRestaurants(criteria) from errmyexceptions.NoMatchingRestaurants: {'region': 'Chiapas'}
Nun wird es interessant. Die Ausgabe enthält den Stack-Trace für NoMatchingRestaurants. Und sie meldet auch das auslösende BurritoCriteriaConflict… was eindeutig angibt, welches das Original war.
In Python 3 können Ausnahmen jetzt verkettet werden. Die raise ... from ...-Syntax ermöglicht dies. Wenn du raise NoMatchingRestaurants(criteria) von err sagst, löst das eine Ausnahme von typeNoMatchingRestaurants aus. Diese ausgelöste Ausnahme hat ein Attribut namens __cause__, dessen Wert die auslösende Ausnahme ist. Python 3 macht intern Gebrauch davon, wenn es die Fehlerinformationen meldet.
Wie kann man das in Python 2 machen? Nun, man kann es nicht. Das ist eines dieser Goodies, für die man einfach upgraden muss. In Python 2 wird die „raise … from“-Syntax nicht unterstützt, so dass die Ausgabe der Exception nur den Stacktrace für NoMatchingRestaurants enthalten wird. Das Transformer-Muster ist natürlich immer noch sehr nützlich.
Das „Message and Raise“-Muster
In diesem Muster protokollieren Sie, dass eine Exception an einem bestimmten Punkt auftritt, erlauben dann aber, dass sie sich ausbreitet und auf einer höheren Ebene behandelt wird:
try: something()except SomeError: logger.warn("...") raise
Sie behandeln die Exception nicht wirklich. Sie unterbrechen nur vorübergehend den Ablauf, um ein Ereignis zu protokollieren. Sie werden dies tun, wenn Sie speziell einen Handler auf höherer Ebene für den Fehler haben und auf diesen zurückgreifen wollen, aber auch protokollieren wollen, dass der Fehler oder seine Bedeutung an einer bestimmten Stelle im Code aufgetreten ist.
Dies kann bei der Fehlersuche sehr nützlich sein – wenn Sie eine Ausnahme erhalten, aber versuchen, den Aufrufkontext besser zu verstehen. Sie können diese Protokollierungsanweisung einfügen, um nützliche Informationen zu erhalten, und sogar gefahrlos in der Produktion einsetzen, wenn Sie die Ergebnisse unter realistischen Bedingungen beobachten müssen.
Das „Cryptic Message“-Anti-Pattern
Nun wenden wir uns einigen Anti-Patterns zu… Dingen, die Sie in Ihrem Code nicht tun sollten.
try: something()except Exception: logger.error("...")
Angenommen, Sie oder jemand in Ihrem Team schreibt diesen Code, und sechs Monate später sehen Sie eine komische Meldung in Ihrem Protokoll. So etwas wie:
ERROR: something bad happened
Nun hoffe und bete ich, dass Sie die Worte „etwas Schlimmes ist passiert“ nicht in Ihrem tatsächlichen Protokoll sehen werden. Der tatsächliche Protokolltext, den Sie sehen, kann jedoch genauso verwirrend sein. Was tun Sie als Nächstes?
Nun, als Erstes müssen Sie herausfinden, wo in der Codebasis diese vage Meldung protokolliert wird. Wenn Sie Glück haben, können Sie den Code schnell durchforsten und genau eine Möglichkeit finden. Wenn Sie kein Glück haben, finden Sie die Protokollmeldung vielleicht in mehreren völlig unterschiedlichen Codepfaden. Dann stellen sich mehrere Fragen:
- Welcher von ihnen löst den Fehler aus?
- Oder sind es mehrere von ihnen? Oder ALLE?
- Welcher Eintrag im Protokoll entspricht welcher Stelle?
Manchmal ist es jedoch nicht einmal möglich, den Code zu durchsuchen, um herauszufinden, wo der Fehler auftritt, da der Protokolltext generiert wird. Überlegen Sie:
what = "something" quality = "bad" event = "happened" logger.error("%s %s %s", what, quality, event)
Wie würden Sie überhaupt danach suchen? Sie kommen vielleicht gar nicht auf die Idee, es sei denn, Sie haben zuerst nach dem vollständigen Satz gesucht und keine Treffer erhalten. Und wenn Sie einen Treffer erhalten, könnte es sich leicht um ein falsches Positiv handeln.
Die ideale Lösung besteht darin, das Argument exc_info zu übergeben:
try: something()except Exception: logger.error("something bad happened", exc_info=True)
Wenn Sie dies tun, wird ein vollständiger Stack-Trace in die Anwendungsprotokolle aufgenommen. Damit wissen Sie genau, welche Zeile in welcher Datei das Problem verursacht, wer sie aufgerufen hat, usw… alle Informationen, die Sie für die Fehlersuche benötigen.
Das teuflischste Python-Antipattern
Wenn ich jemals sehe, dass du das tust, werde ich zu dir nach Hause kommen und deine Computer beschlagnahmen, mich dann in deinen Github-Account hacken und alle deine Repos löschen:
try: something()except Exception: pass
In meinem Newsletter bezeichne ich das als „Das teuflischste Python-Antipattern.“ Beachten Sie, dass Sie damit nicht nur keine nützlichen Ausnahmeinformationen erhalten. Es schafft es auch, die Tatsache zu verbergen, dass überhaupt etwas falsch ist. Es kann sein, dass Sie nicht einmal wissen, dass Sie einen Variablennamen falsch eingegeben haben – ja, dies maskiert tatsächlich NameError – bis Sie nachts um 2 Uhr angepiepst werden, weil die Produktion kaputt ist, und zwar in einer Weise, dass Sie bis zum Morgengrauen brauchen, um es herauszufinden, weil alle möglichen Informationen zur Fehlerbehebung unterdrückt werden.
Tun Sie es einfach nicht. Wenn Sie das Gefühl haben, dass Sie einfach alle Fehler abfangen und ignorieren müssen, werfen Sie zumindest eine große Plane darunter (d.h. verwenden Sie logger.exception() statt pass).
Weitere Muster für die Protokollierung von Ausnahmen
Es gibt noch viele weitere Muster für die Protokollierung von Ausnahmeinformationen in Python, mit unterschiedlichen Kompromissen, Vor- und Nachteilen. Welche Muster haben Sie für nützlich befunden oder auch nicht? Lassen Sie es uns in den Kommentaren wissen.
Erfahren Sie mehr über die Grundlagen der Python-Protokollierung.