零基礎寫框架(2)：故障排查和日誌基礎

關於從零設計 .NET 開發框架
作者：痴者工良
教程說明：

倉庫地址：https://github.com/whuanle/maomi

文件地址：https://maomi.whuanle.cn

作者部落格：

https://www.whuanle.cn

https://www.cnblogs.com/whuanle

故障排查和日誌

.NET 程式進行故障排查的方式有很多，筆者個人總結常用的有以下方式：

IDE 除錯、Visual Studio 中的診斷工具、效能探測器

一般來說，使用 IDE 進行斷點除錯和診斷只適合在本地開發環境，我們可以藉助 IDE 中的工具斷點除錯以及收集程式詳細的執行資訊，IDE 是功能最全、最有效的診斷程式問題的工具。

NET CLI 工具如 dotnet-dump、dotnet-trace 等

.NET CLI 工具本身是基於 System.Diagnostics 、Microsoft.Diagnostics 中的介面實現的，可以跨程序監聽收集 .NET 程序的資訊，比如記憶體快照。

使用 System.Diagnostics 、Microsoft.Diagnostics 中的介面

新版本的 .NET 使用這些介面做堆疊追蹤、效能探測等，微軟官方和社群中的很多工具使用了這些介面，比如 prometheus-net、opentelemetry-dotnet 等，在微服務場景下，這些介面提供了大量有用的資訊，可以整合到可觀測性平臺中。

列印日誌

日誌是程式進行故障排查最常用最不可缺少的一部分，也是最簡單的故障排查方法。程式輸出的日誌可以為故障排查提供有用的資訊，同時透過日誌觀察程式的執行狀態，日誌也可以記錄審計資訊供日後回溯查詢。可是在多年開發工作中，筆者發現大多數開發人員都很少列印日誌，而且列印的日誌資訊對診斷故障幾乎沒幫助，因為這些日誌往往只是使用 try-catch{} 包裹程式碼直接列印異常，或者直接列印 API 請求和響應內容。日誌對於排查問題是很有幫助的，可是開發者往往不重視列印日誌，或者只是列印一些資訊。

基礎設施可觀測性平臺，以及客戶端包如 prometheus-net 等

而對於生產環境，則需要在架構上考慮，根據執行環境採用不同的技術，比如裸機、docker、Kubernetes 、雲函式等環境。以 Kubernetes 叢集環境為例，隨著微服務的發展和現有的專業監控平臺的成熟，需要考慮從基礎設施上去監聽程式的執行狀態，減少在程式碼上對程式的侵入。我們可以採用 Fluentd、Logstash 等收集容器的日誌、Elasticsearch 聚合和儲存日誌，然後使用 Kibana 進行視覺化日誌查詢。這種在程式之後使用工具觀測程式執行狀態的技術被稱為可觀測性技術，目前在可觀測性領域，主要有鏈路追蹤(Tracing)、日誌(Logging)、指標(Metrics) 三類技術，這些技術偏於架構和運維方面，因此在本章的最後一節只作簡單介紹。

我們常常會碰到在開發測試環境千測萬試沒問題，專案上線之後卻出現了意想不到的問題，比如介面效能差、程式碼執行的順序不符合預期等。線上上排查問題比較麻煩，生產環境不能直接使用開發工具除錯，也不能因為排查問題影響到使用者的體驗，因此開發者必須在日誌中預留足夠多的資訊，或者使用各種監控工具收集程式執行資訊，同時開發者需要掌握多種診斷工具的使用方法。對於程式故障的診斷，從開發角度、架構角度和運維角度去看會有不同的工具和方法，而本章是從開發者的角度，介紹一些在設計或定製企業內部開發框架時需要考慮的技術。

日誌

在程式中使用列印執行日誌，是最簡單、最常用的方法，也是最有效的，在本節中，我們來了解在程式中編寫日誌的一些方法以及常用日誌框架的定製使用方法。

日誌抽象介面

.NET 透過 Microsoft.Extensions.Logging.Abstractions 抽象了日誌介面，目前流行的日誌框架都會基於該抽象包實現響應的介面，使得我們在專案中使用抽象日誌介面，而不需要關注使用了哪個日誌框架。

.NET 官方使用Microsoft.Extensions.Logging 實現了這些抽象，而且社群中還有 Serilog 等日誌框架 ，由於 Serilog 框架的擴充套件非常方法，可以靈活地定製需求，所以在本章中筆者會詳細介紹 Serilog 框架的使用方法。

Microsoft.Extensions.Logging.Abstractions 有三個主要介面：

ILogger 用於輸出日誌

