Asp.NetCore源码学习[2-1]：日志

  • 2019 年 10 月 14 日
  • 笔记

Asp.NetCore源码学习[2-1]：日志

在一个系统中，日志是不可或缺的部分。对于.net而言有许多成熟的日志框架，包括Log4Net、NLog、Serilog 等等。你可以在系统中直接使用这些第三方的日志框架，也可以通过这些框架去适配ILoggerProvider 和 ILogger接口。适配接口的好处在于，如果想要切换日志框架，只要实现并注册新的 ILoggerProvider 就可以，而不影响日志使用方的代码。这就是在日志系统中使用门面模式的优点。

本系列源码地址

一、.NetCore 中日志的基本使用

在控制层，我们可以直接通过ILogger直接获取日志实例，也可以通过ILoggerFactory.CreateLogger() 方法获取日志实例Logger。不管使用哪种方法获取日志实例，对于相同的categoryName，返回的是同一个Logger对象。

public class ValuesController : ControllerBase  {      private readonly ILogger _logger1;      private readonly ILogger _logger2;      private readonly ILogger _logger3;        public ValuesController(ILogger<ValuesController> logger, ILoggerFactory loggerFactory)      {          //_logger1是 Logger<T>类型          _logger1 = logger;          //_logger2是 Logger类型          _logger2 = loggerFactory.CreateLogger(typeof(ValuesController));          //_logger3是 Logger<T>类型 该方法每次新建Logger<T>实例          _logger3 = loggerFactory.CreateLogger<ValuesController>();      }        public ActionResult<IEnumerable<string>> Get()      {          //虽然 _logger1、_logger2、_logger3 是不同的对象          //但是 _logger1、_logger3 中的 Logger实例 和 _logger2 是同一个对象          var hashCode1 = _logger1.GetHashCode();          var hashCode2 = _logger2.GetHashCode();          var hashCode3 = _logger3.GetHashCode();          _logger1.LogDebug("Test Logging");          return new string[] { "value1", "value2"};      }  }

二、源码解读

WebHostBuilder内部维护了_configureServices字段,其类型是 Action<WebHostBuilderContext, IServiceCollection>，该委托用于对集合ServiceCollection进行配置，该集合用来保存需要被注入的接口、实现类、生命周期等等。

public class WebHostBuilder  {      private Action<WebHostBuilderContext, IServiceCollection> _configureServices;        public IWebHostBuilder ConfigureServices(Action<WebHostBuilderContext, IServiceCollection> configureServices)      {          _configureServices += configureServices;          return this;      }      public IWebHost Build()      {          var services = new ServiceCollection();//该集合用于保存需要注入的服务          services.AddLogging(services, builder => { });          _configureServices?.Invoke(_context, services);//配置ServiceCollection          //返回Webhost      }  }

首先在CreateDefaultBuilder方法中通过调用ConfigureLogging方法对日志模块进行配置，在这里我们可以注册需要的 ILoggerProvider 实现。

public static IWebHostBuilder CreateDefaultBuilder(string[] args)  {      var builder = new WebHostBuilder();      builder.ConfigureLogging((hostingContext, logging) =>      {          logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));          logging.AddConsole();      }).      return builder;  }

从 ConfigureLogging 方法开始，到ConfigureServices，最后到AddLogging，虽然看上去有点绕，但实际上只是构建了一个委托，并将委托保存到WebHostBuilder._configureServices字段中，该委托用于把日志模块需要的一系列对象类型保存到ServiceCollection中，最终构建依赖注入模块。

public static IWebHostBuilder ConfigureLogging(this IWebHostBuilder hostBuilder, Action<WebHostBuilderContext, ILoggingBuilder> configureLogging)  {      return hostBuilder.ConfigureServices((context, collection) => collection.AddLogging(builder => configureLogging(context, builder)));  }    /// 向IServiceCollection中注入日志系统需要的类  public static IServiceCollection AddLogging(this IServiceCollection services, Action<ILoggingBuilder> configure)  {      if (services == null)      {          throw new ArgumentNullException(nameof(services));      }        services.AddOptions();        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;  }

上面和日志模块相关的注入看起来比较混乱，在这里汇总一下：

可以看到，IConfigureOptions 注入了两个不同的实例，由于在IOptionsMonitor中会顺序执行，所以先通过 默认的DefaultLoggerLevelConfigureOptions去配置LoggerFilterOptions实例，然后读取配置文件的"Logging"节点去配置LoggerFilterOptions实例。

//注入Options，使得在日志模块中可以读取配置  services.AddOptions();    //注入日志模块  services.TryAdd(ServiceDescriptor.Singleton<ILoggerFactory, LoggerFactory>());  services.TryAdd(ServiceDescriptor.Singleton(typeof(ILogger<>), typeof(Logger<>)));    //注册默认的配置 LoggerFilterOptions.MinLevel = LogLevel.Information  services.TryAddEnumerable(ServiceDescriptor.Singleton<IConfigureOptions<LoggerFilterOptions>>(new DefaultLoggerLevelConfigureOptions(LogLevel.Information)));    var logging = new LoggingBuilder(services);  logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));  logging.AddConsole();    public static ILoggingBuilder AddConfiguration(this ILoggingBuilder builder, IConfiguration configuration)  {      //      builder.Services.TryAddSingleton<ILoggerProviderConfigurationFactory, LoggerProviderConfigurationFactory>();      builder.Services.TryAddSingleton(typeof(ILoggerProviderConfiguration<>), typeof(LoggerProviderConfiguration<>));        //注册LoggerFactory中IOptionsMonitor<LoggerFilterOptions>相关的依赖      //这样可以在LoggerFactory中读取配置文件，并在文件发生改变时，对已生成的Logger实例进行相应规则改变      builder.Services.AddSingleton<IConfigureOptions<LoggerFilterOptions>>(new LoggerFilterConfigureOptions(configuration));      builder.Services.AddSingleton<IOptionsChangeTokenSource<LoggerFilterOptions>>(new ConfigurationChangeTokenSource<LoggerFilterOptions>(configuration));        //      builder.Services.AddSingleton(new LoggingConfiguration(configuration));        return builder;  }

日志配置文件

