Serlilog czyli logowanie z ASP.NET CORE

Serilog Na tym blogu mam serię artykułów, które opisują fajne biblioteki NuGet dla ASP.NET CORE. Dziś spojrzymy na Serilog. 

Logowanie błędów informacji jest kluczowe. Mam nawet wpis o tym, jak użyć NLoga w ASP.NET CORE i obecnie go używam na swoim blogu, aby od czasu do czasu sprawdzić jakie błędy w nim są.

Bez logowania nie znalazłbym uszkodzonych wpisów, które w wyniku złego formatowania HTML wyrzucały wyjątek.

Dlaczego Serilog, a nie coś innego? Najważniejsza różnica pomiędzy Serilog a innym frameworkiem do logowania jest fakt, że ta biblioteka ma wybudowany tryb strukturalnego logowania. Każdy element Serilog jest paczką, którą można dodać aby go rozszerzyć.

Serilog też może być skonfigurowane za pomocą appsetting.json. Czyli nie zmieniamy kod aby zmienić styl logowania aplikacji. NLog miał natomiast swoją własną konfigurację w oddzielnym pliku XML co możesz uznać za wadę.

Dlaczego jest to takie ważne? W świecie Kubernetesa i Dockera możesz też potem te konfigurację zmieniać w zależności od środowiska

Stwórzmy więc projekt, aby zobaczyć jak użyć Serilog w .NET 5.

Do projektu dodajemy paczkę NuGet.

Aby skorzystać z Serilog dodajmy go przy budowania hosta aplikacji ASP.NET CORE.

public static IHostBuilder CreateHostBuilder(string[] args) =>
   Host.CreateDefaultBuilder(args)
       .ConfigureWebHostDefaults(webBuilder =>
       {
           webBuilder.UseStartup<Startup>();
       }).UseSerilog((hostingContext, loggerConfiguration) =>
loggerConfiguration.ReadFrom.Configuration(hostingContext.Configuration));

Potem usuwamy domyślną konfigurację logowania w appsettings.json i appsettings.Development.json, aby dodać własną. 

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Information",
        "System": "Information"
      },
      "Using": []
    },
    "WriteTo": [
      {}
    ]
  },
  "AllowedHosts": "*"
}

Gdybyś chciał osiągnąć to samo z poziomu kodu to byś musiał utworzyć taki singleton.

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
    .MinimumLevel.Override("System", LogEventLevel.Information)
    .Enrich.FromLogContext()
    .CreateLogger();

Serilog.Sinks

Serilog używa tak zwanych sinks. Sinks, czyli umywalki to definicja stylu zapisu twoich informacji o logowaniu. Może to być plik, baza danych oraz konsola aplikacji.

Zainstalujemy paczkę Nuget "Serilog.Sinks.Console", czyli umywalkę (xD), która będzie wpisywać informację do konsoli.

Aby z niej skorzystać musimy zmodyfikować konfigurację

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Information",
        "System": "Information"
      }
    },
    "Using": [ "Serilog.Sinks.Console" ],
    "WriteTo": [
      { "Name": "Console" }
    ]
  },
  "AllowedHosts": "*"
}

Przetestujmy czy to działa uruchamiając ten prawie pusty projekt ASP.NET CORE. Jak widać w oknie Output mam logowanie aplikacji.

Okno Output jest nieczytelne. Nie ma problemu

Aplikację ASP.NET Core też można uruchomić jako aplikację konsolową, która tworzy hosta strony. Trzeba tylko wybrać taką opcję w Visual Studio. Zamiast IIS Express wybierz nazwę swojej aplikacji.

Oto rezultat:

Tak działa konsola, ale zapewne chcielibyśmy mieć inny sposób zapisu naszych logów. Serilog posiada mnóstwo Sink. Zobaczmy jak działa umywalka dla bazy danych SQLite "Serilog.Sinks.SQLite"

Oto jakby wyglądała konfiguracja SQLite z poziomu kodu :

private static Logger _logger;

public static void Main(string[] args)
{
    _logger = new LoggerConfiguration()
       .WriteTo.SQLite(@"C:\Users\PanNiebieski\source\repos\SerilogExample\SerilogExample\LogDB.db"
        , "Logs")
       .MinimumLevel.Debug()
        .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
        .MinimumLevel.Override("System", LogEventLevel.Information)
        .Enrich.FromLogContext()
       .CreateLogger();

    _logger.Information("This informational message will be written to SQLite database");

    CreateHostBuilder(args).Build().Run();
}

public static IHostBuilder CreateHostBuilder(string[] args) =>
    Host.CreateDefaultBuilder(args)
        .ConfigureWebHostDefaults(webBuilder =>
        {
            webBuilder.UseStartup<Startup>();
        }).UseSerilog(_logger);

