Logowanie wyższego poziomu z Serilog + Elasticsearch + Kibana

Opublikowano przez

Dzisiaj szybki tutorial jak skorzystać z dobrodziejstw strukturalnego logowania (structured logging) określanego również mianem logowania semantycznego (semantic logging).

Na początek mój przypadek użycia z codziennej pracy. Korzystamy z klasycznych, obytych już przez lata bibliotek do logowania jak log4j, log4net czy wbudowane w .NET Trace. Jednak, jak to bywa często z logami, zaglądamy do nich tylko w przypadku gdy coś padnie i potrzebujemy kompletny stack trace czy przejrzeć kroki operacji. Są bo są. Tak na czarną godzinę. Ostatnio pojawiła się potrzeba bardziej szczegółowego monitorowania metod z warstwy repozytorium, które są wywoływane do bazy danych. Ale nie tylko logowanie! Również późniejsza ich analiza. I w tym miejscu wkracza na scenę pierwszy aktor – Serilog!

Serilog

Serilog, który jak wyżej wspomniane „loggery” także posiada możliwość wypluwania danych do plików ma jedną przeważającą cechę! Logowanie strukturalnych danych. Co to oznacza? W skrócie możliwość logowania obiektów wraz z ich właściwościami. Dodatkowo dostępnych jest wiele tzw. sink (z ang. zlew) czegoś w rodzaju miejsc gdzie dane mają trafiać. Ich listę znajdziecie tutaj.
W moim przypadku wykorzystałem Elasticsearch. 

Elasticsearch

Elasticsearch jest silnikiem, który umożliwia gromadzenie danych, ich przetwarzanie oraz analizę. Komunikacja odbywa się poprzez REST a zapytania formułuję się w formacie JSON. Jest to bardzo popularna platforma (szczególnie z wykorzystaniem całego pakietu Elastic Stack) często wykorzystywana w środowiskach rozproszonych.

Kibana

Ostatni etap – przeglądanie, wizualizacja danych. Kibana jest stworzona do pracy z Elasticsearch. Przy naprawdę niewielkiej konfiguracji uzyskałem kilka wiele mówiących wykresów. A to tylko początek. Nawet nie dotarłem do zapytań i bardziej zaawansowanych funkcjonalności.

Quick Start

Poniżej przedstawiam dosyć prostą konfigurację Serilog. Skonfigurowałem dwa wyjścia:
– Plik tekstowy
– Elasticsearch

_logger = new LoggerConfiguration()
                .WriteTo
                .File(@"..__logsDBPerfsdmstruct.log")
                .WriteTo
                .Elasticsearch(new ElasticsearchSinkOptions(new Uri("http://localhost:9200"))
                    {
                        AutoRegisterTemplate = true,
                        MinimumLogEventLevel = Serilog.Events.LogEventLevel.Information
                    })
                .Destructure.ByTransforming<DbMethodCallInfo>(r =>
                {
                    return new
                    {
                        r.RequestId,
                        r.Module,
                        r.FirstCaller,
                        r.LastCaller,
                        r.DBMethod
                    };
                })
                .CreateLogger();

Dodatkowo ważne jest wskazanie w jaki sposób ma zostać zserializowana struktura logowanego obiektu. Generyczna metoda Destructure.ByTransforming<T> umożliwia wskazanie docelowego typu i definicji nowego obiektu, który trafi do loga. Dzięki temu możemy pominąć pewne właściwości, lub zmienić ich format.

Tak utworzoną instancję logera wywołujemy podobnie jak w innych tego typu bibliotekach poprzez metody Info, Warn, Debug itd. z tą różnicą, że tutaj występuje coś w rodzaju szablonu (template).

_dglogger.Information("DB Call {@DbMethodCallInfo}", dbMethodCallInfo);

Bardzo dobrze zostały one opisane na stronie projektu Writing Log Events. W moim przykładzie poprzez symbol @ wskazałem aby przekazany obiekt został z serializowany. Brak jakiegokolwiek operatora lub użycie $ wskazuje na wykorzystanie metody ToString().

Elasticsearch + Kibana

Tutaj nie ma chyba lepszej opcji niż użycie Dockera. Są gotowe, skonfigurowane obrazy które do celów testowych w zupełności wystarczą. Ja użyłem obrazów z bardzo popularnego repozytorium na
GitHub: https://github.com/deviantony/docker-elk. Wskład wchodzi tutaj cały Elastic Stack: Elasticsearch, Logstach oraz Kibana. Logstach nie miałem potrzeby użyć i nie będę go omawiał.
Szyki klon repo i jedziemy z compose 😉

Kotfis@RUMIA D:PrvGitHubdocker-elk
$ docker-compose up

Przy odrobienie szczęścia (tak Docker się potrafić wywalić 🙂 ) otrzymuje instancję serwisów do których możemy się dostać przez przeglądarkę:

Elasticsearch http://localhost:9200/
Kibana http://localhost:5601

Żeby upewnić się, że cokolwiek trafia do Elastica polecam wpisać w przeglądarce adres:

http://localhost:9200/_cat/indices?v

W ten sposób otrzymamy listę indeksów wraz z ilością dokumentów:

health status index               uuid                   pri rep docs.count docs.deleted store.size pri.store.size
yellow open   logstash-2017.09.02 At15lEHnQJ20qQVju9Ledg   5   1     213004            0     39.1mb         39.1mb
yellow open   .kibana             ZOD1LlKvT6Sht8ZtcCyoCQ   1   1          7            1     48.5kb         48.5kb
yellow open   logstash-2017.09.01 nov4uz4oTPmKzVSVtKQnEg   5   1      20514            0      4.8mb          4.8mb

Ale co z Kibaną zapytacie? Temat na osobny post. Ale żeby wasze oczy ucieszył chodź jeden mały wykresik to podaję kilka istotnych informacji! Przy automatycznym zarejestrowanym szablonie (co zostało uczynione w konfiguracji logera) Serilog utworzy indeks w formacie „logstash-*”. Posługując się nim w pierwszym kroku dodajemy wizualizację wybierając pośród różnego rodzaju wykresów, tabelach itp. Opcjonalnie możemy także stworzyć Dashboard, do którego można podpiąć kilka reprezentacji danych.

Linki do wszystkich wspomnianych produktów, repozytoriów:
Serilog
Elastic Stack
Docker
Docker-Elk (Elasticsearch, Logstach, Kibana)

Na koniec chciałbym polecić rozszerzenie do Chrome Check my links Umożliwia automatyczne przejście po wszystkich linkach dostępnych na stronie co w moim przypadku spełniło rolę automatu i wygenerowało sporo requestów. Więc w krótkim okresie czasu wygenerowałem sporo ruchu.