如何利用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 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”獲取下載地址。
完成整理工作所剩下的就是過濾掉我們當前正在記錄的資訊級日誌訊息。在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中生成的更多基礎結構日誌，而不會丟失有用的資訊。