.NET 中的高性能日志记录

项目
04/11/2024

LoggerMessage 类公开了用于创建可缓存委托的功能，该功能比LoggerMessage（例如 LogInformation 和 LogDebug）需要的对象分配和计算开销要少。对于高性能日志记录方案，请使用 LoggerMessage 模式。

与记录器扩展方法相比，LoggerMessage 具有以下性能优势：

记录器扩展方法需要将值类型（例如 int）“装箱”（转换）到 object 中。 LoggerMessage 模式使用带强类型参数的静态 Action 字段和扩展方法来避免装箱。
记录器扩展方法每次写入日志消息时必须分析消息模板（命名的格式字符串）。如果已定义消息，那么 LoggerMessage 只需分析一次模板即可。

重要

在 .NET 6 及更高版本中，可以使用 LoggerMessage 属性而不是 LoggerMessage 类来创建高性能日志。 LoggerMessageAttribute 提供源生成日志记录支持，旨在为新式 .NET 应用程序提供高度可用且高性能的日志记录解决方案。有关详细信息，请参阅编译时日志记录源生成（.NET 基础知识）。

示例应用展示了具有优先级队列处理辅助角色服务的 LoggerMessage 功能。应用按优先级顺序处理工作项。发生这些操作时，通过 LoggerMessage 模式生成日志消息。

提示

所有日志记录示例源代码都可以在示例浏览器中下载。有关详细信息，请参阅浏览代码示例：.NET 中的日志记录。

定义记录器消息

使用 Define(LogLevel, EventId, String) 创建一个用于记录消息的 Action 委托。 Define 重载允许向命名的格式字符串（模板）传递最多六个类型参数。

提供给 Define 方法的字符串是一个模板，而不是内插字符串。占位符按照指定类型的顺序填充。模板中的占位符名称在各个模板中应当具备描述性和一致性。它们在结构化的日志数据中充当属性名称。对于占位符名称，建议使用帕斯卡拼写法。例如：{Item}、{DateTime}。

每条日志消息都是一个 Action，保存在由 Action 创建的静态字段中。例如，示例应用创建一个字段来描述处理工作项的日志消息：

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

对于 Action，指定：

日志级别。
具有静态扩展方法名称的唯一事件标识符 (EventId)。
消息模板（命名的格式字符串）。

由于对工作项处理取消排队，辅助角色服务应用会进行下列设置：

将日志级别设置为 LogLevel.Critical。
将事件 ID 设置为具有 FailedToProcessWorkItem 方法名称的 13。
将消息模板（命名的格式字符串）设置为字符串。

s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

LoggerMessage.Define 方法用于配置和定义表示日志消息的 Action 委托。

结构化日志记录存储可以使用事件名称（当它获得事件 ID 时）来丰富日志记录。例如，Serilog 使用该事件名称。

通过强类型扩展方法调用 Action。 PriorityItemProcessed 方法会在每次处理工作项时记录一条消息。在（如果）发生异常时调用 FailedToProcessWorkItem：

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

检查应用的控制台输出：

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.
         at WorkerServiceOptions.Example.Worker.ExecuteAsync(CancellationToken stoppingToken) in
         ..\Worker.cs:line 27

要将参数传递给日志消息，创建静态字段时最多定义六种类型。在通过定义 Action 字段的 WorkItem 类型来处理项时，示例应用会记录工作项的详细信息：

private static readonly Action<ILogger, WorkItem, Exception> s_processingPriorityItem;

委托的日志消息模板从提供的类型接收其占位符值。示例应用定义一个委托，用于在 item 参数是 WorkItem 的位置添加一个工作项：

s_processingPriorityItem = LoggerMessage.Define<WorkItem>(
    LogLevel.Information,
    new EventId(1, nameof(PriorityItemProcessed)),
    "Processing priority item: {Item}");

用于记录正在处理工作项的静态扩展方法 PriorityItemProcessed 接收工作项参数值并将其传递给 Action 委托：

public static void PriorityItemProcessed(
    this ILogger logger, WorkItem workItem) =>
    s_processingPriorityItem(logger, workItem, default!);

在辅助角色服务的 ExecuteAsync 方法中，调用 PriorityItemProcessed 以记录消息：

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

检查应用的控制台输出：

info: WorkerServiceOptions.Example.Worker[1]
      Processing priority item: Priority-Extreme (50db062a-9732-4418-936d-110549ad79e4): 'Verify communications'

指定记录器消息作用域

