Wykluczenie health check endpoint z logowania w ASP.NET Core

Kilka miesięcy temu we wpisie Health Checks w ASP.NET Core przedstawiłem konfiguracje health checks w projektach ASP.NET Core. Wszystko byłoby idealnie gdyby nie ilość szumów w logach powstała w skutek cyklicznego odpytywania health check endpoint. Dobrą praktyką byłoby ten szum zbędnych informacji wyeliminować. Sprawdżmy stan aktualny i zobaczmy co rejestruje na console aplikacja z projektu opisanego we wpisie Health Checks w ASP.NET Core. Na poniższym zrzucie widać aktualnie rejestrowane zdarzenia w API.

Moim celem jest pozbycie się informacji o wysłaniu żądania do heatlh endpoint jeśli zakończyło się sukcesem.

Podmiana na Serilog

W tym miejsu kończę zabawę z domyślnym loggerem i użyję biblioteki Serilog. Zacznijmy najpierw od pozbycia się domyślnego loggera (usuwamy logger config z appsettings.json, oraz wszystkich dostępnych providerów z kodu). Po porządkach instalujemy z NuGet wymagane paczki.

<PackageReference Include="Serilog.AspNetCore" Version="3.4.0" />
<PackageReference Include="Serilog.Filters.Expressions" Version="2.1.0" />
<PackageReference Include="Serilog.Settings.Configuration" Version="3.1.0" />

Skupię się tutaj na podstawowym scenariuszu, gdzie zdarzenia będą wypisywane na console. Nie będę poruszał tutaj kwestii konfiguracji Seriloga z innymi sink-ami , oraz pominę kwestie wzbogacenia logów o dodatkowe informacje/pola (enrich). Serilog skonfiguruję poprzez sekcje Serilog w pliku asppsettings.json. W konfiguracji określono, że logi zapisujemy na console. Zdefinionowano domyślny minimalny poziom rejestrowania logów na Infromation. Dla komponentów jak Microsoft, System i HealthChecks zostało ustawione rejestrowanie tylko od poziomu Warning w górę. Niższe poziomy logowania wykluczono, aby nie mieć tysięcy nadmiarowych logów w sink-ach

"Serilog": {
    "Using": [
    ],
    "MinimumLevel": {
        "Default": "Information",
        "Override": {
            "System": "Warning",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information",
            "HealthChecks": "Warning"
        }
    },
    "WriteTo": [
        "Console"
    ],
    "Enrich": [
        "FromLogContext"
    ]
},

W kolejnym kroku wskazujemy, żeby API wykorzystywało Serilog zamiast domyślnego loggera. Ustawiamy odczyt ustawień z pliku konfiguracyjnego.

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

Dodatkowo w metodzie Configure w klasie Startup dodajemy linijkę kodu app.UseSerilogRequestLogging(). W tym miejscu dodajemy Serilog Request Logging middleware do logowania żądań HTTP przez Serilog. Komunikaty logów będę generowane w szablonie w następującej postaci [19:39:14 ERR] HTTP GET /health responded 503 in 6.2627 ms.

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

Serilog jest skonfigurowany, zatem uruchamiamy API i śledzimy pojawiające się zdarzenia na konsoli (screen poniżej). Trochę błędów pojawiło się, ale to zawdzięczam „losowości” w zaimplementowanym własnym health checku. Usługi SQL Server i RabbitMQ uruchomiłem na okres testów, by weryfikacja ich działania nie generowała błędów. Czytelność według mnie znacznie poprawiła się 🙂

Wykluczenie health check endpoint

Przejdźmy do głównego punktu artykułu, czyli jak wykluczyć dowolny endpoint, którego nie chcemy logować. W moim przypadku to będzie health endpoint, ale to także może być endpoint odpowiedzialny za ping czy metryki (zależy od wymagań). Wykorzystam tu funkcjonalność dostarczoną przez bibliotekę Serilog.Filters.Expressions. Do naszej sekcji Serilog w appsettings.json dodałem filtr odpowiedzialny za odrzucenie health endpoint z statusem kodu 200. Powyższy filtr można także utworzyć w kodzie w C#, ale osobiście jestem zwolennikiem konfiguracji Serilog przez plik appsettings.json. Po więcej informacji odsyłam na stronę biblioteki https://github.com/serilog/serilog-filters-expressions

"Serilog": {
    "Using": [
    ],
    "Filter": [
        {
            "Name": "ByExcluding",
            "Args": {
                "expression": "Contains(RequestPath, '/health') and StatusCode=200"
            }
        }
    ],
    "MinimumLevel": {
        "Default": "Information",
        "Override": {
            "System": "Warning",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information",
            "HealthChecks": "Warning"
        }
    },
    "WriteTo": [
        "Console"
    ],
    "Enrich": [
        "FromLogContext"
    ]
},

Zobaczmy czy działa, albo inaczej zobaczmy czy nie wyświetla nam nadmiarowych informacji. Między zalogowanymi błędami jest 30 sekund różnicy, co oznacza, że dwa żądania do endpointu /health zakończyły się sukcesem i nie zostały zalogowane. Udało się osiągnąć cel z powyższego wpisu.

Podsumowując, logowanie zdarzeń możemy zminimalizować poprzez odpowiednie ustawienie minimalnych poziomów logowania oraz poprzez zastosowanie filtrów. Miłego rejestrowania zdarzeń, pamiętajcie o nielogowaniu danych wrażliwych 😉