Dla pewności otwieram bazę danych w programie DBBrowser for SQLite, aby zobaczyć, czy dodałem jakieś rekordy do bazy.

Swoją drogą baza i tabelka sama się utworzyła na podstawie odpowiedniego połączenia z bazą.

Oto jakby ta konfiguracja wyglądałaby w pliku appsettings.json

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Information",
        "System": "Information"
      }
    },
    "Using": [ "Serilog.Sinks.SQLite" ],
    "WriteTo": [
      {
        "Name": "SQLite",
        "Args": {
          "sqliteDbPath": "C:\\Users\\PanNiebieski\\source\\repos\\SerilogExample\\SerilogExample\\LogDB2.db",
          "tableName": "Logs"

        }
      }
    ]
  },
  "AllowedHosts": "*"
}

Możesz zauważyć, że w "WriteTo" trzeba podać takie same parametry tylko trzeba być bardzo dokładny z nazewnictwem. Dla SQLite połączenie będzie się nazywać "sqliteDbPath". Dla SQLServer i jego paczki NuGet "Serilog.Sinks.MSSqlServer" konfiguracja w appsetting.json wyglądałaby tak :

{
  "Serilog": {
    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Microsoft": "Information",
        "System": "Information"
      },
      "Using": [ "Serilog.Sinks.MSSqlServer" ]
    },
    "WriteTo": [
      {
        "Name": "MSSqlServer",
        "Args": {
          "connectionString": "Data Source=(localdb)\\MSSQLLocalDB;Initial Catalog=Logs;Integrated Security=True;Connect Timeout=30;Encrypt=False;TrustServerCertificate=False;ApplicationIntent=ReadWrite;MultiSubnetFailover=False",
          "tableName": "Logs",
          "autoCreateSqlTable": true
        }
      }
    ]
  },
}

Serilog.Enrichers

Do logów możesz dodać mnóstwo dodatkowych informacji. Możesz do logów np. dodać adres IP klienta. Chcesz znaleźć, jakie meta informację możesz dodać do swoich logów, to zobaczy wszystkie paczki NuGet, które kryją się za nazwą Serilog.Enrichers

Nas interesuje paczka "Serilog.Enrichers.ClientInfo". Oczywiście, aby skorzystać z danego mechanizmu, to trzeba dopisać odpowiednią konfigurację.

"Using": [ "Serilog.Sinks.SQLite", "Serilog.Enrichers.ClientInfo" ],
"Enrich": [ "WithClientIp" ],

Tak by to wyglądałoby w kodzie

_logger = new LoggerConfiguration()
     .WriteTo.SQLite(@"C:\Users\PanNiebieski\source\repos\SerilogExample\SerilogExample\LogDB.db"
      , "Logs")
     .Enrich.WithClientIp()
     .MinimumLevel.Debug()
     .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
     .MinimumLevel.Override("System", LogEventLevel.Information)
     .Enrich.FromLogContext()
     .CreateLogger();

Dodajemy Filtry

Analogicznie do Sinks i Enrichers. Filtry także są paczkami NuGet, które trzeba zainstalować.

Oto przykład paczki "Serilog.Expressions", która będzie filtrować zapisy logów pod dane wyrażenie tekstowe.

Oto przykład pomijania logów, gdy odpytujemy cokolwiek w ASP.NET CORE, gdy ścieżka URL zawiera słowo "swagger"

"Filter": [
  {
    "Name": "ByExcluding",
    "Args": {
      "expression": "RequestPath like '%swagger%'"
    }
  }
]

Logowanie zapytań HTTP

Do Serilog możesz dodać logowanie każdego zapytania HTTP.

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    ...
    app.UseSerilogRequestLogging();

W sekcji MinimumLevel.Override dodaj "Microsoft.AspNetCore": "Warning"

"MinimumLevel": {
  "Default": "Information",
  "Override": {
    "Microsoft": "Error",
    "Microsoft.AspNetCore": "Warning",
    "System": "Error"
  },

To wszystko, jeśli chodzi o Serilog. Na koniec zostało mi jeszcze tobie pokazać jak konfiguracja wyglądałaby, gdybyśmy chcieli zapisywać logi do pliku i do konsoli równocześnie.

"Serilog": {
  "MinimumLevel": {
    "Default": "Debug",
    "Override": {
      "Microsoft": "Information",
      "System": "Information"
    }
  },
  "Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
  "WriteTo": [
    { "Name": "Console" },
    {
      "Name": "File",
      "Args": {
        "path": "log.txt",
        "rollingInterval": "Day"
      }
    }
  ]
}

Możesz powiedzieć jak pliki logów powinny być dzielone np. per dzień.

Jak się domyślasz trzeba zainstalować paczkę "Serilog.Sinks.File", aby skorzystać z zapisu do pliku.