Praktyczna Java. Biblioteki do logowania

Logi aplikacji to jed­na z ważniejszych rzeczy w aplikacji, które nie przekłada­ją się bezpośred­nio na funkcjon­al­ność — w przy­pad­ku awarii, czy też po pros­tu bada­jąc ‘zdrowie’ aplikacji jest to pier­wsze miejsce, do którego najpraw­dopodob­niej sięg­niesz po infor­ma­c­je. Na rynku jest jed­nak kil­ka rozwiązań — dzisi­aj pomoże­my Ci świadomie wybrać jed­no z nich.

Wstęp teoretyczny

Z bib­liotek do logowa­nia wszyscy korzys­tamy — świadomie lub nie. Nawet jeśli nie uży­wamy ich bezpośred­nio, jest duża szansa, że któraś z bib­liotek w naszym pro­jek­cie to robi (np. Spring). Dlat­ego warto znać trochę teorii, która stoi ‘za’ tym konceptem.

Jak działa logger

Pod­sta­wową rolą bib­liote­ki do logowa­nia jest przekazanie komu­nikatu wygen­erowanego w kodzie (np. infor­ma­cji, że jakaś oper­ac­ja się powiodła) do odpowied­niego miejs­ca (np. stan­dar­d­owe wyjś­cie kon­soli, plik, ser­w­er zdal­ny), doda­jąc infor­ma­c­je o cza­sie, poziomie i ew kil­ka innych pomoc­niczych. To z pozoru banalne zadanie ma pewien ‘haczyk’ — najczęś­ciej logi trafi­a­ją do plików. Zapis do plików (i odczyt z nich) jest jed­nak ‘naj­droższą’ oper­acją, jaką moż­na wykon­ać w ramach jed­nego kom­put­era. Z tego powodu logowanie potenc­jal­nie (a cza­sem real­nie) znaczą­co spowal­nia naszą aplikację, o ile bib­liote­ka nie obsługu­je tego w ‘spry­t­ny’ sposób. Ten spry­t­ny sposób to tzw asyn­chron­iczność — sam zapis do pliku jest real­i­zowany w innym wątku, niż właś­ci­we zdarze­nie, dzię­ki czemu nie bloku­je go i aplikac­ja może dzi­ałać wyda­jnie. To z kolei generu­je dodatkowe prob­le­my (np. popraw­na obsłu­ga kole­jnoś­ci logowanych danych, zbieranie ich z różnych obszarów aplikacji itp). Na szczęś­cie więk­szość bib­liotek radzi sobie z tym prob­le­mem w sposób ‘przezroczysty’ dla użytkown­ików (pro­gramistów), co pozwala nam skupić się na właś­ci­wej aplikacji :)

Nazwa loggera i hierarchia loggerów

Wszys­tkie log­gery mają swo­ją nazwę, którą nada­je­my w momen­cie tworzenia obiek­tów — częs­to jest to nazwa klasy (peł­na, czyli razem z nazwą paki­etu). Wyni­ka to z fak­tu, że nazwa jest w log­ger­ach znaczą­ca i określa hier­ar­chię, wg której są one kon­fig­urowane. Dla przykładu, log­ger o nazwie ‘pl.kobietydokodu.koty.KotService’ należy do hier­ar­chii ‘pl’, ‘pl.kobietydokodu’, ale nie do ‘org.springframework’. Ponieważ dodatkowo dla każdej hier­ar­chii może­my stosować osob­ną kon­fig­u­rację, pozwala nam to na bard­zo dużą elastyczność.

Może­my np. przekierować do pliku tylko logi, ktore generu­je nasza aplikac­ja — dzię­ki temu nie będzie tam ‘śmieci’ z różnych frame­worków. Może­my też przekierować logi z różnych warstw aplikacji do różnych plików, część zig­norować, logować je na różnych poziomach z różną iloś­cią detali — taka struk­tu­ra daje po pros­tu ogrom możli­woś­ci w zakre­sie kon­fig­u­racji. Nie zmienia to fak­tu że najczęś­ciej logu­je się wszys­tko w jed­no miejsce — zaawan­sowana kon­fig­u­rac­ja jest przy­dat­na w aplikac­jach z ogrom­nym ruchem, które generu­ją np. wiele giga­ba­jtów logów dziennie.

