How to use Serilog enrichers with log context

user_1239406 0
Viewed 7048

Are Serilog enrichers - and LogEvent in particular - expected to be aware of properties pushed onto LogContext?

I have a property which is pushed onto the Serilog context:

using (LogContext.PushProperty(LoggingConstants.MyProperty, _myValue))
{
   // ...
}

I also have a custom enricher registered which adds a property if it's not present, padding it to a specified length:

public class PaddedPropertyEnricher : ILogEventEnricher
{
    private readonly string _propertyName;
    private readonly int _maxLength;

    public PaddedPropertyEnricher(string propertyName, int maxLength)
    {
      _propertyName = propertyName;
      _maxLength = maxLength;
    }

    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
      var property = propertyFactory.CreateProperty(_propertyName, new string(' ', _maxLength));
      logEvent.AddPropertyIfAbsent(property);
    }
}

and:

Log.Logger = new LoggerConfiguration()
                .MinimumLevel.Debug()
                .Enrich.With(new PaddedPropertyEnricher(LoggingConstants.MyProperty, 3))
                 // etc.

The intent of this enricher is so log entries which don't contain the custom property don't result in columns in the the log entries becoming misaligned.

For example, it is intended to transform this:

2021-06-10 12:23:33.676 +12:00 [INF] [] First message without MyProperty
2021-06-10 12:23:33.677 +12:00 [DBG] [123] Second message with MyProperty

into this:

2021-06-10 12:23:33.676 +12:00 [INF] [   ] First message without MyProperty
2021-06-10 12:23:33.677 +12:00 [DBG] [123] Second message with MyProperty

However, this enricher isn't working. When the enricher is registered against the property I'm pushing onto the context, the value retrieved from LogEvent is always null - unless MyProperty is explicitly in the log message itself.

Is this a known limitation, or am I misusing enrichers?

This may be related to the issues encountered at Always log context data using serilog.

serilog c#
2 Answers

The problem was caused by my custom enricher being registered before Enrich.FromLogContext(); e.g.:

// Bad configuration
Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .Enrich.With(new PaddedPropertyEnricher(LoggingConstants.MyProperty, 3))
    .WriteTo.Console(minimumLogLevels.Console, LogFormat)

     // Other sink configuration here

    .Enrich.FromLogContext()
    .CreateLogger();

The issue was resolved by ensuring Enrich.FromLogContext() occurs prior to any enrichers that depend on it; i.e.:

// Good configuration
Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console(minimumLogLevels.Console, LogFormat)

     // Other sink configuration here

    .Enrich.FromLogContext()
    .Enrich.With(new PaddedPropertyEnricher(LoggingConstants.MyProperty, 3))
    .CreateLogger();

Thanks to Olivier Roger for prompting me to look at my full Log.Logger chain.

user_12394060

am I misusing enrichers?

I believe you are in this case.

TL;DR; Enrichers are shared across all sinks and as such they not the best choice if all you want is to target the output formatting of one specific sink. For controlling the output of a sink, you should use the mechanism provided by the sink, which could be an output template, or a custom IFormatProvider.

You seem to be creating a property with whitespaces just to influence how the formatting output of a specific sink. That's not the "Serilog's way" of formatting output for sinks.

When you create a property through an Enricher, they become available to all sinks, and it each sink's responsibility to decides how to best serialize properties based on where they write to.

By creating a property with padding, you're assuming that all sinks will want that property formatted exactly like that, which might not be the case in the future.

If all you want is to add some padding in the Console sink or any other sink that uses the standard Serilog output template, then you can just use the syntax for padding:

.WriteTo.Console(outputTemplate: "{Message}[{MyProperty,3}]")

This will ensure a padding of 3 whitespaces when rendering the property (and 3 whitespaces if the property is not present).

If you need more control over the output of a sink, then you would provide a custom IFormatProvider.

You can see more details in the docs on Formatting-Output.

user_2116720
Related