Edit

Share via

High-performance logging in .NET

For high-performance logging scenarios in .NET 6 and later versions, use the LoggerMessageAttribute with compile-time source generation. This approach provides the best performance by eliminating boxing, temporary allocations, and message template parsing at runtime.

Source-generated logging provides the following performance advantages over logger extension methods, such as LogInformation and LogDebug:

  • Eliminates boxing: Logger extension methods require "boxing" (converting) value types, such as int, into object. Source-generated logging avoids boxing by using strongly typed parameters.
  • Parses templates at compile time: Logger extension methods must parse the message template (named format string) every time a log message is written. Source-generated logging parses templates once at compile time.
  • Reduces allocations: The source generator creates optimized code that minimizes object allocations and temporary memory usage.

The sample app demonstrates high-performance logging features with a priority queue processing worker service. The app processes work items in priority order. As these operations occur, log messages are generated using source-generated logging.

Tip

All of the logging example source code is available in the Samples Browser for download. For more information, see Browse code samples: Logging in .NET.

Define logger messages with source generation

To create high-performance log messages in .NET 6 and later, define partial methods decorated with LoggerMessageAttribute. The source generator creates the implementation at compile time.

Basic logging method

For a simple log message, define a partial method with the attribute specifying the event ID, log level, and message template:

public static partial class Log
{
    [LoggerMessage(
        EventId = 13,
        Level = LogLevel.Critical,
        Message = "Epic failure processing item!")]
    public static partial void FailedToProcessWorkItem(
        ILogger logger, Exception ex);
}

The message template uses placeholders that are filled by method parameters. Placeholder names should be descriptive and consistent across templates. They serve as property names within structured log data. We recommend Pascal casing for placeholder names. For example, {Item}, {DateTime}.

Call the logging method from your code. For example, when an exception occurs during work item processing:

try
{
    // Process work item.
}
catch (Exception ex)
{
    Log.FailedToProcessWorkItem(logger, ex);
}

This code produces console output like:

crit: WorkerServiceOptions.Example.Worker[13]
      Epic failure processing item!
      System.Exception: Failed to verify communications.

Logging with parameters

To pass parameters to a log message, add them as method parameters. The parameter names match the placeholders in the message template:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Call the method with the logger and parameter values:

var workItem = queue.Dequeue();
Log.PriorityItemProcessed(logger, workItem);

This code produces console output like:

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

Structured logging stores can use the event name when it's supplied with the event ID to enrich logging. For example, Serilog uses the event name.

Define logger message scope with source generation

You can define log scopes to wrap a series of log messages with additional context. With source-generated logging, you combine the LoggerMessageAttribute methods with the standard ILogger.BeginScope method.

Enable IncludeScopes in the console logger section of appsettings.json:

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

Create source-generated logging methods and wrap them in a scope using BeginScope:

public static partial class Log
{
    [LoggerMessage(
        EventId = 1,
        Level = LogLevel.Information,
        Message = "Processing priority item: {Item}")]
    public static partial void PriorityItemProcessed(
        ILogger logger, WorkItem item);
}

Use the logging method within a scope in your application code:

using (_logger.BeginScope("Processing scope, started at: {DateTime}", DateTime.Now))
{
    Log.PriorityItemProcessed(_logger, workItem);
}

Inspect the log messages in the app's console output. The following result shows priority ordering of log messages with the log scope message included:

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'

Legacy approach: LoggerMessage.Define (for .NET Framework and .NET Core 3.1)

Before source-generated logging was introduced in .NET 6, the recommended high-performance logging approach was to use the LoggerMessage.Define method to create cacheable delegates. While this approach is still supported for backward compatibility, new code should use source-generated logging with LoggerMessageAttribute instead.

The LoggerMessage class exposes functionality to create cacheable delegates that require fewer object allocations and reduced computational overhead compared to logger extension methods, such as LogInformation and LogDebug. LoggerMessage provides the following performance advantages over logger extension methods:

  • Logger extension methods require "boxing" (converting) value types, such as int, into object. The LoggerMessage pattern avoids boxing by using static Action fields and extension methods with strongly typed parameters.
  • Logger extension methods must parse the message template (named format string) every time a log message is written. LoggerMessage only requires parsing a template once when the message is defined.

Note

If you're maintaining code that uses LoggerMessage.Define, consider migrating to source-generated logging. For .NET Framework or .NET Core 3.1 applications, continue using LoggerMessage.Define.

Define a logger message

Use Define(LogLevel, EventId, String) to create an Action delegate for logging a message. Define overloads permit passing up to six type parameters to a named format string (template).

The string provided to the Define method is a template and not an interpolated string. Placeholders are filled in the order that the types are specified. Placeholder names in the template should be descriptive and consistent across templates. They serve as property names within structured log data. We recommend Pascal casing for placeholder names. For example, {Item}, {DateTime}.

Each log message is an Action held in a static field created by LoggerMessage.Define. For example, the sample app creates a field to describe a log message for the processing of work items:

private static readonly Action<ILogger, Exception> s_failedToProcessWorkItem;

For the Action, specify:

  • The log level.
  • A unique event identifier (EventId) with the name of the static extension method.
  • The message template (named format string).

As work items are dequeued for processing, the worker service app sets the:

  • Log level to LogLevel.Critical.
  • Event ID to 13 with the name of the FailedToProcessWorkItem method.
  • Message template (named format string) to a string.
s_failedToProcessWorkItem = LoggerMessage.Define(
    LogLevel.Critical,
    new EventId(13, nameof(FailedToProcessWorkItem)),
    "Epic failure processing item!");

The LoggerMessage.Define method is used to configure and define an Action delegate, which represents a log message.

Structured logging stores can use the event name when it's supplied with the event ID to enrich logging. For example, Serilog uses the event name.

The Action is invoked through a strongly typed extension method. The PriorityItemProcessed method logs a message every time a work item is processed. FailedToProcessWorkItem is called if and when an exception occurs:

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

Inspect the app's console output:

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

To pass parameters to a log message, define up to six types when creating the static field. The sample app logs the work item details when processing items by defining a WorkItem type for the Action field:

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

The delegate's log message template receives its placeholder values from the types provided. The sample app defines a delegate for adding a work item where the item parameter is a WorkItem:

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

The static extension method for logging that a work item is being processed, PriorityItemProcessed, receives the work item argument value and passes it to the Action delegate:

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

In the worker service's ExecuteAsync method, PriorityItemProcessed is called to log the message:

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

Inspect the app's console output:

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

Log-level guarded optimizations

You can optimize performance by checking the LogLevel with ILogger.IsEnabled(LogLevel) before invoking the corresponding Log* method. When logging isn't configured for the given LogLevel, ILogger.Log isn't called. In addition, value-type boxing and an allocation of object[] (to represent the parameters) are avoided.

For more information, see:

See also

  • Last updated on