On Serilog 'log enrichment' feature

This brief note is for .NET developers who use Serilog (great tool, by the way!) for logging implementations. I want to cover a very powerful, though rarely spoken of, feature - 'log enrichment'. It is an interesting concept and implementation which they describe as 'log events can be enriched with properties in various ways'. The main idea is that whatever log event gets written, it may be improved with custom data coming from various sources.

So, what implementing log enrichers would give and how may it be applied? The first thing to mention is that neither business code, nor application code is designed to produce logs; it has a completely different purpose. The less logging code we have inside our business and application code, the cleaner, less coupled, and more cohesive our code is. Those working with enterprise code are quite used to code 'spiced up' with logging statements. While 'what and when' to log and 'what and when' not to log is a matter of non-ending debates and particular scenarios and requirements, writing clean code is always a goal.

Serilog enrichers are a way of abstracting away collecting and providing custom data for logs, and thus contribute to cleaner code. Often some piece of data is not available at a code location where we want to write a log event, and it would either need to be injected as a dependency or some kind of 'provider' should in place to feed it into logs. An opposite case is also quite typical: we produce data that should or may be logged somewhere down the pipeline. Now let's review a sample implementation designed to solve these problems.

Let's take as an example logging some currently authenticated user information with each log event.

public sealed class UserIdEnricher : ILogEventEnricher {
    private const string UserIdPropertyName = "UserId";
    
    private readonly IHttpContextAccessor contextAccessor;
    
    public UserIdEnricher(IHttpContextAccessor contextAccessor) {
        this.contextAccessor = contextAccessor;
    }
    
    void ILogEventEnricher.Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) {
        if (contextAccessor.HttpContext == null) {
            return;
        }
    
        int? userId = ... // logic to extract the id; the id may as well be a string or a GUID
    
        if (userId.HasValue) {
            var property = new LogEventProperty(UserIdPropertyName, new ScalarValue(userId));
            logEvent.AddOrUpdateProperty(property);
        }
    }
}

We have a class that implements a Serilog interface, ILogEventEnricher. Its Enrich method is called by Serilog to enrich a log event with the data we extract from our bearer token from the current HttpContext. This data would be submitted with every logged event, thus we would know the user id responsible for an operation without contaminating our operation related code. We would only need to add this enricher to our logging configuration.

We can do it in two very simple ways. Either add it where we build the LoggingConfiguration instance for Serilog:

services.AddScoped<ILogEventEnricher, UserIdEnricher>(); // services is IServiceCollection

and then use this powerful Serilog configuration method:

loggerConfiguration.ReadFrom.Services(provider); // provider is IServiceProvider

The 'ReadFrom.Services()' call simply gets from the DI container all registered instances of these interfaces and applies them to given Serilog configuration:

• ILogEventEnricher
• ILoggerSettings
• IDestructuringPolicy
• ILogEventFilter
• ILogEventSink

So, it allows to 'stuff' our DI container with everything we want Serilog to use, and will build the logging infrastructure accordingly.

Let's review another custom log enricher sample implementation:

public sealed class CustomLogEnricher : ILogEventEnricher {
    private readonly Dictionary<string, List<string>> properties = new();
    
    public CustomLogEnricher With(string property, string value) {
        if (string.IsNullOrWhiteSpace(value)) {
            return this;
        }
    
        if (properties.TryGetValue(property, out var values)) {
            values.Add(value);
        } else {
            properties.Add(property, new() { value });
        }
    
        return this;
    }
    
    void ILogEventEnricher.Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) {
        foreach (var item in properties) {
            LogEventPropertyValue value = item.Value.Count == 1
                ? new ScalarValue(item.Value[0])
                : new SequenceValue(item.Value.Select(x => new ScalarValue(x)));
            logEvent.AddOrUpdateProperty(new LogEventProperty(item.Key, value));
        }
    }
}

And that's how we would register it:

services
    .AddScoped<CustomLogEnricher>()
    .AddTransient<ILogEventEnricher>(provider => provider.GetRequiredService<CustomLogEnricher>());

This is a more generic implementation of a log enricher. It can be injected as a dependency, and call its With method to provide custom data for log events. Again, this implementation is more a sample to demonstrate the concept of log enrichers than a real production code.

Serilog has the LogContext enricher which allows to add and remove (via IDisposable interface) custom data, and clearly supersedes this rather naive implementation.

Log enrichers allow to implement very sophisticated logic what custom data can get logged, as they may analyze the log event level, check if any exception is being logged, use injected service, and do whatever you should deem useful.

Log enrichers allow to write cleaner code which is very easy to cover with unit tests. So, those writing complex logging code, please do have a closer look at this feature - it may save you a day!