如何利用Serilog的RequestLogging來精簡ASP.NET Core的日志輸出-有解無憂

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

第1部分-使用Serilog RequestLogging減少日志詳細程度（本文）
第2部分-使用Serilog記錄所選的終結點屬性
第3部分-使用Serilog.AspNetCore記錄MVC屬性
第4部分-從Serilog請求日志記錄中排除健康檢查端點

作者：依樂祝

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

原文地址：https://andrewlock.net/using-serilog-aspnetcore-in-asp-net-core-3-reducing-log-verbosity/

眾所周知，ASP.NET Core的重要改變之一是把日志記錄內置于框架中，這意味著您可以（如果需要）從自己的標準日志基礎設施訪問所有深層基礎設施日志，缺點是有時您會收到太多的日志，

在這個簡短的系列文章中，我將介紹如何使用Serilog的ASP.NET Core請求日志記錄功能，在第一篇文章中，我將講述如何將Serilog的RequestLoggingMiddleware添加到您的應用程式，以及它提供的好處，在后續文章中，我將描述如何進一步自定義行為，

我已經將這些帖子草擬了一段時間，從那時起，Serilog的創建者Nicholas Blumhardt就在ASP.NET Core 3.0中使用Serilog撰寫了一篇詳盡的博客文章，這是一篇非常詳細（至少我認為是這樣）的文章，我強烈建議您閱讀，您可以在他的文章中找到我在本系列文章中談論的大部分內容，所以請查看！

原生請求日志

