Protokollausnahme mit Traceback

Wie kann ich meine Python-Fehler protokollieren?

try:
    do_something()
except:
    # How can I log my exception here, complete with its traceback?

Verwenden Sie diese Option logging.exceptionaus dem except:Handler / Block heraus, um die aktuelle Ausnahme zusammen mit den Ablaufverfolgungsinformationen zu protokollieren, denen eine Nachricht vorangestellt ist.

import logging
LOG_FILENAME = '/tmp/logging_example.out'
logging.basicConfig(filename=LOG_FILENAME, level=logging.DEBUG)

logging.debug('This message should go to the log file')

try:
    run_my_stuff()
except:
    logging.exception('Got exception on main handler')
    raise

Schauen Sie sich nun die Protokolldatei an /tmp/logging_example.out:

DEBUG:root:This message should go to the log file
ERROR:root:Got exception on main handler
Traceback (most recent call last):
  File "/tmp/teste.py", line 9, in <module>
    run_my_stuff()
NameError: name 'run_my_stuff' is not defined

Verwendungsoptionen exc_infokönnen besser sein, bleibt Warnung oder Fehlertitel:

try:
    # coode in here
except Exception as e:
    logging.error(e, exc_info=True)

Mein Job hat mich kürzlich beauftragt, alle Tracebacks / Ausnahmen aus unserer Anwendung zu protokollieren. Ich habe zahlreiche Techniken ausprobiert, die andere online gestellt hatten, wie die oben beschriebene, mich aber für einen anderen Ansatz entschieden. Überschreiben traceback.print_exception.

Ich habe einen Artikel unter http://www.bbarrows.com/. Das wäre viel einfacher zu lesen, aber ich füge ihn auch hier ein.

Als ich mit der Protokollierung aller Ausnahmen beauftragt wurde, auf die unsere Software in der Natur stoßen könnte, habe ich verschiedene Techniken ausprobiert, um unsere Python-Ausnahme-Tracebacks zu protokollieren. Zuerst dachte ich, dass der Python-System-Ausnahme-Hook sys.excepthook der perfekte Ort wäre, um den Protokollierungscode einzufügen. Ich habe etwas Ähnliches versucht wie:

import traceback
import StringIO
import logging
import os, sys

def my_excepthook(excType, excValue, traceback, logger=logger):
    logger.error("Logging an uncaught exception",
                 exc_info=(excType, excValue, traceback))

sys.excepthook = my_excepthook  

Dies funktionierte für den Hauptthread, aber ich stellte bald fest, dass mein sys.excepthook in keinem neuen Thread vorhanden sein würde, den mein Prozess gestartet hatte. Dies ist ein großes Problem, da in diesem Projekt fast alles in Threads geschieht.

Nachdem ich gegoogelt und viele Dokumentationen gelesen hatte, fand ich die hilfreichsten Informationen im Python Issue Tracker.

Der erste Beitrag im Thread zeigt ein Arbeitsbeispiel für das sys.excepthookNICHT-Fortbestehen über Threads (wie unten gezeigt). Anscheinend ist dies erwartetes Verhalten.

import sys, threading

def log_exception(*args):
    print 'got exception %s' % (args,)
sys.excepthook = log_exception

def foo():
    a = 1 / 0

threading.Thread(target=foo).start()

Die Nachrichten in diesem Python Issue-Thread führen tatsächlich zu 2 vorgeschlagenen Hacks. Entweder Unterklasse Threadund Wrap der Run-Methode in unserem eigenen Versuch außer Block, um Ausnahmen oder Affen-Patch abzufangen und zu protokollierenthreading.Thread.run , um in Ihrem eigenen Versuch außer Block auszuführen und die Ausnahmen zu protokollieren.

Die erste Methode der Unterklasse Threadscheint mir in Ihrem Code weniger elegant zu sein, da Sie Ihre benutzerdefinierte ThreadKlasse ÜBERALL importieren und verwenden müssten, wo immer Sie einen Protokollierungsthread haben möchten . Dies war ein Ärger, da ich unsere gesamte Codebasis durchsuchen und alles Normale Threadsdurch diesen Brauch ersetzen musste Thread. Es war jedoch klar, was dies Threadtat, und es würde für jemanden einfacher sein, zu diagnostizieren und zu debuggen, wenn mit dem benutzerdefinierten Protokollierungscode ein Fehler auftrat. Ein benutzerdefinierter Protokollierungsthread könnte folgendermaßen aussehen:

class TracebackLoggingThread(threading.Thread):
    def run(self):
        try:
            super(TracebackLoggingThread, self).run()
        except (KeyboardInterrupt, SystemExit):
            raise
        except Exception, e:
            logger = logging.getLogger('')
            logger.exception("Logging an uncaught exception")

Die zweite Methode zum Patchen von Affen threading.Thread.runist nett, da ich sie direkt danach einmal ausführen __main__und meinen Protokollierungscode in allen Ausnahmen instrumentieren konnte. Das Patchen von Affen kann beim Debuggen jedoch ärgerlich sein, da es die erwartete Funktionalität von etwas ändert. Der vorgeschlagene Patch vom Python Issue Tracker war:

def installThreadExcepthook():
    """
    Workaround for sys.excepthook thread bug
    From
http://spyced.blogspot.com/2007/06/workaround-for-sysexcepthook-bug.html

(https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1230540&group_id=5470).
    Call once from __main__ before creating any threads.
    If using psyco, call psyco.cannotcompile(threading.Thread.run)
    since this replaces a new-style class method.
    """
    init_old = threading.Thread.__init__
    def init(self, *args, **kwargs):
        init_old(self, *args, **kwargs)
        run_old = self.run
        def run_with_except_hook(*args, **kw):
            try:
                run_old(*args, **kw)
            except (KeyboardInterrupt, SystemExit):
                raise
            except:
                sys.excepthook(*sys.exc_info())
        self.run = run_with_except_hook
    threading.Thread.__init__ = init