Hier­ar­chia wynika­ją­ca z nazwy log­gera to główny powód, dla którego log­gery są twor­zone w konkret­nych obiek­tach osob­no, a nie np. wstrzyki­wane za pomocą kon­tenera IoC (np. Springa).

Poziomy logowania

Właś­ci­wie każ­da bib­liote­ka ofer­u­je różne tzw. poziomy logowa­nia. Poziom to nic innego jak ‘ważność’ danej wiado­moś­ci, częs­to uży­wanym sche­matem są opc­je: FATAL, ERROR, WARNING, INFO, DEBUG, TRACE w różnych wari­antach (np. brak poziomu FATAL czy TRACE). Niek­tóre bib­liote­ki pozwala­ją na defin­iowanie włas­nych poziomów (np. Log4J). W tym zakre­sie wyróż­nia się paki­et java.util.logging (omówiony poniżej), który defini­u­je zupełnie odmi­enne poziomy: SEVERE, WARNING, INFO, CONFIG, FINE, FINER, FINEST.

Poza infor­ma­cją w logu na tem­at poziomu (opcjon­al­nie, w zależnoś­ci od kon­fig­u­racji), uży­wany jest on także w kon­fig­u­racji — np. na środowisku pro­duk­cyjnym wyłącza­jąc wszys­tkie logi ‘niższe’ niż INFO. Dzię­ki temu nie trze­ba dodawać warunk­ów i tym­cza­sowych logów na czas rozwi­ja­nia lub debu­gowa­nia konkret­nego frag­men­tu kodu, wystar­czy skon­fig­urować odpowied­nio log­gery i poprawnie uży­wać poziomów.

Porównywanie

Ponieważ bib­liote­ki te real­izu­ją bard­zo specy­ficzną i względ­nie prostą funkcję, ciężko jest porówny­wać je ze wzglę­du na dostęp­ne funkc­je. Dlat­ego ograniczymy się pokaza­nia, jak utworzyć odpowied­nie obiek­ty w każdej z tych bib­liotek oraz wyp­isa­nia prob­lemów, z jaki­mi możesz się spotkać pracu­jąc z konkret­ny­mi bibliotekami.

Wybier­a­jąc rozwiązanie do Two­jego pro­jek­tu, zwróć uwagę przede wszys­tkim na to, czy będziesz musi­ała dokony­wać wielu zmi­an w aplikacji (oraz czy ew możesz je rozwiązać za pomocą Slf4J), czy któryś z prob­lemów może być przeszkodą w Twoim sys­temie oraz to, która jest najpop­u­larniejsza (co przekła­da się na najlep­szy sup­port społecznoś­ci) — w pod­sumowa­niu zna­jdziesz też naszą rekomen­dację w tym zakresie :)

Biblioteki logujące

Pier­wszą, liczniejszą, grupę stanow­ią bib­liote­ki logu­jące — czyli te, które obsługu­ją zapis komu­nikatów do pliku czy na kon­solę i odpowied­nią ich obsługę.

Java Logging API (java.util.logging; zwana też JUL)

Paki­et java.util.logging jest częś­cią Javy SE, aby go użyć nie jest konieczne dodawanie żad­nych depen­den­cy do pro­jek­tu. Paki­et ten zapew­nia bard­zo prosty ‘szkielet’, w którym więk­szość specy­ficznych ele­men­tów (np. inne for­ma­towanie, inte­grac­je z sys­te­mem zbiera­nia logów itp) musimy samodziel­nie zapro­gramować. W kwestii różnic pomiędzy tą bib­lioteką a inny­mi, JUL logu­je domyśl­nie na stan­dar­d­owe wyjś­cie błędów, pod­czas gdy częś­ciej logi zbier­amy ze stan­dar­d­owego wyjś­cia (zwykłego). Posi­a­da także niespo­tykane w innych imple­men­tac­jach poziomy logowa­nia (np. ‘CONFIG’, ‘FINE’, ‘FINER’, które zastępu­ją znane nam ‘DEBUG’).

