Poikkeusten kirjaaminen Pythonissa

Aaron Maxwell on Powerful Python -kirjan kirjoittaja.

Poikkeuksia tapahtuu. Ja kehittäjinä meidän on yksinkertaisesti käsiteltävä niitä. Jopa kirjoittaessamme ohjelmistoja, jotka auttavat meitä löytämään burritoja.

Odota, menen asioiden edelle… palaamme siihen vielä. Kuten olin sanomassa: Se, miten käsittelemme poikkeuksia, riippuu kielestä. Ja laajassa mittakaavassa toimivissa ohjelmistoissa lokitus on yksi tehokkaimmista ja arvokkaimmista työkaluista, joita meillä on virhetilanteiden käsittelyyn. Katsotaanpa joitain tapoja, joilla nämä toimivat yhdessä.

”Iso pressu”-kuvio

Aloitetaan yhdestä ääripäästä:

try: main_loop()except Exception: logger.exception("Fatal error in main loop")

Tämä on laaja katvealue. Se sopii johonkin koodipolkuun, jossa tiedät, että koodilohko (eli main_loop()) voi aiheuttaa useita poikkeuksia, joita et ehkä ennakoi. Ja sen sijaan, että antaisit ohjelman keskeytyä, päätät, että on parempi kirjata virhetiedot ja jatkaa siitä eteenpäin.

Taika tässä on exception-metodilla. (logger on sovelluksesi logger-olio – jokin, joka palautettiin esimerkiksi logging.getLogger():llä.) Tämä ihmeellinen metodi kaappaa koko pinojäljen poikkeuslohkon kontekstissa ja kirjoittaa sen kokonaisuudessaan.

Huomaa, että sinun ei tarvitse välittää poikkeusobjektia tähän. Annat kuitenkin viestin merkkijonon. Tämä kirjaa koko pinojäljen, mutta liittää rivin eteen viestisi. Lokissa näkyvä monirivinen viesti voi siis näyttää tältä:

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

Pinojäljen yksityiskohdilla ei ole väliä – tämä on leluesimerkki, joka havainnollistaa aikuisten ratkaisua reaalimaailman ongelmaan. Huomaa vain, että ensimmäinen rivi on viesti, jonka annoit logger.exception(), ja seuraavat rivit ovat koko pinojälki, mukaan lukien poikkeustyyppi (tässä tapauksessa ZeroDivisionError). Se nappaa ja kirjaa kaikenlaiset virheet tällä tavalla.

Oletusarvoisesti logger.exception käyttää lokitasoa ERROR. Vaihtoehtoisesti voit käyttää tavallisia lokimenetelmiä – logger.debug(), logger.info(), logger.warn() jne. – ja välittää exc_info-parametrin asettamalla sen arvoksi True:

while True: try: main_loop() except Exception: logger.error("Fatal error in main loop", exc_info=True)

Asettamalla exc_info arvoksi True lokitukseen sisällytetään koko pinon jälki…. täsmälleen samalla tavalla kuin logger.exception() tekee. Ainoa ero on, että voit helposti vaihtaa lokitason joksikin muuksi kuin virheeksi: Korvaa vain logger.error esimerkiksi logger.warn:lla.

Hauska fakta: Big Tarp -kuviolla on melkein pirullinen vastine, josta luet alla.

”Pinpoint”-kuvio

Katsotaan nyt toista ääripäätä. Kuvittele, että työskentelet OpenBurrito SDK:n kanssa, joka on kirjasto, joka ratkaisee ratkaisevan tärkeän ongelman löytää myöhäisillan burrito-paikka lähellä nykyistä sijaintiasi. Oletetaan, että sillä on funktio nimeltä find_burrito_joints(), joka normaalisti palauttaa luettelon sopivista ravintoloista. Mutta tietyissä harvinaisissa olosuhteissa se saattaa aiheuttaa poikkeuksen nimeltä 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()

Malli tässä on suorittaa optimistisesti jokin koodi – tässä tapauksessa kutsu find_burrito_joints():lle – try-lohkon sisällä. Jos tietty poikkeustyyppi herää, kirjaat viestin, hoidat tilanteen ja jatkat eteenpäin.

Keskeinen ero on except-lauseke. Big Tarp -lauseen avulla periaatteessa pyydystät ja kirjaat kaikki mahdolliset poikkeukset. Pinpointilla pyydystät hyvin tietyn poikkeustyypin, jolla on semanttista merkitystä kyseisessä koodin kohdassa.

