.Net Core中的日志Logging使用以及源码解析

在.Net Core中系统自带的集成了日志系统,看一下如何使用:

第一步先添加LogProvider,这个是为了告诉容器我们日志输出的来源,LogProvider的目的是创建Logger,在Asp.Net Core中默认添加了3个Provider:

            .ConfigureLogging((hostingContext, logging) =>
            {
                logging.AddConfiguration(hostingContext.Configuration.GetSection("Logging"));
                logging.AddConsole();
                logging.AddDebug();
                logging.AddEventSourceLogger();
            })

这里添加的LoggerProvider最终都会被注入到LoggerFactory中,用于创建ILogger。

上述代码里还看到了AddConfiguration,这是通过配置添加日志过滤条件。后面会具体讲解。

添加完Provider之后,就可以从容器中获取日志对象,获取的时候有两种类型可以获取:

  • ILogger<T>:直接获取日志输出对象。
  • ILoggerFactory:获取日志工厂,然后调用ILogger CreateLogger(string categoryName);这个方法产生一个日志输出对象。实际上第一种方式,直接获取的ILogger<T,>内部也包含了一个ILogger对象,它最终也是调用的内部的ILogger进行操作,自己本身没有干任何事情。可以看一下ILogger<T>的实现类代码:
        public class Logger<T> : ILogger<T>
        {
            private readonly ILogger _logger;
    
            /// <summary>
            /// Creates a new <see cref="Logger{T}"/>.
            /// </summary>
            /// <param name="factory">The factory.</param>
            public Logger(ILoggerFactory factory)
            {
                if (factory == null)
                {
                    throw new ArgumentNullException(nameof(factory));
                }
    
                _logger = factory.CreateLogger(TypeNameHelper.GetTypeDisplayName(typeof(T)));
            }
    
            IDisposable ILogger.BeginScope<TState>(TState state)
            {
                return _logger.BeginScope(state);
            }
    
            bool ILogger.IsEnabled(LogLevel logLevel)
            {
                return _logger.IsEnabled(logLevel);
            }
    
            void ILogger.Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
            {
                _logger.Log(logLevel, eventId, state, exception, formatter);
            }
        }

    从这里看出,如果以泛型的方式去获取,categoryName就是这个类的全称,基本上就等于typeof(T).FullName,这个会在后续的日志过滤中起到效果。

在Controller中使用日志

这是一个最简单的例子,实际记录日志的地方,一般不会在构造里面:

    public class HomeController : Controller
    {
        public HomeController(ILogger<HomeController> loggerT, ILoggerFactory loggerFactory)
        {
            var testLog = loggerFactory.CreateLogger("Test");

            loggerT.LogInformation("Info");
            testLog.LogInformation("Info");
        }
}

讲到这里你可能会有一些疑问:我添加了多个LogProvider,自然会产生多个ILogger,那这里通过工厂类产生的ILogger到底是哪一个?答案是:一个都不是!这里通过工厂产生的ILogger是系统的默认实现Microsoft.Extensions.Logging.Logger。而在这个默认实现Logger里,有一个LoggerInformation数组。LoggerInformation包含了这些LogProvider产生的ILogger和一些过滤条件,在不添加任何过滤条件的情况下,上述的代码同时会记录到3个不同的地方。

添加了多少个LogProvider,这个LoggerInformation数组的长度就为多少。LoggerInformation和LogProvider一一对应。

另外,如果想以注入的方式去获取ILogger是行不通的,因为在初始化的时候,不会向容器中注册ILogger的实现,只会注册ILoggerFactory和ILogger<T>。值得一提的是,每产生一个ILogger(默认实现Logger)都会根据CategoryName缓存起来。

日志过滤

在讲日志过滤的时候,我们要先明确日志过滤的筛选的条件有哪些:

  • Category:这个值就是在创建ILogger(系统默认的实现Logger)时,传递的那个categoryName参数。对于以ILogger<T>方式获取的日志对象,这个值就是T的类型全称。
  • ProviderType:这个值就很简单,就是创建该ILogger的LogProvider的类型。
  • LogLevel:日志记录的级别,这是一个系统定义的枚举类型:
    public enum LogLevel
        {
            /// <summary>
            /// Logs that contain the most detailed messages. These messages may contain sensitive application data.
            /// These messages are disabled by default and should never be enabled in a production environment.
            /// </summary>
            Trace = 0,
    
            /// <summary>
            /// Logs that are used for interactive investigation during development.  These logs should primarily contain
            /// information useful for debugging and have no long-term value.
            /// </summary>
            Debug = 1,
    
            /// <summary>
            /// Logs that track the general flow of the application. These logs should have long-term value.
            /// </summary>
            Information = 2,
    
            /// <summary>
            /// Logs that highlight an abnormal or unexpected event in the application flow, but do not otherwise cause the
            /// application execution to stop.
            /// </summary>
            Warning = 3,
    
            /// <summary>
            /// Logs that highlight when the current flow of execution is stopped due to a failure. These should indicate a
            /// failure in the current activity, not an application-wide failure.
            /// </summary>
            Error = 4,
    
            /// <summary>
            /// Logs that describe an unrecoverable application or system crash, or a catastrophic failure that requires
            /// immediate attention.
            /// </summary>
            Critical = 5,
    
            /// <summary>
            /// Not used for writing log messages. Specifies that a logging category should not write any messages.
            /// </summary>
            None = 6,
        }

