C# - Serilog - Enrichers leaving blank entries

Question

Figured out the basics of Serilog. Now trying to add a few enrichers so I can print username or machinename or classname, etc in the every log lines.

This is the code I have so far,

using System;
using Serilog;
using Serilog.Sinks.SystemConsole;
using Serilog.Sinks.File;
using Serilog.Enrichers;
using Serilog.Core;
using Serilog.Events;
using System.Threading;
using Serilog.Context;

var outputTemplate = "{MachineName} | {UserName} | {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] | {ClassName} | {Message:l}{NewLine}{Exception}";
var Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console(outputTemplate: outputTemplate)
    .WriteTo.File("logFile-.log",
                  outputTemplate: outputTemplate)
    .Enrich.FromLogContext()
    .Enrich.WithEnvironmentUserName()
    .Enrich.WithProperty("Version", "1.0.0")
    .CreateLogger();

Logger.Information("Hello, Serilog!");

var position = new { Latitude = 25, Longitude = 134 };
var elapsedMs = 35;

for (int i = 0; i < 5; i++)
{
    Logger.Information("Processed {@position} in {elapsed} ms.", position, elapsedMs);
    Logger.Information("");
}

using (LogContext.PushProperty("SourceContext", "TestClass"))
{
    for (int i = 0; i < 5; i++)
    {
        Logger.Information("Processed {@position} in {elapsed} ms.", position, elapsedMs);
        Logger.Information("");
    }
}

Output

 |  | 2018-03-03 19:02:56.247 -05:00 [INFO] |  | Hello, Serilog!
 |  | 2018-03-03 19:02:56.287 -05:00 [INFO] |  | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.295 -05:00 [INFO] |  |
 |  | 2018-03-03 19:02:56.295 -05:00 [INFO] |  | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.296 -05:00 [INFO] |  |
 |  | 2018-03-03 19:02:56.297 -05:00 [INFO] |  | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.298 -05:00 [INFO] |  |
 |  | 2018-03-03 19:02:56.298 -05:00 [INFO] |  | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.299 -05:00 [INFO] |  |
 |  | 2018-03-03 19:02:56.300 -05:00 [INFO] |  | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.301 -05:00 [INFO] |  |
 |  | 2018-03-03 19:02:56.302 -05:00 [INFO] | TestClass | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.307 -05:00 [INFO] | TestClass |
 |  | 2018-03-03 19:02:56.308 -05:00 [INFO] | TestClass | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.310 -05:00 [INFO] | TestClass |
 |  | 2018-03-03 19:02:56.310 -05:00 [INFO] | TestClass | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.311 -05:00 [INFO] | TestClass |
 |  | 2018-03-03 19:02:56.312 -05:00 [INFO] | TestClass | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.313 -05:00 [INFO] | TestClass |
 |  | 2018-03-03 19:02:56.316 -05:00 [INFO] | TestClass | Processed {Latitude=25, Longitude=134} in 35 ms.
 |  | 2018-03-03 19:02:56.317 -05:00 [INFO] | TestClass |
 Press any key to continue . . .

From my understanding, I have to manually define the "placeholders" (MachineName or UserName or ClassName) in outputTemplate while creating the Logger object. I am not sure how to make these placeholders optional (i.e. without printing blank space in log line) if I don't need to use them. (I would not like to print class name for few lines for examples). Or maybe I don't understand the concept of Enrichers properly.

Any help is greatly appreciated!!

Answer 1

If I understood you correctly, you have 2 questions here:

1. Why Machine name and User name do not appear in logs?
2. How to make enricher placeholder optional?

1. Why Machine name and User name do not appear in logs?

Machine name does not appear in log because you have not added appropriate enricher - WithMachineName(). Add following call to the configuration:

var Logger = new LoggerConfiguration()
// ...
.Enrich.WithMachineName()
// ...

User name does not appear in log because you used incorrect placeholder {UserName} while it should be {EnvironmentUserName}.

Here is logger configuration that fixes both issues:

var outputTemplate = "{MachineName} | {EnvironmentUserName} | {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] | {ClassNameDelimited} | {Message:l}{NewLine}{Exception}";
var Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console(outputTemplate: outputTemplate)
    .WriteTo.File("logFile-.log",
        outputTemplate: outputTemplate)
    .Enrich.FromLogContext()
    .Enrich.WithEnvironmentUserName()
    .Enrich.WithMachineName()
    .Enrich.WithProperty("Version", "1.0.0")
    .CreateLogger();

2. How to make enricher placeholder optional?

Placeholder like {MachineName} is just replaced with property value. If value is missing it's replaced with empty string. So in fact placeholder is optional. However for output template like "{MachineName} | Something" this will result in " | Something" log entry. When you define such output template, nothing will remove constant string " | " from the result entry.

There is a solution for this problem, however it requires some efforts. The plan is the following:

1. Make a delimiter a part of of substituted property value.
2. Write custom enricher that checks whether underlying value exists. If yes, enricher will enrich log entry with original value concatenated with a delimiter. If value does not exist, enricher will not add anything, which will prevent appearing of delimiter without a value in log.

Here is a sample of such enricher:

public class DelimitedEnricher : ILogEventEnricher
{
    private readonly ILogEventEnricher innerEnricher;
    private readonly string innerPropertyName;
    private readonly string delimiter;

    public DelimitedEnricher(string innerPropertyName, string delimiter)
    {
        this.innerPropertyName = innerPropertyName;
        this.delimiter = delimiter;
    }

    public DelimitedEnricher(ILogEventEnricher innerEnricher, string innerPropertyName, string delimiter) : this(innerPropertyName, delimiter)
    {
        this.innerEnricher = innerEnricher;
    }

    public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
    {
        innerEnricher?.Enrich(logEvent, propertyFactory);

        LogEventPropertyValue eventPropertyValue;
        if (logEvent.Properties.TryGetValue(innerPropertyName, out eventPropertyValue))
        {
            var value = (eventPropertyValue as ScalarValue)?.Value as string;
            if (!String.IsNullOrEmpty(value))
            {
                logEvent.AddPropertyIfAbsent(new LogEventProperty(innerPropertyName + "Delimited", new ScalarValue(value + delimiter)));
            }
        }
    }
}

Here are extension methods for configuring enrichers:

public static class DelimitedEnrichersExtensions
{
    public const string Delimiter = " | ";

    public static LoggerConfiguration WithEnvironmentUserNameDelimited(this LoggerEnrichmentConfiguration enrichmentConfiguration)
    {
        return enrichmentConfiguration.With(new DelimitedEnricher(new EnvironmentUserNameEnricher(), EnvironmentUserNameEnricher.EnvironmentUserNamePropertyName, Delimiter));
    }

    public static LoggerConfiguration WithMachineNameDelimited(this LoggerEnrichmentConfiguration enrichmentConfiguration)
    {
        return enrichmentConfiguration.With(new DelimitedEnricher(new MachineNameEnricher(), MachineNameEnricher.MachineNamePropertyName, Delimiter));
    }

    public static LoggerConfiguration WithPropertyDelimited(this LoggerEnrichmentConfiguration enrichmentConfiguration, string propertyName)
    {
        return enrichmentConfiguration.With(new DelimitedEnricher(propertyName, Delimiter));
    }
}

Finally here is a configuration that uses this custom enricher:

var outputTemplate = "{MachineNameDelimited}{EnvironmentUserNameDelimited}{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u4}] | {ClassNameDelimited}{Message:l}{NewLine}{Exception}";
var Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .WriteTo.Console(outputTemplate: outputTemplate)
    .WriteTo.File("logFile-.log",
        outputTemplate: outputTemplate)
    .Enrich.FromLogContext()
    .Enrich.WithEnvironmentUserNameDelimited()
    .Enrich.WithMachineNameDelimited()
    .Enrich.WithPropertyDelimited("ClassName")
    .Enrich.WithProperty("Version", "1.0.0")
    .CreateLogger();