Inicjowanie log­gera wyglą­da następująco:

protected final Logger log = Logger.getLogger(getClass().getName()); //java.util.logging.Logger

Z kolei jego użycie:

log.log(Level.INFO, "Przetwarzam {0} elementów", lista.size());

Zaletą jest niewąt­pli­wie możli­wość para­me­tryza­cji treś­ci loga oraz fakt, że jest wbu­dowany w Javę. Jest to jed­nak frame­work bard­zo prosty, cza­sem okreąlany wręcz nai­wnym w kwestii imple­men­tacji, i może przys­porzyć prob­lemów w więk­szych pro­jek­tach, które inten­sy­wnie korzys­ta­ją z loga. Jest też mało wygod­ny w uży­ciu — każdy log musimy poprzedz­ić enu­mem z poziomem logowa­nia —  inne bib­liote­ki zapew­ni­a­ją osob­ne metody, co jest czytel­niejsze. Raczej nieza­le­cany w pro­duk­cyjnych aplikacjach.

Log4J (strona projektu)

Log4J mimo upły­wu cza­su pozosta­je jed­ną z najpop­u­larniejszych bib­liotek do logowa­nia — całkiem słusznie, ponieważ jest naprawdę solid­ną imple­men­tacją z wielo­ma możli­woś­ci­a­mi. Obec­nie pro­jekt nie jest rozwi­jany, do wszel­kich nowych zas­tosowań zale­ca się uży­cie Log­back — bib­liote­ki twor­zonej przez te same oso­by, które pra­cow­ały przy Log4J.

Inic­jal­iza­c­ja log­gera wyglą­da następująco:

protected final Logger log = Logger.getLogger(getClass()); //org.apache.log4j.Logger;

Przykład jego uży­cia w kodzie:

log.error("Coś poszło nie tak : " + kodBledu);

Log4J nie zadzi­ała bez kon­fig­u­racji (tzn. będzie moż­na z niego korzys­tać, ale żadne infor­ma­c­je nie pojaw­ią się na kon­soli lub w pliku). Kon­fig­u­racji moż­na dokony­wać pro­gramowo, za pomocą pliku XML oraz za pomocą pliku .prop­er­ties, co jest najpop­u­larniejszą metodą. Przykład­owy plik kon­fig­u­racji (wiado­moś­ci na poziomie INFO, wyp­isy­wane tylko na kon­solę) wyglą­da następująco:

log4j.rootLogger=INFO, stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{yyyy-MM-dd HH:mm:ss} %-5p %c{1}:%L - %m%n

Sama bib­liote­ka w obec­nej wer­sji nie ma znanych prob­lemów, które były­by istot­nym prze­ci­wwskazaniem do jej stosowa­nia. Następ­ca, Log­back, uży­wa nieco innej architek­tu­ry i nowszych rozwiązań z API Javy, przez co jest wyda­jniejszy i bardziej elasty­czny. Migrac­ja z Log4J do Log­back nie musi być jed­nak pri­o­ry­tetem w projekcie.

Logback (strona projektu)

Log­back to następ­ca Log4J, rozwi­jany przez z grub­sza tą samą grupę osób. Zde­cy­dowano się na nową nazwę z uwa­gi na zmi­anę kon­cepcji — Log­back został napisany od nowa, w zupełnie inny sposób niż Log4J, przez co jest min­i­mal­nie szyb­szy i bardziej elasty­czny (szczegóły dlaczego warto go uży­wać zna­jdziesz w doku­men­tacji Log­back). Jed­ną ze zmi­an jest także fakt, że bez żad­nej kon­fig­u­racji przyj­mowana jest kon­fig­u­rac­ja domyśl­na — czyli wyp­isy­wanie wszys­t­kich logów na stan­dar­d­owe wyjś­cie konsoli.

