Aaron Maxwell a Powerful Python szerzője.
A kivételek előfordulnak. És fejlesztőként egyszerűen foglalkoznunk kell velük. Még akkor is, amikor olyan szoftvert írunk, amely segít nekünk megtalálni a burritókat.
Várj, elébe megyek a dolgoknak… erre még visszatérünk. Ahogy mondtam: A nyelvtől függ, hogyan kezeljük a kivételeket. És a méretarányosan működő szoftverek esetében a naplózás az egyik legerősebb, legértékesebb eszközünk a hibaállapotok kezelésére. Nézzünk meg néhány módot, ahogy ezek együtt működnek.
A “Nagy ponyvás” minta
Az egyik végletből fogunk kiindulni:
try: main_loop()except Exception: logger.exception("Fatal error in main loop")
Ez egy tág fogódzkodó. Alkalmas néhány olyan kódútra, ahol tudjuk, hogy a kódblokk (pl. main_loop()) számos olyan kivételt vethet fel, amire nem számíthatunk. És ahelyett, hogy hagynád, hogy a program befejeződjön, úgy döntesz, hogy jobb, ha naplózod a hibainformációt, és onnan folytatod.
A varázslat itt a exception módszerrel történik. (A logger az alkalmazásod naplózó objektuma – valami, amit például a logging.getLogger() segítségével kaptál vissza.) Ez a csodálatos metódus rögzíti a teljes stack trace-t a kivételblokk kontextusában, és teljes egészében kiírja.
Megjegyezzük, hogy itt nem kell átadni a kivételobjektumot. Átadsz viszont egy üzenetsztringet. Ez naplózza a teljes stack trace-t, de egy sor elé írja az üzenetet. Így a naplóban megjelenő többsoros üzenet így nézhet ki:
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
A stack trace részletei nem számítanak – ez egy játékpélda, amely egy valós probléma felnőtt megoldását szemlélteti. Csak figyeljük meg, hogy az első sor a logger.exception()-nek átadott üzenet, az ezt követő sorok pedig a teljes stack trace, beleértve a kivétel típusát (ebben az esetben ZeroDivisionError). Így bármilyen hibát elkap és naplóz.
A logger.exception alapértelmezés szerint az ERROR naplózási szintet használja. Alternatívaként használhatjuk a szokásos naplózási módszereket – logger.debug(), logger.info(), logger.warn() stb. -, és átadhatjuk a exc_info paramétert, True értékre állítva:
while True: try: main_loop() except Exception: logger.error("Fatal error in main loop", exc_info=True)
A exc_info True értékre állításával a naplózás tartalmazza a teljes veremkövetést…., pontosan úgy, ahogy a logger.exception() teszi. Az egyetlen különbség az, hogy a naplózási szintet könnyen megváltoztathatja a hibától eltérő szintre: Csak cseréld ki például a logger.error-et logger.warn-ra.
Vicces tény: A Big Tarp mintának van egy szinte ördögi megfelelője, amelyről alább olvashatsz.
A “Pinpoint” minta
Most nézzük a másik végletet. Képzeljük el, hogy az OpenBurrito SDK-val dolgozunk, egy olyan könyvtárral, amely azt a létfontosságú problémát oldja meg, hogy megtaláljuk az aktuális tartózkodási helyünkhöz közeli késő esti burrito-büfét. Tegyük fel, hogy van egy find_burrito_joints() nevű függvénye, amely általában a megfelelő éttermek listáját adja vissza. Bizonyos ritka körülmények között azonban egy BurritoCriteriaConflict nevű kivételt vethet fel.
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()
A minta itt az, hogy optimistán végrehajtunk néhány kódot – ebben az esetben a find_burrito_joints() hívását – egy try blokkban. Abban az esetben, ha egy bizonyos típusú kivétel keletkezik, naplózunk egy üzenetet, kezeljük a helyzetet, és továbblépünk.
A legfontosabb különbség a except záradék. A Big Tarp segítségével alapvetően minden lehetséges kivételt elkapunk és naplózunk. A Pinpoint-tal egy nagyon specifikus kivételtípust fogsz el, amelynek szemantikai jelentősége van a kód adott helyén.
Figyelj arra is, hogy logger.warn()-t használok a logger.exception() helyett. (Ebben a cikkben bárhol, ahol warn() szerepel, helyettesítheti info(), vagy error(), stb.) Más szóval, egy adott súlyosságú üzenetet naplózok ahelyett, hogy a teljes stack trace-t naplóznám.
Miért dobom el a stack trace információit? Mert nem olyan hasznos ebben a kontextusban, ahol egy konkrét kivételtípust fogok el, amelynek egyértelmű jelentése van a kód logikájában. Például ebben a részletben:
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"
Itt a KeyError nem akármilyen hiba. Ha feljön, az azt jelenti, hogy egy speciális helyzet állt elő – nevezetesen, hogy nincs definiálva a karakterek között a “sidekick” szerepkör, ezért vissza kell esnem egy alapértelmezettre. A napló stack trace-ekkel való feltöltése nem lesz hasznos egy ilyen helyzetben. És itt fogod használni a Pinpointot.
A “Transformer” Pattern
Itt elkapsz egy kivételt, naplózod, majd felvetsz egy másik kivételt. Először is, itt van, hogyan működik ez Python 3-ban:
try: something()except SomeError as err: logger.warn("...") raise DifferentError() from err
A Python 2-ben el kell hagynod a “from err”-t:
try: something()except SomeError as err: logger.warn("...") raise DifferentError()
(Kiderül, hogy ennek nagy következményei vannak. Erről majd később.) Ezt a mintát akkor akarod használni, ha olyan kivétel kerülhet elő, ami nem jól illeszkedik az alkalmazásod logikájához. Ez gyakran előfordul a könyvtárhatárok körül.
Képzeljük el például, hogy a openburrito SDK-t használjuk a gyilkos alkalmazásunkhoz, amely lehetővé teszi, hogy az emberek megtalálják a késő esti burrito éttermeket. A find_burrito_joints() függvény BurritoCriteriaConflict-et emelhet, ha túl válogatósak vagyunk. Ez az SDK által kitett API, de ez nem képezi le kényelmesen az alkalmazásod magasabb szintű logikáját. A kód ezen pontjára jobban illik egy általad definiált, NoMatchingRestaurants nevű kivétel.
Ebben a helyzetben így fogod alkalmazni a mintát (Python 3 esetén):
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
Ez egyetlen sor kimenetet okoz a naplódban, és kivált egy új kivételt. Ha soha nem kapjuk el, akkor ennek a kivételnek a hibakimenete így néz ki:
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'}
Most ez érdekes. A kimenet tartalmazza a NoMatchingRestaurants stack trace-jét. És a kiváltó BurritoCriteriaConflict-t is jelzi… egyértelműen megadva, hogy melyik volt az eredeti.
A Python 3-ban a kivételek már láncolhatók. Ezt a raise ... from ... szintaxis biztosítja. Ha azt mondjuk, hogy raise NoMatchingRestaurants(criteria) az err-ből, akkor az egy typeNoMatchingRestaurants kivételt hoz létre. Ennek a felvetett kivételnek van egy __cause__ nevű attribútuma, amelynek értéke a felvető kivétel. A Python 3 ezt használja belsőleg a hibainformáció jelentésénél.
Hogyan csináljuk ezt a Python 2-ben? Nos, nem lehet. Ez egyike azoknak a finomságoknak, amikhez csak frissíteni kell, hogy megkapd. A Python 2-ben a “raise … from” szintaxis nem támogatott, így a kivétel kimenete csak a NoMatchingRestaurants stack trace-t fogja tartalmazni. A Transformer minta természetesen továbbra is tökéletesen hasznos.
A “Message and Raise” minta
Ezzel a mintával naplózod, hogy egy kivétel egy adott ponton bekövetkezik, de aztán hagyod, hogy továbbterjedjen és egy magasabb szinten kezeljék:
try: something()except SomeError: logger.warn("...") raise
Ténylegesen nem kezeled a kivételt. Csak ideiglenesen megszakítod az áramlást, hogy naplózz egy eseményt. Ezt akkor csinálod, ha kifejezetten van egy magasabb szintű kezelője a hibának, és arra akarsz támaszkodni, de azt is naplózni akarod, hogy a hiba bekövetkezett, vagy annak jelentését a kód egy bizonyos helyén.
Ez leginkább a hibakeresésnél lehet hasznos – amikor egy kivételt kapsz, de megpróbálod jobban megérteni a hívó kontextust. Ezt a naplózási utasítást közbeiktathatja, hogy hasznos információkkal szolgáljon, és akár biztonságosan telepítheti a termelésbe, ha valós körülmények között kell megfigyelnie az eredményeket.
A “rejtélyes üzenet” antimintája
Most néhány antimintára fordítjuk figyelmünket… olyan dolgokra, amelyeket nem szabadna tennie a kódjában.
try: something()except Exception: logger.error("...")
Tegyük fel, hogy ön vagy valaki a csapatából megírja ezt a kódot, majd hat hónappal később egy vicces üzenetet lát a naplóban. Valami olyasmit, mint:
ERROR: something bad happened
Most remélem és imádkozom, hogy nem fogod látni a “valami rossz történt” szavakat az aktuális naplódban. Azonban a tényleges naplószöveg, amit látsz, ugyanolyan zavarba ejtő lehet. Mit tegyen ezután?
Nos, az első dolog az, hogy kitalálja, hol van a kódbázisban ez a homályos üzenet naplózva. Ha szerencsés vagy, akkor gyorsan végig tudod grepelni a kódot, és pontosan egy lehetőséget találsz. Ha nem vagy szerencsés, akkor előfordulhat, hogy a naplóüzenetet több teljesen különböző kódútvonalon találod meg. Ami több kérdést is felvet:
- Melyik váltja ki a hibát?
- Vagy esetleg több is? Vagy MINDEN?
- Melyik bejegyzés a naplóban melyik helynek felel meg?
Néha azonban még csak nem is lehet grep-elni vagy keresni a kódban, hogy megtaláljuk, hol történik a hiba, mert a napló szövege generálódik. Gondoljunk csak bele:
what = "something" quality = "bad" event = "happened" logger.error("%s %s %s", what, quality, event)
Hogyan lehetne egyáltalán rákeresni? Talán eszébe sem jut, hacsak nem keresett rá először a teljes kifejezésre, és nem kapott találatot. Ha pedig mégis találatot kapna, az könnyen lehet hamis pozitív eredmény.
Az ideális megoldás a exc_info argumentum átadása:
try: something()except Exception: logger.error("something bad happened", exc_info=True)
Amikor ezt teszi, a teljes stack trace bekerül az alkalmazásnaplókba. Ebből pontosan megtudhatod, hogy melyik fájl melyik sora okozza a problémát, ki hívta meg, satöbbi… minden olyan információ, amire szükséged van a hibakeresés megkezdéséhez.
A legördögibb Python Antipattern
Ha valaha is meglátom, hogy ezt csinálod, a házadhoz megyek, hogy elkobozzam a számítógépeidet, majd feltöröm a github fiókodat és törlöm az összes reposodat:
try: something()except Exception: pass
A hírlevelemben úgy hivatkozom erre, mint “A legördögibb Python Antipattern”. Figyeld meg, hogy ez nem csak, hogy nem ad semmilyen hasznos kivételinformációt. Azt is sikerül teljesen elrejtenie, hogy egyáltalán valami baj van. Lehet, hogy soha nem is tudod meg, hogy elírtál egy változó nevét – igen, ez valóban elrejti a NameError-t -, amíg hajnali kettőkor meg nem csipogtatnak, mert a termelés elromlott, méghozzá úgy, hogy hajnalig tart rájönni, mert minden lehetséges hibaelhárítási információ el van nyomva.
Egyszerűen ne csináld. Ha úgy érzed, hogy egyszerűen minden hibát el kell fognod és figyelmen kívül kell hagynod, legalább dobj alá egy nagy ponyvát (azaz használd a logger.exception()-t a pass helyett).
Még több kivételnaplózási minta
Még több minta létezik a kivételinformációk naplózására Pythonban, különböző kompromisszumokkal, előnyökkel és hátrányokkal. Milyen mintákat találtál hasznosnak, vagy nem? Ossza meg mindenkivel a hozzászólásokban.
Tudjon meg többet a Python naplózás alapjairól.