19 | 日志作用域：解決不同請求之間的日志干擾

開始之前先看一下上一節的代碼

// 配置的框架 var configBuilder = new ConfigurationBuilder(); configBuilder.AddCommandLine(args); configBuilder.AddJsonFile("appsettings.json", optional: false, reloadOnChange: true);var config = configBuilder.Build(); IServiceCollection serviceCollection = new ServiceCollection(); serviceCollection.AddSingleton<IConfiguration>(p => config);// 日志的框架 serviceCollection.AddLogging(builder => {builder.AddConfiguration(config.GetSection("Logging"));// 注冊 Logging 配置的 Sectionbuilder.AddConsole();// 先使用一個 Console 的日志輸出提供程序builder.AddDebug(); });

我們可以觀察到配置的框架和日志的框架，它們的設計模式是很相似的

區別就是：

配置的框架是從不同的數據源讀取數據并且供給我們結構化的數據可以讀取

日志框架是用統一的記錄方式，讓我們可以把日志記錄到不同的地方去，輸出到不同的地方去

接下來演示一下關于日志的作用域的部分

日志作用域幾個常用場景：

1、一個事務包含多條操作時：比如說在一個事務里面去操作的時候，會需要記錄多條日志，需要把多條日志串聯在一起，而不是記錄成一行

2、復雜流程的日志關聯時：比如說工作流流程里面去進入這個日志

3、調用鏈追蹤與請求處理過程對應時：如果在調用鏈追蹤過程中記錄了多條日志，希望把日志串聯在一起的時候，作用域就發揮了作用

源碼鏈接：
https://github.com/witskeeper/geektime/tree/master/samples/LoggingScopeDemo

主程序

