初始化
要用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 | 特征 |
|---|---|
| JsonFormatter | 基礎的Json格式，只有模版，沒有日志全文 |
| JsonFormatter(renderMessage: true) | 相比JsonFormatter增加了RenderedMessage節點存儲日志全文 |
| CompactJsonFormatter | 相比JsonFormatter，縮短了屬性名，比如用@t代替Timestamp |
| RenderedCompactJsonFormatter | 相比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" ]
]
}
}