零基礎(chǔ)寫框架(3): Serilog.NET 中的日志使用技巧
.NET 中的日志使用技巧
Serilog
Serilog 是 .NET 社區(qū)中使用最廣泛的日志框架，所以筆者使用一個小節(jié)單獨講解使用方法。
示例項目在 Demo2.Console 中。
創(chuàng)建一個控制臺程序，引入兩個包：
Serilog.Sinks.Console
Serilog.Sinks.File
除此之外，還有
Serilog.Sinks.Elasticsearch、Serilog.Sinks.RabbitMQ等。Serilog 提供了用于將日志事件以各種格式寫入存儲的接收器。下面列出的許多接收器都是由更廣泛的 Serilog 社區(qū)開發(fā)和支持的；https://github.com/serilog/serilog/wiki/Provided-Sinks
可以直接使用代碼配置 Serilog：
private static Serilog.ILogger GetLogger()
{
const string LogTemplate = "{SourceContext} {Scope} {Timestamp:HH:mm} [{Level}] {Message:lj} {Properties:j} {NewLine}{Exception}";
var logger = new LoggerConfiguration()
.Enrich.WithMachineName()
.Enrich.WithThreadId()
.Enrich.FromLogContext()
#if DEBUG
.MinimumLevel.Debug()
#else
.MinimumLevel.Information()
#endif
.WriteTo.Console(outputTemplate: LogTemplate)
.WriteTo.File("log.txt", rollingInterval: RollingInterval.Day, outputTemplate: LogTemplate)
.CreateLogger();
return logger;
}
如果想從配置文件中加載，添加 Serilog.Settings.Configuration：
private static Serilog.ILogger GetJsonLogger()
{
IConfiguration configuration = new ConfigurationBuilder()
.SetBasePath(AppContext.BaseDirectory)
.AddJsonFile(path: "serilog.json", optional: true, reloadOnChange: true)
.Build();
if (configuration == null)
{
throw new ArgumentNullException($"未能找到 serilog.json 日志配置文件");
}
var logger = new LoggerConfiguration()
.ReadFrom.Configuration(configuration)
.CreateLogger();
return logger;
}
serilog.json 配置文件示例：
{
"Serilog": {
"Using": [ "Serilog.Sinks.Console", "Serilog.Sinks.File" ],
"MinimumLevel": {
"Default": "Debug"
},
"Enrich": [ "FromLogContext", "WithMachineName", "WithThreadId" ],
"WriteTo": [
{
"Name": "Console",
"Args": {
"outputTemplate": "{SourceContext} {Scope} {Timestamp:HH:mm} [{Level}] {Message:lj} {Properties:j} {NewLine}{Exception}"
}
},
{
"Name": "File",
"Args": {
"path": "logs/log-.txt",
"rollingInterval": "Day",
"outputTemplate": "{SourceContext} {Scope} {Timestamp:HH:mm} [{Level}] {Message:lj} {Properties:j} {NewLine}{Exception}"
}
}
]
}
}
依賴注入 Serilog。
引入 Serilog.Extensions.Logging 包。
private static Microsoft.Extensions.Logging.ILogger InjectLogger()
{
var logger = GetJsonLogger();
var ioc = new ServiceCollection();
ioc.AddLogging(builder => builder.AddSerilog(logger: logger, dispose: true));
var loggerProvider = ioc.BuildServiceProvider().GetRequiredService<ILoggerProvider>();
return loggerProvider.CreateLogger("Program");
}
最后，使用不同方式配置 Serilog 日志，然后啟動程序打印日志。
static void Main()
{
var log1 = GetLogger();
log1.Debug("溪源More、癡者工良");
var log2 = GetJsonLogger();
log2.Debug("溪源More、癡者工良");
var log3 = InjectLogger();
log3.LogDebug("溪源More、癡者工良");
}
20:50 [Debug] 溪源More、癡者工良 {"MachineName": "WIN-KQDULADM5LA", "ThreadId": 1}
20:50 [Debug] 溪源More、癡者工良 {"MachineName": "WIN-KQDULADM5LA", "ThreadId": 1}
20:50 [Debug] 溪源More、癡者工良 {"MachineName": "WIN-KQDULADM5LA", "ThreadId": 1}
在 ASP.NET Core 中使用日志
示例項目在 Demo2.Api 中。
新建一個 ASP.NET Core API 新項目，引入 Serilog.AspNetCore 包。
在 Program 中添加代碼注入 Serilog 。
var builder = WebApplication.CreateBuilder(args);
Log.Logger = new LoggerConfiguration()
.ReadFrom.Configuration(builder.Configuration)
.CreateLogger();
builder.Host.UseSerilog(Log.Logger);
//builder.Host.UseSerilog();
將前面示例中的 serilog.json 文件內(nèi)容復(fù)制到 appsettings.json 中。
啟動程序后，嘗試訪問 API 接口，會打印示例如下的日志：
Microsoft.AspNetCore.Hosting.Diagnostics 20:32 [Information] Request finished HTTP/1.1 GET http://localhost:5148/WeatherForecast - - - 200 - application/json;+charset=utf-8 1029.4319ms {"ElapsedMilliseconds": 1029.4319, "StatusCode": 200, "ContentType": "application/json; charset=utf-8", "ContentLength": null, "Protocol": "HTTP/1.1", "Method": "GET", "Scheme": "http", "Host": "localhost:5148", "PathBase": "", "Path": "/WeatherForecast", "QueryString": "", "EventId": {"Id": 2}, "RequestId": "0HMOONQO5ONKU:00000003", "RequestPath": "/WeatherForecast", "ConnectionId": "0HMOONQO5ONKU"}
如果需要為請求上下文添加一些屬性信息，可以添加一個中間件，示例如下：
app.UseSerilogRequestLogging(options =>
{
options.EnrichDiagnosticContext = (diagnosticContext, httpContext) =>
{
diagnosticContext.Set("TraceId", httpContext.TraceIdentifier);
};
});
HTTP GET /WeatherForecast responded 200 in 181.9992 ms {"TraceId": "0HMSD1OUG2DHG:00000003" ... ...
對請求上下文添加屬性信息，比如當(dāng)前請求的用戶信息，在本次請求作用域中使用日志打印信息時，日志會包含這些上下文信息，這對于分析日志還有幫助，可以很容易分析日志中那些條目是同一個上下文。在微服務(wù)場景下，會使用 ElasticSearch 等日志存儲引擎查詢分析日志，如果在日志中添加了相關(guān)的上下文屬性，那么在分析日志時可以通過對應(yīng)的屬性查詢出來，分析日志時可以幫助排除故障。
如果需要打印 http 的請求和響應(yīng)日志，我們可以使用 ASP.NET Core 自帶的 HttpLoggingMiddleware 中間件。
首先注入請求日志攔截服務(wù)。
builder.Services.AddHttpLogging(logging =>
{
logging.LoggingFields = HttpLoggingFields.All;
// 避免打印大量的請求和響應(yīng)內(nèi)容，只打印 4kb
logging.RequestBodyLogLimit = 4096;
logging.ResponseBodyLogLimit = 4096;
});
通過組合 HttpLoggingFields 枚舉，可以配置中間件打印 Request、Query、HttpMethod、Header、Response 等信息。
可以將HttpLogging 中間件放在 Swagger、Static 之后，這樣的話可以避免打印哪些用處不大的請求，只保留 API 請求相關(guān)的日志。
app.UseHttpLogging();
HttpLoggingMiddleware 中的日志模式是以 Information 級別打印的，在項目上線之后，如果每個請求都被打印信息的話，會降低系統(tǒng)性能，因此我們可以在配置文件中覆蓋配置，避免打印普通的日志。
"Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware": "Information"
上下文屬性和作用域
示例項目在 Demo2.ScopeLog 中。
日志范圍注意事項
Microsoft.Extensions.Logging.Abstractions 提供 BeginScopeAPI，可用于添加任意屬性以記錄特定代碼區(qū)域內(nèi)的事件。
解釋其作用
API 有兩種形式：
IDisposable BeginScope<TState>(TState state)
IDisposable BeginScope(this ILogger logger, string messageFormat, params object[] args)
使用如下的模板：
{SourceContext} {Timestamp:HH:mm} [{Level}] (ThreadId:{ThreadId}) {Message}{NewLine}{Exception} {Scope}
使用示例：
static void Main()
{
var logger = GetLogger();
using (logger.BeginScope("Checking mail"))
{
// Scope is "Checking mail"
logger.LogInformation("Opening SMTP connection");
using (logger.BeginScope("Downloading messages"))
{
// Scope is "Checking mail" -> "Downloading messages"
logger.LogError("Connection interrupted");
}
}
}
而在 Serilog 中，除了支持上述接口外，還通過 LogContext 提供了在日志中注入上下文屬性的方法。其作用是添加屬性之后，使得在其作用域之內(nèi)打印日志時，日志會攜帶這些上下文屬性信息。
using (LogContext.PushProperty("Test", 1))
{
// Process request; all logged events will carry `RequestId`
Log.Information("{Test} Adding {Item} to cart {CartId}", 1,1);
}
嵌套復(fù)雜一些：
using (LogContext.PushProperty("A", 1))
{
log.Information("Carries property A = 1");
using (LogContext.PushProperty("A", 2))
using (LogContext.PushProperty("B", 1))
{
log.Information("Carries A = 2 and B = 1");
}
log.Information("Carries property A = 1, again");
}
當(dāng)需要設(shè)置大量屬性時，下面的方式會比較麻煩；
using (LogContext.PushProperty("Test1", 1))
using (LogContext.PushProperty("Test2", 2))
{
}
例如在 ASP.NET Core 中間件中，我們可以批量添加：
public async Task InvokeAsync(HttpContext context, RequestDelegate next)
{
var enrichers = new List<ILogEventEnricher>();
if (!string.IsNullOrEmpty(correlationId))
{
enrichers.Add(new PropertyEnricher(_options.EnricherPropertyNames.CorrelationId, correlationId));
}
using (LogContext.Push(enrichers.ToArray()))
{
await next(context);
}
}
在業(yè)務(wù)系統(tǒng)中，可以通過在中間件獲取 Token 中的用戶信息，然后注入到日志上下文中，這樣打印出來的日志，會攜帶用戶信息。
非侵入式日志
非侵入式的日志有多種方法，比如 ASP.NET Core 中間件管道，或者使用 AOP 框架。
這里可以使用筆者開源的 CZGL.AOP 框架，Nuget 中可以搜索到。
示例項目在 Demo2.AopLog 中。
有一個類型，我們需要在執(zhí)行 SayHello 之前和之后打印日志，將參數(shù)和返回值記錄下來。
public class Hello
{
public virtual string SayHello(string content)
{
var str = $"Hello,{content}";
return str;
}
}
編寫統(tǒng)一的切入代碼，這些代碼將在函數(shù)被調(diào)用時執(zhí)行。
Before 會在被代理的方法執(zhí)行前或被代理的屬性調(diào)用時生效，你可以通過 AspectContext 上下文，獲取、修改傳遞的參數(shù)。
After 在方法執(zhí)行后或?qū)傩哉{(diào)用時生效，你可以通過上下文獲取、修改返回值。
public class LogAttribute : ActionAttribute
{
public override void Before(AspectContext context)
{
Console.WriteLine($"{context.MethodInfo.Name} 函數(shù)被執(zhí)行前");
foreach (var item in context.MethodValues)
Console.WriteLine(item.ToString());
}
public override object After(AspectContext context)
{
Console.WriteLine($"{context.MethodInfo.Name} 函數(shù)被執(zhí)行后");
Console.WriteLine(context.MethodResult.ToString());
return context.MethodResult;
}
}
改造 Hello 類，代碼如下：
[Interceptor]
public class Hello
{
[Log]
public virtual string SayHello(string content)
{
var str = $"Hello,{content}";
return str;
}
}
然后創(chuàng)建代理類型：
static void Main(string[] args)
{
Hello hello = AopInterceptor.CreateProxyOfClass<Hello>();
hello.SayHello("any one");
Console.Read();
}
啟動程序，會輸出：
SayHello 函數(shù)被執(zhí)行前
any one
SayHello 函數(shù)被執(zhí)行后
Hello,any one
你完全不需要擔(dān)心 AOP 框架會給你的程序帶來性能問題，因為 CZGL.AOP 框架采用 EMIT 編寫，并且自帶緩存，當(dāng)一個類型被代理過，之后無需重復(fù)生成。
CZGL.AOP 可以通過 .NET Core 自帶的依賴注入框架和 Autofac 結(jié)合使用，自動代理 CI 容器中的服務(wù)。這樣不需要 AopInterceptor.CreateProxyOfClass 手動調(diào)用代理接口。
CZGL.AOP 代碼是開源的，可以參考筆者另一篇博文：
浙公網(wǎng)安備 33010602011771號