Huomaa myös, että käytän logger.warn() eikä logger.exception(). (Tässä artikkelissa aina kun näet warn(), voit korvata sen info() tai error() jne.) Toisin sanoen kirjaan viestin tietyllä vakavuudella sen sijaan, että kirjaisin koko pinojäljen.

Miksi heitän pinojäljen tiedot pois? Koska se ei ole yhtä hyödyllinen tässä yhteydessä, jossa pyydystän tietyn poikkeustyypin, jolla on selkeä merkitys koodin logiikassa. Esimerkiksi tässä pätkässä:

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"

Tässä KeyError ei ole mikä tahansa virhe. Kun se herää, se tarkoittaa, että on ilmennyt tietty tilanne – nimittäin, että hahmoluettelossani ei ole määritelty ”sidekick”-roolia, joten minun on turvauduttava oletusarvoon. Lokin täyttämisestä pinojäljityksellä ei ole hyötyä tällaisessa tilanteessa. Ja tässä kohtaa käytät Pinpointia.

Transformer-kuvio

Tässä otat kiinni poikkeuksen, kirjaat sen lokiin ja nostat sitten toisen poikkeuksen. Ensinnäkin, näin se toimii Python 3:ssa:

try: something()except SomeError as err: logger.warn("...") raise DifferentError() from err

Python 2:ssa sinun on pudotettava pois ”from err”:

try: something()except SomeError as err: logger.warn("...") raise DifferentError()

(Tällä osoittautuu olevan suuria seurauksia. Siitä lisää hetken kuluttua.) Haluat käyttää tätä mallia silloin, kun saatetaan herättää poikkeus, joka ei sovi hyvin sovelluksesi logiikkaan. Tämä tapahtuu usein kirjastorajojen ympärillä.

Kuvittele esimerkiksi, että käytät openburrito SDK:ta tappajasovellukseesi, jonka avulla ihmiset voivat löytää myöhäisillan burrito-paikkoja. find_burrito_joints()-funktio saattaa nostaa BurritoCriteriaConflict, jos olemme liian nirsoja. Tämä on SDK:n paljastama API, mutta se ei sopivasti vastaa sovelluksesi korkeamman tason logiikkaa. Paremmin koodin tähän kohtaan sopii määrittelemäsi poikkeus, jonka nimi on NoMatchingRestaurants.

Tässä tilanteessa sovellat mallia näin (Python 3:lle):

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

Tämä aiheuttaa yhden rivin tulosteen lokiisi ja laukaisee uuden poikkeuksen. Jos sitä ei koskaan saada kiinni, tuon poikkeuksen virhetuloste näyttää tältä:

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

Nyt tämä on mielenkiintoista. Tuloste sisältää NoMatchingRestaurants:n pinojäljen. Ja se raportoi myös aloittavan BurritoCriteriaConflict:n… täsmentäen selvästi, kumpi oli alkuperäinen.

Python 3:ssa poikkeuksia voi nyt ketjuttaa. raise ... from ...-syntaksi tarjoaa tämän. Kun sanot raise NoMatchingRestaurants(criteria) from err, se herättää poikkeuksen typeNoMatchingRestaurants. Tällä nostetulla poikkeuksella on attribuutti nimeltä __cause__, jonka arvo on aloittava poikkeus. Python 3 hyödyntää tätä sisäisesti ilmoittaessaan virhetietoja.

Miten tämä tehdään Python 2:ssa? No, et voi. Tämä on yksi niistä herkuista, jotka sinun täytyy vain päivittää saadaksesi. Python 2:ssa ”raise … from” -syntaksia ei tueta, joten poikkeustulosteesi sisältää vain NoMatchingRestaurants:n pinojäljen. Transformer-kuvio on tietenkin edelleen täysin käyttökelpoinen.

The ”Message and Raise” Pattern

Tässä kuviossa kirjaat, että poikkeus tapahtuu tietyssä kohdassa, mutta annat sen sitten levitä ja tulla käsitellyksi korkeammalla tasolla:

try: something()except SomeError: logger.warn("...") raise

Et varsinaisesti käsittele poikkeusta. Keskeytät vain tilapäisesti virran kirjaamaan tapahtuman. Teet näin silloin, kun sinulla on nimenomaan korkeamman tason käsittelijä virheelle ja haluat turvautua siihen, mutta haluat myös kirjata, että virhe tapahtui tai sen merkityksen tietyssä kohdassa koodia.

