重新整理 .net core 實踐篇—————日誌系統之戰地記者[十五]

前言

本節開始整理日誌相關的東西。先整理一下日誌的基本原理。

正文

首先介紹一下包:

Microsoft.Extengsion.Logging.Abstrations

這個是介面包。

Microsoft.Extengsion.Logging

這個是實現包

Microsoft.Extengsion.Logging.Console

這個是擴充套件包

程式碼如下:

static void Main(string[] args)
{
	IConfigurationBuilder configurationBuilder = new ConfigurationBuilder();
	configurationBuilder.AddJsonFile("appsettings.json",optional:false,reloadOnChange:true);
	var config = configurationBuilder.Build();

	IServiceCollection serviceCollection = new ServiceCollection();
	serviceCollection.AddSingleton<IConfiguration>(p=>config);

	serviceCollection.AddLogging(builder =>
	{
		builder.AddConfiguration(config.GetSection("Logging"));
		builder.AddConsole();
	});

	IServiceProvider service = serviceCollection.BuildServiceProvider();

	ILoggerFactory loggerFactory = service.GetService<ILoggerFactory>();

	var loggerObj = loggerFactory.CreateLogger("Default");

	loggerObj.LogInformation(2021, "Default,now that is 2021");

	var loggerObj2 = loggerFactory.CreateLogger("loggerObj");

	loggerObj2.LogDebug(2021, "loggerObj,now that is 2021");

	Console.ReadKey();
}

配置檔案:

{
  "Logging": {
    "LogLevel": {
      "Default": "Debug",
      "Microsoft": "Warning",
      "Microsoft.Hosting.Lifetime": "Information"
    },
    "Console": {
      "LogLevel": {
        "Default": "Information",
        "Program": "Trace",
        "loggerObj": "Debug"
      }
    }
  }
}

結果:

首先是配置級別的問題,檢視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,
/// <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,
/// <summary>Logs that track the general flow of the application. These logs should have long-term value.</summary>
Information,
/// <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,
/// <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,
/// <summary>Logs that describe an unrecoverable application or system crash, or a catastrophic failure that requires
/// immediate attention.</summary>
Critical,
/// <summary>Not used for writing log messages. Specifies that a logging category should not write any messages.</summary>
None,
}

從上之下，依次提高log級別。

比如說設定了log 級別是Error，那麼Debug、Information、Warning 都不會被答應出來。

那麼就來分析一下程式碼吧。

AddLogging:

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;
}

這裡面給註冊了ILoggerFactory和ILogger。然後設定了一個列印log的級別配置，LogLevel.Information，這個就是如果我們沒有配置檔案預設就是Information這種級別了。

configure(new LoggingBuilder(services)) 給我們的委託提供了一個LoggingBuilder的例項化物件。這個物件就是用來專門做擴充套件的，是解耦的一種方式。

internal class LoggingBuilder : ILoggingBuilder
{
	public LoggingBuilder(IServiceCollection services)
	{
		Services = services;
	}

	public IServiceCollection Services { get; }
}

這個LoggingBuilder 類基本什麼功能都沒有，但是因為有了這樣一個類，就可以作為擴充套件的標誌了。

比如說上文的:

builder.AddConfiguration(config.GetSection("Logging"));
builder.AddConsole();

看下AddConfiguration:

public static ILoggingBuilder AddConfiguration(this ILoggingBuilder builder, IConfiguration configuration)
{
	builder.AddConfiguration();

	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;
}

這裡面給我們注入了配置檔案的配置:builder.Services.AddSingleton<IConfigureOptions>(new LoggerFilterConfigureOptions(configuration))

同時給我們註冊監聽令牌:builder.Services.AddSingleton<IOptionsChangeTokenSource>(new ConfigurationChangeTokenSource(configuration));

這裡給我們註冊配置儲存在LoggingConfiguration中：builder.Services.AddSingleton(new LoggingConfiguration(configuration));

因為LoggingConfiguration 儲存了，故而我們隨時可以獲取到LoggingConfiguration 的配置。

看下AddConsole:

