.Net Core Logging模組原始碼閱讀

李正浩發表於2023-01-12
原始碼

.Net Core Logging模組原始碼閱讀

前言

在Asp.Net Core Webapi專案中經常會用到ILogger，於是在空閒的時候就clone了一下官方的原始碼庫下來研究，這裡記錄一下。

官方庫地址在: https://github.com/dotnet/runtime/tree/main/src/libraries ，其中所有以Microsoft.Extensions.Logging開頭的資料夾內都是日誌相關的模組

核心類

日誌模組中最核心的類其實就是三個: ILogger、ILoggerFactory、ILoggerProvider，三者的作用如下：

  1. ILogger：負責根據日誌級別寫入日誌
  2. ILoggerProvider：負責建立ILogger(但不應該直接使用它來建立一個ILogger)
  3. 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：

  1. ConsoleLoggerProcessor類裡面也比較簡單，就是在後臺開啟一個執行緒專門用於輸出日誌，這樣就不會阻塞主執行緒了，這個類的程式碼就不貼了，感興趣的可以自己看一下。
  2. 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秒內日誌如果沒有輸出完，這些日誌就沒有了

對於輸出到控制檯，丟失了也就丟失了，但是對於一些輸出到檔案或者資料庫的Provider，這就是一個比較大的問題了，所以如果有人需要自己實現Provider，這是一個需要考慮的問題，如果只是簡單粗暴地同步輸出到檔案或資料庫，那會阻塞業務程式碼的執行，所以還得看個人權衡
當然如果你用的是Serilog，那就很簡單，因為它有一個Log.CloseAndFlush()方法用來保證日誌全部輸出
這一部分總結一下就是官方的日誌模組，必須保證IOC容器的釋放，如果用Serilog，那就用CloseAndFlush，對於兩者，都得捕獲所有可能導致程式意外退出的異常，否則均無法保證日誌全部儲存

提一嘴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("測試此條日誌顏色是否改變為紅色");

執行後就可以看到同時輸出了兩種日誌

總結一下這部分，想實現自己的輸出目的，比如資料庫、http、檔案等，只需要自己實現一個Prodiver、一個Logger，就OK了

參考文章

  1. ILogger、ILoggerFactory、ILoggerProvider三者關係 https://stackoverflow.com/questions/51345161/should-i-take-ilogger-iloggert-iloggerfactory-or-iloggerprovider-for-a-libra
  2. 官方文件 https://learn.microsoft.com/zh-cn/dotnet/core/extensions/custom-logging-provider
  3. 官方示例自定義一個日誌提供類 https://github.com/dotnet/docs/tree/main/docs/core/extensions/snippets/configuration/console-custom-logging

相關文章