零基础写框架(2)：故障排查和日志基础
关于从零设计 .NET 开发框架
作者：痴者工良
教程说明：
仓库地址：https://github.com/whuanle/maomi
作者博客：
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");
}
