如何從Serilog請求日誌記錄中排除健康檢查終結點

這是在ASP.NET Core 3.X中使用Serilog.AspNetCore系列文章的第四篇文章：。 1. "第1部分使用Serilog RequestLogging減少日誌詳細程度" 2. "第2部分使用Serilog記錄所選的終結點屬性" 3. "第3部分使用Serilog.AspN ...

這是在ASP.NET Core 3.X中使用Serilog.AspNetCore系列文章的第四篇文章：。

作者：依樂祝

譯文地址：https://www.cnblogs.com/yilezhu/p/12253361.html

原文地址：https://andrewlock.net/using-serilog-aspnetcore-in-asp-net-core-3-excluding-health-check-endpoints-from-serilog-request-logging/

在本系列的前幾篇文章中，我描述瞭如何配置Serilog的RequestLogging中間件以向Serilog的請求日誌摘要中添加附加屬性，例如請求主機名或選定的端點名稱。我還展示瞭如何使用過濾器將MVC或RazorPage特定的屬性添加到摘要日誌。

在本文中，我將展示如何過濾掉某個特定請求的摘要日誌消息。當您有一個訪問比較頻繁的端點時，這非常有用，因為為每個請求都進行記錄幾乎沒有什麼價值。

健康檢查訪問較頻繁

這篇文章的動機來自我們在Kubernetes中運行應用程式時看到的行為。Kubernetes使用兩種類型的“健康檢查”（或“探針”）來檢查應用程式是否正常運行：liveness probes和readiness probes。您可以將探測配置為嚮應用程式發出HTTP請求，作為應用程式正常運行的指示器。

從Kubernetes 1.16版開始，存在第三種探針，即startup probe。

在ASP.NET Core 2.2+中提供的健康檢查終結點非常適合這些探針。您可以設置一個簡單，沒有任何返回值的健康檢查，該健康檢查對每個請求返回200 OK的響應，以使Kubernetes知道您的應用程式沒有崩潰。

在ASP.NET Core 3.x中，可以使用終結點路由來配置健康檢查。您必須在Startup.cs中的ConfigureServices中通過調用AddHealthChecks()來添加必須的服務，併在Configure中使用MapHealthChecks()來添加健康檢查終結點：

public class Startup
{
    public void ConfigureServices(IServiceCollection services)
    {
        // ..other service configuration

        services.AddHealthChecks(); // Add health check services
    }

    public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
        {
            // .. other middleware
            app.UseRouting();
            app.UseAuthorization();
            app.UseEndpoints(endpoints =>
            {
                endpoints.MapHealthChecks("/health"); //Add health check endpoint
                endpoints.MapControllers();
            });
        }
}

在上面的示例中，向/healthz發送請求將調用健康檢查終結點。由於我沒有配置任何運行狀況檢查200，因此只要應用程式正在運行，端點將始終返迴響應：

在上面的示例中，向/healthz發送請求將調用運行狀況檢查終結點。由於我沒有配置任何運行的健康檢查，因此只要應用程式正在運行，端點將始終返回200響應：

這裡存在的唯一的問題是Kubernetes將非常頻繁的調用這個終結點。當然，確切的頻率由您決定，但每10秒檢查一次應該是很常見的。但是如果你想讓Kubernetes可以快速重啟有故障的Pod的話，您就需要一個相對較高的頻率了。

這本身不是問題；Kestrel每秒可以處理數百萬個請求，因此這不是性能問題。這裡令人比較煩惱的問題是每個請求都會生成一定數量的日誌。雖然它沒有MVC基礎架構的請求所示的那麼多-每個請求10個日誌，但是即使每個請求只有1個日誌（就像我們從Serilog.AspNetCore獲得的那樣）都可能會令人不快。

