Jak pracovat s logovací knihovnou

Tento zápisek se krátce věnuje logovacím knihovnám v Javě a práci s nimi – konkrétně commons-logging a log4j.

Logovací knihovna

Ve svých projektech používám dvojici knihoven commons-logging a log4j. První jmenovaná je velmi jednoduchá (což vidím jako výhodu), sama o sobě loguje snad jen jen na standardní a chybový výstup a obvykle se použije jen jako fasáda pro jinou knihovnu. Pro tyto účely pak často používám log4j – de facto standard pro logování (už nejen pro Javu). Výhoda tohoto řešení je zřejmá – log4j je možno kdykoliv nahradit jinou knihovnou dle požadavků zákazníka a podobně.

Nastavení je jednoduché – po přidání knihoven do projektu stačí mít v CLASSPATH soubory commons-logging.properties a log4j.properties. V prvním souboru pouze definujeme, že chceme logovat přes knihovnu log4j.

# Commons Logging configuration
org.apache.commons.logging.Log=org.apache.commons.logging.impl.Log4JLogger

Knihovna Commons Logging se ale chová chytře a vlastně tento soubor vůbec není potřeba – pokud najde v CLASSPATH log4j, loguje tam. Pakliže zjistí, že jede na JRE 1.4 nebo vyšší, použije logger z JRE. A ve chvíli, kdy není ani jedna podmínka splněna, loguje na standardní výstup vlastními prostředky. Já soubor uvádím ale explicitně. Hodnotu org.apache.commons.logging.Log lze nastavit také proměnnou – následující ukázka je přímo z kódu (můžete použít i java proměnnou -D).

static {
  System.getProperties().setProperty("org.apache.commons.logging.Log",
     "org.apache.commons.logging.impl.Log4JLogger");
}

Nastavení log4j je podobné, bližší informace podá dokumentace.

# log4j properties
log4j.rootLogger=WARN, A1
log4j.appender.A1=org.apache.log4j.ConsoleAppender
log4j.appender.A1.Target=System.out
log4j.appender.A1.layout=org.apache.log4j.PatternLayout
log4j.appender.A1.layout.ConversionPattern=%-5p %C{1}: %m [%t] %x%n

Nyní lze použít knihovnu commons-logging pro logování, vše bude dostávat knihovna log4j, která zprávy zpracuje dle daného nastavení.

Něco málo o výjimkách

O výjimkách v jazyce Java toho bylo napsáno mnoho, takže nebudu opisovat již napsané. Zachycují vyjímečný stav programu, takže by neměly být zneužívány jako nosiče dat, logiky či jako berličky – to je myslím jasné.

Někteří programátoři navyklí na jazyk C (nebo jiné imperativní jazyky) občas provádějí toto:

MyObject = myMethod(param1, param2);
if (myObject == null) {
	// something is wrong
}

Toto je jasný případ zbytečného testování návratových hodnot. Kdykoli je to možné, použijte pro chybný stav výjimku. Ještě než budu pokračovat, tak musím uvést, že testovat na null není ve své podstatě nic špatného – pakliže nemáte jinou možnost (nejste autorem knihovny, kterou používáte – například), tak holt testovat musíte. Jinak bychom mohli dostat NPE.

Zpátky k příkladu – v tomto případě by tedy měla metoda myMethod vyhazovat výjimku a v kódu místo ifu by měl být použit try blok.

try {
	myObject = myMethod(param1, param2);
} catch (MyException e) {
	// something is wrong
}

Velmi často se programátoři zdráhají tvořit vlastní výjimky. V nejhorším případě se přikloní k výše uvedenému testování návratových hodnot, v lepším použijí nějakou standardní výjimku Javy – a bohužel v některých případech vyberou nevhodného kandidáta. Ačkoli je to věc vkusu, už před časem jsem se věnoval problému NPE.

Je výhodné tvořit vlastní sadu výjimek a v místech, kde je to potřeba, výjimky vyhazovat (do cause ukládáme příčinu – vnořenou výjimku). Dnešní programovací prostředí nabízejí komfort, vytvoření potomka z třídy je otázkou pár sekund. Je vhodné zapřemýšlet, jakou hiearchii vlastních výjimek vytvořit – u jednoduššího projektu nebude vůbec na škodu mít jen jednu uživatelskou výjimku.