Erst als ich anfing, meine Ausnahmeprotokollierung zu testen, wurde mir klar, dass ich alles falsch gemacht hatte.

Zum Testen hatte ich einen platziert

raise Exception("Test")

irgendwo in meinem Code. Das Umschließen einer Methode, die diese Methode aufrief, war jedoch ein Versuch mit Ausnahme eines Blocks, der den Traceback druckte und die Ausnahme verschluckte. Das war sehr frustrierend, weil ich sah, dass der Traceback auf STDOUT gedruckt, aber nicht protokolliert wurde. Dann entschied ich, dass eine viel einfachere Methode zum Protokollieren der Tracebacks darin bestand, die Methode zu patchen, mit der der gesamte Python-Code die Tracebacks selbst druckt, traceback.print_exception. Am Ende hatte ich etwas Ähnliches wie das Folgende:

def add_custom_print_exception():
    old_print_exception = traceback.print_exception
    def custom_print_exception(etype, value, tb, limit=None, file=None):
        tb_output = StringIO.StringIO()
        traceback.print_tb(tb, limit, tb_output)
        logger = logging.getLogger('customLogger')
        logger.error(tb_output.getvalue())
        tb_output.close()
        old_print_exception(etype, value, tb, limit=None, file=None)
    traceback.print_exception = custom_print_exception

Dieser Code schreibt den Traceback in einen String-Puffer und protokolliert ihn im Protokollierungsfehler. Ich habe einen benutzerdefinierten Protokollierungshandler eingerichtet, der den 'customLogger'-Logger eingerichtet hat, der die ERROR-Protokolle aufnimmt und zur Analyse nach Hause sendet.

Sie können alle nicht erfassten Ausnahmen im Hauptthread protokollieren, indem Sie einen Handler zuweisen sys.excepthook, möglicherweise mithilfe des exc_infoParameters der Protokollierungsfunktionen von Python :

import sys
import logging

logging.basicConfig(filename='/tmp/foobar.log')

def exception_hook(exc_type, exc_value, exc_traceback):
    logging.error(
        "Uncaught exception",
        exc_info=(exc_type, exc_value, exc_traceback)
    )

sys.excepthook = exception_hook

raise Exception('Boom')

Wenn Ihr Programm - Threads jedoch beachten , dann die Threads erstellt threading.Threadwerden nicht Auslöser , sys.excepthookwenn eine abgefangene Ausnahme in ihnen auftritt, wie in angemerkt Ausgabe 1230540 auf Pythons issue tracker. Es wurden dort einige Hacks vorgeschlagen, um diese Einschränkung zu umgehen, z. B. das Patchen Thread.__init__von Affen zum Überschreiben self.runmit einer alternativen runMethode, bei der das Original in einen tryBlock eingeschlossen und sys.excepthookaus dem exceptBlock heraus aufgerufen wird. Alternativ können Sie nur manuell wickeln den Einstiegspunkt für jede Ihrer Fäden in try/ exceptselbst.

Nicht erfasste Ausnahmemeldungen werden an STDERR gesendet. Anstatt Ihre Protokollierung in Python selbst zu implementieren, können Sie STDERR mit einer beliebigen Shell, mit der Sie Ihr Python-Skript ausführen, an eine Datei senden. In einem Bash-Skript können Sie dies mit der Ausgabeumleitung tun, wie im BASH-Handbuch beschrieben .

Beispiele

Anhängen von Fehlern an Datei, andere Ausgabe an das Terminal:

./test.py 2>> mylog.log

Datei mit verschachtelter STDOUT- und STDERR-Ausgabe überschreiben:

./test.py &> mylog.log

Was ich gesucht habe:

import sys
import traceback

exc_type, exc_value, exc_traceback = sys.exc_info()
traceback_in_var = traceback.format_tb(exc_traceback)

Sehen:

• https://docs.python.org/3/library/traceback.html

Sie können den Traceback mit einem Logger auf jeder Ebene abrufen (DEBUG, INFO, ...). Beachten Sie, dass bei Verwendung logging.exceptiondie Stufe FEHLER ist.

# test_app.py
import sys
import logging

logging.basicConfig(level="DEBUG")

def do_something():
    raise ValueError(":(")

try:
    do_something()
except Exception:
    logging.debug("Something went wrong", exc_info=sys.exc_info())

DEBUG:root:Something went wrong
Traceback (most recent call last):
  File "test_app.py", line 10, in <module>
    do_something()
  File "test_app.py", line 7, in do_something
    raise ValueError(":(")
ValueError: :(

BEARBEITEN:

Dies funktioniert auch (mit Python 3.6)

logging.debug("Something went wrong", exc_info=True)

Hier ist eine Version, die sys.excepthook verwendet

import traceback
import sys

logger = logging.getLogger()

def handle_excepthook(type, message, stack):
     logger.error(f'An unhandled exception occured: {message}. Traceback: {traceback.format_tb(stack)}')

sys.excepthook = handle_excepthook

vielleicht nicht so stylisch, aber einfacher:

#!/bin/bash
log="/var/log/yourlog"
/path/to/your/script.py 2>&1 | (while read; do echo "$REPLY" >> $log; done)

Hier ist ein einfaches Beispiel aus der Python 2.6-Dokumentation :

import logging
LOG_FILENAME = '/tmp/logging_example.out'
logging.basicConfig(filename=LOG_FILENAME,level=logging.DEBUG,)

logging.debug('This message should go to the log file')