19 | 日志作用域：解決不同請(qǐng)求之間的日志干擾

開(kāi)始之前先看一下上一節(jié)的代碼

// 配置的框架 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"));// 注冊(cè) Logging 配置的 Sectionbuilder.AddConsole();// 先使用一個(gè) Console 的日志輸出提供程序builder.AddDebug(); });

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

區(qū)別就是：

配置的框架是從不同的數(shù)據(jù)源讀取數(shù)據(jù)并且供給我們結(jié)構(gòu)化的數(shù)據(jù)可以讀取

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

接下來(lái)演示一下關(guān)于日志的作用域的部分

日志作用域幾個(gè)常用場(chǎng)景：

1、一個(gè)事務(wù)包含多條操作時(shí)：比如說(shuō)在一個(gè)事務(wù)里面去操作的時(shí)候，會(huì)需要記錄多條日志，需要把多條日志串聯(lián)在一起，而不是記錄成一行

2、復(fù)雜流程的日志關(guān)聯(lián)時(shí)：比如說(shuō)工作流流程里面去進(jìn)入這個(gè)日志

3、調(diào)用鏈追蹤與請(qǐng)求處理過(guò)程對(duì)應(yīng)時(shí)：如果在調(diào)用鏈追蹤過(guò)程中記錄了多條日志，希望把日志串聯(lián)在一起的時(shí)候，作用域就發(fā)揮了作用

源碼鏈接：
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); //用工廠模式將配置對(duì)象注冊(cè)到容器管理serviceCollection.AddLogging(builder =>{builder.AddConfiguration(config.GetSection("Logging"));builder.AddConsole();builder.AddDebug();});IServiceProvider service = serviceCollection.BuildServiceProvider();var logger = service.GetService<ILogger<Program>>();// 相當(dāng)于記錄了一條上下文串聯(lián)的日志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"}}} }

啟動(dòng)程序，輸出如下：

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

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

"IncludeScopes": true,

啟動(dòng)程序，輸出如下：

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，這個(gè)是由我們決定 Scope 的內(nèi)容是什么，一般推薦使用一個(gè)唯一標(biāo)識(shí)，比如 HTTP 請(qǐng)求的 id，或者是 session 的 id，或者是事務(wù)的 id

接著修改為循環(huán)

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

啟動(dòng)程序，輸出如下：

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

這里可以看到分割線有點(diǎn)錯(cuò)亂，這是因?yàn)?Console 的提供程序?qū)嶋H上內(nèi)部是用異步的方式在記錄，那也就是這里遇到并發(fā)的問(wèn)題

調(diào)整一下代碼，讓主線程休息一下

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

這樣子啟動(dòng)之后順序就正確了

在程序啟動(dòng)的情況下，修改 Debug 目錄下的配置文件

"IncludeScopes": false,

修改保存后在控制臺(tái)輸入回車，可以看到配置生效了，意味著可以使用配置熱更新能力來(lái)動(dòng)態(tài)修改配置的輸出，調(diào)整配置輸出的級(jí)別

比如將

"LoggingScopeDemo.Program": "Trace",

修改為

"LoggingScopeDemo.Program": "Error",

修改保存后在控制臺(tái)輸入回車，只會(huì)輸出 Error 級(jí)別

這是在控制臺(tái)里面的效果，接下來(lái)看一下在一個(gè) ASP.NET Core Web 應(yīng)用下面的日志是什么樣子

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

這是一個(gè)默認(rèn)的工程，僅僅在應(yīng)用程序里面加了兩行代碼

[HttpGet] public async Task<IEnumerable<WeatherForecast>> Get() {_logger.LogInformation("開(kāi)始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();}

日志級(jí)別

"Console": {"IncludeScopes": true}

啟動(dòng)程序，輸出如下：

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

可以看到，記錄的 開(kāi)始Get了 以及 Get睡醒了，都包含了 RequestPath，RequestId，SpanId，TraceId 這些信息，這些信息是當(dāng)前請(qǐng)求的上下文

也就意味著可以在記錄日志的時(shí)候，用請(qǐng)求上下文把日志串聯(lián)起來(lái)，多個(gè)請(qǐng)求的日志可以區(qū)分開(kāi)來(lái)，無(wú)論記錄了多條還是單條

也就意味著可以在事務(wù)處理的過(guò)程中，復(fù)雜的流程的過(guò)程中，或者調(diào)用鏈的處理過(guò)程中，當(dāng)然還有其他的場(chǎng)景任意的需要將多條日志串聯(lián)起來(lái)的場(chǎng)景，都可以用作用域來(lái)實(shí)現(xiàn)這個(gè)能力

總結(jié)

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

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。