Jakmile máme jednu nebo více uživatelských výjimek (vždy je dobré mít jednu kořenovou výjimku – jednoho rodiče), je nutné přemýšlet o tom, kde uživatelské výjimky odchytnout a zpracovat.

U konzolové aplikace to může být až třeba metoda main, která provede případné logování pomocí commons-logging nebo log4j. Je výhodné odchytávat uživatelské výjimky na jednom (nebo „konečném počtu“) místě. Příkad:

try {
  worker.work();
} catch (ConvertorException e) {
  System.err.println("Error while converting: " + e.getMessage());
  // report exception only if debug (or trace) enabled
  if (log.isDebugEnabled()) {
    log.fatal("Error while converting, conversion has not finished properly", e);
  } else {
    log.fatal("Error while converting, conversion has not finished properly");
  }
}

Toto je typická ukázka zpracování uživatelské výjimky ConvertorException, která je zároveň rodičem všech uživatelských výjimek v programu. Na konzoli do chybového výstupu vypiše patřičnou hlášku plus detailnější popis výjimky (pomocí getMessage). Poté zaloguje pomocí logovacího subsystému detailnější popis a v případě, že je aktivován DEBUG, tak vkládá i stacktrace. Výpisy zásobníku nemusejí být vhodné, pakliže se jedná o něco nezávažného (jako například FileNotFoundExceptioin) – mohou být kdykoli aktivovány (v tomto případě konzolové aplikace pomocí parametrů -debug nebo -trace).

Podobně se řeší programy s uživatelským rozhraním. Obvykle je vhodné připravit nějaký speciální chybový dialog, který po klepnutí na tlačítko „Detaily“ zobrazí kromě hlášky také stacktrace.

Úrovně výjimek

Úroveň pro CLÚroveň pro log4jPopis
TRACETRACENejnižší úroveň, obvykle vypisujeme pouze do souboru. Vhodné pro různé check-pointy (metoda zavolána, různé počítadla pro ladící účely). Tato úroveň může obsahovat mnoho zpráv, často je programátory nevyužívána a je psáno zbytečně mnoho informací do úrovně DEBUG.
DEBUGDEBUGLadící hlášky, které pomáhají zákazníkovi identifikovat prvotní problém, případně vytvořit report pro dodavatele, aby mohl chybu opravit. V DEBUG by nemělo být příliš hlášek, ale zároveň by tato úroveň měla poskytovat dostatek informací k tomu, aby mohlo být zpětně zjištěno, v čem je problém.
INFOINFOHlášky INFO obvykle nejsou vypisovány ve standardní instalaci, ale zákazník si může zvýšit vypisování z WARN na INFO a měl by vidět o něco více informací. Hlášky INFO jsou vhodné zejména pro různé informační zprávy typu něco se startuje, server znovu načetl konfiguraci nebo že aplikace načítá soubor z disku.
WARNWARNTato úroveň by měla být zapnuta v implicitní instalaci softwaru, program informuje o události, která není obvyklá. Příklad – potřebná konfigurační hodnota nebyla nalezena v konfiguraci, program použije defaultní hodnotu. Je vždy dobré se zamyslet, jestli daná je daná hláška chybou (ERROR), varováním (WARN) nebo dokonce pouze informativního charakteru (INFO).
ERRORERRORV aplikaci došlo k chybovému stavu, který však nenaruší běh programu. Typicky například nemohl být zpracován požadavek na serveru kvůli špatné konfiguraci nebo třeba chyba vstupních dat – program neprovede svoji činnost, ale čeká na další (validní) vstup.
FATALFATALDošlo k vyjímečnému stavu a program ukončuje svoji činnost. Například soubor nebyl vůbec nalezen, chyba v programu nebo došla paměť.

Konfigurace úrovní je možné dělat pomocí properties souborů (v případě například serverových aplikací), nebo přímo z programu (nastavení, přepínače) v případě klientských aplikací.

Jak psát hlášky

Všechny metody pro logování (fatal, error, warn, info, debug, trace) přijímají řetězec a některé i výjimku, která způsobila vlastní hlášení. Vždy je nutné napsat jednou větou, v čem může být problém.