Inicjowanie logera wyglą­da następująco:

protected final Logger log = LoggerFactory.getLogger(getClass());

Uwa­ga! W powyższym frag­men­cie inter­fe­jsy i klasy pochodzą z paki­etu org.slf4j ! Wyni­ka to z fak­tu, że Log­back bazu­je na Slf4j i nie defini­u­je włas­nych, dodatkowych iterfejsów!

Z kolei jego wywołanie:

log.debug("Wykonuje operację ABCDE");

Nie­s­tandar­d­ową kon­fig­u­rację moż­na zdefin­iować w plikach logback.xml oraz logback-test.xml (oba mają iden­ty­czną struk­turę), przykład­owa zawartość takiego pliku (zawartość pobrana z doku­men­tacji log­back):

<configuration>
 <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
 <!-- encoders are assigned the type
 ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
 <encoder>
 <pattern>%d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
 </encoder>
 </appender>
 <root level="debug">
 <appender-ref ref="STDOUT" />
 </root>
</configuration>

Log­back pozwala także na przekazanie ścież­ki do pliku kon­fig­u­ra­cyjnego jako zmi­en­ną sys­te­mową logback.configurationFile, co może być przy­datne, jeśli chce­my np. na ser­w­er­ach pro­duk­cyjnych logować w określony sposób, nieza­leżnie od ustaw­ień aplikacji.

tinylog (strona projektu)

Tiny­log to taka opc­ja ‘min­i­mum’ jeśli chodzi o logowanie — ideą twór­ców było to, że sko­ro więk­szość pro­jek­tów nie korzys­ta z zaawan­sowanych funkcji log­gerów, ich hier­ar­chii itp, to lep­iej stworzyć bib­liotekę, która będzie ich pozbaw­iona, a przez to będzie lże­jsza. Na stron­ie zna­jdziemy też porów­nanie wyda­jnoś­ci z inny­mi bib­lioteka­mi — jest ono oczy­wiś­cie prawdzi­we, ale należy mieć świado­mość, że wzrost wyda­jnoś­ci jest oku­pi­ony funkcjon­al­noś­cią i elasty­cznoś­cią. Bib­liote­ka ta nie wyma­ga tworzenia log­gera, wszys­tkie jej metody są staty­czne, przykład­owe uży­cie wyglą­da następująco:

Logger.info("Witaj świecie!");

Bib­liotekę moż­na kon­fig­urować za pomocą zmi­en­nych sys­te­mowych lub pro­gramowo, domyśl­nie wyp­isu­je ona wszys­tkie logi na poziomie info i wyższych na stan­dar­d­owe wyjś­cie konsoli.

Z naszej strony nie pole­camy za bard­zo takiego pode­jś­cia — elasty­czność, jaką dają inne narzędzia jest zde­cy­dowanie warta ich potenc­jal­nego kosz­tu w kwestii wyda­jnoś­ci, szczegól­nie w przy­pad­ku pro­jek­tów, które się rozwi­ja­ją lub musza być utrzymy­wane. Teo­re­ty­cznie posi­a­da ona inte­grację z slf4j, ale korzys­ta­jąc z niej w ten sposób tracimy ‘min­i­mal­izm’, w który ta bib­liote­ka celu­je (i równie dobrze moż­na wyko­rzys­tać Log­back, który także zadzi­ała w podob­ny sposób bez konfiguracji)
W niek­tórych zas­tosowa­ni­ach jed­nak będzie ona miała sens, w szczegól­noś­ci w sys­temach wbu­dowanych czy innych z bard­zo ogranic­zony­mi zasoba­mi, dlat­ego zamieszcza­my ją w tym porów­na­niu — bardziej jako cieka­wostkę, z dużym ostrzeżeniem.

Abstrakcje

W tej kat­e­gorii mamy trochę mniej reprezen­tan­tów — bib­liote­ka te nie zaj­mu­ją się właś­ci­wym logowaniem, a dostar­cze­niem wspól­nego inter­fe­j­su dla różnych bib­liotek logu­ją­cych. Dzię­ki temu zabiegowi, moż­na właś­ci­wie dowol­nie ‘wymieni­ać’ bib­liote­ki logu­jące bez zmi­any lin­ij­ki kodu. Slf4j ma też kil­ka asów w rękaw­ie, o czym powiemy za chwilę.

