Logging Performance Improvements with Source Generators in C# .NET

Tag: C#

Ricardo Mauro

• 4 min read

Source Generators in .NET have become increasingly popular among developers for their ability to generate code during compilation, leading to performance optimizations and cleaner codebases. In this article, we explore how you can leverage .NET Source Generators to significantly improve logging performance and maintainability in .NET applications.

In this post, we will explore how to use source generators for logging, the improvements and benefits they bring, and some practical tips to get the most out of this feature.

Log using Source Generatored Log Method

Using source generators for logging in .NET can help streamline logging calls, reduce overhead, and provide more efficient, type-safe logging.

The Microsoft.Extensions.Logging namespace has integrated support for source-generated logging, which we will explore in detail.

Setting Up Source-Generated Logging

To get started, you need to ensure you have the necessary packages. Typically, you would include the following in your project:

dotnet add package Microsoft.Extensions.Logging
dotnet add package Microsoft.Extensions.Logging.Abstractions

Next, you need to enable the logging source generator. This is done by defining logging methods in a static partial class with the LoggerMessage attribute.

Here’s an example:

using Microsoft.Extensions.Logging;

public static partial class Log
{
    [LoggerMessage(EventId = 0, Level = LogLevel.Information, Message = "Processing item {ItemId}")]
    public static partial void ProcessingItem(ILogger logger, int itemId);

    [LoggerMessage(EventId = 1, Level = LogLevel.Error, Message = "Failed to process item {ItemId}: {ErrorMessage}")]
    public static partial void ProcessingItemFailed(ILogger logger, int itemId, string errorMessage);
}

Using the Generated Logging Methods

With the logging methods defined, you can use them in your application as follows:

public void ProcessItem(int itemId)
{
    try
    {
        // Processing logic here
        Log.ProcessingItem(_logger, itemId);
    }
    catch (Exception ex)
    {
        Log.ProcessingItemFailed(_logger, itemId, ex.Message);
    }
}

Behind the Scenes: The Generated Code

During the compilation of the project the partial class for Log will generated and compiled along with the source code.

source-generator

Observe the generated code for the logging methods.

partial class Log
{
    /// <summary>
    /// Logs "Processing item {ItemId}" at "Information" level.
    /// </summary>
    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.2.0.0")]
    public static partial void ProcessingItem(global::Microsoft.Extensions.Logging.ILogger logger, int itemId)
    {
        if (!logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
        {
            return;
        }

        var state = global::Microsoft.Extensions.Logging.LoggerMessageHelper.ThreadLocalState;

        _ = state.ReserveTagSpace(2);
        state.TagArray[1] = new("ItemId", itemId);
        state.TagArray[0] = new("{OriginalFormat}", "Processing item {ItemId}");

        logger.Log(
            global::Microsoft.Extensions.Logging.LogLevel.Information,
            new(0, nameof(ProcessingItem)),
            state,
            null,
            [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.2.0.0")] static string (s, _) =>
            {
                var itemId = s.TagArray[1].Value;
                return global::System.FormattableString.Invariant($"Processing item {itemId}");
            });

        state.Clear();
    }

    /// <summary>
    /// Logs "Failed to process item {ItemId}: {ErrorMessage}" at "Error" level.
    /// </summary>
    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.2.0.0")]
    public static partial void ProcessingItemFailed(global::Microsoft.Extensions.Logging.ILogger logger, int itemId, string errorMessage)
    {
        var state = global::Microsoft.Extensions.Logging.LoggerMessageHelper.ThreadLocalState;

        _ = state.ReserveTagSpace(3);
        state.TagArray[2] = new("ItemId", itemId);
        state.TagArray[1] = new("ErrorMessage", errorMessage);
        state.TagArray[0] = new("{OriginalFormat}", "Failed to process item {ItemId}: {ErrorMessage}");

        logger.Log(
            global::Microsoft.Extensions.Logging.LogLevel.Error,
            new(1, nameof(ProcessingItemFailed)),
            state,
            null,
            [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Gen.Logging", "8.2.0.0")] static string (s, _) =>
            {
                var itemId = s.TagArray[2].Value;
                var errorMessage = s.TagArray[1].Value ?? "(null)";
                return global::System.FormattableString.Invariant($"Failed to process item {itemId}: {errorMessage}");
            });

        state.Clear();
    }
}

Improvements and Benefits

  1. Performance: Source-generated logging methods are more performant than traditional logging methods because the code is generated at compile time, avoiding reflection and dynamic code generation at runtime.

  2. Type Safety: The generated methods provide type-safe logging. If you change the parameters or the message template, you will get compile-time errors instead of runtime issues.

  3. Reduced Boilerplate: You write the logging methods once, and the source generator takes care of the rest, reducing the amount of repetitive code in your project.

  4. Consistency: Ensures that logging messages are consistent across the application, as they are defined in one place.

Practical Tips

  • Use Descriptive Names: When defining logging methods, use descriptive names and message templates to make it clear what each log entry represents.

  • Keep It Organized: Group related logging methods in the same partial class to keep your code organized.

  • Event IDs: Use unique event IDs for each logging method to help with filtering and analyzing logs.

  • Log Levels: Carefully choose the appropriate log level (e.g., Information, Error, Warning) to avoid cluttering your logs with unnecessary information.

  • Template Matching: Ensure that the message templates match the method parameters exactly to avoid runtime errors.

Keeping Organized

Group related logging methods in the same partial class to keep your code organized.

using Microsoft.Extensions.Logging;

namespace TodoList;

public static partial class Log
{
    [LoggerMessage(EventId = 0, Level = LogLevel.Information, Message = "Processing item {ItemId}")]
    public static partial void ProcessingItem(ILogger logger, int itemId);

    [LoggerMessage(EventId = 1, Level = LogLevel.Error, Message = "Failed to process item {ItemId}: {ErrorMessage}")]
    public static partial void ProcessingItemFailed(ILogger logger, int itemId, string errorMessage);
}

public class Todo(ILogger<Todo> logger)
{
    public void ProcessItem(int itemId)
    {
        try
        {
            // Processing logic here
            Log.ProcessingItem(logger, itemId);
        }
        catch (Exception ex)
        {
            Log.ProcessingItemFailed(logger, itemId, ex.Message);
        }
    }
}

Conclusion

Source generators provide a powerful way to improve logging in .NET applications.

By generating logging code at compile time, you can achieve better performance, type safety, and consistency. Incorporate source-generated logging into your projects to take advantage of these benefits and streamline your logging implementation.

If you have any questions or would like to see more examples, feel free to reach out. Happy coding!

References

https://learn.microsoft.com/en-us/dotnet/core/extensions/logger-message-generator

For more detailed articles and hands-on tutorials on .NET and C#, check out my blog at rmauro.dev. Subscribe to my newsletter, Developers Garage, for weekly updates and curated content.

Love Discord?