.Net Core Logging模块源码阅读
前言
在Asp.Net Core Webapi项目中经常会用到ILogger，于是在空闲的时候就clone了一下官方的源码库下来研究，这里记录一下。
核心类
日志模块中最核心的类其实就是三个: ILogger、ILoggerFactory、ILoggerProvider，三者的作用如下：
- ILogger：负责根据日志级别写入日志
- ILoggerProvider：负责创建ILogger(但不应该直接使用它来创建一个ILogger)
- ILoggerFactory：用于注册一个或者多个ILoggerProvider，然后工厂用所有的这些Provider来创建ILogger
下面我们从一个控制台应用开始逐步深入学习：
using Microsoft.Extensions.Logging;
using Microsoft.Extensions.Logging.Console;
// A
LoggerFactory loggerFactory=new LoggerFactory();
// B (注意这里是演示使用，实际上不能传default,应该传一个配置,后面给出能运行的示例)
loggerFactory.AddProvider(new ConsoleLoggerProvider(default));
// C
var logger=loggerFactory.CreateLogger("default");
// D
logger.LogInformation("Hello World");
上面四行代码我分别用ABCD标注，我们可以打开官方的源码来进行学习。
首先是A行，我们创建了一个LoggerFactory，我们先看一下这个类里面到底有什么重要的东西：
public interface ILoggerFactory : IDisposable
{
/// <summary>
/// Creates a new <see cref="ILogger"/> instance.
/// </summary>
/// <param name="categoryName">The category name for messages produced by the logger.</param>
/// <returns>The <see cref="ILogger"/>.</returns>
ILogger CreateLogger(string categoryName);
/// <summary>
/// Adds an <see cref="ILoggerProvider"/> to the logging system.
/// </summary>
/// <param name="provider">The <see cref="ILoggerProvider"/>.</param>
void AddProvider(ILoggerProvider provider);
}
public class LoggerFactory : ILoggerFactory
{
// 创建Logger时会添加对应Category的Logger
private readonly Dictionary<string, Logger> _loggers = new Dictionary<string, Logger>(StringComparer.Ordinal);
// 添加LoggingProvider的时候会加入到这个列表中
private readonly List<ProviderRegistration> _providerRegistrations = new List<ProviderRegistration>();
// 构造函数 默认没有任何Provider
public LoggerFactory() : this(Array.Empty<ILoggerProvider>())
{
}
}
从上面的代码中可以看出在创建的时候其实啥也没干，只是创建了一个空的LoggerFactory，然后我们看一下B行，这里我们添加了一个ConsoleLoggerProvider，这个类是干嘛的呢？我们看一下它的代码：
/// <summary>
/// Adds the given provider to those used in creating <see cref="ILogger"/> instances.
/// </summary>
/// <param name="provider">The <see cref="ILoggerProvider"/> to add.</param>
public void AddProvider(ILoggerProvider provider)
{
lock (_sync)
{
// 添加对应的provider，第二个参数dispose的意思是当LogFactory被销毁时是否也同时销毁这个Provider，这个参数在使用IOC容器时非常重要
AddProviderRegistration(provider, dispose: true);
// 下面这段代码的逻辑是：当添加了一个新的LogProvider时，更新所有已经创建的Logger，让它们也能够使用新的Provider
foreach (KeyValuePair<string, Logger> existingLogger in _loggers)
{
Logger logger = existingLogger.Value;
LoggerInformation[] loggerInformation = logger.Loggers;
int newLoggerIndex = loggerInformation.Length;
Array.Resize(ref loggerInformation, loggerInformation.Length + 1);
loggerInformation[newLoggerIndex] = new LoggerInformation(provider, existingLogger.Key);
logger.Loggers = loggerInformation;
(logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers);
}
}
}
当第一次阅读上面这段代码时，LoggerInformation类我们是没见过的，先看一下类的定义：
internal readonly struct LoggerInformation
{
public LoggerInformation(ILoggerProvider provider, string category) : this()
{
ProviderType = provider.GetType();
Logger = provider.CreateLogger(category);
Category = category;
// 这个涉及到IOC容器中多Scope的问题，如果一个Provider继承了这个接口，表示可以消费外部Scope的日志消息，这里不过多介绍
ExternalScope = provider is ISupportExternalScope;
}
public ILogger Logger { get; }
public string Category { get; }
public Type ProviderType { get; }
public bool ExternalScope { get; }
}
可以看出其实LoggerInformation就是一个包含了ILoggerProvider和ILogger的结构体，用于表示一个Logger的日志信息
好了我们回到B行代码继续看，ConsoleLoggerProvider是官方提供的控制台日志输出Provider，我们也可以从源码中看到，这里不继续讲，看C行的代码内部做了什么：
/// <summary>
/// Creates an <see cref="ILogger"/> with the given <paramref name="categoryName"/>.
/// </summary>
/// <param name="categoryName">The category name for messages produced by the logger.</param>
/// <returns>The <see cref="ILogger"/> that was created.</returns>
public ILogger CreateLogger(string categoryName)
{
lock (_sync)
{
// 尝试从已经创建的Logger中获取 没获取到则创建一个对应category的Logger
if (!_loggers.TryGetValue(categoryName, out Logger logger))
{
logger = new Logger
{
// CreateLoggers获取到的就是我们上面说的LoggerInformation，该函数代码在下面
Loggers = CreateLoggers(categoryName),
};
// 使用过滤规则过滤
(logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers);
_loggers[categoryName] = logger;
}
return logger;
}
}
// 这个函数几行代码的逻辑是根据所有的Provider创建一个对应category的LoggerInformation数组
private LoggerInformation[] CreateLoggers(string categoryName)
{
var loggers = new LoggerInformation[_providerRegistrations.Count];
for (int i = 0; i < _providerRegistrations.Count; i++)
{
loggers[i] = new LoggerInformation(_providerRegistrations[i].Provider, categoryName);
}
return loggers;
}
好了，到了这一步我们的Logger终于创建出来了，可以写日志了，继续看D行代码打印日志是怎么实现的：
// 第一步进入这个函数
public static void LogInformation(this ILogger logger, string? message, params object?[] args)
{
logger.Log(LogLevel.Information, message, args);
}
// 第二步进入这个函数
public static void Log(this ILogger logger, LogLevel logLevel, string? message, params object?[] args)
{
logger.Log(logLevel, 0, null, message, args);
}
// 第三步进入这个函数
public static void Log(this ILogger logger, LogLevel logLevel, EventId eventId, Exception? exception, string? message, params object?[] args)
{
if (logger == null)
{
throw new ArgumentNullException(nameof(logger));
}
logger.Log(logLevel, eventId, new FormattedLogValues(message, args), exception, _messageFormatter);
}
// 第四步进入这个函数
void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
_logger.Log(logLevel, eventId, state, exception, formatter);
}
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
// 这里的logger就是从所有prodiver中生成出来的
MessageLogger[] loggers = MessageLoggers;
for (int i = 0; i < loggers.Length; i++)
{
ref readonly MessageLogger loggerInfo = ref loggers[i];
if (!loggerInfo.IsEnabled(logLevel))
{
continue;
}
LoggerLog(logLevel, eventId, loggerInfo.Logger, exception, formatter, ref exceptions, state);
}
// 调用所有Provider生成出来的logger，使用相应实现的Log函数从而达到输出到不同地方的目的
static void LoggerLog(LogLevel logLevel, EventId eventId, ILogger logger, Exception exception, Func<TState, Exception, string> formatter, ref List<Exception> exceptions, in TState state)
{
try
{
logger.Log(logLevel, eventId, state, exception, formatter);
}
catch (Exception ex)
{
if (exceptions == null)
{
exceptions = new List<Exception>();
}
exceptions.Add(ex);
}
}
}
上面这段代码中其实有一个非常重要的地方还没说，那就是ILogger的实现其实是不止一个的，有一个普通的Logger类，还有一个泛型类Logger<T>:
internal sealed class Logger : ILogger
{
}
public interface ILogger<out TCategoryName> : ILogger
{
}
public class Logger<T> : ILogger<T>
{
private readonly ILogger _logger;
public Logger(ILoggerFactory factory)
{
_logger = factory.CreateLogger(TypeNameHelper.GetTypeDisplayName(typeof(T), includeGenericParameters: false, nestedTypeDelimiter: '.'));
}
}
平时我们使用的都是泛型的Logger，因为Logger是internal级别的，也就是内部使用，也就是说泛型的Logger就是一个包装类，包装了一个普通的Logger，这个普通的Logger是从所有Provider中生成出来的，而泛型的Logger只是把泛型的类型名传给了普通的Logger，这样就实现了泛型的Logger的功能。
好了，到这一步我们已经可以大概明白.NET官方的日志模块是怎么个流程了，下面我们举一反三，看看Logger和IOC是怎么集成的
IOC
上来就先来一个示例：
ServiceCollection serviceCollection = new();
serviceCollection.AddLogging(configure =>
{
configure.AddConsole();
});
using var sp=serviceCollection.BuildServiceProvider();
var logger = sp.GetRequiredService<ILogger<Program>>();
logger.LogInformation("hello world");
相信经常写.NET的对ServiceCollection和ServiceProvider都不陌生，这里我们就不多说了，直接看看日志模块是怎么集成的。这里最重要的其实就一行——AddLogging，我们直接看源码:
public static IServiceCollection AddLogging(this IServiceCollection services, Action<ILoggingBuilder> configure)
{
// 注入Option相关的类
services.AddOptions();
// 下面两句是核心 注入LoggerFactory和ILogger<>
services.TryAdd(ServiceDescriptor.Singleton<ILoggerFactory, LoggerFactory>());
services.TryAdd(ServiceDescriptor.Singleton(typeof(ILogger<>), typeof(Logger<>)));
services.TryAddEnumerable(ServiceDescriptor.Singleton<IConfigureOptions<LoggerFilterOptions>>(
new DefaultLoggerLevelConfigureOptions(LogLevel.Information)));
// 新东西 下面介绍
configure(new LoggingBuilder(services));
return services;
}
上面这段代码中只有一个新的类，那就是LoggingBuilder，还是看源码：
internal sealed class LoggingBuilder : ILoggingBuilder
{
public LoggingBuilder(IServiceCollection services)
{
Services = services;
}
public IServiceCollection Services { get; }
}
这个类本身看起来很简单，其实是官方把相应的逻辑都写在扩展函数里了：
public static class LoggingBuilderExtensions
{
public static ILoggingBuilder SetMinimumLevel(this ILoggingBuilder builder, LogLevel level)
{
builder.Services.Add(ServiceDescriptor.Singleton<IConfigureOptions<LoggerFilterOptions>>(
new DefaultLoggerLevelConfigureOptions(level)));
return builder;
}
public static ILoggingBuilder AddProvider(this ILoggingBuilder builder, ILoggerProvider provider)
{
builder.Services.AddSingleton(provider);
return builder;
}
public static ILoggingBuilder ClearProviders(this ILoggingBuilder builder)
{
builder.Services.RemoveAll<ILoggerProvider>();
return builder;
}
public static ILoggingBuilder Configure(this ILoggingBuilder builder, Action<LoggerFactoryOptions> action)
{
builder.Services.Configure(action);
return builder;
}
}
好了，使用依赖注入后，所有的类都不需要自己new了，在调用GetRequiredService时，由于ILogger<T>依赖了ILoggerFactory，所以会先调用ILoggerFactory的构造函数，然后再调用ILogger<T>的构造函数，这样就实现了日志模块的注入。
官方的控制台Provider
这里属于扩展介绍，我们看一下官方的ConsoleProvider里面有什么东西：
public class ConsoleLoggerProvider : ILoggerProvider, ISupportExternalScope
{
private readonly IOptionsMonitor<ConsoleLoggerOptions> _options;
private readonly ConcurrentDictionary<string, ConsoleLogger> _loggers;
private ConcurrentDictionary<string, ConsoleFormatter> _formatters;
private readonly ConsoleLoggerProcessor _messageQueue;
public ConsoleLoggerProvider(IOptionsMonitor<ConsoleLoggerOptions> options)
: this(options, Array.Empty<ConsoleFormatter>()) { }
public ILogger CreateLogger(string name)
{
if (_options.CurrentValue.FormatterName == null || !_formatters.TryGetValue(_options.CurrentValue.FormatterName, out ConsoleFormatter? logFormatter))
{
logFormatter = _options.CurrentValue.Format switch
{
ConsoleLoggerFormat.Systemd => _formatters[ConsoleFormatterNames.Systemd],
_ => _formatters[ConsoleFormatterNames.Simple],
};
if (_options.CurrentValue.FormatterName == null)
{
UpdateFormatterOptions(logFormatter, _options.CurrentValue);
}
}
return _loggers.TryGetValue(name, out ConsoleLogger? logger) ?
logger :
_loggers.GetOrAdd(name, new ConsoleLogger(name, _messageQueue, logFormatter, _scopeProvider, _options.CurrentValue));
}
public void Dispose()
{
_optionsReloadToken?.Dispose();
_messageQueue.Dispose();
}
}
上面其实最重要的东西就是两个，一个是ConsoleLoggerProcessor，还有一个就是ConsoleLogger：
ConsoleLoggerProcessor类里面也比较简单，就是在后台开启一个线程专门用于输出日志，这样就不会阻塞主线程了，这个类的代码就不贴了，感兴趣的可以自己看一下。ConsoleLogger就是对应记录日志类，用于实现在控制台输出日志的逻辑，如果是输出到数据库，可以自己实现一个DBLogger。
此处有一个我觉得比较重要的地方要提，就是如果程序意外退出，这些没输出的日志就直接丢失了，或者日志队列里日志实在是太多了，也不一定保证能在退出时全部输出,我们可以看下代码：
internal class ConsoleLoggerProcessor : IDisposable
{
private readonly Queue<LogMessageEntry> _messageQueue;
public ConsoleLoggerProcessor(IConsole console, IConsole errorConsole, ConsoleLoggerQueueFullMode fullMode, int maxQueueLength)
{
_messageQueue = new Queue<LogMessageEntry>();
_outputThread = new Thread(ProcessLogQueue)
{
IsBackground = true,
Name = "Console logger queue processing thread"
};
_outputThread.Start();
}
public void Dispose()
{
CompleteAdding();
try
{
_outputThread.Join(1500); // with timeout in-case Console is locked by user input
}
catch (ThreadStateException) { }
}
private void CompleteAdding()
{
lock (_messageQueue)
{
_isAddingCompleted = true;
Monitor.PulseAll(_messageQueue);
}
}
}
在Dispose中有这段代码：_outputThread.Join(1500)，也就是说1.5秒内日志如果没有输出完，这些日志就没有了
提一嘴Serilog
现在.NET中的日志框架很多，比如nlog，serilog，当然第二个目前更加好用(个人体验)，我们注入Serilog其实也就一句话：
serviceCollection.AddLogging(configure =>
{
configure.AddSerilog();
});
public static ILoggingBuilder AddSerilog(
this ILoggingBuilder builder,
ILogger logger = null,
bool dispose = false)
{
if (builder == null)
throw new ArgumentNullException(nameof (builder));
if (dispose)
ServiceCollectionServiceExtensions.AddSingleton<ILoggerProvider, SerilogLoggerProvider>(builder.Services, (Func<IServiceProvider, SerilogLoggerProvider>) (services => new SerilogLoggerProvider(logger, true)));
else
builder.AddProvider((ILoggerProvider) new SerilogLoggerProvider(logger));
builder.AddFilter<SerilogLoggerProvider>((string) null, LogLevel.Trace);
return builder;
}
可以看到其实非常简单，其实就是把Serilog的LoggerProvider注入到DI容器中了，然后LogFactory会用这个Provider了
自己实现一个简单的Provider
我们可以自己实现一个简单Provider来加深自己的理解，其实官方也有相应的示例代码：https://github.com/dotnet/docs/tree/main/docs/core/extensions/snippets/configuration/console-custom-logging，这里也提供一个简单的示例：
public class CustomConsoleLogger:ILogger
{
public CustomConsoleLogger(string categoryName)
{
CategoryName = categoryName;
}
public string CategoryName { get; set; }
public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception? exception, Func<TState, Exception?, string> formatter)
{
ConsoleColor originalColor = Console.ForegroundColor;
Console.ForegroundColor = ConsoleColor.Red;
Console.WriteLine($"{formatter(state, exception)}");
}
public bool IsEnabled(LogLevel logLevel)
{
//默认所有级别记录
return true;
}
public IDisposable BeginScope<TState>(TState state) => default!;
}
public class CustomConsoleProvider:ILoggerProvider
{
private readonly ConcurrentDictionary<string, CustomConsoleLogger> _loggers =
new(StringComparer.OrdinalIgnoreCase);
public void Dispose()
{
_loggers.Clear();
}
public ILogger CreateLogger(string categoryName)
{
return _loggers.GetOrAdd(categoryName, name => new CustomConsoleLogger(name));
}
}
// 调用
ServiceCollection serviceCollection = new();
serviceCollection.AddLogging(configure =>
{
configure.AddConsole();
// configure.AddSerilog();
configure.AddProvider(new CustomConsoleProvider());
});
using var sp=serviceCollection.BuildServiceProvider();
var logger = sp.GetRequiredService<ILogger<Program>>();
logger.LogInformation("测试此条日志颜色是否改变为红色");
运行后就可以看到同时输出了两种日志
参考文章
- ILogger、ILoggerFactory、ILoggerProvider三者关系 https://stackoverflow.com/questions/51345161/should-i-take-ilogger-iloggert-iloggerfactory-or-iloggerprovider-for-a-libra
- 官方文档 https://learn.microsoft.com/zh-cn/dotnet/core/extensions/custom-logging-provider
- 官方示例自定义一个日志提供类 https://github.com/dotnet/docs/tree/main/docs/core/extensions/snippets/configuration/console-custom-logging