在本節中，首先讓我們創建一個標準的ASP.NET Core 3.0的Razor pages應用，當然你也可以直接使用dotnet new webapp命令來進行創建，這將創建一個標準Program.cs，如下所示：

 public class Program
    {
        public static void Main(string[] args)
        {
            CreateHostBuilder(args).Build().Run();
        }

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

還有一個Startup.cs，用于配置中間件管道，Configure如下所示：

 public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
        {
            if (env.IsDevelopment())
            {
                app.UseDeveloperExceptionPage();
            }
            else
            {
                app.UseExceptionHandler("/Error");
                // The default HSTS value is 30 days. You may want to change this for production scenarios, see https://aka.ms/aspnetcore-hsts.
                app.UseHsts();
            }

            app.UseHttpsRedirection();
            app.UseStaticFiles();

            app.UseRouting();

            app.UseAuthorization();

            app.UseEndpoints(endpoints =>
            {
                endpoints.MapRazorPages();
            });
        }

如果您運行該應用程式并導航至主頁，則默認情況下，您會在控制臺中看到每個請求都會產生許多的日志，以下日志是針對對主頁的單個請求生成的（此后我還沒有包括對CSS和JS檔案的其他請求）（這是是開發環境請求出現的日志）：

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:5001/
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint '/Index'
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[3]
      Route matched with {page = "/Index"}. Executing page /Index
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[101]
      Executing handler method SerilogRequestLogging.Pages.IndexModel.OnGet - ModelState is Valid
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[102]
      Executed handler method OnGet, returned result .
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[103]
      Executing an implicit handler method - ModelState is Valid
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[104]
      Executed an implicit handler method, returned result Microsoft.AspNetCore.Mvc.RazorPages.PageResult.
info: Microsoft.AspNetCore.Mvc.RazorPages.Infrastructure.PageActionInvoker[4]
      Executed page /Index in 221.07510000000002ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint '/Index'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 430.9383ms 200 text/html; charset=utf-8

單個請求就是10條日志，現在，很清楚，它正在Development環境中運行，該環境默認情況下將Microsoft名稱空間中的所有資訊記錄在“Information”或更高的級別，如果我們切換到Production環境，則默認模板會將Microsoft命名空間的日志過濾到“Warning” ，現在導航到默認主頁會生成以下日志（這里注意，如果你現在使用ASP.NET Core3.1貌似Microsoft命名空間默認日志級別已經改為Warning）：

是的，根本沒有日志！上一次運行中生成的所有日志都位于Microsoft命名空間中，并且屬于“Information”級別，因此將它們全部過濾掉，就個人而言，我覺得這有點麻煩，如果生產版本僅僅只是想記錄一部分內容，而其他相關聯的內容則不進行記錄，這將會更有用的，

一種可能的解決方案是自定義應用于每個命名空間的過濾器，例如，您可以將Microsoft.AspNetCore.Mvc.RazorPages命名空間限制為“Warning”級別，而將更通用的Microsoft命名空間保留為“Information”級別，現在，您將獲得精簡后的日志集：

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/2 GET https://localhost:5001/
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint '/Index'
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint '/Index'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 184.788ms 200 text/html; charset=utf-8

這些日志中包含一些有用的資訊-URL，HTTP方法，時間資訊，端點等-并且沒有太多冗余，但是，仍然令人討厭的是它們是四個單獨的日志訊息，（還是很多，如果能精簡成一條日志記錄是不是會好很多）

這是Serilog RequestLoggingMiddleware旨在解決的問題-為請求中的每個步驟創建單獨的日志相反，它是創建一個包含所有相關資訊的“摘要”日志訊息，

將Serilog添加到應用程式

使用Serilog RequestLoggingMiddleware 的一個前提條件就是您正在使用Serilog！在本節中，我將介紹將Serilog添加到ASP.NET Core應用程式中，如果您已經安裝了Serilog，請跳至下一部分，

首先安裝Serilog.AspNetCore NuGet軟體包，再加上控制臺和Seq接收器【這是一個漂亮的可視化日志UI】，以便我們可以查看日志，您可以通過運行以下命令從命令列執行此操作：

dotnet add package Serilog.AspNetCore
dotnet add package Serilog.Sinks.Seq

現在該用Serilog替換默認日志了，您可以通過多種方式執行此操作，但是建議的方法是在Program.Main 執行其他任何操作之前先配置記錄器，這與ASP.NET Core通常使用的方法背道而馳，但建議用于Serilog，結當然這會導致您的的Program.cs檔案變得更長：

// Additional required namespaces
using Serilog;
using Serilog.Events;

namespace SerilogDemo
{
    public class Program
    {
        public static void Main(string[] args)
        {
            // Create the Serilog logger, and configure the sinks
            Log.Logger = new LoggerConfiguration()
               .MinimumLevel.Debug()
               .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
               .Enrich.FromLogContext()
               .WriteTo.Console()
               .WriteTo.Seq("http://localhost:5341")
               .CreateLogger();
            // Wrap creating and running the host in a try-catch block
            try
            {
                Log.Information("Starting host");
                CreateHostBuilder(args).Build().Run();
            }
            catch (Exception ex)
            {
                Log.Fatal(ex, "Host terminated unexpectedly");
            }
            finally
            {
                Log.CloseAndFlush();
            }
        }

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

盡管這樣設定可能顯得更為復雜，但是此設定可確保例如在appsettings.json檔案格式錯誤或缺少組態檔的情況下仍會獲取日志，如果現在運行您的應用程式，您將看到與我們最初相同的10條日志，只是格式略有不同：

[13:30:27 INF] Request starting HTTP/2 GET https://localhost:5001/  
[13:30:27 INF] Executing endpoint '/Index'
[13:30:27 INF] Route matched with {page = "/Index"}. Executing page /Index
[13:30:27 INF] Executing handler method SerilogRequestLogging.Pages.IndexModel.OnGet - ModelState is Valid
[13:30:27 INF] Executed handler method OnGet, returned result .
[13:30:27 INF] Executing an implicit handler method - ModelState is Valid
[13:30:27 INF] Executed an implicit handler method, returned result Microsoft.AspNetCore.Mvc.RazorPages.PageResult.
[13:30:27 INF] Executed page /Index in 168.28470000000002ms
[13:30:27 INF] Executed endpoint '/Index'
[13:30:27 INF] Request finished in 297.0663ms 200 text/html; charset=utf-8

現在，通過在應用程式生命周期的早期進行配置，我們的日志記錄配置的更加健壯，但實際上尚未解決我們提出的問題，為此，我們將添加RequestLoggingMiddleware，

切換到Serilog的 `RequestLoggingMiddleware`

RequestLoggingMiddleware被包含在Serilog.AspNetCore中，可以被用于為每個請求添加一個單一的“摘要”日志訊息，如果您已經完成了上一節中的步驟，則添加這個中間件將變得很簡單，在您的Startup類中，在您想要記錄日志的位置使用UseSerilogRequestLogging()進行呼叫：

// Additional required namespace
using Serilog;

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
    // ... Error handling/HTTPS middleware
    app.UseStaticFiles();

    app.UseSerilogRequestLogging(); // <-- Add this line

    app.UseRouting();
    app.UseAuthorization();
    app.UseEndpoints(endpoints =>
    {
        endpoints.MapRazorPages();
    });
}

與ASP.NET Core的中間件管道一樣，順序很重要，當請求到達RequestLoggingMiddleware中間件時，它將啟動計時器，并將請求傳遞給后續中間件進行處理，當后面的中間件最終生成回應（或拋出例外），則回應通過中間件管道傳遞回到請求記錄器，并在其中記錄了結果并寫入概要日志資訊，

Serilog只能記錄到達中間件的請求，在上面的例子中，我已經在StaticFilesMiddleware之后添加了RequestLoggingMiddleware ，因此如果請求被UseStaticFiles處理并使管道短路的話，日志將不會被記錄，鑒于靜態檔案中間件非常嘈雜，而且通常這是人們期望的行為（靜態檔案進行短路，不需要進行記錄），但是如果您也希望記錄對靜態檔案的請求，則可以在管道中serilog中間件移動到更早的位置，

如果我們再一次運行該應用程式，你還是會看到原來的10個日志訊息，但你會看到一個額外的通過SerilogRequestLoggingMiddleware匯總的日志訊息，倒數第二的訊息：

# Standard logging from ASP.NET Core infrastructure
[14:15:44 INF] Request starting HTTP/2 GET https://localhost:5001/  
[14:15:44 INF] Executing endpoint '/Index'
[14:15:45 INF] Route matched with {page = "/Index"}. Executing page /Index
[14:15:45 INF] Executing handler method SerilogRequestLogging.Pages.IndexModel.OnGet - ModelState is Valid
[14:15:45 INF] Executed handler method OnGet, returned result .
[14:15:45 INF] Executing an implicit handler method - ModelState is Valid
[14:15:45 INF] Executed an implicit handler method, returned result Microsoft.AspNetCore.Mvc.RazorPages.PageResult.
[14:15:45 INF] Executed page /Index in 124.7462ms
[14:15:45 INF] Executed endpoint '/Index'

# Additional Log from Serilog
[14:15:45 INF] HTTP GET / responded 200 in 249.6985 ms

# Standard logging from ASP.NET Core infrastructure
[14:15:45 INF] Request finished in 274.283ms 200 text/html; charset=utf-8

關于此日志，有幾點需要說明下：

它在一條訊息中包含您想要的大多數相關資訊-HTTP方法，URL路徑，狀態代碼，持續時間，
顯示的持續時間略短于Kestrel在后續訊息中記錄的值，這是可以預期的，因為Serilog僅在請求到達其中間件時才開始計時，而在回傳時停止計時（在生成回應之后），
在這兩種情況下，使用結構日志記錄時都會記錄其他值，例如，記錄了RequestId和SpanId（用于跟蹤功能），因為它們是日志記錄范圍的一部分，您可以在登錄到seq的請求的以下影像中看到這一點，
默認情況下，我們確實會丟失一些資訊，例如，不再記錄終結點名稱和Razor頁面處理程式，在后續文章中，我將展示如何將它們添加到摘要日志中，
如果想要通過``http://localhost:5341 訪問UI，你可能需要下載seq進行安裝，由于某種不知名的原因，可能下載會很慢，所以當然你也可以關注公眾號“DotNetCore實戰”然后回復關鍵字“seq”獲取下載地址，

到Seq的RequestLoggingMiddleware日志顯示結構化日志包括其他屬性

完成整理作業所剩下的就是過濾掉我們當前正在記錄的資訊級日志訊息，在Program.cs中更新Serilog配置以添加額外的過濾器：

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Information)
    // Filter out ASP.NET Core infrastructre logs that are Information and below
    .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning) 
    .Enrich.FromLogContext()
    .WriteTo.Console()
    .WriteTo.Seq("http://localhost:5341")
    .CreateLogger();

