如何利用Serilog的RequestLogging来精简ASP.NET Core的日志输出
這是該系列的第一篇文章:在ASP.NET Core 3.0中使用Serilog.AspNetCore。
第1部分-使用Serilog RequestLogging來簡化ASP.NET Core的日志輸出(本篇文章)
第2部分-使用Serilog記錄所選的端點名稱[敬請期待]
第3部分-使用Serilog.AspNetCore記錄MVC屬性[敬請期待]
作者:依樂祝
譯文地址: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 sinksLog.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 blocktry{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 middlewareapp.UseStaticFiles();app.UseSerilogRequestLogging(); // <-- Add this lineapp.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”獲取下載地址。
完成整理工作所剩下的就是過濾掉我們當前正在記錄的信息級日志消息。在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中生成的更多基礎結構日志,而不會丟失有用的信息。
好看你就點點我總結
以上是生活随笔為你收集整理的如何利用Serilog的RequestLogging来精简ASP.NET Core的日志输出的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: 什么?原来C#还有这两个关键字
- 下一篇: net下的高性能轻量化半自动orm+li