Aaron Maxwell jest autorem książki Powerful Python.
Wyjątki się zdarzają. I jako programiści po prostu musimy sobie z nimi radzić. Nawet podczas pisania oprogramowania, które ma nam pomóc znaleźć burritos.
Czekaj, wyprzedzam samego siebie… jeszcze do tego wrócimy. Jak już mówiłem: To, jak radzimy sobie z wyjątkami, zależy od języka. A dla oprogramowania działającego w skali, logowanie jest jednym z najpotężniejszych i najcenniejszych narzędzi, jakie mamy do radzenia sobie z warunkami błędu. Przyjrzyjmy się kilku sposobom, w jaki one ze sobą współpracują.
Wzorzec „Big Tarp”
Zaczniemy od jednej skrajności:
try: main_loop()except Exception: logger.exception("Fatal error in main loop")
Jest to szeroki catch-all. Nadaje się do niektórych ścieżek kodu, gdzie wiesz, że blok kodu (tj. main_loop()) może wywołać szereg wyjątków, których możesz nie przewidzieć. I zamiast pozwolić na zakończenie programu, decydujesz, że lepiej jest rejestrować informacje o błędach i kontynuować od tego miejsca.
Magia tutaj jest z metodą exception. (logger jest obiektem loggera twojej aplikacji – czymś, co zostało zwrócone z logging.getLogger(), na przykład). Ta wspaniała metoda przechwytuje pełny ślad stosu w kontekście bloku except i zapisuje go w całości.
Zauważ, że nie musisz przekazywać tutaj obiektu wyjątku. Przekazujesz natomiast łańcuch wiadomości. Spowoduje to zapisanie pełnego śladu stosu, ale doda linię z twoją wiadomością. Tak więc wielowierszowa wiadomość, która pojawi się w twoim dzienniku, może wyglądać tak:
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
Szczegóły śladu stosu nie mają znaczenia – jest to zabawkowy przykład, który ilustruje dorosłe rozwiązanie prawdziwego problemu. Wystarczy zauważyć, że pierwszy wiersz to wiadomość przekazana do logger.exception(), a kolejne wiersze to pełny ślad stosu, w tym typ wyjątku (w tym przypadku ZeroDivisionError). W ten sposób wyłapie i zapisze w dzienniku każdy rodzaj błędu.
Domyślnie logger.exception używa poziomu dziennika ERROR. Alternatywnie można użyć zwykłych metod logowania – logger.debug(), logger.info(), logger.warn() itd. – i przekazać parametr exc_info, ustawiając go na True:
while True: try: main_loop() except Exception: logger.error("Fatal error in main loop", exc_info=True)
Ustawienie parametru exc_info na True spowoduje, że logowanie obejmie pełny ślad stosu…. dokładnie tak, jak robi to logger.exception(). Jedyna różnica polega na tym, że możesz łatwo zmienić poziom logowania na coś innego niż błąd: Po prostu zamień logger.error na logger.warn, na przykład.
Fun fact: Wzorzec Big Tarp ma niemal diaboliczny odpowiednik, o którym przeczytasz poniżej.
Wzorzec „Pinpoint”
Przyjrzyjrzyjmy się teraz drugiej skrajności. Wyobraźmy sobie, że pracujemy z OpenBurrito SDK, biblioteką rozwiązującą kluczowy problem znalezienia nocnego burrito w pobliżu miejsca, w którym aktualnie się znajdujemy. Załóżmy, że ma ona funkcję o nazwie find_burrito_joints(), która normalnie zwraca listę odpowiednich restauracji. Ale w pewnych rzadkich okolicznościach może ona podnieść wyjątek o nazwie BurritoCriteriaConflict.
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()
Wzorzec polega na optymistycznym wykonaniu pewnego kodu – wywołania funkcji find_burrito_joints(), w tym przypadku – wewnątrz bloku try. W przypadku, gdy zostanie podniesiony określony typ wyjątku, rejestrujesz komunikat, radzisz sobie z sytuacją i idziesz dalej.
Kluczową różnicą jest klauzula except. W przypadku Big Tarp, w zasadzie łapiesz i rejestrujesz każdy możliwy wyjątek. Z Pinpointem, wyłapujesz bardzo specyficzny typ wyjątku, który ma znaczenie semantyczne w tym konkretnym miejscu w kodzie.
Zauważ również, że używam logger.warn() zamiast logger.exception(). (W tym artykule, gdziekolwiek zobaczysz warn(), możesz zastąpić info(), lub error(), itd.) Innymi słowy, rejestruję komunikat o określonym nasileniu, zamiast rejestrować cały ślad stosu.
Dlaczego wyrzucam informacje o śladzie stosu? Ponieważ nie jest ona tak użyteczna w tym kontekście, gdzie wyłapuję konkretny typ wyjątku, który ma wyraźne znaczenie w logice kodu. Na przykład, w tym snippecie:
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"
Tutaj, KeyError nie jest po prostu jakimkolwiek błędem. Kiedy jest on podniesiony, oznacza to, że wystąpiła specyficzna sytuacja – mianowicie, w moim zestawie postaci nie ma zdefiniowanej roli „sidekick”, więc muszę wrócić do domyślnej. Wypełnianie logu śladem stosu nie będzie przydatne w tego typu sytuacjach. I właśnie w tym celu użyjesz Pinpointa.
Wzorzec „Transformer”
Tutaj łapiesz wyjątek, rejestrujesz go, a następnie podnosisz inny wyjątek. Po pierwsze, oto jak to działa w Pythonie 3:
try: something()except SomeError as err: logger.warn("...") raise DifferentError() from err
W Pythonie 2, musisz zrezygnować z „from err”:
try: something()except SomeError as err: logger.warn("...") raise DifferentError()
(Okazuje się, że ma to duże znaczenie. Więcej na ten temat za chwilę.) Będziesz chciał użyć tego wzorca, gdy może zostać podniesiony wyjątek, który nie pasuje do logiki Twojej aplikacji. To często występuje wokół granic biblioteki.
Na przykład, wyobraź sobie, że używasz openburrito SDK dla swojej zabójczej aplikacji, która pozwala ludziom znaleźć późno w nocy stawy burrito. Funkcja find_burrito_joints() może podnieść BurritoCriteriaConflict, jeśli jesteśmy zbyt wybredni. To jest API eksponowane przez SDK, ale nie jest to wygodne mapowanie do logiki wyższego poziomu twojej aplikacji. Lepszym rozwiązaniem w tym miejscu kodu jest zdefiniowany przez Ciebie wyjątek o nazwie NoMatchingRestaurants.
W tej sytuacji zastosujesz wzorzec w następujący sposób (dla Pythona 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
Spowoduje to pojawienie się pojedynczej linii danych wyjściowych w dzienniku i wywołanie nowego wyjątku. Jeśli nie zostanie on złapany, wyjście błędu tego wyjątku wygląda tak:
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'}
Teraz jest to interesujące. Dane wyjściowe zawierają ślad stosu dla NoMatchingRestaurants. Zgłasza również inicjujący BurritoCriteriaConflict… wyraźnie określając, który z nich był oryginalny.
W Pythonie 3 wyjątki mogą być teraz łączone w łańcuchy. Zapewnia to składnia raise ... from .... Kiedy mówisz raise NoMatchingRestaurants(criteria) from err, to podnosi wyjątek o wartości typeNoMatchingRestaurants. Ten podniesiony wyjątek ma atrybut o nazwie __cause__, którego wartością jest wyjątek inicjujący. Python 3 korzysta z tego wewnętrznie podczas przekazywania informacji o błędach.
Jak to zrobić w Pythonie 2? Cóż, nie możesz. Jest to jedno z tych dobrodziejstw, które po prostu trzeba uaktualnić, aby je uzyskać. W Pythonie 2 składnia „raise … from” nie jest obsługiwana, więc twoje wyjście wyjątku będzie zawierało tylko ślad stosu dla NoMatchingRestaurants. Wzorzec Transformer jest oczywiście nadal doskonale użyteczny.
Wzorzec „Message and Raise”
W tym wzorcu rejestrujesz wystąpienie wyjątku w określonym punkcie, ale następnie pozwalasz mu się rozprzestrzeniać i być obsługiwanym na wyższym poziomie:
try: something()except SomeError: logger.warn("...") raise
Właściwie nie obsługujesz wyjątku. Po prostu tymczasowo przerywasz przepływ, aby zarejestrować zdarzenie. Zrobisz to, gdy masz już konkretny handler wyższego poziomu dla błędu i chcesz na nim się oprzeć, ale chcesz również zarejestrować, że błąd wystąpił lub jego znaczenie w określonym miejscu w kodzie.
To może być najbardziej przydatne w rozwiązywaniu problemów – gdy otrzymujesz wyjątek, ale próbujesz lepiej zrozumieć kontekst wywołania. Możesz wstrzyknąć tę deklarację logowania, aby dostarczyć użytecznych informacji, a nawet bezpiecznie wdrożyć ją na produkcję, jeśli musisz obserwować wyniki w realistycznych warunkach.
Przeciwwskazania do „krypto-komunikatów”
Teraz zwrócimy uwagę na pewne przeciwwskazania… rzeczy, których nie powinieneś robić w swoim kodzie.
try: something()except Exception: logger.error("...")
Załóżmy, że ty lub ktoś z twojego zespołu napisze ten kod, a następnie sześć miesięcy później zobaczysz zabawną wiadomość w swoim dzienniku. Coś w stylu:
ERROR: something bad happened
Teraz mam nadzieję i modlę się, że nie zobaczysz słów „coś złego się stało” w swoim faktycznym dzienniku. Jednak rzeczywisty tekst dziennika, który zobaczysz, może być równie zaskakujący. Co teraz zrobisz?
Najpierw musisz dowiedzieć się, gdzie w bazie kodu jest rejestrowana ta niejasna wiadomość. Jeśli masz szczęście, będziesz w stanie szybko przeszukać kod i znaleźć dokładnie jedną możliwość. Jeśli nie masz szczęścia, możesz znaleźć komunikat dziennika w kilku zupełnie różnych ścieżkach kodu. Pozostanie kilka pytań:
- Która z nich wywołuje błąd?
- Czy jest to kilka z nich? Lub WSZYSTKIE z nich?
- Który wpis w dzienniku odpowiada któremu miejscu?
Czasami jednak nie jest nawet możliwe grepowanie lub przeszukiwanie kodu w celu znalezienia miejsca, w którym to się dzieje, ponieważ tekst dziennika jest generowany. Rozważ:
what = "something" quality = "bad" event = "happened" logger.error("%s %s %s", what, quality, event)
Jak byś tego szukał? Możesz nawet o tym nie myśleć, chyba że najpierw szukałeś pełnej frazy i nie otrzymałeś żadnych trafień. A jeśli trafisz, może to być fałszywie pozytywny wynik.
Idealnym rozwiązaniem jest przekazanie argumentu exc_info:
try: something()except Exception: logger.error("something bad happened", exc_info=True)
Gdy to zrobisz, do logów aplikacji zostanie dołączony pełny ślad stosu. To mówi dokładnie, która linia w jakim pliku powoduje problem, kto ją wywołał, et cetera… wszystkie informacje, których potrzebujesz, aby rozpocząć debugowanie.
Najbardziej Diaboliczny Antypattern Pythona
Jeśli kiedykolwiek zobaczę, jak to robisz, przyjdę do twojego domu, skonfiskuję twoje komputery, a następnie włamię się na twoje konto github i usunę wszystkie twoje repozytoria:
try: something()except Exception: pass
W moim biuletynie odnoszę się do tego jako „Najbardziej Diaboliczny Antypattern Pythona”. Zauważ, jak to nie tylko nie daje ci żadnych użytecznych informacji o wyjątkach. Udaje mu się również całkowicie ukryć fakt, że cokolwiek jest nie tak w pierwszej kolejności. Możesz nawet nie wiedzieć, że źle wpisałeś nazwę zmiennej – tak, to faktycznie maskuje NameError – aż do momentu, gdy dostaniesz stronę o 2 w nocy, ponieważ produkcja jest zepsuta, w sposób, który zajmie ci do rana, aby to zrozumieć, ponieważ wszystkie możliwe informacje o rozwiązywaniu problemów są tłumione.
Po prostu nie rób tego. Jeśli czujesz, że po prostu musisz złapać i zignorować wszystkie błędy, przynajmniej rzuć pod to duży brezent (np. użyj logger.exception() zamiast pass).
Więcej wzorców rejestrowania wyjątków
W Pythonie istnieje wiele innych wzorców rejestrowania informacji o wyjątkach, z różnymi kompromisami, zaletami i wadami. Jakie wzorce okazały się dla Ciebie przydatne, a jakie nie? Daj znać w komentarzach.
Dowiedz się więcej o podstawach logowania w Pythonie.
Znaki towarowe Loggly i SolarWinds, znaki usługowe i logo są wyłączną własnością SolarWinds Worldwide, LLC lub jej podmiotów stowarzyszonych. Wszystkie inne znaki towarowe są własnością ich odpowiednich właścicieli.
.