Drastically reducing memory usage with Log (Part 2)

As seen in the previous article, logging is a common practice in .NET application development, allowing for monitoring behavior or debugging applications. However, there are more efficient approaches that provide better performance when writing logs.

In this post, we will compare the common Logger with the LoggerMessage, analyzing the advantages and disadvantages of each.

The common Logger is the one that uses extension methods of the ILogger interface, such as LogInformation, LogDebug, LogError, among others. These methods are simple and convenient to use but have some disadvantages:

• They require the boxing conversion of value types, such as int, into object. This implies unnecessary memory allocations and copy costs.
• The analysis of the message template (named string format) is performed every time a log message is written. This incurs additional computational costs and potential formatting errors.
• It is not possible to dynamically customize the log level since it is statically defined in the code.

On the other hand, LoggerMessage is a class that offers functionalities to create delegates that can be cached, resulting in fewer object allocations and lower computational overhead compared to Logger extension methods. For high-performance log recording scenarios, the use of the LoggerMessage pattern is recommended, which presents the following advantages:

• Avoids boxing conversion by using fields defined in static actions and extension methods with strongly typed parameters.
• The message template analysis is performed only once, at the time the message is defined, and not on every log call.
• Allows dynamically specifying the log level as a parameter of the log method.

To use LoggerMessage, it is necessary to define an Action delegate using the Define method of the LoggerMessage class, informing the log level, event ID, and message template. Then, the delegate can be invoked by passing the ILogger instance and the message parameters. For example:

public static class LoggerMessageExtension
{
    private static readonly Action<ILogger, int, Exception?> LoggerMessageInformation =
        LoggerMessage.Define<int>(
            LogLevel.Information, 
            0, 
            "Gerando LogInformation : O pedido de número {Pedido} foi criado!");

    public static void LogMessageInformation(this ILogger logger, int pedido)
    {
        LoggerMessageInformation(logger, pedido, null);
    }
}

In the above example, we define a static delegate to log an informative message about an order number, using an integer parameter for the order number. We then create a static method to invoke this delegate, passing the ILogger instance and the order number.

A more convenient alternative to using LoggerMessage is through the LoggerMessageAttribute attribute. This attribute is part of the Microsoft.Extensions.Logging namespace and, when used, generates high-performance log APIs at compile time. The log API generation is designed to provide a highly efficient and user-friendly log solution.

The automatically generated code depends on the ILogger interface in conjunction with the LoggerMessage.Define functionality. The log API generator is triggered when the LoggerMessageAttribute is used in partial log methods. When triggered, it is capable of automatically generating the implementation of the partial methods being decorated or providing compile-time diagnostics with guidance on proper usage.

The compile-time log solution is generally faster at runtime than existing log approaches. This is achieved by eliminating boxing, temporary allocations, and copies whenever possible.

To use the LoggerMessageAttribute, the class and method consuming it need to be declared as partial. The Source Generator is triggered during compilation and generates an implementation of the partial method.

public static partial class LoggerMessageExtensionSourceGenerator
{
    [LoggerMessage(EventId = 1,
        Level = LogLevel.Information,
        Message = "Pedido {Pedido} gerado com sucesso!")]
    public static partial void LogMessageInformationSource(ILogger logger, int pedido);
}

In the above example, the log method is static and the log level is specified in the attribute definition. When using the attribute in a static context, it is necessary to pass the ILogger instance as a parameter or modify the method definition to use the "this" keyword and make it an extension method.

public static partial class LoggerMessageExtensionSourceGenerator
{
    [LoggerMessage(EventId = 1,
        Level = LogLevel.Information,
        Message = "Pedido {Pedido} gerado com sucesso!")]
    public static partial void LogMessageInformationSource(this ILogger logger, int pedido);
}

Sometimes, it is necessary for the log level to be dynamic instead of being statically defined in the code. This can be achieved by omitting the log level in the attribute and requiring it as a parameter for the log method.

public static partial class LoggerMessageExtensionSourceGenerator
{
    [LoggerMessage(
        EventId = 1,
        Message = "Pedido {Pedido} gerado com sucesso!")]
    public static partial void LogMessageInformationSource(
      this ILogger logger, 
      LogLevel level, /* Nível de log dinâmico como parâmetro, em vez de definido no atributo. */
      int pedido);
}

Benchmark

Observing the results above (loop with 100,000 iterations), it is evident that the LogInformation method of the common Logger tends to allocate memory and be slower compared to the LoggerMessage (22x faster and no allocation) and the associated Source Generator (26x faster and no allocation).

Conclusion

The common Logger and the LoggerMessage are two approaches for logging information in .NET, each with its advantages and disadvantages. The common Logger is simpler and more intuitive but can result in additional performance costs and potential formatting errors. On the other hand, the LoggerMessage is more efficient and offers a safer approach but requires a bit more code and may be less readable.

The choice between the common Logger and the LoggerMessage depends on the specific scenario and the developer's preferences. If performance is a significant concern and it is necessary to avoid unnecessary memory allocations, the LoggerMessage may be the best option. It offers the possibility to pre-define delegates that can be cached and reused, minimizing the performance impact. Additionally, it allows dynamically customizing the log level.

On the other hand, if simplicity and convenience are priorities, the common Logger may be more suitable. It offers simple-to-use extension methods and does not require the prior definition of delegates. However, it is essential to be aware of the potential performance costs and formatting errors associated with this approach.

In summary, the choice between the common Logger and the LoggerMessage depends on the balance between performance, ease of use, and personal preferences. Both approaches have their place in .NET application development, and it is essential to consider the specific context when deciding which one to use.

Reference:

High-performance logging in .NET