  • Logging::LogLevel节点，适用于所有ILoggerProvider 的规则。
  • Logging::{ProviderName}::LogLevel节点，适用于名称为{ProviderName}的ILoggerProvider
  • 在LogLevel节点下，"Default"节点值代表了适用于所有CategoryName的日志级别
  • 在LogLevel节点下，非"Default"节点使用节点名去匹配CategoryName，最多支持一个"*"
  "Logging": {      "CaptureScopes": true,      "LogLevel": { // 适用于所有 ILoggerProvider        "Default": "Information",        "Microsoft": "Warning"      },      "Console": { // 适用于 ConsoleLoggerProvider[ProviderAlias("Console")]        "LogLevel": {          // 对于 CategoryName = "Microsoft.Hosting.Lifetime" 优先等级从上到下递减：          // 1.开头匹配 等效于 "Microsoft.Hosting.Lifetime*"          "Microsoft.Hosting.Lifetime": "Information",          // 2.首尾匹配          "Microsoft.*.Lifetime": "Information",          // 3.开头匹配          "Microsoft": "Warning",          // 4.结尾匹配          "*Lifetime": "Information",          // 5.匹配所有          "*": "Information",          // 6.CategoryName 全局配置          "Default": "Information"        }      }    }

1、 日志相关的接口

1.1 ILoggerFactory 接口

ILoggerFactory是日志工厂类，用于注册需要的ILoggerProvider，并生成Logger 实例。Logger对象是日志系统的门面类，通过它我们可以写入日志，却不需要关心具体的日志写入实现。只要注册了相应的ILoggerProvider， 在系统中我们就可以通过Logger同时向多个路径写入日志信息，比如说控制台、文件、数据库等等。

/// 用于配置日志系统并创建Logger实例的类  public interface ILoggerFactory : IDisposable  {      /// 创建一个新的Logger实例      /// <param name="categoryName">消息类别,一般为调用Logger所在类的全名</param>      ILogger CreateLogger(string categoryName);        /// 向日志系统注册一个ILoggerProvider      void AddProvider(ILoggerProvider provider);  }

1.2 ILoggerProvider 接口

ILoggerProvider 用于提供 具体日志实现类，比如ConsoleLogger、FileLogger等等。

public interface ILoggerProvider : IDisposable  {      /// 创建一个新的ILogger实例(具体日志写入类)      ILogger CreateLogger(string categoryName);  }

1.3 ILogger 接口

虽然Logger和具体日志实现类都实现ILogger接口，但是它们的作用是完全不同的。其两者的区别在于:Logger是系统中写入日志的统一入口,而 具体日志实现类 代表了不同的日志写入途径，比如ConsoleLogger、FileLogger等等。

/// 用于执行日志记录的类  public interface ILogger  {      /// 写入一条日志条目      /// <typeparam name="TState">日志条目类型</typeparam>      /// <param name="logLevel">日志级别</param>      /// <param name="eventId">事件ID</param>      /// <param name="state">将会被写入的日志条目(可以为对象)</param>      /// <param name="exception">需要记录的异常</param>      /// <param name="formatter">格式化器:将state和exception格式化为字符串</param>      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);  }

2、 LoggerFactory 日志工厂类的实现

在构造函数中做了两件事情：

  • 获取在DI模块中已经注入的ILoggerProvider，将其保存到集合中。类型ProviderRegistration 拥有字段ShouldDispose，其含义为：在LoggerFactory生命周期结束之后，该ILoggerProvider是否需要释放。虽然在系统中LoggerFactory为单例模式，但是其提供了一个静态方法生成一个可释放的DisposingLoggerFactory。
  • 通过IOptionsMonitor 绑定更改回调，在配置文件发生更改时，执行相应动作。
public class LoggerFactory : ILoggerFactory  {      private readonly Dictionary<string, Logger> _loggers = new Dictionary<string, Logger>(StringComparer.Ordinal);        private readonly List<ProviderRegistration> _providerRegistrations = new List<ProviderRegistration>();        private IDisposable _changeTokenRegistration;        private LoggerExternalScopeProvider _scopeProvider;        public LoggerFactory(IEnumerable<ILoggerProvider> providers, IOptionsMonitor<LoggerFilterOptions> filterOption)      {          foreach (var provider in providers)          {              AddProviderRegistration(provider, dispose: false);          }          _changeTokenRegistration = filterOption.OnChange((o, _) => RefreshFilters(o));          RefreshFilters(filterOption.CurrentValue);      }        /// 注册日志提供器      private void AddProviderRegistration(ILoggerProvider provider, bool dispose)      {          _providerRegistrations.Add(new ProviderRegistration          {              Provider = provider,              ShouldDispose = dispose          });          // 如果日志提供器 实现 ISupportExternalScope 接口          if (provider is ISupportExternalScope supportsExternalScope)          {              if (_scopeProvider == null)              {                  _scopeProvider = new LoggerExternalScopeProvider();              }              //将单例 LoggerExternalScopeProvider 保存到 provider._scopeProvider 中              //将单例 LoggerExternalScopeProvider 保存到 provider._loggers.ScopeProvider 里面              supportsExternalScope.SetScopeProvider(_scopeProvider);          }      }  }

CreateLogger方法：

  • 内部使用字典保存categoryName 和对应的Logger。
  • Logger 内部维护三个数组:LoggerInformation[]、MessageLogger[]、ScopeLogger[]
  • 在LoggerInformation的构造函数中生成了实际的日志写入类(FileLogger、ConsoleLogger)
/// 创建 Logger 日志门面类  public ILogger CreateLogger(string categoryName)  {      lock (_sync)      {          if (!_loggers.TryGetValue(categoryName, out var logger))// 如果字典中不存在新建Logger          {              logger = new Logger              {                  Loggers = CreateLoggers(categoryName),              };              (logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers);// 根据配置应用过滤规则              _loggers[categoryName] = logger;// 加入字典          }          return logger;      }  }    /// 根据注册的ILoggerProvider，创建Logger需要的 LoggerInformation[]  private LoggerInformation[] CreateLoggers(string categoryName)  {      var loggers = new LoggerInformation[_providerRegistrations.Count];      for (var i = 0; i < _providerRegistrations.Count; i++)      {          loggers[i] = new LoggerInformation(_providerRegistrations[i].Provider, categoryName);      }      return loggers;  }  internal readonly struct LoggerInformation  {      public LoggerInformation(ILoggerProvider provider, string category) : this()      {          ProviderType = provider.GetType();          Logger = provider.CreateLogger(category);          Category = category;          ExternalScope = provider is ISupportExternalScope;      }        /// 具体日志写入途径实现类      public ILogger Logger { get; }        /// 日志类别名称      public string Category { get; }        /// 日志提供器Type      public Type ProviderType { get; }        /// 是否支持 ExternalScope      public bool ExternalScope { get; }  }

ApplyFilters方法：

  • MessageLogger[]取值逻辑：遍历LoggerInformation[]，从配置文件中读取对应的日志级别， 如果在配置文件中没有对应的配置，默认取_filterOptions.MinLevel。如果读取到的日志级别大于LogLevel.Critical，则将其加入MessageLogger[]。
  • ScopeLogger[]取值逻辑：如果 ILoggerProvider实现了ISupportExternalScope接口，那么使用LoggerExternalScopeProvider作为Scope功能的实现。反之，使用ILogger作为其Scope功能的实现。
  • 多个 ILoggerProvider共享同一个 LoggerExternalScopeProvider
/// 根据配置应用过滤  private (MessageLogger[] MessageLoggers, ScopeLogger[] ScopeLoggers) ApplyFilters(LoggerInformation[] loggers)  {      var messageLoggers = new List<MessageLogger>();      var scopeLoggers = _filterOptions.CaptureScopes ? new List<ScopeLogger>() : null;        foreach (var loggerInformation in loggers)      {          // 通过 ProviderType Category从 LoggerFilterOptions 中匹配对应的配置          RuleSelector.Select(_filterOptions,              loggerInformation.ProviderType,              loggerInformation.Category,              out var minLevel,              out var filter);            if (minLevel != null && minLevel > LogLevel.Critical)          {              continue;          }            messageLoggers.Add(new MessageLogger(loggerInformation.Logger, loggerInformation.Category, loggerInformation.ProviderType.FullName, minLevel, filter));            // 不支持 ExternalScope： 启用 ILogger 自身实现的scope          if (!loggerInformation.ExternalScope)          {              scopeLoggers?.Add(new ScopeLogger(logger: loggerInformation.Logger, externalScopeProvider: null));          }      }        // 只要其中一个Provider支持 ExternalScope：将 _scopeProvider 加入 scopeLoggers      if (_scopeProvider != null)      {          scopeLoggers?.Add(new ScopeLogger(logger: null, externalScopeProvider: _scopeProvider));      }        return (messageLoggers.ToArray(), scopeLoggers?.ToArray());  }

LoggerExternalScopeProvider 大概的实现逻辑：

  • 通过 Scope 组成了一个单向链表，每次 beginscope 向链表末端增加一个新的元素，Dispose的时候，删除链表最末端的元素。我们知道LoggerExternalScopeProvider 在系统中是单例模式，多个请求进来，加入线程池处理。通过使用AsyncLoca来实现不同线程间数据独立。AsyncLocal的详细特性可以参照此处。
  • 有两个地方开启了日志作用域：
  • 1、通过 socket监听到请求后，将KestrelConnection加入线程池，线程池调度执行IThreadPoolWorkItem.Execute()方法。在这里开启了一次
  • 2、在构建请求上下文对象的时候(HostingApplication.CreateContext())，开启了一次

3、Logger 日志门面类的实现

  • MessageLogger[]保存了在配置文件中启用的那些ILogger
  • 需要注意的是，由于配置文件更改后，会调用ApplyFilters()方法，并为MessageLogger[]赋新值，所以在遍历之前，需要保存当前值，再进行处理。否则会出现修改异常。
internal class Logger : ILogger  {      public LoggerInformation[] Loggers { get; set; }      public MessageLogger[] MessageLoggers { get; set; }      public ScopeLogger[] ScopeLoggers { get; set; }        public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)      {          var loggers = MessageLoggers;          if (loggers == null)          {              return;          }            List<Exception> exceptions = null;          for (var i = 0; i < loggers.Length; i++)          {              ref readonly var loggerInfo = ref loggers[i];              if (!loggerInfo.IsEnabled(logLevel))              {                  continue;              }                LoggerLog(logLevel, eventId, loggerInfo.Logger, exception, formatter, ref exceptions, state);          }            if (exceptions != null && exceptions.Count > 0)          {              ThrowLoggingError(exceptions);          }            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);              }          }      }  }

最后

这篇文章也压在箱底一段时间了，算是匆忙结束。还有挺多想写的，包括 Diagnostics、Activity、Scope等等，这些感觉需要结合SkyAPM-dotnet源码一起说才能理解，争取能够写出来吧。

VirMach 便宜 VPS

QNews

QNews