这几个参数和ILogger(LogProvider产生的)会一起被保存到LoggerInformation这个对象中。在LoggerInformation还有一个属性也是用做日志过滤的:

public Func<string, string, LogLevel, bool> Filter { get; set; }

这是一个委托需要三个参数,分别代表Category,ProviderType,LogLevel,返回布尔值,代表是否启用该日志类型。当有了这些信息后,每当使用ILogger(系统的默认实现Logger)进行日志书写时,会循环遍历LoggerInformation数组对象,这样就可以独立控制每一个LogProvider产生的ILogger对象,根据不同的Provider,Category和LogLevel来决定是否需要输出日志。

接下来的问题就是,如何配置过滤规则?配置过滤规则唯一途径就是配置LoggerFilterOptions这个对象。如何自己配置一个Option对象,请参考我同系列的前一篇文章。

系统提供了一系列的的扩展方法帮我们去配置这个对象,详情可以参考:https://github.com/aspnet/Extensions/blob/master/src/Logging/Logging/src/FilterLoggingBuilderExtensions.cs,也有基于配置的扩展,其核心代码是:https://github.com/aspnet/Extensions/blob/master/src/Logging/Logging.Configuration/src/LoggerFilterConfigureOptions.cs 那这个LoggerFilterOptions又是什么呢,一起看一下源代码:

    public class LoggerFilterOptions
    {
        /// <summary>
        /// Gets or sets the minimum level of log messages if none of the rules match.
        /// </summary>
        public LogLevel MinLevel { get; set; }

        /// <summary>
        /// Gets the collection of <see cref="LoggerFilterRule"/> used for filtering log messages.
        /// </summary>
        public IList<LoggerFilterRule> Rules { get; } = new List<LoggerFilterRule>();
    }

 

系统提供的所有扩展方法,都是往这个对象的Rules添加Rule,然后在创建一个ILogger(LogProvider创建的)的时候根据一定的规则去匹配到属于这个ILogger(LogProvider创建的)的那条Rule,赋值给LoggerInformation的Filter属性。也就是说,即使有很多条Rule,但是最终只会找到最符合条件的那条Rule。如果一条都找不到,那就使用MinLevel。默认情况下MinLevel是Information。而这个LoggerFilterRule包含的属性,就是前面提到的那几个筛选条件:

    public class LoggerFilterRule
    {
        public LoggerFilterRule(string providerName, string categoryName, LogLevel? logLevel, Func<string, string, LogLevel, bool> filter)
        {
            ProviderName = providerName;
            CategoryName = categoryName;
            LogLevel = logLevel;
            Filter = filter;
        }

        /// <summary>
        /// Gets the logger provider type or alias this rule applies to.
        /// </summary>
        public string ProviderName { get; }

        /// <summary>
        /// Gets the logger category this rule applies to.
        /// </summary>
        public string CategoryName { get; }

        /// <summary>
        /// Gets the minimum <see cref="LogLevel"/> of messages.
        /// </summary>
        public LogLevel? LogLevel { get; }

        /// <summary>
        /// Gets the filter delegate that would be applied to messages that passed the <see cref="LogLevel"/>.
        /// </summary>
        public Func<string, string, LogLevel, bool> Filter { get; }

        public override string ToString()
        {
            return $"{nameof(ProviderName)}: '{ProviderName}', {nameof(CategoryName)}: '{CategoryName}', {nameof(LogLevel)}: '{LogLevel}', {nameof(Filter)}: '{Filter}'";
        }
    }

 