這裡的主要問題是成功進行健康檢查請求的日誌實際上並未告訴我們任何有用的信息。它們與任何業務活動都不相關，它們純粹是基礎設施。這裡如果能夠跳過這些請求的Serilog請求摘要日誌會很好。在下一部分中，我將介紹我所想出的方法，該方法依賴於本系列前面幾篇文章的內容，併在其基礎上做出更改。

定製用於Serilog請求日誌的日誌級別

在上一篇文章中，我展示瞭如何在Serilog請求日誌中包括所選終結點。我的方法是在註冊Serilog中間件時為RequestLoggingOptions.EnrichDiagnosticContext屬性提供一個自定義函數

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    // ... Other middleware

    app.UseSerilogRequestLogging(opts
        // EnrichFromRequest helper function is shown in the previous post
        => opts.EnrichDiagnosticContext = LogHelper.EnrichFromRequest); 

    app.UseRouting();
    app.UseAuthorization();
    app.UseEndpoints(endpoints =>
    {
        endpoints.MapHealthChecks("/healthz"); //Add health check endpoint
        endpoints.MapControllers();
    });
}

RequestLoggingOptions具有另一個屬性，GetLevel該屬性的Func<>被用於確定應用於給定請求日誌的日誌記錄級別。預設情況下，它設置為以下功能：

public static class SerilogApplicationBuilderExtensions
{
    static LogEventLevel DefaultGetLevel(HttpContext ctx, double _, Exception ex) =>
        ex != null
            ? LogEventLevel.Error 
            : ctx.Response.StatusCode > 499 
                ? LogEventLevel.Error 
                : LogEventLevel.Information;
}

此函數檢查是否為請求引發了異常，或者響應代碼是否為5xx錯誤。如果是這樣，它將創建一個Error級別的摘要日誌，否則將創建一個Information級別日誌。

假設您希望將摘要日誌記錄為Debug而不是Information。首先，您將創建一個具有以下所需邏輯的輔助函數，如下所示：

public static class LogHelper
{
    public static LogEventLevel CustomGetLevel(HttpContext ctx, double _, Exception ex) =>
        ex != null
            ? LogEventLevel.Error 
            : ctx.Response.StatusCode > 499 
                ? LogEventLevel.Error 
                : LogEventLevel.Debug; //Debug instead of Information
}

然後，您可以在調用時設置級別功能UseSerilogRequestLogging()：

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    // ... Other middleware

    app.UseSerilogRequestLogging(opts => {
        opts.EnrichDiagnosticContext = LogHelper.EnrichFromRequest;
        opts.GetLevel = LogHelper.CustomGetLevel; // Use custom level function
    });

    //... other middleware
}

現在，您的請求摘要日誌將全部記錄為Debug，除非發生錯誤（Seq的屏幕截圖）：

顯示調試請求日誌的序列

但這如何解決我們的冗長日誌的問題呢？

當你在配置Serilog時，你通常應該會定義一個最低請求級別。例如，以下簡單配置將預設級別設置為Debug()，並將其寫入控制台接收器：

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console()
    .CreateLogger();

因此，過濾日誌的最簡單方法是使日誌級別低於MinimumLevel記錄器配置中指定的級別。一般而言，如果使用最低級別Verbose，它將幾乎總是被過濾掉。

困難之處在於我們不想總是將Verbose用作摘要日誌的日誌級別。如果這樣做，我們將不會獲得任何非錯誤的請求日誌，而Serilog中間件將變得毫無意義！

相反，我們希望將日誌級別設置為Verbose 僅針對運行健康檢查端點的請求。在下一節中，我將展示如何在不影響其他請求的情況下識別這些請求。

將自定義日誌級別用於健康檢查終結點請求

我們需要的是能夠在寫入摘要日誌時識別出健康檢查的請求的能力。如前所示，該GetLevel()方法將當前HttpContext作為參數，因此理論上有一些可行性。對我來說，最明顯的做法是：

將HttpContext.Request路徑與已知的健康檢查路徑列表進行比較
當健康檢查終結點被請求時，使用選定的端點元數據來進行標識