namespace LoggingScopeDemo {class Program{static void Main(string[] args){var configBuilder = new ConfigurationBuilder();configBuilder.AddCommandLine(args);configBuilder.AddJsonFile("appsettings.json", optional: false, reloadOnChange: true);var config = configBuilder.Build();IServiceCollection serviceCollection = new ServiceCollection();serviceCollection.AddSingleton(p => config); //用工廠模式將配置對象注冊到容器管理serviceCollection.AddLogging(builder =>{builder.AddConfiguration(config.GetSection("Logging"));builder.AddConsole();builder.AddDebug();});IServiceProvider service = serviceCollection.BuildServiceProvider();var logger = service.GetService<ILogger<Program>>();// 相當于記錄了一條上下文串聯的日志using (logger.BeginScope("ScopeId:{scopeId}", Guid.NewGuid())){logger.LogInformation("這是Info");logger.LogError("這是Error");logger.LogTrace("這是Trace");}}} }

配置文件

{"Logging": {"LogLevel": {"Default": "Debug","Microsoft": "Warning","Microsoft.Hosting.Lifetime": "Information"},"Console": {"IncludeScopes": false,"LogLevel": {"Default": "Information","LoggingScopeDemo.Program": "Trace","alogger": "Trace"}}} }

啟動程序，輸出如下：

info: LoggingScopeDemo.Program[0]這是Info fail: LoggingScopeDemo.Program[0]這是Error trce: LoggingScopeDemo.Program[0]這是Trace

和之前一樣的輸出，接著修改配置文件

"IncludeScopes": true,

啟動程序，輸出如下：

info: LoggingScopeDemo.Program[0]=> ScopeId:b8ef7682-6c6d-4f74-83c8-b9fd4613c623這是Info fail: LoggingScopeDemo.Program[0]=> ScopeId:b8ef7682-6c6d-4f74-83c8-b9fd4613c623這是Error trce: LoggingScopeDemo.Program[0]=> ScopeId:b8ef7682-6c6d-4f74-83c8-b9fd4613c623這是Trace

可以看到，日志里面有 scope，并且三條日志都包含了相同的 ScopeId，這個是由我們決定 Scope 的內容是什么，一般推薦使用一個唯一標識，比如 HTTP 請求的 id，或者是 session 的 id，或者是事務的 id

接著修改為循環

// 只要輸入不是 Esc 就循環執行 while (Console.ReadKey().Key != ConsoleKey.Escape) {// 相當于記錄了一條上下文串聯的日志using (logger.BeginScope("ScopeId:{scopeId}", Guid.NewGuid())){logger.LogInformation("這是Info");logger.LogError("這是Error");logger.LogTrace("這是Trace");}Console.WriteLine("============分割線============="); } Console.ReadKey();

啟動程序，輸出如下：

info: LoggingScopeDemo.Program[0]=> ScopeId:cc25dd86-d3fe-41e8-b607-61912c65bde7這是Info ============分割線============= fail: LoggingScopeDemo.Program[0]=> ScopeId:cc25dd86-d3fe-41e8-b607-61912c65bde7這是Error trce: LoggingScopeDemo.Program[0]=> ScopeId:cc25dd86-d3fe-41e8-b607-61912c65bde7這是Trace

這里可以看到分割線有點錯亂，這是因為 Console 的提供程序實際上內部是用異步的方式在記錄，那也就是這里遇到并發的問題

調整一下代碼，讓主線程休息一下

System.Threading.Thread.Sleep(100); Console.WriteLine("============分割線=============");

這樣子啟動之后順序就正確了

在程序啟動的情況下，修改 Debug 目錄下的配置文件

"IncludeScopes": false,

修改保存后在控制臺輸入回車，可以看到配置生效了，意味著可以使用配置熱更新能力來動態修改配置的輸出，調整配置輸出的級別

比如將

"LoggingScopeDemo.Program": "Trace",

修改為

"LoggingScopeDemo.Program": "Error",

修改保存后在控制臺輸入回車，只會輸出 Error 級別

這是在控制臺里面的效果，接下來看一下在一個 ASP.NET Core Web 應用下面的日志是什么樣子

源碼鏈接：
https://github.com/witskeeper/geektime/tree/master/samples/LoggingDemo

這是一個默認的工程，僅僅在應用程序里面加了兩行代碼

[HttpGet] public async Task<IEnumerable<WeatherForecast>> Get() {_logger.LogInformation("開始Get了");_logger.LogInformation("Get睡醒了");var rng = new Random();return Enumerable.Range(1, 5).Select(index => new WeatherForecast{Date = DateTime.Now.AddDays(index),TemperatureC = rng.Next(-20, 55),Summary = Summaries[rng.Next(Summaries.Length)]}).ToArray();}

日志級別

"Console": {"IncludeScopes": true}

啟動程序，輸出如下：

info: LoggingDemo.Controllers.WeatherForecastController[0]=> RequestPath:/weatherforecast RequestId:0HLU2MTQ99HO2:00000001, SpanId:|7bb9cb12-4a0fe499cae27707., TraceId:7bb9cb12-4a0fe499cae27707, ParentId: => LoggingDemo.Controllers.WeatherForecastController.Get (LoggingDemo)開始Get了 info: LoggingDemo.Controllers.WeatherForecastController[0]=> RequestPath:/weatherforecast RequestId:0HLU2MTQ99HO2:00000001, SpanId:|7bb9cb12-4a0fe499cae27707., TraceId:7bb9cb12-4a0fe499cae27707, ParentId: => LoggingDemo.Controllers.WeatherForecastController.Get (LoggingDemo)Get睡醒了

可以看到，記錄的 開始Get了 以及 Get睡醒了，都包含了 RequestPath，RequestId，SpanId，TraceId 這些信息，這些信息是當前請求的上下文

也就意味著可以在記錄日志的時候，用請求上下文把日志串聯起來，多個請求的日志可以區分開來，無論記錄了多條還是單條

也就意味著可以在事務處理的過程中，復雜的流程的過程中，或者調用鏈的處理過程中，當然還有其他的場景任意的需要將多條日志串聯起來的場景，都可以用作用域來實現這個能力

總結

以上是生活随笔為你收集整理的.NET Core开发实战（第19课：日志作用域：解决不同请求之间的日志干扰）--学习笔记...的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。