Slf4j (strona projektu)

Slf4j to najpop­u­larniejsza obec­nie abstrakc­ja, która jest uży­wana w 40–70% pro­jek­tów (w zależnoś­ci od źródła, w które spo­jrzymy). Pow­stała jako bezpośred­nia odpowiedź na prob­le­my z Apache Com­mons Log­ging i jest rozwi­jana przez devel­op­erów związanych z pro­jek­tem Log­back (stanowi ona też pod­stawę tej bib­liote­ki). Z uwa­gi na prostą i wygod­ną obsługę, licencję pozwala­jącą na dowolne wyko­rzys­tanie, właś­ci­wie bezprob­le­mowe dzi­ałanie i pełną dowol­ność w zakre­sie bib­liote­ki uży­wanej ‘pod spo­dem’ Slf4J właś­ci­wie nie ma obec­nie alter­natyw — nie ist­nieje powszech­ny prob­lem z tą bib­lioteką, który nowa bib­liote­ka miała­by rozwiązać ;)

Inicjowanie log­gera wyglą­da następująco:

protected final Logger log = LoggerFactory.getLogger(getClass());

A jego użycie:

log.info("Witaj świecie!");

Gorą­co rekomen­du­je­my uży­wanie Slf4j jako fasady do logowa­nia w Two­jej aplikacji — poniżej zna­jdziesz kil­ka przykładów jak moż­na ją wyko­rzys­tać w pełni.

Korzyści

Szablony

Aby rozwiązać częsty prob­lem (patrz poniżej, w sekcji o anty­w­zor­cu) Slf4J wprowadz­ił szablony — inny­mi słowy zami­ast samemu budować wiado­mość (która potenc­jal­nie może nie zostać nigdzie wyświ­et­lona, a przy okazji tworzenia wywołu­je metody toString() różnych obiek­tów, które z kolei mogą być kosz­towne do wywoła­nia), mówimy Slf4J jak ma to zro­bić, i robi to za nas! Przykładowo:

log.debug("Duży i skomplikowany obiekt: {} wysłany przez użytkownika {}", duzyObiekt, obiektUzytkownika)

zamieni ‘{}’ na kole­jne argu­men­ty przekazane do metody, ale zro­bi to tylko jeśli będzie to fak­ty­cznie potrzeb­ne (tzn. jeśli wiado­moś­ci na tym poziomie są fak­ty­cznie logowane). Dzię­ki temu­nie musimy się martwić o dodatkowe warun­ki i wyda­jność — bib­liote­ka załatwi to za nas.

Adaptery do innych API

Kole­jną bard­zo przy­dat­ną funkcją są adaptery do innych API. Jeśli Two­ja aplikac­ja korzys­ta już np. z Apache Com­mons Log­ging, nie musisz przepisy­wać całego kodu! Slf4J dostar­cza mod­uł, który ‘uda­je’ inną bib­liotekę (w tym przy­pad­kuy będzie to Apache Com­mons Log­ging) i przekierowu­je wszys­tkie wywoła­nia do Slf4J — dzię­ki temu bez zmi­any lin­ij­ki kodu możesz wyko­rzys­tać wszys­tkie zale­ty w potenc­jal­nie dowol­nej aplikacji!

Inne

Slf4J ma wielu zwolen­ników, z których każdy poda kil­ka kole­jnych powodów, dla którego warto użyć właśnie tej bib­liote­ki. Zain­tere­sowanych odsyłamy np. do dyskusji na stack­over­flow.

JCL  (Jakarta Commons Logging / Apache Commons Logging; strona projektu)

Apache Com­mons Log­ging to pier­wsza więk­sza pró­ba stworzenia wspól­nej fasady dla różnych bib­liotek. Z uwa­gi na sposób imple­men­tacji wys­tępowały z nią noto­ryczne prob­le­my (patrz poniżej), przez co została w więk­szoś­ci pro­jek­tów porzu­cona na korzyść Slf4J.