Tämä voi olla hyödyllisintä vianetsinnässä – kun saat poikkeuksen, mutta yrität ymmärtää paremmin kutsuvaa kontekstia. Voit välittää tämän lokilausekkeen antamaan hyödyllistä tietoa ja jopa ottaa sen turvallisesti käyttöön tuotannossa, jos haluat tarkkailla tuloksia realistisissa olosuhteissa.

The ”Cryptic Message” Antipattern

Nyt käännetään huomiomme joihinkin anti-patterneihin… asioihin, joita sinun ei pitäisi tehdä koodissasi.

try: something()except Exception: logger.error("...")

Esitettäisiin, että sinä tai joku tiimistäsi kirjoittaa tämän koodin, ja sitten kuuden kuukauden kuluttua huomaat hassun viestin lokissasi. Jotain sellaista kuin:

ERROR: something bad happened

Nyt toivon ja rukoilen, ettet näe sanoja ”jotain pahaa tapahtui” varsinaisessa lokissasi. Varsinainen lokiteksti, jonka näet, saattaa kuitenkin olla yhtä hämmentävä. Mitä teet seuraavaksi?

Noh, ensimmäiseksi on selvitettävä, missä kohtaa koodipohjaa tämä epämääräinen viesti lokitetaan. Jos olet onnekas, voit nopeasti grepata koodin läpi ja löytää täsmälleen yhden mahdollisuuden. Jos et ole onnekas, saatat löytää lokiviestin useista täysin eri koodipoluista. Mikä jättää sinulle useita kysymyksiä:

  • Mikä niistä laukaisee virheen?
  • Vai onko se useita niistä? Vai KAIKKI niistä?
  • Mikä kirjaus lokissa vastaa mitäkin kohtaa?

Joskus ei kuitenkaan ole edes mahdollista grepata tai etsiä koodin läpi löytääkseen paikan, jossa virhe tapahtuu, koska lokiteksti syntyy. Mieti:

 what = "something" quality = "bad" event = "happened" logger.error("%s %s %s", what, quality, event)

Miten tuota voisi edes etsiä? Et ehkä edes tule ajatelleeksi sitä, ellet ensin etsi koko lausetta etkä saa osumia. Ja jos saisitkin osuman, se voisi helposti olla väärä positiivinen tulos.

Ideaalinen ratkaisu on välittää exc_info-argumentti:

try: something()except Exception: logger.error("something bad happened", exc_info=True)

Kun teet näin, täysi pinojälki sisällytetään sovelluslokeihin. Tämä kertoo tarkalleen, mikä rivi missäkin tiedostossa aiheuttaa ongelman, kuka sitä kutsui ja niin edelleen… kaikki tiedot, joita tarvitset debuggauksen aloittamiseen.

Piruisin Python-antipattern

Jos joskus näen sinun tekevän tämän, tulen kotiisi takavarikoimaan tietokoneesi, murtaudun sitten github-tilillesi ja poistan kaikki reposi:

try: something()except Exception: pass

Kirjeessäni viittaan tähän nimellä ”Piruisin Python-antipattern”. Huomaa, kuinka tämä ei ainoastaan anna sinulle mitään hyödyllistä poikkeustietoa. Se onnistuu myös täysin piilottamaan sen, että jokin on ylipäätään pielessä. Et ehkä koskaan edes tiedä, että kirjoitit muuttujan nimen väärin – kyllä, tämä itse asiassa peittää NameErrorin – ennen kuin sinua kutsutaan kahdelta yöllä, koska tuotanto on rikki tavalla, jonka selvittäminen kestää aamuun asti, koska kaikki mahdollinen vianmääritystieto on tukahdutettu.

Älä vain tee sitä. Jos sinusta tuntuu, että sinun on yksinkertaisesti pakko ottaa kiinni ja sivuuttaa kaikki virheet, heitä ainakin iso pressu alle (eli käytä logger.exception() pass:n sijasta logger.exception()).

Lisää poikkeusten kirjaamismalleja

Pythonissa on paljon muitakin malleja poikkeustiedon kirjaamiseen, joilla on erilaiset kompromissit, hyvät ja huonot puolensa. Mitä kuvioita olet havainnut hyödyllisiksi, tai et? Kerro kaikille kommenteissa.

Opi lisää Python-loggauksen perusteista.

Logglyn ja SolarWindsin tavaramerkit, palvelumerkit ja logot ovat SolarWinds Worldwide, LLC:n tai sen tytäryhtiöiden yksinomaista omaisuutta. Kaikki muut tavaramerkit ovat omistajiensa omaisuutta.

Vastaa

Sähköpostiosoitettasi ei julkaista.