Loggstandard for Cerebrum

1   Kjapp skisse av loggingrammeverket

kode -> logger -> handler* <-> formatter

Loggere har navn, og settes opp i konfigurasjonsfil. Vi gjør da

Factory.get_logger(navn) i koden. I Cerebrum er navn logiske navn, f.eks. cronjob. I Java vil man f.eks. bruke klassenavn.

Loggeren sender meldingene videre til null til flere handlere, som igjen bruker formattere til å legge på timestamp osv. En handler kan gjøre alt fra lagre til fil, database, sende til ekstern logger, sende mail og mer.

2   Dagens praksis

Logging i Cerebrum gjøres i dag slik det har vært gjort lenge. Standardrammeverket for logging ble vel tatt i bruk før det ble innlemmet i Python. Vi har også lokale tilpasninger (se eget dokument).

Det meste av loggingen skjer med loggeren cronjob, som skriver loggen til en fil basert på filnavnet. En annen jobb, maillog_exception, leser gjennom loggen og sender advarsler og feil i drift i e-post.

Loggene brukes på forskjellige måter. F.eks. har drift en liste over loggmeldinger, og hva som skal gjøres med disse. (E.g. denne meldingen betyr sannsynligvis at x. Dette må fikses av y i system z, send mail til denne adressen.) I andre tilfeller vet man at noe er galt med A (f.eks. en person), og man må spore opp hendelser knyttet til A. Kanskje brukes også loggen til å forstå hva scriptet egentlig gjør.

3   Fremtiden?

Vi har sett noe av dette på utviklerforum. Eksempler som ble trukket frem var Logstash og Zabbix. Dette er verktøyer som kan lese inn loggfilene (eller man kan sikkert ha en egen handler for verktøyet), parser filene (med regexer ol. kan verktøyet lagre tiden på loggmeldingen, og man kan plukke ut annen info), og lager statistikk. Vi bør mao. lage loggmeldinger som er enkelt å behandle i slike verktøy.

4   Behov for drift

Drift ønsker at vi logger så mye som mulig. Her kan gjerne debug-nivåer brukes, slik at meldingene enkelt kan filtreres ut. Drift kan kjøre scriptet med høyere loggnivå når det trengs, eller man kan bruke en handler til en egen verbosfil som roteres ofte.

Når det gjelder format på loggene, er det hensiktsmessig at det er enkelt å kopiere fra logg til f.eks. bofh. Skriver man ut en entity-id, er det fint om den prefikses med «id:».

Drift hadde også forslag om at fødselsnummer stort sett ikke trenger logges. I de tilfeller det er naturlig å logge fødselsnummer, kan man logge på laveste nivå, slik at det normalt ikke skrives ut.

Det er også lurt å ha loggmeldinger som bekrefter state. Om feilen drift leter efter skyldes en obskur feil i filformatet, kan loggen bekrefte at filen er lest inn som forventet.

Drift har behov for mest mulig negativ informasjon: F.eks. hvorfor er ikke denne personen med i utplukket? Dette er ofte vanskelig å finne, da spørringer lages for å hente ut de som skal med. Men en utfordring å ta med seg.

5   Andre gode prinsipper

Det finnes en rekke verktøyer som kan «parse» loggmeldinger vha. regex. Loggmeldinger bør være søkbare. Det finnes en del nøkkelord som er lurt å forholde seg til, slik at man bruker samme ord om samme begrep (f.eks. user/account). Vi bør her forholde oss til de termer som er innarbeidet.

Normalt bør en loggmelding være på én linje. Dersom det blir for langt, kan efterfølgende linjer rykkes inn, eller man kan bruke flere logger-kall. Det første er nok likevel å anbefale.

Script som leser rader og itererer gjennom disse radene, bør logge for hver rad. Gjerne som første del av løkken. Dette gjør det enkelt å finne raden hvor scriptet feiler dersom det krasjer.

6   Levels

Bruk de ulike loggnivåene. Nivåene warning, error og critical er til for feil som skal fanges opp og håndteres. Det er litt opp til utvikleren å sette seg inn i hva som er slike feiltilstander. Andre feiltilstander logges som info.

Bruk nivået info til meldinger som alltid er greie å ha. Eks.

• Behandler person x i løkken
• Kobler til server example.com
• Viktig informasjon som er lest?
• …

Ekstra logging kan gjøres med debug-nivåene:

• trace (kaller funksjon f med argument x)
• kommer til å gjøre noe som kan slenge exc.
• har gjort noe som kan slenge exc.

Vi har flere undernivåer for debug. De laveste kan brukes for debugoutput under utvikling.

Forøvrig er endring av loggnivå noe vi raskt bør godkjenne hvis driftere kommer med patch.

7   Format/innhold

logger.info("…" % (x, y, z))
logger.info("…", x, y, z)