/// <param name="builder">The <see cref="ILoggingBuilder"/> to use.</param>
public static ILoggingBuilder AddConsole(this ILoggingBuilder builder)
{
	builder.AddConfiguration();

	builder.AddConsoleFormatter<JsonConsoleFormatter, JsonConsoleFormatterOptions>();
	builder.AddConsoleFormatter<SystemdConsoleFormatter, ConsoleFormatterOptions>();
	builder.AddConsoleFormatter<SimpleConsoleFormatter, SimpleConsoleFormatterOptions>();

	builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<ILoggerProvider, ConsoleLoggerProvider>());
	LoggerProviderOptions.RegisterProviderOptions<ConsoleLoggerOptions, ConsoleLoggerProvider>(builder.Services);

	return builder;
}

builder.Services.TryAddEnumerable(ServiceDescriptor.Singleton<ILoggerProvider, ConsoleLoggerProvider>()) 裡面給我們ILoggerProvider 增加了一個ConsoleLoggerProvider，故而我們多了一個列印的功能。

LoggerProviderOptions.RegisterProviderOptions<ConsoleLoggerOptions, ConsoleLoggerProvider>(builder.Services) 給我們加上了ConsoleLoggerOptions 繫結為ConsoleLoggerProvider的配置。

RegisterProviderOptions 如下:

public static void RegisterProviderOptions<TOptions, TProvider>(IServiceCollection services) where TOptions : class
{
	services.TryAddEnumerable(ServiceDescriptor.Singleton<IConfigureOptions<TOptions>, LoggerProviderConfigureOptions<TOptions, TProvider>>());
	services.TryAddEnumerable(ServiceDescriptor.Singleton<IOptionsChangeTokenSource<TOptions>, LoggerProviderOptionsChangeTokenSource<TOptions, TProvider>>());
}

接下來就是呼叫服務:

var loggerObj = loggerFactory.CreateLogger("Default");

loggerObj.LogInformation(2021, "Default,now that is 2021");

看下LoggerFactory的CreateLogger：

public ILogger CreateLogger(string categoryName)
{
	if (CheckDisposed())
	{
		throw new ObjectDisposedException(nameof(LoggerFactory));
	}

	lock (_sync)
	{
		if (!_loggers.TryGetValue(categoryName, out Logger logger))
		{
			logger = new Logger
			{
				Loggers = CreateLoggers(categoryName),
			};

			(logger.MessageLoggers, logger.ScopeLoggers) = ApplyFilters(logger.Loggers);

			_loggers[categoryName] = logger;
		}

		return logger;
	}
}

裡面做了快取，如果categoryName有快取的話直接使用快取，如果沒有那麼呼叫CreateLoggers建立。

檢視CreateLoggers:

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的provider，封裝進LoggerInformation。

檢視LoggerInformation:

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; }

	public Type ProviderType { get; }

	public bool ExternalScope { get; }
}

裡面呼叫了我們，每個provider的CreateLogger。

那麼這個時候我們就找一個provider 看下CreateLogger到底做了什麼，這裡就找一下ConsoleLoggerProvider，因為我們新增了這個。

[ProviderAlias("Console")]
 public class ConsoleLoggerProvider : ILoggerProvider, ISupportExternalScope
{
        private readonly IOptionsMonitor<ConsoleLoggerOptions> _options;
        public ILogger CreateLogger(string name)
        {
            if (_options.CurrentValue.FormatterName == null || !_formatters.TryGetValue(_options.CurrentValue.FormatterName, out ConsoleFormatter logFormatter))
            {
#pragma warning disable CS0618
                logFormatter = _options.CurrentValue.Format switch
                {
                    ConsoleLoggerFormat.Systemd => _formatters[ConsoleFormatterNames.Systemd],
                    _ => _formatters[ConsoleFormatterNames.Simple],
                };
                if (_options.CurrentValue.FormatterName == null)
                {
                    UpdateFormatterOptions(logFormatter, _options.CurrentValue);
                }
#pragma warning disable CS0618
            }

            return _loggers.GetOrAdd(name, loggerName => new ConsoleLogger(name, _messageQueue)
            {
                Options = _options.CurrentValue,
                ScopeProvider = _scopeProvider,
                Formatter = logFormatter,
            });
        }
}

看到這個IOptionsMonitor，就知道console 配置是支援熱更新的，裡面建立了ConsoleLogger，這個ConsoleLogger就是用來打log正在的呼叫類。

值得注意的是_messageQueue這個，看了列印log還是有一個佇列的，按照先進先出原則。