那查找Rule的匹配规则又是什么呢?核心代码如下(可以直接看后面的解释):

    internal class LoggerRuleSelector
    {
        public void Select(LoggerFilterOptions options, Type providerType, string category, out LogLevel? minLevel, out Func<string, string, LogLevel, bool> filter)
        {
            filter = null;
            minLevel = options.MinLevel;

            // Filter rule selection:
            // 1. Select rules for current logger type, if there is none, select ones without logger type specified
            // 2. Select rules with longest matching categories
            // 3. If there nothing matched by category take all rules without category
            // 3. If there is only one rule use it's level and filter
            // 4. If there are multiple rules use last
            // 5. If there are no applicable rules use global minimal level

            var providerAlias = ProviderAliasUtilities.GetAlias(providerType);
            LoggerFilterRule current = null;
            foreach (var rule in options.Rules)
            {
                if (IsBetter(rule, current, providerType.FullName, category)
                    || (!string.IsNullOrEmpty(providerAlias) && IsBetter(rule, current, providerAlias, category)))
                {
                    current = rule;
                }
            }

            if (current != null)
            {
                filter = current.Filter;
                minLevel = current.LogLevel;
            }
        }

        private static bool IsBetter(LoggerFilterRule rule, LoggerFilterRule current, string logger, string category)
        {
            // Skip rules with inapplicable type or category
            if (rule.ProviderName != null && rule.ProviderName != logger)
            {
                return false;
            }

            if (rule.CategoryName != null && !category.StartsWith(rule.CategoryName, StringComparison.OrdinalIgnoreCase))
            {
                return false;
            }

            if (current?.ProviderName != null)
            {
                if (rule.ProviderName == null)
                {
                    return false;
                }
            }
            else
            {
                // We want to skip category check when going from no provider to having provider
                if (rule.ProviderName != null)
                {
                    return true;
                }
            }

            if (current?.CategoryName != null)
            {
                if (rule.CategoryName == null)
                {
                    return false;
                }

                if (current.CategoryName.Length > rule.CategoryName.Length)
                {
                    return false;
                }
            }

            return true;
        }
    }

 

在配置规则时ProviderName默认应该是类的全称,而上面提到的ProviderAlias指的是该类的别称,在类上面添加ProviderAliasAttribute为它定义一个别称,方便配置。

再来看IsBetter方法:

  1. 如果传进来的Rule应用于某一个具体的Provider,并且和当前Log的Provider不一致,则直接返回False,因为不匹配
  2. 如果传进来的的Rule应用于某一个具体的Category(默认是类的全名),并且和当前Log的Category不匹配,则返回False,因为不匹配
  3. 如果当前的Rule应用于某一个具体的Provider,并且传进来的Rule不是应用于某一个具体的Provider,则返回False,因为当前的优先级更高
  4. 如果当前的Rule不是应用于某一个具体的Provider,并且传进来的Rule是应用于某一个具体的Provider(由于第一点的存在,传进来的Rule的Provider一定是和当前Log一致的,由于第二点的存在,如果传进来的Rule包含Category,则一定和当前的Log一致),则返回True,因为传进来的优先级更高
  5. 如果当前的Rule是应用于某一个具体的Category,并且传递进来的Rule不是应用于某一个具体的Category,则返回False,因为当前优先级更高
  6. 如果当前的Rule是应用于某一个具体的Category,并且当前传递进来的Rule也是应用于某一个具体的Category,但是当前的匹配度更高(字符串长度越长),则返回False,因为当前的优先级更高
  7. 其余都返回True

那么最终Rule的匹配度,由低到高应该是:

  1. ProviderName: null,CategoryName:null
  2. ProviderName: null,CategoryName:Matched(匹配的长度越长,说明越匹配)
  3. ProviderName: Matched,CategoryName:null
  4. ProviderName: Matched,CategoryName:Matched(匹配的长度越长,说明越匹配)

CategoryName的匹配度指的是字符串长度。如果一个Rule都没找到,那就使用MinLevel。

最佳实践

使用配置文件,去配置日志过滤条件,注意:使用配置文件时,只能设置特定的Provider和Category的LogLevel,不能指定委托类型的Filter。想要使用Filter,只能用编码的方式配置。来看一个日志配置实例:

  "Logging": {
    "LogLevel": {
      "Default": "Debug"
    },
    "Console": {
      "LogLevel": {
        "Default": "Warning",
        "CoreLogging.Controllers": "Error",
        "CoreLogging.Controllers.HomeController": "Info"
      }
    }
  }

 

在Logging下面的直接子节点LogLevel下面配置的,代表Proivder为null,同时子节点的名称代表Category,值代表LogLevel。

而Logging下面的其它直接子节点,节点名称代表ProviderName。其下的LogLevel子节点下面的子节点,名称代表Category,值代表LogLevel。

另外Category的值为Default,最终解析的时候会解析成null,不区分大小写。

这里的Console可以使用Microsoft.Extensions.Logging.Console.ConsoleLoggerProvider代替,因为ConsoleLoggerProvider有一个特性别称Console,所以可以不写全称。[ProviderAlias("Console")]

最终这个配置会被解释成:

  1. 非Console的日志记录时,只记录日志级别高于Debug
  2. Console的日志,如果Category不以CoreLogging.Controllers开头,则只记录级别高于Warning的
  3. Console的日志,如果Category以CoreLogging.Controllers开头但不以CoreLogging.Controllers.HomeController开头,则只记录级别高于Error的
  4. Console的日志,如果Category以CoreLogging.Controllers.HomeController开头,则只记录级别高于Info的

 

文中提到的源码都在https://github.com/zhurongbo111/AspNetCoreDemo/tree/master/03-Logging

上一篇:.Net Core3.0 配置Configuration


下一篇:RobotFramework Selenium2 关键字