Inicjowanie log­gera wyglą­da następująco:

protected final Log log = LogFactory.getLog(getClass());

A jego użycie:

log.info("Witaj świecie!");

JCL sam w sobie nie ofer­ował żad­nych dodatkowych funkcjon­al­noś­ci, co także przy­czyniło się do spad­ku jego pop­u­larnoś­ci na korzyść Slf4J.

Problemy

Głównym prob­le­mem trapią­cym JCL jest sposób ‘ład­owa­nia’ bib­liotek, z których korzys­ta do fak­ty­cznego logowa­nia. W imple­men­tacji zde­cy­dowano się na sposób z uży­ciem class­load­erów, co w więk­szych pro­jek­tach, z dynam­iczny­mi mod­uła­mi, zaczęło gen­erować prob­le­my i negaty­wnie wpły­wało na wyda­jność. Zain­tere­sowanych odsyłamy do szer­szego i bardziej tech­nicznego opisu na stron­ie http://articles.qos.ch/classloader.html, a my ograniczymy się do powiedzenia, że Slf4J korzys­ta z innych sposobów, dzię­ki czemu opisy­wane prob­le­my go nie dotyczą.

Dobre praktyki

Jeśli chodzi o logowanie, warto zaw­cza­su pomyśleć o tym, aby zro­bić to dobrze — dzię­ki temu w przyszłoś­ci unikniesz wielu prob­lemów anal­izu­jąc treść logów w poszuki­wa­niu źródła problemu.

Loggery jako pola statyczne vs pola obiektu

Więk­szość bib­liotek pozwala uży­wać klasy, jako nazwy twor­zonego log­gera. Częstą prak­tyką jest tworze­nie pola staty­cznego, w którym nazwą log­gera jest nazwa klasy.

Powodu­je to pewien prob­lem przy dziedz­icze­niu — klasy dziedz­iczące po danej klasie, o ile nie zadeklaru­ją włas­nego log­gera, będą korzys­tały z log­gera utwor­zonego w klasie nadrzęd­nej, a więc także o nazwie takiej, jak klasa nadrzęd­na. Z tego powodu ciężko będzie odróżnić jedne wpisy od drugich.

Rozwiązaniem jest tworze­nie log­gerów jako pól obiek­tu, a nie staty­cznych, oraz uży­wanie get­Class() zami­ast szty­wno wpisanej nazwy klasy. Dzię­ki temu log­gery będą zawsze wskazy­wały praw­idłową nazwę (pode­jś­cie to jest stosowane w przykładach powyżej).

Krótką dyskusję zna­jdziesz w tym wątku na Stack Over­flow. Ogól­nie ujmu­jąc — uży­cie pól obiek­ty (a nie staty­cznych) jest bardziej intu­icyjne w przy­pad­ku dziedz­iczenia, choć pole staty­czne bardziej odpowia­da idei log­gerów (jeden wspól­ny, współdzielony przez wiele instancji).

Logowanie wybranych informacji, a nie całych obiektów

Dość częstą prak­tyką jest logowanie całych obiek­tów zami­ast wybranych infor­ma­cji — przykład­owo tworze­nie użytkown­i­ka powodu­je zapisanie infor­ma­cji do logu ze wszys­tki­mi szczegóła­mi (wywołu­jąc metodę toString() obiek­tu). Ma to dwie potenc­jalne kon­sek­wenc­je: po pier­wsze, obję­tość logu rośnie dra­maty­cznie, szczegól­nie w przy­pad­ku kom­plek­sowych obiek­tów z wielo­ma pozioma­mi zag­nieżdże­nia; po drugie rodzi to potenc­jalne ryzyko wycieku poufnych infor­ma­cji (np. skró­tu hasła, adresu zamieszka­nia itp) — z założe­nia logi aplikacji są gorzej chro­nione niż np. baza danych. W rzeczy­wis­toś­ci w logu wystar­cza­ją­ca jest infor­ma­c­ja, że został utwor­zony użytkown­ik o loginie xyz oraz id 123 — w razie potrze­by wszys­tkie dodatkowe infor­ma­c­je moż­na pobrać z bazy danych. Czytel­ność tego typu logu jest także znaczą­co więk­sza, co przyspiesza anal­izę prob­lemów i ich rozwiązywanie.

