nLog i structured logging

Jak już tak zacząłem czytać o Nlog to z miejsca natrafiłem na kolejną nowość która na razie jest w wersji Alpha ale jak to wjedzie to będzie miazga! Więc szykować się do solidnej, bardzo fajnej zmiany!  Dosłownie jakieś 3 tygodnie temu, nLog wypuścił wersję biblioteki która wspiera structured logging. Zaraz sobie o wszystkim opowiemy.

Our first alpha with structured logging is online! https://t.co/p8CYsRvwnm #structuredlogging #nlog

— NLog .Net Logging (@NLogOfficial) February 12, 2017

Co to jest Structured Logging?

Do tej pory, jak logowaliśmy dane, to logowaliśmy je jako jeden wiersz danych. Mogły być te dane rozdzielone przecinkiem lub innym znakiem. Ale wyglądały one mniej więcej tak:

2017-01-18 09:47:21.4398|TRACE|App.Web.Services.UrlConverter|'wfd' converted to: 'https://some.link.ie:443/wfd/4'
2017-01-18 09:47:22.1213|TRACE|App.Web.ReadModels.NotificationSearchReadModel|Retrieving list of notifications for: Neil TEST (3865c58d-3a54-4f08-97bb-441e26f7e152)

Takie coś mogło być zapisywane do wielu plików. Jednak ma to pewne wady. Wyzyskiwanie i indeksowanie czegoś takiego graniczy z cudem. To znaczy, nie jest to wygodny sposób przechowywania dużej liczby logów. Nie jest to też optymalny. Dla programistów, może i wystarczający. Ale dla osób odpowiedzialnych za utrzymanie systemów już nie bardzo.

Dlatego też przydaje się zapis strukturowy logów, to znaczy, zapis w innej postaci, na przykład JSON lub XML. Czyli taki zapis jak my mieliśmy wyżej można by przekształcić na:

{
  "time": "2017-01-18 09:47:21.4398",
  "level": "TRACE",
  "logger": "App.Web.Services.UrlConverter",
  "message": "wfd' converted to: 'https://some.ling.ie:443/wfd/4"
}
{
  "time": "2017-01-18 09:47:22.1213",
  "level": "TRACE",
  "logger": "App.Web.ReadModels.NotificationSearchReadModel",
  "message": "Retrieving list of notifications for: Neil TEST (3865c58d-3a54-4f08-97bb-441e26f7e152) "
}

I to tyle. To jest log strukturowy, który można dużo łatwiej analizować, jak i indeksować.

nLog do tej pory

nLog miał wsparcie (pewne) na tworzenie plików logów strukturowych dzięki serializacji. Mogliśmy nasz standardowy output zamienić na Json na przykład, dzięki JsonLayout. I to by też wystarczyło (szkoda, że i o tym nie wiedziałem, opcja dostępna od połowy 2015 roku).

Jednak wsparcie to ograniczało się do zapisu tego co już mamy w postaci niezbyt skomplikowanej. Nie było możliwości dodania dodatkowych zmiennych, dodatkowych informacji, które mogą być bardzo przydatne – na przykład czas data, którą możemy indexować i sortować po. Jak mamy string: To Był test 2016-10-20 – to datę musielibyśmy w jakiś sposób wyciągnąć i sparsować. Co nie było łatwe – nie zawsze.

Dzięki pewnej zmianie już jednak jest to proste :)

nLog w wersji alpha

Teraz, tworząc wpis nLog akceptuje Message Templates, czyli coś co już Serilog w .NET miał. Dzięki czemu, jeden zapis może mieć wiele reprezentacji w tym bardzo fajną i przejrzystą reprezentację strukturową.

Następujący kod:

_log.Trace("I'm {Age} year's old, and I was born {Date}", 34, DateTime.Now);

Wygeneruje nam standardowo taki o to wpis:

2017-03-04 14:54:49.2398|TRACE|ConsoleApplication3.Program|I'm 34 year's old, and I was born 04.03.2017 14:54:49

Jeżeli zaś wykorzystamy logowanie strukturalne to dostaniemy:

{
  "time": "2017-03-04 14:54:49.2398",
  "level": "TRACE",
  "logger": "ConsoleApplication3.Program",
  "message": "I'm 34 year's old, and I was born 04.03.2017 14:54:49",
  "Age": 34,
  "Date": "04\/03\/2017 14:54:49"
}

By skorzystać z logowania strukturalnego trzeba ustawić layout w configu dla określonego target:

<layout xsi:type="JsonLayout" includeAllProperties="true">
    <attribute name="time" layout="${longdate}" />
    <attribute name="level" layout="${level:upperCase=true}"/>
    <attribute name="logger" layout="${logger}"/>
    <attribute name="message" layout="${message}" />
</layout>

Kluczem tutaj jest includeAllProperties – to właśnie ta opcja wrzuci Age i Date.

Podsumowanie

Jak dla mnie bomba :) kilka godzin z dokumentacją i wiem, że ten czas nie był zmarnowany! Żeby tak zawsze było :) To co teraz robi nLog to naprawdę krok w dobrym kierunku, jak i krok ku lepszej integracji z narzędziami zewnętrznymi takimi jak ElasticSearch.

Co sądzicie o tej opcji? Podoba się ona wam?