第一種選擇是最明顯的，但是它真的不值得嘗試。一旦你陷入其中，你會發現你必須開始複製請求路徑並處理各種邊緣情況，因此在這裡我將跳過該情況。

第二種方法使用了與我上一篇文章中使用的方法類似，在該方法中，我們獲得了EndpointRoutingMiddleware為給定請求選擇的IEndpointFeature。此功能（如果存在）提供了所選端點的顯示名稱和路由數據等詳細信息。

如果我們假設健康檢查是使用預設顯示名稱註冊的，即"Health checks"，則我們可以使用HttpContext來標識“健康檢查”的請求，如下所示：

public static class LogHelper
{
    private static bool IsHealthCheckEndpoint(HttpContext ctx)
    {
        var endpoint = ctx.GetEndpoint();
        if (endpoint is object) // same as !(endpoint is null)
        {
            return string.Equals(
                endpoint.DisplayName, 
                "Health checks",
                StringComparison.Ordinal);
        }
        // No endpoint, so not a health check endpoint
        return false;
    }
}

我們可以將此功能與預設GetLevel功能的自定義版本結合使用，以確保運行健康檢查請求的摘要日誌使用Verbose級別，當發生錯誤時使用Error而其他請求則使用Information：

public static class LogHelper
{
    public static LogEventLevel ExcludeHealthChecks(HttpContext ctx, double _, Exception ex) => 
        ex != null
            ? LogEventLevel.Error 
            : ctx.Response.StatusCode > 499 
                ? LogEventLevel.Error 
                : IsHealthCheckEndpoint(ctx) // Not an error, check if it was a health check
                    ? LogEventLevel.Verbose // Was a health check, use Verbose
                    : LogEventLevel.Information;
        }
}

這個嵌套的三目運算符有一個額外的邏輯-對於無錯誤，我們檢查是否選擇了顯示名為“Health check”的端點，如果選擇了，則使用級別Verbose，否則使用Information。

您可以進一步推廣此代碼，以允許傳入其他顯示名稱或其他自定義使用的日誌級別。為了簡單起見，我在這裡沒有這樣做，但是GitHub上的相關示例代碼顯示瞭如何執行此操作。

剩下的就是更新Serilog中間件RequestLoggingOptions以使用您的新功能：

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    // ... Other middleware

    app.UseSerilogRequestLogging(opts => {
        opts.EnrichDiagnosticContext = LogHelper.EnrichFromRequest;
        opts.GetLevel = LogHelper.ExcludeHealthChecks; // Use the custom level
    });

    //... other middleware
}

這時候當你運行應用程式後檢查日誌時，您會看到標準請求的普通請求日誌，但沒有健康檢查的日誌（除非發生錯誤！）。在下麵的屏幕截圖中，我將Serilog配置為也記錄Verbose日誌，以便您可以查看運行狀況檢查請求-通常會將它們過濾掉！

Seq屏幕截圖顯示了使用詳細級別的運行狀況檢查請求

總結

在本文中，我展示瞭如何為Serilog中間件的RequestLoggingOptions提供一個自定義函數，該函數定義了要為給定請求的日誌使用的LogEventLevel。例如，我展示瞭如何使用它將預設級別更改為Debug。如果您選擇的級別低於最低級別，它將被完全過濾掉，並且不會被記錄。

我還展示了您可以使用這種方法來過濾通過調用健康檢查端點生成的公共（低級別的）請求日誌。一般來說，這些請求只有在指出問題時才有意義，但它們通常也會在成功時生成請求日誌。由於這些端點被頻繁調用，因此它們可以顯著增加寫入的日誌數量（無用）。

本文中的方法是檢查選定的IEndpointFeature並檢查它是否具有顯示名稱“Health checks”。如果是，請求日誌將使用Verbose級別寫入，這通常會被過濾掉。為了更靈活，您可以自定義在這個帖子中顯示的日誌來處理多個端點名稱，或者任何其他的標準。