Serilog在 ASP.NET CORE的使用

初始化

要用Serilog替換原生的Log，需要做如下配置：

添加Nuget：

dotnet add package Serilog.AspNetCore

修改Main方法

public static void Main(string[] args)
{
  Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Information()
    .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
    .MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
    .Enrich.FromLogContext()
    .WriteTo.Console()
    .CreateLogger();
  try
  {
    Log.Information("Starting web host");
    CreateHostBuilder(args).Build().Run();
  }
  catch (Exception ex)
  {
    Log.Fatal(ex, "Host terminated unexpectedly");
  }
  finally
  {
    Log.Information("Ending web host");
    Log.CloseAndFlush();
  }
}

UseSerilog()

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

經過這兩處修改，就完成了用Serilog對原生的Log的替換。

主動記錄日志

在需要記錄日志的地方通過這樣的代碼可以獲得log執行個體

private readonly ILogger log = Log.Logger;

Serilog定義的日志級别有：

Verbose
Debug
Information
Warning
Error
Fatal

原生log和Serilog的輸出對比

在Web API模版項目中，LogLeve為預設

"Microsoft": "Information"

的情況下，針對一次API請求：對比下原生log和Serilog的輸出：

原生Log：

info: Microsoft.AspNetCore.Hosting.Diagnostics[1]
      Request starting HTTP/1.1 GET http://localhost:5000/weatherforecast  
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[0]
      Executing endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[3]
      Route matched with {action = "Get", controller = "WeatherForecast"}. Executing controller action with signature System.Collections.Generic.IEnumerable`1[SerilogTest.WeatherForecast] Get() on controller SerilogTest.Controllers.WeatherForecastController (SerilogTest).
info: Microsoft.AspNetCore.Mvc.Infrastructure.ObjectResultExecutor[1]
      Executing ObjectResult, writing value of type 'SerilogTest.WeatherForecast[]'.
info: Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker[2]
      Executed action SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest) in 21.2528ms
info: Microsoft.AspNetCore.Routing.EndpointMiddleware[1]
      Executed endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
info: Microsoft.AspNetCore.Hosting.Diagnostics[2]
      Request finished in 102.3501ms 200 application/json; charset=utf-8

Serilog：

[22:12:13 INF] Request starting HTTP/1.1 GET http://localhost:5000/weatherforecast  
[22:12:13 INF] Executing endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
[22:12:13 INF] Route matched with {action = "Get", controller = "WeatherForecast"}. Executing controller action with signature System.Collections.Generic.IEnumerable`1[SerilogTest.WeatherForecast] Get() on controller SerilogTest.Controllers.WeatherForecastController (SerilogTest).
[22:12:13 INF] Executing ObjectResult, writing value of type 'SerilogTest.WeatherForecast[]'.
[22:12:13 INF] Executed action SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest) in 22.6404ms
[22:12:13 INF] Executed endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
[22:12:13 INF] Request finished in 104.071ms 200 application/json; charset=utf-8

兩者Log數量都是7條，Serilog相比原生log增加了時間資訊，但缺少了輸出日志元件的名稱，整體來看Serilog的日志要更加緊湊。

使用RequestLoggingMiddleware

每次API請求都輸出這麼多日志資訊，其中很多資訊都是不被關心的，這些資訊不僅會妨礙對有用資訊的查找，還會為日志的存儲造成負擔。Serilog提供的RequestLogging中間件可以為每個請求記錄一條單一的摘要日志。

首先，添加中間件:

app.UseSerilogRequestLogging()

