log4net vs nLog

Kolejny raz o logowaniu… "bo to naprawdę ważne™" :).

W świecie .NET mamy dwie liczące się biblioteki oferujące logowanie informacji z aplikacji: log4net oraz nLog. Oczywiście znajdą się też inne rozwiązania: od koszmarnych (The Logging Application Block z EntLiba) po głupie (pisanie własnego loggera i jego produkcyjne wykorzystanie).

Z tych dwóch zdecydowanie bardziej popularny jest log4net. I ja także od niego zacząłem. Gdy po raz pierwszy zobaczyłem możliwości tej biblioteki to dosłownie szczena mi opadła wbijając spację w biurko. Wcześniej mieliśmy w projekcie Logging Application Block, a po podmianie konsola naszego CallCenter zaczęła czarodziejsko mienić się wszelkimi kolorami tęczy. Każda informacja była wreszcie prezentowana w taki sposób, w jaki chciałem ją widzieć. A do tego doszły zmiany konfiguracji loggera w locie, bez restartowania aplikacji – wystarczy edytować i zapisać plik XML! Cudo-niewido. Teraz się z tym już obyłem, ale na początku naprawdę gały miałem rozpostarte na oścież i napatrzeć się na logi nie mogłem. Właściwie dopiero wtedy logowanie czegokolwiek nabrało sensu.

W którymś kolejnym projekcie postanowiłem (o czym zresztą pisałem) zobaczyć co oferuje konkurent. I… do log4neta już nie wróciłem. W każdym kolejnym nowym projekcie umieszczam bez zastanowienia nLog.

Temat ten wyskoczył podczas kilku rozmów z fellow-devs i zawsze dostawałem pytanie: dlaczego nLog jest lepszy? Pytanie jak najbardziej na miejscu i tutaj postaram się na nie odpowiedzieć.

Zacznę jednak od stwierdzenia trochę sprzecznego: nLog bynajmniej nie jest lepszy. Po prostu dla mnie osobiście korzysta się z niego wygodniej. Możliwości obu są ogromne i bardzo do siebie zbliżone, więc diabeł tkwi w szczegółach. Jakby nie miał gdzie tkwić. Co zatem powoduje, że wybieram nLog?

Deklaracja loggera

Nie uznaję czegoś takiego jak wstrzykiwanie loggera przez DI czy pisanie własnej abstrakcji nad zewnętrzną biblioteką. Jest to sztuka dla sztuki i nie ma żadnego sensu (jeśli ktoś uważa inaczej to chętnie poznam argumenty). W każdej klasie, która chce coś zalogować, deklaruję statyczne pole loggera i tyle. Loggery mogą mieć swoje nazwy, która to cecha niesie za sobą wiele korzyści. Jeśli nazwiemy logger tak jak typ, który go zawiera, będziemy mogli z poziomu konfiguracji sterować logami na BARDZO szczegółowym poziomie. Np: niech wszystkie logi z klasy A zapisują się do tego pliku, logi powyżej poziomu DEBUG z całej aplikacji zapiszmy do pliku innego, natomiast wszystkie błędy z przestrzeni nazw BBB.CCC dodatkowo wysyłajmy na maila. To jest MOC!

I tutaj natrafiamy na pierwsze udogodnienie w nLogu, ponieważ wystarczy coś takiego:

  1:  private static readonly Logger _log = LogManager.GetCurrentClassLogger();

Z kolei dla log4net instrukcja ta będzie wyglądać tak

  1:  private static readonly ILog _log = LogManager.GetLogger(typeof ([current_class]));

Niby nic wielkiego, bo można samemu dopisać metodę przejeżdżającą się po stosie wywołań tak jak robi to nLog, albo stworzyć odpowiedni snippet w VS czy R# i też nie jest źle. Ale mimo wszystko bardzo mi się to spodobało.

Konfiguracja

W tym punkcie być może wyjdę na kretyna, ale… jakoś nigdy nie ogarnąłem struktury konfiguracji log4neta i używanych tam pojęć. logger, appender, mapping. layout… wiem że nie ma w tym niby nic skomplikowanego, ale z palca nic tam nie napiszę. A nawet z kopiuj/wklej muszę się niekiedy zastanowić o co tam w ogóle chodzi.

Jest to bardzo subiektywne odczucie, ale struktura konfiguracji w nLogu wydaje mi się bardziej naturalna. Po prostu taka jak powinna być. Mamy targets, czyli miejsca w które ma trafić informacja. Oraz rules, czyli zbiór reguł kierujących odpowiednie logi w odpowiednie strony. Tyle.