Wytyczne dotyczące polityki logowania w projekcie

Podob­nie jak w wielu innych aspek­tach pro­jek­tu, jed­nym z najważniejszych celów zespołu powin­na być spójność — w tym wypad­ku logowanie tego samego rodza­ju infor­ma­cji w ten sam sposób (na tym samym poziomie) w tym samym miejs­cu (mod­ule). Poli­ty­ka logowa­nia może być wspól­na dla całej firmy lub specy­ficz­na dla danego pro­jek­tu czy nawet mod­ułu pro­jek­tu ( o ile jest on samodziel­ną aplikacją / sys­te­mem), i powin­na zaw­ier­ać wytyczne:

• co będzie logowane i na każdym poziomie (jakie zdarzenia są na tyle intere­su­jące, aby je logować na danym poziomie)
• jakie infor­ma­c­je mogą trafić do logu (najczęś­ciej jest to ID oraz nazwa wyświ­et­lana; ważne, żeby infor­ma­c­je te pozwalały odnaleźć kom­plet infor­ma­cji w bazie danych, ale jed­nocześnie nie stanow­iły ryzy­ka wycieku wrażli­wych informacji)
• jak będą nazy­wane log­gery (czy od nazwy klas, czy może w inny sposób)
• gdzie będą prze­chowywane logi i przez jaki okres czasu
• gdzie będą emi­towane logi (w której warst­wie aplikacji)

Zanied­ban­ie poli­ty­ki logowa­nia może prowadz­ić do sytu­acji, w której pewne zdarzenia będą logowane wielokrot­nie, pod­czas gdy inne będą pomi­jane; może dojść do wycieku danych poprzez prze­ję­cie logów lub kluc­zowe dla rozwiąza­nia prob­le­mu infor­ma­c­je mogły zostać przed­w­cześnie ska­sowane lub nie wiado­mo, gdzie ich szukać. Poli­ty­ka logowa­nia może przynieść korzyś­ci w każdego rozmi­aru pro­jek­cie i nie musi to być coś, co wyma­ga długich doku­men­tów — najprost­sza wer­s­ja będzie zaw­ier­ała tylko kil­ka punk­tów, np:

• wszys­tkie logi nie będące opisem błędu/wyjątku są emi­towane w warst­wie serwisów
• każdy log może zaw­ier­ać tylko id obiek­tu oraz jego nazwę wyświ­et­laną (o ile nie zaw­iera ona danych wrażliwych)
• poszczególne poziomy logowa­nia i ich znaczenie: 
  • fatal — błędy kry­ty­czne, nieob­służone i bloku­jące dzi­ałanie sys­te­mu / procesu
  • error — błędy, które są obsługi­wane i bloku­ją tylko kreśloną część procesu/wycinek funkcjonalności
  • warn — błędy, które są obsłużone, a ich wpływ na pro­ces został zni­welowany (np. poprzez ponowie­nie czynności)
  • info — infor­ma­c­je do audy­tu, zakończe­nie real­iza­cji ważnego procesu
  • debug — infor­ma­c­je devel­op­er­skie, np. pełne obiek­ty zami­ast samych id (patrz: sekc­ja o pod­wójnych logach)

Te proste reguły wystar­czą, aby znacznie polep­szyć czytel­ność logów w pro­jek­cie i usprawnić ich analizę.

Podwójne logi, na różnych poziomach

Logi aplikacji powin­ny być zarazem pełne (infor­mować o wszys­t­kich ważnych zdarzeni­ach, pozwala­jąc na ich odt­worze­nie), jak i czytelne (możli­wie zwięzłe, zachowu­jąc możli­wość man­u­al­nej i pro­gramowej anal­izy). Niełatwe jest logowanie w zgodzie z obiema tymi zasada­mi, ale jest na to rada — pod­wójne logi.