public void Configure(IApplicationBuilder app, IWebHostEnvironment env)
{
  if (env.IsDevelopment())
  {
    app.UseDeveloperExceptionPage();
  }
  app.UseSerilogRequestLogging();
  ...

與管道中的其他中間件一樣，順序很重要。當請求到達RequestLoggingMiddleware中間件時，它将啟動計時器，并将請求傳遞給後續中間件進行處理。當後面的中間件最終生成響應（或抛出異常），則響應通過中間件管道傳遞回到請求記錄器，并在其中記錄了結果并輸出日志。是以這個中間件要放在盡量靠前的位置。

輸出效果

倒數第二條日志就是RequestLoggingMiddleware輸出的

[11:25:43 INF] Request starting HTTP/1.1 GET http://localhost:5000/weatherforecast  
[11:25:43 INF] Executing endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
[11:25:43 INF] Route matched with {action = "Get", controller = "WeatherForecast"}. Executing controller action with signature System.Collections.Generic.IEnumerable`1[SerilogTest.WeatherForecast] Get() on controller SerilogTest.Controllers.WeatherForecastController (SerilogTest).
[11:25:43 INF] Executing ObjectResult, writing value of type 'SerilogTest.WeatherForecast[]'.
[11:25:43 INF] Executed action SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest) in 22.9249ms
[11:25:43 INF] Executed endpoint 'SerilogTest.Controllers.WeatherForecastController.Get (SerilogTest)'
[11:25:43 INF] HTTP GET /weatherforecast responded 200 in 172.8042 ms
[11:25:43 INF] Request finished in 184.1417ms 200 application/json; charset=utf-8

有了RequestLoggingMiddleware輸出的日志，就可以關閉系統記錄的Information級别的日志了，這可以通過在Program.cs中設定LoggerConfiguration時增加

MinimumLevel.Override("Microsoft", LogEventLevel.Warning)

過濾器來實作：

Log.Logger = new LoggerConfiguration()
  .MinimumLevel.Information()
  .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
  .Enrich.FromLogContext()
  .WriteTo.Console()
  .CreateLogger();

之後就隻會輸出一條日志：

[11:25:43 INF] HTTP GET /weatherforecast responded 200 in 172.8042 ms

輸出Json格式

作為一款結構化日志元件，對Json格式的支援也是必不可少的，Serilog支援如下四種渲染方式：

JsonFormatter
JsonFormatter(renderMessage: true)
CompactJsonFormatter
RenderedCompactJsonFormatter

可以在配置LoggerConfiguration時開啟Json輸出，這裡把文本格式+四種Json格式都開啟，對比下它們之間的差異

Log.Logger = new LoggerConfiguration()
  .MinimumLevel.Information()
  .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
  .Enrich.FromLogContext()
  .WriteTo.Console()
  .WriteTo.Console(new JsonFormatter())
  .WriteTo.Console(new JsonFormatter(renderMessage: true))
  .WriteTo.Console(new CompactJsonFormatter())
  .WriteTo.Console(new RenderedCompactJsonFormatter())
  .CreateLogger();

對比

// 文本
[12:58:08 INF] GET /weatherforecast responsed 200 in 60.439784 ms, localhost:5000, application/json; charset=utf-8, 1423

// JsonFormatter
{
	"Timestamp": "2020-12-27T12:58:08.2277150+08:00",
	"Level": "Information",
	"MessageTemplate": "{RequestMethod} {RequestPath} responsed {StatusCode} in {Elapsed} ms, {RequestHost}, {ContentType}, {DataLoadTime}",
	"Properties": {
		"DataLoadTime": 1423,
		"RequestHost": "localhost:5000",
		"ContentType": "application/json; charset=utf-8",
		"RequestMethod": "GET",
		"RequestPath": "/weatherforecast",
		"StatusCode": 200,
		"Elapsed": 60.439784,
		"SourceContext": "Serilog.AspNetCore.RequestLoggingMiddleware",
		"RequestId": "0HM5A4G0BVC68:00000001",
		"SpanId": "|dbf998b9-4418b3255ee44f3e.",
		"TraceId": "dbf998b9-4418b3255ee44f3e",
		"ParentId": "",
		"ConnectionId": "0HM5A4G0BVC68"
	}
}

// JsonFormatter(renderMessage: true)
{
	"Timestamp": "2020-12-27T12:58:08.2277150+08:00",
	"Level": "Information",
	"MessageTemplate": "{RequestMethod} {RequestPath} responsed {StatusCode} in {Elapsed} ms, {RequestHost}, {ContentType}, {DataLoadTime}",
	"RenderedMessage": "\"GET\" \"/weatherforecast\" responsed 200 in 60.439784 ms, \"localhost:5000\", \"application/json; charset=utf-8\", 1423",
	"Properties": {
		"DataLoadTime": 1423,
		"RequestHost": "localhost:5000",
		"ContentType": "application/json; charset=utf-8",
		"RequestMethod": "GET",
		"RequestPath": "/weatherforecast",
		"StatusCode": 200,
		"Elapsed": 60.439784,
		"SourceContext": "Serilog.AspNetCore.RequestLoggingMiddleware",
		"RequestId": "0HM5A4G0BVC68:00000001",
		"SpanId": "|dbf998b9-4418b3255ee44f3e.",
		"TraceId": "dbf998b9-4418b3255ee44f3e",
		"ParentId": "",
		"ConnectionId": "0HM5A4G0BVC68"
	}
}

// CompactJsonFormatter
{
	"@t": "2020-12-27T04:58:08.2277150Z",
	"@mt": "{RequestMethod} {RequestPath} responsed {StatusCode} in {Elapsed} ms, {RequestHost}, {ContentType}, {DataLoadTime}",
	"DataLoadTime": 1423,
	"RequestHost": "localhost:5000",
	"ContentType": "application/json; charset=utf-8",
	"RequestMethod": "GET",
	"RequestPath": "/weatherforecast",
	"StatusCode": 200,
	"Elapsed": 60.439784,
	"SourceContext": "Serilog.AspNetCore.RequestLoggingMiddleware",
	"RequestId": "0HM5A4G0BVC68:00000001",
	"SpanId": "|dbf998b9-4418b3255ee44f3e.",
	"TraceId": "dbf998b9-4418b3255ee44f3e",
	"ParentId": "",
	"ConnectionId": "0HM5A4G0BVC68"
}

// RenderedCompactJsonFormatter
{
	"@t": "2020-12-27T04:58:08.2277150Z",
	"@m": "\"GET\" \"/weatherforecast\" responsed 200 in 60.439784 ms, \"localhost:5000\", \"application/json; charset=utf-8\", 1423",
	"@i": "54a66a75",
	"DataLoadTime": 1423,
	"RequestHost": "localhost:5000",
	"ContentType": "application/json; charset=utf-8",
	"RequestMethod": "GET",
	"RequestPath": "/weatherforecast",
	"StatusCode": 200,
	"Elapsed": 60.439784,
	"SourceContext": "Serilog.AspNetCore.RequestLoggingMiddleware",
	"RequestId": "0HM5A4G0BVC68:00000001",
	"SpanId": "|dbf998b9-4418b3255ee44f3e.",
	"TraceId": "dbf998b9-4418b3255ee44f3e",
	"ParentId": "",
	"ConnectionId": "0HM5A4G0BVC68"
}

Formatter	特征
	基礎的Json格式，隻有模版，沒有日志全文
	相比JsonFormatter增加了RenderedMessage節點存儲日志全文
	相比JsonFormatter，縮短了屬性名，比如用@t代替Timestamp
	相比CompactJsonFormatter，有日志全文(@m)，不再包含日志模版

Serilog預設隻輸出了如下幾方面的資訊：

RequestMethod：GET
RequestPath：/weatherforecast
StatusCode：200
Elapsed：172.8042 ms

日志雖然足夠精簡，但相比系統Log也缺少了一些有用的資訊。後面Enrichment一節将介紹擴充的方法。

結構化日志

Serilog用Json格式來表示結構化日志。記錄日志時使用類似C#字元串模版的方式。

預設格式

值類型、string、基于值類型或string的集合和Dictionary會被存儲為Json對象的一個屬性，比如：

var count = 333;
Log.Error("Retrieved {Count} records", count);

var c = new List<string> {"a", "b"};
Log.Information("list is {List}", c);

會被分别存儲為：

{
	...
	"Count":333
	...
}
{
	...
	"List":["a","b"]
	...
}

@運算符

如果要記錄的是一個class的執行個體，用上面的記錄方式會強制調用ToString方法，并不會拿到内部屬性的值。是以對于除值類型和基于值類型的集合、Dictionary之外的資料結構，應該使用@運算符，将這個執行個體内部的值存儲為Json對象

var dto = new FakeDTO { A = "A",B="B"};
Log.Information("test is {FakeDTO}", dto);
// 輸出："FakeDTO":"SerilogTest.Controllers.FakeDTO"
Log.Information("test is {@FakeDTO}", dto);
// 輸出：,"FakeDTO":{"A":"A","B":"B","C":null,"D":null,"E":null,"$type":"FakeDTO"}

...

public class FakeDTO
{
  public string A { get; set; }
  public string B { get; set; }
  public string C { get; set; }
  public string D { get; set; }
  public string E { get; set; }
}

自定義要儲存的屬性

@運算符雖然可以将類轉化為Json，但如果隻需要記錄類中的一部分屬性，比如FakeDTO隻對其A和B感興趣，可以通過在LoggerConfiguration中配置Destructure來讓Json中隻包含需要的屬性。

Log.Logger = new LoggerConfiguration()
        ...
        .Destructure.ByTransforming<FakeDTO>(r => new {A1 = r.A, B1 = r.B})

// 輸出："FakeDTO":{"A1":"A","B1":"B"}

關于性能的注意事項

盡量使用模版的方式，而不是由自己拼接日志内容：

// Do:
Log.Information("The time is {Now}", DateTime.Now);

// Don't:
Log.Information("The time is " + DateTime.Now);

這兩種方式可能在性能上會有差别，比如當提高到Log級别限制為Warning後，即使Info級别的日志不再被輸出，後者仍然會執行拼接字元串的操作，而模版方式不會出現這樣的問題，在日志記錄較多的場合，兩者将會有明顯的性能差距。

Enrichment

Serilog也提供了通過Enricher擴充其請求日志資訊的方法。

列舉部分Enrichers

Enricher	Usage
Serilog.Enrichers.Thread	WithThreadId()
Serilog.Enrichers.Environment	WithMachineName() and WithEnvironmentUserName()
Serilog.Enrichers.Process	WithProcessId()
Serilog.Web.Classic	WithHttpRequestId()
Serilog.Exceptions	WithExceptionDetails()
Serilog.Enrichers.Demystify	WithDemystifiedStackTraces()
Serilog.Enrichers.CorrelationId	WithCorrelationId
Serilog.Enrichers.ClientInfo	WithClientIp() and WithClientAgent()

要使用這些Enricher，需要在配置LoggerConfiguration的時候添加，比如：

Log.Logger = new LoggerConfiguration()
  .Enrich.WithThreadId()
  ...

自定義要擴充資訊

使用Enrich.WithProperty可以更靈活地添加擴充資訊，比如添加IP位址，然後在記Log的地方通過{IP}模版就可以拿到了。

.Enrich.WithProperty("IP", "127.0.0.1")

為RequestLog添加擴充資訊

除了使用Serilog已經提供的Enrichers，還可以通過在引入使用RequestLoggingMiddleware時增加如下配置：

app.UseSerilogRequestLogging(options =>
{
  // Customize the message template
  options.MessageTemplate = "{RequestMethod} {RequestPath} responsed {StatusCode} in {Elapsed} ms, {RequestHost}, {ContentType}";

  // Attach additional properties to the request completion event
  options.EnrichDiagnosticContext = (diagnosticContext, httpContext) =>
  {
    diagnosticContext.Set("RequestHost", httpContext.Request.Host.Value);
    diagnosticContext.Set("ContentType", httpContext.Response.ContentType);
  };
});

這樣RequestHost和ContentType就被添加到RequestLog中了，此處的MessageTemplate必須設定，否則日志中不會包含新添加的資訊。

[12:03:19 INF] GET /weatherforecast responsed 200 in 62.095594 ms, localhost:5000, application/json; charset=utf-8

此外由于Serilog已經将IDiagnosticContext作為單例添加到DI容器中，是以可以從任何類中通路diagnosticContext并為某些屬性設定值，但UseSerilogRequestLogging處設定值的優先級是最高的。

LogContext

使用LogContext還可以在局部動态地覆寫某些屬性的值。

首先添加Enricher

Log.Logger = new LoggerConfiguration()
  .Enrich.FromLogContext()
  ...

然後就可以使用

LogContext.PushProperty

來進行屬性覆寫了，在Log輸出的Properties節點下就會增加剛才Push的屬性。PushProperty會将指定的屬性Push到棧頂，并傳回一個IDisposeable對象，在這個IDisposeable對象被釋放之前，遇到要輸出的Log中存在這一屬性的地方，就會從棧中拿到它的值。對于同一屬性，後Push的值是優先級更高的。

var A = "A1";
log.Information("value = {A}", A); // value = A1
using (LogContext.PushProperty("A", "A2"))
{
  log.Information("value = {A}"); // value = A2
  using (LogContext.PushProperty("A", "A3"))
  {
    log.Information("value = {A}"); // value = A3
  }
  log.Information("value = {A}"); // value = A2
}
log.Information("value = {A}"); // value = {A}

Json配置

Serilog也提供了Json檔案配置的方式，便于在不同的部署環境使用不同的配置。

首先添加關于Json檔案的配置

var configuration = new ConfigurationBuilder()
  .SetBasePath(Directory.GetCurrentDirectory())
  .AddJsonFile("appsettings.json", optional:false)
  .AddJsonFile($"appsettings.{Environment.GetEnvironmentVariable("ASPNETCORE_ENVIRONMENT") ?? "Production"}.json", optional: true)
  .Build();

然後前面用代碼配置的方式就可以被替換掉了，使用了ReadFrom.Configuration(), sectionName指定了配置的根節點，如果沒有設定sectionName則使用預設值“Serilog”。

// Log.Logger = new LoggerConfiguration()
//   .MinimumLevel.Information()
//   .MinimumLevel.Override("Microsoft", LogEventLevel.Warning)
//   .Enrich.FromLogContext()
//   .Destructure.ByTransforming<FakeDTO>(r => new {A1 = r.A, B1 = r.B})
//   .WriteTo.Console()
//   .WriteTo.Console(new RenderedCompactJsonFormatter())
//   .CreateLogger();

Log.Logger = new LoggerConfiguration()
  .ReadFrom.Configuration(configuration, sectionName: "CustomSection")
  .CreateLogger();

Json配置方式的局限

但Json配置的方式相對代碼的方式也有很多局限。在用來配置日志級别、要Override的系統日志級别、Enricher、簡單的WriteTo等是沒有問題的。但自定義的Destructure還有JsonFormatter等還是需要用代碼方式的。

{
  "CustomSection": {
    "MinimumLevel": "Information",
    "WriteTo": [
      { "Name": "Console" }
    ],
    "Override": {
      "Microsoft": "Information"
    },
    "Enrich": [ "FromLogContext", "WithMachineName" ]
    ]
  }
}

參考資料

https://github.com/serilog/serilog/wiki

Serilog在 ASP.NET CORE的使用

初始化

添加Nuget：

修改Main方法

UseSerilog()

主動記錄日志

原生log和Serilog的輸出對比

使用RequestLoggingMiddleware

輸出效果

輸出Json格式

結構化日志

預設格式

@運算符

自定義要儲存的屬性

關于性能的注意事項

Enrichment

列舉部分Enrichers

自定義要擴充資訊

為RequestLog添加擴充資訊

LogContext

Json配置

Json配置方式的局限

繼續閱讀

Asp.Net Core 項目中使用 Serilog 輸出日志到 Elasticsearch

如何使用Serilog.AspNetCore記錄ASP.NET Core3.0的MVC屬性

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

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

Serilog進階玩法之用Serilog記錄所選終結點附加屬性

asp.net core使用serilog将日志推送到騰訊雲日志服務

十八、.net core（.NET 6）搭建ElasticSearch(ES)系列之使用Logstash通過Rabbitmq接收Serilog日志到ES

七、.net core(.NET 6)使用Serilog進行配置和實作日志記錄

ASP.NET MVC的最佳日志記錄庫介紹4個日志記錄庫log4netNLOGSerilogELMAH

.net将日志送出給logstash

基于.NET6平台開發WebApi（三）—— 添加Serilog支援