ILoggerFactory 獲取日誌介面，並儲存日誌提供器。

ILoggerProvider 提供日誌介面。

ILoggerFactory

.NET Core 中很多標準介面都實踐了工廠模式的思想，ILoggerFactory 正是工廠模式的介面，而 LoggerFactory 是工廠模式的實現。

其定義如下：

public interface ILoggerFactory : IDisposable
{
    ILogger CreateLogger(string categoryName);
    void AddProvider(ILoggerProvider provider);
}

ILoggerFactory 工廠介面的作用是建立一個 ILogger 型別的例項，即 CreateLogger 介面。

logging providers 稱為日誌記錄程式。Logging Providers 將日誌顯示或儲存到特定介質，例如 控制檯、日誌檔案、Elasticsearch 等。

微軟官方提供了很多很多日誌包：

• Microsoft.Extensions.Logging.Console
• Microsoft.Extensions.Logging.AzureAppServices
• Microsoft.Extensions.Logging.Debug
• Microsoft.Extensions.Logging.EventLog
• Microsoft.Extensions.Logging.EventSource
• Microsoft.Extensions.Logging.TraceSource

ILoggerProvider

透過實現ILoggerProvider介面可以建立自己的日誌記錄提供程式，比如控制檯、檔案等，表示可以建立 ILogger 例項的型別。

其定義如下：

public interface ILoggerProvider : IDisposable
{
    ILogger CreateLogger(string categoryName);
}

ILogger

ILogger 介面提供了將日誌記錄到基礎儲存的方法，其定義如下：

public interface ILogger
{
    void Log<TState>(LogLevel logLevel, 
                     EventId eventId, 
                     TState state, 
                     Exception exception, 
                     Func<TState, Exception, string> formatter);
    
    bool IsEnabled(LogLevel logLevel);
    IDisposable BeginScope<TState>(TState state);
} 

ILogger 雖然只有三個介面的，但是新增日誌類庫之後，會有很多擴充套件方法。

總結一下，如果要使用一個日誌框架，需要實現 ILogger 、ILoggerFactory 、ILoggerProvider 。

而社群中使用最廣泛的 Serilog 框架則提供了 File、Console、Elasticsearch、Debug、MSSqlServer、Email 等，還包含大量的擴充套件。

日誌等級

Logging API 中，規定了 7 種日誌等級，其定義如下：

public enum LogLevel
{
  Debug = 1,
  Verbose = 2,
  Information = 3,
  Warning = 4,
  Error = 5,
  Critical = 6,
  None = int.MaxValue
}

我們可以透過 ILogger 中的函式，輸出以下幾種等級的日誌：

            logger.LogInformation("Logging information.");
            logger.LogCritical("Logging critical information.");
            logger.LogDebug("Logging debug information.");
            logger.LogError("Logging error information.");
            logger.LogTrace("Logging trace");
            logger.LogWarning("Logging warning.");