DefineScope(string) 方法创建一个用于定义日志作用域的 Func<TResult> 委托。 DefineScope 重载允许向命名的格式字符串（模板）传递最多六个类型参数。

Define 方法也一样，提供给 DefineScope 方法的字符串是一个模板，而不是内插字符串。占位符按照指定类型的顺序填充。模板中的占位符名称在各个模板中应当具备描述性和一致性。它们在结构化的日志数据中充当属性名称。对于占位符名称，建议使用帕斯卡拼写法。例如：{Item}、{DateTime}。

使用 DefineScope 方法定义一个日志作用域，以应用到一系列日志消息中。在 appsettings.json 的控制台记录器部分启用 IncludeScopes：

{
    "Logging": {
        "Console": {
            "IncludeScopes": true
        },
        "LogLevel": {
            "Default": "Information",
            "Microsoft": "Warning",
            "Microsoft.Hosting.Lifetime": "Information"
        }
    }
}

要创建日志作用域，请添加一个字段来保存该作用域的 Func<TResult> 委托。示例应用创建一个名为 s_processingWorkScope (Internal/LoggerExtensions.cs) 的字段：

private static readonly Func<ILogger, DateTime, IDisposable?> s_processingWorkScope;

使用 DefineScope 来创建委托。调用委托时最多可以指定 6 种类型作为模板参数使用。示例应用使用包含处理开始的日期时间的消息模板：

s_processingWorkScope =
    LoggerMessage.DefineScope<DateTime>(
        "Processing scope, started at: {DateTime}");

为日志消息提供一种静态扩展方法。包含已命名属性的任何类型参数（这些参数出现在消息模板中）。示例应用接受自定义时间戳的 DateTime 以记录和返回 _processingWorkScope：

public static IDisposable? ProcessingWorkScope(
    this ILogger logger, DateTime time) =>
    s_processingWorkScope(logger, time);

该作用域将日志记录扩展调用包装在 using 块中：

protected override async Task ExecuteAsync(
    CancellationToken stoppingToken)
{
    using (IDisposable? scope = logger.ProcessingWorkScope(DateTime.Now))
    {
        while (!stoppingToken.IsCancellationRequested)
        {
            try
            {
                WorkItem? nextItem = priorityQueue.ProcessNextHighestPriority();

                if (nextItem is not null)
                {
                    logger.PriorityItemProcessed(nextItem);
                }
            }
            catch (Exception ex)
            {
                logger.FailedToProcessWorkItem(ex);
            }

            await Task.Delay(1_000, stoppingToken);
        }
    }
}

检查应用控制台输出中的日志消息。以下结果显示日志消息的优先级排序，其中包括日志作用域消息：

info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Extreme (7d153ef9-8894-4282-836a-8e5e38319fb3): 'Verify communications'
info: Microsoft.Hosting.Lifetime[0]
      Application started. Press Ctrl+C to shut down.
info: Microsoft.Hosting.Lifetime[0]
      Hosting environment: Development
info: Microsoft.Hosting.Lifetime[0]
      Content root path: D:\source\repos\dotnet-docs\docs\core\extensions\snippets\logging\worker-service-options
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-High (dbad6558-60cd-4eb1-8531-231e90081f62): 'Validate collection'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1eabe213-dc64-4e3a-9920-f67fe1dfb0f6): 'Propagate selections'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Medium (1142688d-d4dc-4f78-95c5-04ec01cbfac7): 'Enter pooling [contention]'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Low (e85e0c4d-0840-476e-b8b0-22505c08e913): 'Health check network'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (07571363-d559-4e72-bc33-cd8398348786): 'Ping weather service'
info: WorkerServiceOptions.Example.Worker[1]
      => Processing scope, started at: 04/11/2024 11:27:52
      Processing priority item: Priority-Deferred (2bf74f2f-0198-4831-8138-03368e60bd6b): 'Set process state'
info: Microsoft.Hosting.Lifetime[0]
      Application is shutting down...

日志级防护优化

在调用相应的 Log* 方法之前，可通过使用 ILogger.IsEnabled(LogLevel) 检查 LogLevel 来进行另一种性能优化。未为给定的 LogLevel 配置日志记录时，以下语句为 true：

ILogger.Log 未调用。
避免分配表示参数的 object[]。
避免值类型装箱。

参考信息：

另请参阅

.NET 中的日志记录

.NET 中的高性能日志记录

定义记录器消息

指定记录器消息作用域

日志级防护优化

另请参阅

反馈

其他资源