Logging with Source Generators in .NET
Tags: csharp, dotnet
Published: 2023-06-19 21:33:45

---
title: Logging with Source Generators in .NET
published: true
date: 2023-02-19 10:24:13 UTC
tags: csharp,dotnet
canonical_url: https://www.euantorano.co.uk/posts/2023/02/19/logging-with-source-generators-in-net/
---

.NET 6 added a new feature called [Source Generators](https://learn.microsoft.com/en-us/dotnet/csharp/roslyn-sdk/source-generators-overview), allowing projects to generate code at compile time. This opens up a whole load of cool new opportunities for libraries to implement new functionality or improve existing functionality by eliminating boilerplate code.

One such library is [Microsoft.Extensions.Logging](https://learn.microsoft.com/en-us/dotnet/core/extensions/logging?tabs=command-line), the standard logging library supplied by many of the built in templates for apps like web apps and worker apps.

The logging library supports [compile-time logging source generation](https://learn.microsoft.com/en-us/dotnet/core/extensions/logger-message-generator) via the `LoggerMessage `attribute. It generates code which includes calls to `LoggerMessage.Define` and includes checks for whether the log level is enabled or not (though this check can be omitted by passing a parameter to the attribute).

## So, what does this look like?

The definition for logging methods is pretty simple:

```c#
using Microsoft.Extensions.Logging;

internal static partial class Logging
{
    [LoggerMessage(
        EventId = 0,
        EventName = "Main",
        Level = LogLevel.Information,
        Message = "Program is starting"
    )]
    internal static partial void ProgramStarting(ILogger logger);

    [LoggerMessage(
        EventId = 1,
        EventName = "Main",
        Level = LogLevel.Error,
        Message = "Error dividing by divisor: {divisor}"
    )]
    internal static partial void DivisionError(ILogger logger, Exception ex, decimal divisor);
}
```

So far, pretty simple. You define a `static partial class` to contain your logging methods, which are in turn defined as `static partial void`. You then decorate each logging method with the `LoggerMessage `attribute and provide an event ID, an optional event name, a log level and a message. Your methods can take parameters to be substituted within the log message, along with an exception to be logged for error logging purposes.

At compile time, this then generates code like the following:

```c#
partial class Logging
{
    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "7.0.7.1805")]
    private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.Exception?> __ProgramStartingCallback =
        global::Microsoft.Extensions.Logging.LoggerMessage.Define(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(0, "Main"), "Program is starting", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "7.0.7.1805")]
    internal static partial void ProgramStarting(global::Microsoft.Extensions.Logging.ILogger logger)
    {
        if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
        {
            __ProgramStartingCallback(logger, null);
        }
    }
    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "7.0.7.1805")]
    private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.Decimal, global::System.Exception?> __DivisionErrorCallback =
        global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.Decimal>(global::Microsoft.Extensions.Logging.LogLevel.Error, new global::Microsoft.Extensions.Logging.EventId(1, "Main"), "Error dividing by divisor: {divisor}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

    [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "7.0.7.1805")]
    internal static partial void DivisionError(global::Microsoft.Extensions.Logging.ILogger logger, global::System.Exception ex, global::System.Decimal divisor)
    {
        if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Error))
        {
            __DivisionErrorCallback(logger, divisor, ex);
        }
    }
}
```

Usage is simple too:

```c#
using ILoggerFactory loggerFactory = LoggerFactory.Create(b =>
{
    b.AddConsole();
});

ILogger logger = loggerFactory.CreateLogger<Program>();

Logging.ProgramStarting(logger);

// some time later when an error occurs...

Logging.DivisionError(logger, ex, divisor);
```

## So, what are the advantages?

There are a couple of advantages to this as I see them:

- Your log messages are presence checked at compile time. This means if you define a parameter in your logger message but forget to pass it within the method definition, the project will fail to compile with an error such as: `error SYSLIB1014: Template 'divisor' is not provided as argument to the logging method`.
- In addition to the above, parameters are checked to ensure that parameters are named the same in both the logger message definition and the method parameter. Failure to do so also results in a compile error such as: `SYSLIB1015: Argument 'd' is not referenced from the logging message`.
- As message parameter names are checked at compile time and used by name, you can provide parameters in the method signature in any order. This means that if you decide to change the log message in the future to add a parameter, you can simply add it to the end of the method signature rather than having to update every usage. 
- Provides compile warnings for duplicated event IDs. If you define two log methods with the same event ID you get a compile warning such as: `warning SYSLIB1006: Multiple logging methods are using event id 0 in class Logging`.