Idea jest dość pros­ta — logu­je­my tylko najważniejsze infor­ma­c­je na poziomie info (np. “Zamówie­nie 1234 zostało utwor­zone”), a na poziomie debug jed­nocześnie logu­je­my wszys­tkie detale. Logi te mogą trafi­ać w jed­no miejsce (np. na kon­sole, z założe­niem, że są one uży­wane tylko pod­czas roz­wo­ju aplikacji) lub może­my mieć np. dwa pli­ki logów — jeden logu­ją­cy ‘wszys­tko’ (wraz z komu­nikata­mi na poziomie debug), oraz dru­gi logu­ją­cy tylko ‘ważne’ rzeczy (np. na poziomie info lub warn­ing). Anal­ize moż­na wtedy rozpocząć od tego ‘którszego’ logu, po czym zna­j­du­jąc intere­su­jące nas ele­men­ty odnaleźć odpowiada­jące im frag­men­ty w ‘pełnym’ logu wraz z kom­pletem informacji.

To pode­jś­cie  wyma­ga jed­nak uwa­gi — należy zwró­cić szczegól­ną uwagę, aby do logów nie trafiły dane wrażli­we — grozi to wyciekiem danych, jeśli na środowisku pro­duk­cyjnym przy­pad­kowo będziemy zapisy­wali także te logi z pełny­mi informacjami.

Antywzorzec if ( logger.isXXXEnabled() )

W pro­jek­tach korzys­ta­ją­cych bezpośred­nio z log4j czy JUL częs­to może­my spotkać poniższe ‘kosz­mar­ki’:

if (log.isDebugEnabled()) {
    log.debug("Jakieś info o obiekcie: " + obiekt);
}

Wynika­ją one z prostego prob­le­mu — nawet, jeśli poziom debug jest nieak­ty­wny, bez warunku if dookoła wywołana zostanie meto­da toString() obiek­tu, która może być kosz­tow­na (pod wzglę­dem cza­sowym lub pamię­ciowym). Poza fak­tem, że kod ten wyglą­da trag­icznie i jest praw­ie nietestowal­ny, częs­to pro­gramiś­ci bez zas­tanowienia wstaw­ia­ją te kon­strukc­je nawet, jeśli logowany jest prosty ciąg znaków (z niewiedzy lub lenist­wa i tumiwisizmu).

Lep­szym pode­jś­ciem jest uży­cie abstrakcji, np. Slf4J i wyko­rzys­tanie szablonów — dzię­ki temu meto­da toString zostanie wywołana tylko i wyłącznie kiedy będzie taka potrze­ba. Powyższy kod z uży­ciem Slf4J wyglą­dał­by następująco:

log.debug("Jakieś info o obiekcie: {}", obiekt);

Lombok

Pamię­taj, że każdy z tych log­gerów ma odpowied­nią adno­tację w Lom­boku (jeśli nie wiesz co to jest, zachę­camy do zapoz­na­nia się z naszym krótkim tuto­ri­alem). Dzię­ki temu nie będziesz musi­ała pamię­tać, jak inicjować dany logger!

Podsumowanie

Pisząc aplikację staraj się nie uza­leż­ni­ać kodu od konkret­nej imple­men­tacji / wybranej bib­liote­ki. Właśnie dlat­ego zachę­camy do korzys­ta­nia z abstrakcji takich jak Slf4j — zapew­ni­a­ją one spójne API dla różnych bib­liotek, zarówno obec­nych, jak i potenc­jal­nie tych, które pow­staną w przyszłoś­ci. Dzię­ki temu w sytu­acji, kiedy będziesz potrze­bowała funkcji z innej niż uży­wana doty­chczas bib­liote­ki do logowa­nia, Twój kod się nie zmieni — zmieni się jedynie kon­fig­u­rac­ja (a najpraw­dopodob­niej tylko zależność).