在日誌配置檔案中，我們常常看到這樣的配置

    "MinimumLevel": {
      "Default": "Debug",
      "Override": {
        "Default": "Debug",
        "Microsoft": "Warning",
        "System": "Warning"
      }

MinimumLevel 屬性配置了日誌列印的最低等級限制，低於此等級的日誌不會輸出。Override 則可以對不同的名稱空間進行自定義限制。

比如，我們希望能夠將程式的業務日誌詳細列印出來，所以我們預設等級可以設定為 Debug，但是 System、Microsoft 開頭的名稱空間也會列印大量的日誌，這些日誌用處不大，所以我們可以設定等級為 Warning，這樣日誌程式針對 System、Microsoft 開頭的名稱空間，只會輸出 Warning 等級以上的日誌。

當然，System、Microsoft 中也有一些類庫列印的日誌比較重要，因此我們可以單獨配置此名稱空間的輸出等級：

      "Override": {
        "Default": "Debug",
        "Microsoft.AspNetCore.HttpLogging.HttpLoggingMiddleware": "Information",
        "Microsoft": "Warning",
        "System": "Warning"
      }

在 ASP.NET Core 中，以下名稱空間各有不同的用途，讀者可以單獨為這些名稱空間進行配置最小日誌列印等級。

類別	說明
Microsoft.AspNetCore	常規 ASP.NET Core 診斷。
Microsoft.AspNetCore.DataProtection	考慮、找到並使用了哪些金鑰。
Microsoft.AspNetCore.HostFiltering	所允許的主機。
Microsoft.AspNetCore.Hosting	HTTP 請求完成的時間和啟動時間。 載入了哪些承載啟動程式集。
Microsoft.AspNetCore.Mvc	MVC 和 Razor 診斷。 模型繫結、篩選器執行、檢視編譯和操作選擇。
Microsoft.AspNetCore.Routing	路由匹配資訊。
Microsoft.AspNetCore.Server	連線啟動、停止和保持活動響應。 HTTP 證書資訊。
Microsoft.AspNetCore.StaticFiles	提供的檔案。

在本章的剩餘小節中，筆者將會介紹如何實現自定義日誌框架、Serilog 的使用、如何使用 .NET 設計診斷工具。

自定義日誌框架

本節示例專案在 Demo2.MyLogger.Console 中。

建立控制檯專案後，新增 Microsoft.Extensions.Logging.Console 引用。

建立 MyLoggerOptions ，儲存日誌配置：

	public class MyLoggerOptions
	{
		/// <summary>
		/// 最小日誌等級
		/// </summary>
		public LogLevel DefaultLevel { get; set; } = LogLevel.Debug;
	}

建立自定義日誌記錄器：

	/// <summary>
	/// 自定義的日誌記錄器
	/// </summary>
	public class MyConsoleLogger : ILogger
	{
		// 日誌名稱
		private readonly string _name;
		private readonly MyLoggerOptions _options;

		public MyConsoleLogger(string name, MyLoggerOptions options)
		{
			_name = name;
			_options = options;
		}

		public IDisposable? BeginScope<TState>(TState state) where TState : notnull => default!;

		// 判斷是否啟用日誌等級
		public bool IsEnabled(LogLevel logLevel)
		{
			return logLevel >= _options.DefaultLevel;
		}

		// 記錄日誌，formatter 由框架提供的字串格式化器
		public void Log<TState>(
			LogLevel logLevel,
			EventId eventId,
			TState state,
			Exception? exception,
			Func<TState, Exception?, string> formatter)
		{
			if (!IsEnabled(logLevel))
			{
				return;
			}
			if (logLevel == LogLevel.Critical)
			{
				System.Console.ForegroundColor = System.ConsoleColor.Red;
				System.Console.WriteLine($"[{logLevel}] {_name} {formatter(state, exception)} {exception}");
				System.Console.ResetColor();
			}
			else if (logLevel == LogLevel.Error)
			{
				System.Console.ForegroundColor = System.ConsoleColor.DarkRed;
				System.Console.WriteLine($"[{logLevel}] {_name} {formatter(state, exception)} {exception}");
				System.Console.ResetColor();
			}
			else
			{
				System.Console.WriteLine($"[{logLevel}] {_name} {formatter(state, exception)} {exception}");
			}
		}
	}

建立自定義日誌提供器：

	[ProviderAlias("MyConsole")]
	public sealed class MyLoggerProvider : ILoggerProvider
	{
		private MyLoggerOptions _options;
		private readonly ConcurrentDictionary<string, MyConsoleLogger> _loggers =
			new(StringComparer.OrdinalIgnoreCase);

		public MyLoggerProvider(MyLoggerOptions options)
		{
			_options = options;
		}

		public ILogger CreateLogger(string categoryName) =>
			_loggers.GetOrAdd(categoryName, name => new MyConsoleLogger(name, _options));

		public void Dispose()
		{
			_loggers.Clear();
		}
	}

編寫擴充套件函式，注入自定義日誌提供器：

	public static class MyLoggerExtensions
	{
		public static ILoggingBuilder AddMyConsoleLogger(
			this ILoggingBuilder builder, Action<MyLoggerOptions> action)
		{
			MyLoggerOptions options = new();
			if (action != null)
			{
				action.Invoke(options);
			}

			builder.AddConfiguration();
			builder.Services.TryAddEnumerable(
				ServiceDescriptor.Singleton<ILoggerProvider>(new MyLoggerProvider(options)));
			return builder;
		}
	}

最後使用 Microsoft.Extensions.Logging 中的 LoggerFactory，構建日誌工廠，從中生成 ILogger 物件，最後列印日誌：

		static void Main(string[] args)
		{
			using ILoggerFactory factory = LoggerFactory.Create(builder =>
			{
				builder.AddConsole();
				builder.AddMyConsoleLogger(options =>
				{
					options.DefaultLevel = LogLevel.Debug;
				});
			});
			ILogger logger1 = factory.CreateLogger("Program");
			ILogger logger2 = factory.CreateLogger<Program>();

			logger1.LogError(new Exception("報錯了"), message: "Hello World! Logging is {Description}.", args: "error");
			logger2.LogError(new Exception("報錯了"), message: "Hello World! Logging is {Description}.", args: "error");
		}