通過最后的更改，您現在將獲得一組干凈的請求日志，其中包含每個請求的摘要資料：

[14:29:53 INF] HTTP GET / responded 200 in 129.9509 ms
[14:29:56 INF] HTTP GET /Privacy responded 200 in 10.0724 ms
[14:29:57 INF] HTTP GET / responded 200 in 3.3341 ms
[14:30:54 INF] HTTP GET /Missing responded 404 in 16.7119 ms

在下一篇文章中，我將介紹如何通過記錄其他資料來增強此日志，

摘要

在本文中，我描述了如何使用Serilog.AspNetCore的請求日志記錄中間件來減少為每個ASP.NET Core請求生成的日志數，同時仍記錄摘要資料，如果您已經在使用Serilog，則非常容易啟用，只需在您的Startup.cs檔案中呼叫UseSerilogRequestLogging()，

當請求到達此中間件時，它將啟動計時器，當后續的中間件生成回應（或引發例外）時，回應將通過中間件管道回傳到請求記錄器，記錄器記錄結果并撰寫摘要日志訊息，

添加請求日志記錄中間件之后，您可以過濾掉默認情況下在ASP.NET Core 3.0中生成的更多基礎結構日志，而不會丟失有用的資訊，

轉載請註明出處，本文鏈接：https://www.uj5u.com/net/69007.html

標籤：.NET Core

上一篇：聊聊HTTP請求那一些事_HttpWebRequest_一篇就夠了

下一篇：在 ASP.NET Core 程式啟動前運行你的代碼

如何利用Serilog的RequestLogging來精簡ASP.NET Core的日志輸出

原生請求日志

將Serilog添加到應用程式

切換到Serilog的 RequestLoggingMiddleware

摘要

切換到Serilog的 `RequestLoggingMiddleware`