Někteří programátoři popíšou chybu (např. „Soubor nenalezen“), to je ale špatně. Taková informace je uživateli k ničemu, je potřeba popsat příčinu chyby – tedy proč k tomu došlo, resp. co program dělal, když k výjimce došlo. Snažíme se popsat příčinu, nikoliv chybu samotnou!

Než hlášku napíšete, podívejte se v kódu do try bloku a na výjimku, kterou zachycujeme. Zamyslete se nad tím, když výjimka nastane, jakou informaci případný řešitel potřebuje. Na konci nepíšeme žádnou interpunkci (tečku, dvojtečku). Správné popisy jsou:

log.info("Starting server");
log.error("Cannot read configuration file " + filename, exception);
log.fatal("Too many open connections, increase the OCL variable");

Špatné popisky:

log.error("File not found", exception);
log.error("Error occured in program", exception);
log.fatal("Program error: ", exception);

Dobrou praxí je také všechny chybové hlášky načítat z property souboru a navíc v nich ukládat i chybové kódy. Pomůže to lépe identifikovat místa v kódu a lépe provázat s dokumentací. Příklad:

# error messages
XYERR01=XYERR01: The selected option is not available in this mode
XYERR02=XYERR02: File %s not found in path

Všimněte si, že chybové kódy jsou ještě jednou zopakovány také v textu výjimky a vypíší se zároveň s textem chyby. Je dobré vytvořit si na to vlastní implementace výjimek, které se o načítání a správné zobrazování postarají.

Tento můj dokument neberte jako dogma, je to jen sběr mých dosavadních zkušeností. Budu rád, když se o názory podělíte v diskusi.

Odkazy

Diskuze

Jira, 21.03.2008 13:18:

Protože commons-logging způsobuje poměrně zásadní problém v běhu aplikace (způsobený classloaderem - bliže viz. http://www.qos.ch/logging/classloader.jsp) je vhodnější použít knihovnu SLF4J (http://www.slf4j.org/), která logovací framework volí staticky (přidáním patřičného JARu na class path).

 
huuu, 21.03.2008 13:54:

okrem toho ma SLF4J vyhodu ze eliminuje 'skvele' logovacie zapisy typu: log.debug(„foo: “ + foo + “ huu: “ + huu); na log.debug(„foo: {} huu: {}“, foo, huu);

 
Lukáš Zapletal, 21.03.2008 15:47:

U tak jednoduché knihovničky by člověk tak dalekosáhlé problémy nečekal. O tom jsem nevěděl. Ten statický způsob mi připadá opravdu jednodušší a přímočařejší.

 
Robert Novotny, 22.03.2008 15:14:

Ono kdesi bol pekny clanok o tom, ze commons-logging vznikla ako pomocna logovacia medzivrstva do akehosi Apache Projektu a nik necakal, ze sa toho vsetci chytia a zacnu ju masovo pouzivat. Myslim, ze aj autor sa vyjadril, ze povodne nebola stavana na situacie, v ktorych sa pouziva a preto vznikaju tie problemy.

Niektore projekty zacali pomaly migrovat na SLF4J (Wicket, Tapestry), ale otazka je, co bude s tymi najdolezitejsimi (Spring je nejasny, Hibernate planuje migraciu v 3.3)

 
Lukáš Zapletal, 25.03.2008 08:29:

To je divné, když ji umístili do commons poolu, tak to přeci museli čekat

 
Lukáš Vlček, 26.03.2008 20:32:

Něco málo jsem o tom napsal zde: http://blog.lukas-vlcek.com/2007/05/jakarta-commons-logging-and-slf4j.html najdeš tam linky, kde je problém popsaný a nějaké informace od autora commons-logging. Další článek je tady: http://blog.lukas-vlcek.com/2007/09/switching-from-log4j-to-slf4j.html zde už přímo popisuji zkušenosti z přechodem z commons-logging a log4j na slf4j.

Hodně zdaru… Lukáš

 
Lukáš Zapletal, 28.03.2008 11:13:

Díky moc za info!

 
If you can't read the letters on the image, download this .wav file to get them read to you.
pridej.cz
blog/jak_pracovat_s_logovaci_knihovnou.txt · Poslední úprava: 29.05.2008 09:04 (external edit)
Creative Commons License Valid CSS Driven by DokuWiki Recent changes RSS feed Valid XHTML 1.0