Zaloguj wyjątek z funkcją śledzenia

Jak mogę rejestrować błędy Pythona?

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

Użyj logging.exceptionz modułu except:obsługi / bloku, aby zarejestrować bieżący wyjątek wraz z informacjami o śledzeniu, poprzedzonymi komunikatem.

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

Teraz patrząc na plik dziennika /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

Użyj exc_infoopcji może być lepsze, pozostaje ostrzeżenie lub tytuł błędu:

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

Moja praca ostatnio zleciła mi rejestrowanie wszystkich danych śledzenia / wyjątków z naszej aplikacji. Wypróbowałem wiele technik, które inni opublikowali w Internecie, takich jak ta powyżej, ale zdecydowałem się na inne podejście. Zastępowanie traceback.print_exception.

Mam napis na http://www.bbarrows.com/ Byłby o wiele łatwiejszy do odczytania, ale wkleię go również tutaj.

Kiedy otrzymałem zadanie rejestrowania wszystkich wyjątków, które nasze oprogramowanie może napotkać na wolności, wypróbowałem wiele różnych technik, aby zarejestrować nasze śledzenie wyjątków w Pythonie. Na początku pomyślałem, że hak wyjątków systemu Pythona, sys.excepthook, będzie idealnym miejscem do wstawienia kodu logowania. Próbowałem czegoś podobnego do:

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  

To działało w przypadku głównego wątku, ale wkrótce odkryłem, że mój sys.excepthook nie będzie istniał w żadnym nowym wątku, który rozpoczął mój proces. To ogromny problem, ponieważ w tym projekcie prawie wszystko dzieje się w wątkach.

Po przeszukaniu go i przeczytaniu dużej ilości dokumentacji, najbardziej pomocne informacje, które znalazłem, pochodziły z narzędzia do śledzenia problemów w Pythonie.

Pierwszy post w wątku pokazuje działający przykład sys.excepthookNIE utrzymującego się w wątkach (jak pokazano poniżej). Najwyraźniej jest to oczekiwane zachowanie.

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()

Komunikaty w tym wątku dotyczącym Pythona naprawdę skutkują 2 sugerowanymi hackami. Albo podklasę Threadi zawiń metodę run w naszej własnej try z wyjątkiem bloku, aby przechwytywać i rejestrować wyjątki, lub małpę łatkę threading.Thread.rundo uruchomienia we własnym try, z wyjątkiem blokowania i rejestrowania wyjątków.

Pierwsza metoda tworzenia podklas Threadwydaje mi się mniej elegancka w twoim kodzie, ponieważ musiałbyś importować i używać swojej niestandardowej Threadklasy WSZĘDZIE, gdzie chciałbyś mieć wątek logowania. Skończyło się to kłopotem, ponieważ musiałem przeszukać całą naszą bazę kodu i zastąpić wszystko normalne Threadstym niestandardowym Thread. Jednak było jasne, co to Threadrobi, i byłoby łatwiej dla kogoś zdiagnozować i debugować, gdyby coś poszło nie tak z niestandardowym kodem logowania. Niestandardowy wątek rejestrowania może wyglądać następująco:

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")

Druga metoda patchowania małp threading.Thread.runjest fajna, ponieważ mogłem ją po prostu uruchomić raz zaraz po __main__i instrumentować mój kod logowania we wszystkich wyjątkach. Poprawianie małp może być denerwujące przy debugowaniu, ponieważ zmienia oczekiwaną funkcjonalność czegoś. Sugerowana łatka z narzędzia do śledzenia problemów Pythona to:

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

Dopiero gdy zacząłem testować rejestrowanie wyjątków, zdałem sobie sprawę, że wszystko idzie źle.

Aby przetestować, umieściłem plik

raise Exception("Test")

gdzieś w moim kodzie. Jednak zawijanie metody, która wywołała tę metodę, było blokiem try z wyjątkiem, który wypisał traceback i połknął wyjątek. To było bardzo frustrujące, ponieważ widziałem, że traceback przenosi wydruk do STDOUT, ale nie został zarejestrowany. Wtedy zdecydowałem, że o wiele łatwiejszą metodą rejestrowania śladów jest po prostu małpa łata metodę, której cały kod Pythona używa do drukowania samych śladów, traceback.print_exception. Skończyło się na czymś podobnym do następującego:

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

Ten kod zapisuje dane śledzenia w buforze ciągów i rejestruje je w dzienniku ERROR. Mam niestandardowy program obsługi rejestrowania, który konfiguruje rejestrator „customLogger”, który pobiera dzienniki poziomu BŁĘDU i wysyła je do domu do analizy.

Możesz rejestrować wszystkie nieprzechwycone wyjątki w głównym wątku, przypisując procedurę obsługi do sys.excepthook, być może używając exc_infoparametru funkcji logowania Pythona :

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')

Jeśli jednak Twój program używa wątków, pamiętaj, że wątki utworzone za pomocą niethreading.Thread będą wyzwalane, gdy wystąpi w nich nieprzechwycony wyjątek, jak wspomniano w numerze 1230540 dotyczącym śledzenia problemów w języku Python. Sugerowano tam kilka hacków, aby obejść to ograniczenie, np. Małpa łatanie w celu nadpisania alternatywną metodą, która zawija oryginał w bloku i wywołuje z wnętrza bloku. Alternatywnie możesz po prostu ręcznie zawinąć punkt wejścia dla każdego z wątków w / w sobie.sys.excepthookThread.__init__self.runruntrysys.excepthookexcepttryexcept

Nieprzechwycone komunikaty o wyjątkach trafiają do STDERR, więc zamiast implementować logowanie w samym Pythonie, możesz wysłać STDERR do pliku przy użyciu dowolnej powłoki, której używasz do uruchomienia skryptu Pythona. W skrypcie Bash możesz to zrobić za pomocą przekierowania wyjścia, jak opisano w przewodniku BASH .

Przykłady

Dołącz błędy do pliku, inne dane wyjściowe do terminala:

./test.py 2>> mylog.log

Nadpisz plik z przeplatanym wyjściem STDOUT i STDERR:

./test.py &> mylog.log

Czego szukałem:

import sys
import traceback

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

Widzieć:

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

Możesz uzyskać śledzenie za pomocą loggera na dowolnym poziomie (DEBUG, INFO, ...). Zwróć uwagę, że użycie logging.exceptionpoziomu to ERROR.

# 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: :(

EDYTOWAĆ:

To też działa (używając Pythona 3.6)

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

Oto wersja korzystająca z sys.excepthook

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

może nie tak stylowy, ale łatwiejszy:

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

Oto prosty przykład zaczerpnięty z dokumentacji Pythona 2.6 :

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')