Nie jest to wielki problem, ale lepiej czuję się w XMLu nLoga niż log4neta (BTW, logger to chyba jedyna rzecz której nie konfiguruję w kodzie).

API logowania

Obie biblioteki umożliwiają logowanie tekstu z formatowaniem, czyli możemy wysłać do loggera:

  1:  ...("{0} texttexttext {1}", user.Id, action.Id);

Tutaj szczegół z diabłem polega na tym, że log4net rozróżnia pomiędzy logowaniem zwykłego stringa a stringa z formatowaniem. Powyższa linijka w log4net wyglądać więc będzie tak:

  1:  _log.DebugFormat("{0} texttexttext {1}", user.Id, action.Id);

Z kolei w nLog niezależnie od tego czy chcemy zapisać czysty string, czy też go sformatować, mamy instrukcję:

  1:  _log.Debug("{0} texttexttext {1}", user.Id, action.Id);

Niby pierdoła, ale po co niepotrzebnie komplikować życie i mnożyć metody? Chcę zalogować to co chcę zalogować, a biblioteka niech zdecyduje jak to zrobić.

Deferred logging

Niekiedy zbudowanie wiadomości do zalogowania może być dość skomplikowane i składać się z pobieraniem informacji z wielu obiektów, łączeniem stringów itd. Należy tego oczywiście unikać, jeśli zbudowana wiadomość nie zostanie zalogowana z powodu konfiguracji loggera. Po co pchać coś do Debug na produkcji, gdzie prawdopodobnie logowanie zaczyna się od mniej szczegółowego poziomu?

W tym celu obie biblioteki umożliwiają sprawdzenie w kodzie czy w warto budować wiadomość do zalogowania czy też nie przez właściwości _log.IsDebugEnabled, _log.IsInfoEnabled etc. Wystarczy instrukcja if i wiemy wszystko…

Ale w nLog można pójść o krok dalej:

  1:  _log.Debug(() => "log msg");

Przekazana funkcja wykona się tylko gdy faktycznie ma zostać zalogowana. (oczywiście dodanie tego do log4net to jedna banalna extension method, ale znowu: po co skoro gdzieś indziej mamy to za darmo?).

Inicjalizacja

Początek logowania w log4net może nastąpić po… inicjalizacji konfiguracji. Czyż to nie oczywiste? Piszemy gdzieś przy starcie aplikacji taką instrukcję:

  1:  log4net.Config.XmlConfigurator.ConfigureAndWatch(logConfigurationFile);

i let the logging begin!

Czy w ogóle da się prościej?

Ano okazało się że da się, i chyba to mnie najbardziej zafascynowało w nLog. Bo tam… tworzymy plik konfiguracyjny NLog.config, umieszczamy w katalogu aplikacji i… tyle! W kodzie nie mamy żadnej inicjalizacji, po prostu działa SAMO. Wypas.

Log levels

log4net oferuje następujące poziomy logowania: DEBUG, INFO, WARN, ERROR, FATAL.

nLog z kolei: TRACE, DEBUG, INFO, WARN, ERROR, FATAL.

Różnica? W nLog mamy TRACE. Bardzo przydatny dodatek, nadający się na przykład do logowania wywoływania wszystkich metod i ich parametrów (za pomocą AOP). Oczywiście na produkcji czegoś takiego nie załączymy, ale podczas debuggowania informacja ta może być nieoceniona. Cały poziom DEBUG mamy wówczas dla siebie – walimy tam informacje ręcznie (więcej o tym jak sam staram się wykorzystywać poziomy logowania – wkrótce).

Jeszcze raz podkreślam: absolutnie nie uważam, że z log4net jest coś nie tak albo że nie warto go używać. Jak zresztą widać przekonały mnie głównie niewielkie pierdoły, bez których spokojnie można żyć. Obie biblioteki są świetne i jeżeli nie korzystasz z żadnej nich to bardzo radzę zacząć przygodę z którąkolwiek. Jeśli jedna bez namysłu dodajesz zawsze do referencji log4net zakładając, że właściwie nie ma dla niej alternatywy, to zachęcam do spojrzenia na nLoga. Może Cię miło zaskoczyć.

Inna sprawa, że bez większego problemu można by uzupełnić log4net kilkoma powyższymi funkcjami za pomocą extension methods i też byłoby całkiem git.

Na koniec ciekawostka: nLog został napisany (i jest nadal utrzymywany) przez naszego rodaka, Jarka Kowalskiego, aktualnie pracującego w MS nad Entity Framework.