天天看點

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

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

  1. 第1部分-使用Serilog RequestLogging減少日志詳細程度(本文)
  2. 第2部分-使用Serilog記錄所選的終結點屬性
  3. 第3部分-使用Serilog.AspNetCore記錄MVC屬性
  4. 第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個日志消息,但你會看到一個額外的通過Serilog

RequestLoggingMiddleware

彙總的日志消息,倒數第二的消息:

# 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”擷取下載下傳位址。
如何利用Serilog的RequestLogging來精簡ASP.NET Core的日志輸出

完成整理工作所剩下的就是過濾掉我們目前正在記錄的資訊級日志消息。在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.cnblogs.com/yilezhu

聯系:[email protected] .NET Core實戰項目交流群:637326624 微信:jkingzhu

本文版權歸作者和部落格園共有,歡迎轉載,但未經作者同意必須保留此段聲明,且在文章頁面明顯位置給出原文連接配接,否則保留追究法律責任的權利。如有問題或建議,請多多賜教,非常感謝。

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