那麼最後來看一下loggerObj.LogInformation(2021, "Default,now that is 2021");:

第一層
public static void LogInformation(this ILogger logger, EventId eventId, string message, params object[] args)
{
	logger.Log(LogLevel.Information, eventId, message, args);
}
第二層
public static void Log(this ILogger logger, LogLevel logLevel, EventId eventId, string message, params object[] args)
{
         logger.Log(logLevel, eventId, 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);
}

那麼這個logger.Log 是呼叫具體某個logger，像consoleLogger 嗎？不是，我們看LoggerFactory的CreateLogger時候封裝了：

logger = new Logger
{
       Loggers = CreateLoggers(categoryName),
};

那麼看下Logger的Log到底幹了什麼。

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)
	{
		MessageLogger[] loggers = MessageLoggers;
		if (loggers == null)
		{
			return;
		}

		List<Exception> exceptions = null;
		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);
		}

		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);
			}
		}
	}
}

裡面迴圈判斷是否當前級別能夠輸出：!loggerInfo.IsEnabled(logLevel)

然後呼叫對應的具體ILog實現的Log，這裡貼一下ConsoleLogger 的實現:

[ThreadStatic]
private static StringWriter t_stringWriter;

public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
	if (!IsEnabled(logLevel))
	{
		return;
	}
	if (formatter == null)
	{
		throw new ArgumentNullException(nameof(formatter));
	}
	t_stringWriter ??= new StringWriter();
	LogEntry<TState> logEntry = new LogEntry<TState>(logLevel, _name, eventId, state, exception, formatter);
	Formatter.Write(in logEntry, ScopeProvider, t_stringWriter);

	var sb = t_stringWriter.GetStringBuilder();
	if (sb.Length == 0)
	{
		return;
	}
	string computedAnsiString = sb.ToString();
	sb.Clear();
	if (sb.Capacity > 1024)
	{
		sb.Capacity = 1024;
	}
	_queueProcessor.EnqueueMessage(new LogMessageEntry(computedAnsiString, logAsError: logLevel >= Options.LogToStandardErrorThreshold));
}

把這個佇列的也貼一下，比較經典吧。

internal class ConsoleLoggerProcessor : IDisposable
{
	private const int _maxQueuedMessages = 1024;

	private readonly BlockingCollection<LogMessageEntry> _messageQueue = new BlockingCollection<LogMessageEntry>(_maxQueuedMessages);
	private readonly Thread _outputThread;

	public IConsole Console;
	public IConsole ErrorConsole;

	public ConsoleLoggerProcessor()
	{
		// Start Console message queue processor
		_outputThread = new Thread(ProcessLogQueue)
		{
			IsBackground = true,
			Name = "Console logger queue processing thread"
		};
		_outputThread.Start();
	}

	public virtual void EnqueueMessage(LogMessageEntry message)
	{
		if (!_messageQueue.IsAddingCompleted)
		{
			try
			{
				_messageQueue.Add(message);
				return;
			}
			catch (InvalidOperationException) { }
		}

		// Adding is completed so just log the message
		try
		{
			WriteMessage(message);
		}
		catch (Exception) { }
	}

	// for testing
	internal virtual void WriteMessage(LogMessageEntry entry)
	{
		IConsole console = entry.LogAsError ? ErrorConsole : Console;
		console.Write(entry.Message);
	}

	private void ProcessLogQueue()
	{
		try
		{
			foreach (LogMessageEntry message in _messageQueue.GetConsumingEnumerable())
			{
				WriteMessage(message);
			}
		}
		catch
		{
			try
			{
				_messageQueue.CompleteAdding();
			}
			catch { }
		}
	}

	public void Dispose()
	{
		_messageQueue.CompleteAdding();

		try
		{
			_outputThread.Join(1500); // with timeout in-case Console is locked by user input
		}
		catch (ThreadStateException) { }
	}
}

結

因為是實踐篇，只是具體執行過程帶過一下，細節篇的時候，會詳細介紹一下機制，比如說ConsoleLoggerProcessor的這種佇列機制，又比如說Logger模型設計等。

以上只是個人整理，如有錯誤，望請指出。

下一節，服務與logger系統之間。

重新整理 .net core 實踐篇—————日誌系統之戰地記者[十五]

前言

正文

結

相關文章