零基礎寫框架(3): Serilog.NET 中的日誌使用技巧

痴者工良發表於2024-06-18

.NET 中的日誌使用技巧

Serilog

Serilog 是 .NET 社群中使用最廣泛的日誌框架,所以筆者使用一個小節單獨講解使用方法。

示例專案在 Demo2.Console 中。

建立一個控制檯程式,引入兩個包:

Serilog.Sinks.Console
Serilog.Sinks.File

除此之外,還有 Serilog.Sinks.ElasticsearchSerilog.Sinks.RabbitMQ 等。Serilog 提供了用於將日誌事件以各種格式寫入儲存的接收器。下面列出的許多接收器都是由更廣泛的 Serilog 社群開發和支援的;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 檔案內容複製到 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" ... ...

對請求上下文新增屬性資訊,比如當前請求的使用者資訊,在本次請求作用域中使用日誌列印資訊時,日誌會包含這些上下文資訊,這對於分析日誌還有幫助,可以很容易分析日誌中那些條目是同一個上下文。在微服務場景下,會使用 ElasticSearch 等日誌儲存引擎查詢分析日誌,如果在日誌中新增了相關的上下文屬性,那麼在分析日誌時可以透過對應的屬性查詢出來,分析日誌時可以幫助排除故障。

如果需要列印 http 的請求和響應日誌,我們可以使用 ASP.NET Core 自帶的 HttpLoggingMiddleware 中介軟體。

首先注入請求日誌攔截服務。

builder.Services.AddHttpLogging(logging =>
{
    logging.LoggingFields = HttpLoggingFields.All;
	// 避免列印大量的請求和響應內容,只列印 4kb
    logging.RequestBodyLogLimit = 4096;
    logging.ResponseBodyLogLimit = 4096;
});

透過組合 HttpLoggingFields 列舉,可以配置中介軟體列印 Request、Query、HttpMethod、Header、Response 等資訊。

可以將HttpLogging 中介軟體放在 Swagger、Static 之後,這樣的話可以避免列印哪些用處不大的請求,只保留 API 請求相關的日誌。

app.UseHttpLogging();

HttpLoggingMiddleware 中的日誌模式是以 Information 級別列印的,在專案上線之後,如果每個請求都被列印資訊的話,會降低系統效能,因此我們可以在配置檔案中覆蓋配置,避免列印普通的日誌。

"Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware": "Information"

上下文屬性和作用域

示例專案在 Demo2.ScopeLog 中。

日誌範圍注意事項
Microsoft.Extensions.Logging.Abstractions 提供 BeginScopeAPI,可用於新增任意屬性以記錄特定程式碼區域內的事件。

解釋其作用

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");
            }
        }
    }

image-20231220212411976

而在 Serilog 中,除了支援上述介面外,還透過 LogContext 提供了在日誌中注入上下文屬性的方法。其作用是新增屬性之後,使得在其作用域之內列印日誌時,日誌會攜帶這些上下文屬性資訊。

        using (LogContext.PushProperty("Test", 1))
        {
            // Process request; all logged events will carry `RequestId`
            Log.Information("{Test} Adding {Item} to cart {CartId}", 1,1);
        }

巢狀複雜一些:

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");
}

當需要設定大量屬性時,下面的方式會比較麻煩;

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);
        }
    }

在業務系統中,可以透過在中介軟體獲取 Token 中的使用者資訊,然後注入到日誌上下文中,這樣列印出來的日誌,會攜帶使用者資訊。

非侵入式日誌

非侵入式的日誌有多種方法,比如 ASP.NET Core 中介軟體管道,或者使用 AOP 框架。

這裡可以使用筆者開源的 CZGL.AOP 框架,Nuget 中可以搜尋到。

czgl.aop

示例專案在 Demo2.AopLog 中。

有一個型別,我們需要在執行 SayHello 之前和之後列印日誌,將引數和返回值記錄下來。

    public class Hello
    {
		public virtual string SayHello(string content)
		{
			var str = $"Hello,{content}";
			return str;
		}
    }

編寫統一的切入程式碼,這些程式碼將在函式被呼叫時執行。

Before 會在被代理的方法執行前或被代理的屬性呼叫時生效,你可以透過 AspectContext 上下文,獲取、修改傳遞的引數。

After 在方法執行後或屬性呼叫時生效,你可以透過上下文獲取、修改返回值。

	public class LogAttribute : ActionAttribute
	{
		public override void Before(AspectContext context)
		{
			Console.WriteLine($"{context.MethodInfo.Name} 函式被執行前");
			foreach (var item in context.MethodValues)
				Console.WriteLine(item.ToString());
		}

		public override object After(AspectContext context)
		{
			Console.WriteLine($"{context.MethodInfo.Name} 函式被執行後");
			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;
		}
	}

然後建立代理型別:

        static void Main(string[] args)
        {
            Hello hello = AopInterceptor.CreateProxyOfClass<Hello>();
            hello.SayHello("any one");
            Console.Read();
        }

啟動程式,會輸出:

SayHello 函式被執行前
any one
SayHello 函式被執行後
Hello,any one

你完全不需要擔心 AOP 框架會給你的程式帶來效能問題,因為 CZGL.AOP 框架採用 EMIT 編寫,並且自帶快取,當一個型別被代理過,之後無需重複生成。

CZGL.AOP 可以透過 .NET Core 自帶的依賴注入框架和 Autofac 結合使用,自動代理 CI 容器中的服務。這樣不需要 AopInterceptor.CreateProxyOfClass 手動呼叫代理介面。

CZGL.AOP 程式碼是開源的,可以參考筆者另一篇博文:

https://www.cnblogs.com/whuanle/p/13160139.html

相關文章