Serilog property enrichment but still required in call to actual write call?

Question

I am adding Serilog to our logging infrastructure and am confused by the following:

public class OzCpWriteEntryExInput : OzCpAppServiceInputBase
{
    private readonly ILogger _Logger;

    /// <summary>
    ///     Class constructor
    /// </summary>
    public OzCpWriteEntryExInput(ILogger aLogger)
    {
        //Save params supplied
        _Logger = aLogger;

        //Create resources required
        Entry = new OzCpLogEntryContextInput();
    }

    public OzCpLogEntryContextInput Entry { get; set; }

    public ILogger Logger => _Logger;
}

public class OzCpLoggingService : OzCruisingPlatformAppServiceBase, IOzCpLoggingService
{
    private const string MESSAGE_TEMPLATE =
        "{LogVersion} {DateTimeUtc:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level}] [{LevelRange}] [{ApplicationHostName}] [{ApplicationName}] [{ApplicationVersion}] [{Location}] {Message}{NewLine}{Exception}{NewLine}{StackTrace}{NewLine}{UserDataKind}{@UserData}";

    public OzCpBuildLoggerOutput BuildLogger(OzCpBuildLoggerInput aParams)
    {
        OzCpBuildLoggerOutput result = new OzCpBuildLoggerOutput();
        //#TODO (DE) Convert logger hard coded values into settings
        bool logToUdp = true;

        //By default logging will include all events
        LoggerConfiguration loggerConfiguration = new LoggerConfiguration()
            .Enrich.WithProperty("LogVersion", "01.00")
            .MinimumLevel.Verbose();

        if (logToUdp)
        {
            loggerConfiguration.WriteTo.Udp(IPAddress.Loopback, 11000, 0, LogEventLevel.Verbose, MESSAGE_TEMPLATE);
        }

        //Finally we can build the logger
        result.Logger = loggerConfiguration.CreateLogger();

        return result;
    }

    /// <summary>
    ///     Writes an entry to the supplied logger and associated log sinks.
    /// </summary>
    /// <param name="aParams">Parameters defining the entry to be written.</param>
    /// <returns>Returns whether the entry was written to the logger.</returns>
    public OzCpWriteEntryExOutput WriteEntryEx(OzCpWriteEntryExInput aParams)
    {
        OzCpWriteEntryExOutput result = new OzCpWriteEntryExOutput();

        //These variable values are only the ones out of the entry as the logger "enriches" the other values based on
        //what has been passed in when it was configured
        object[] messageTemplateVariableValues =
        {
            "***",   //Log Version is actually an enriched property!!!!
            aParams.Entry.DateTimeUtc,
            aParams.Entry.LevelRange,
            aParams.Entry.Location,
            aParams.Entry.StackTrace,
            aParams.Entry.UserDataKind,
            aParams.Entry.UserData
        };

        switch (aParams.Entry.EntryKind)
        {
            case OzCpLoggingEntryKindEnum.Verbose:
                aParams.Logger.Verbose(aParams.Entry.Exception, MESSAGE_TEMPLATE, messageTemplateVariableValues);
                break;
        }

        return result;
    }
}

Ultimately callers to WriteLogEx() can supply their own Serilog.ILogger. I won't go into the reasons as to why this is the case, just assume this is a requirement.

As an example I include BuildLogger() which sets up an ILogger to write to UDP with a custom message template and some additional properties via the enrichment configuration builder.

All pretty straight forward. However now when I go to write to the ILogger using ILogger.Verbose() I need to pass parameters for the tokens in the message template.

However this appears to be ordinal based so the first one goes into {LogVersion} which is supposed to be being completed via the enricher configuration previously set up for the logger.

if I don't LogVersion the formatted message template is off by one and naturally if I include it then I get:

*** 2016-04-14 14:53:57.677 +10:00 [Information]...

instead of what I want which is:

01.00 2016-04-14 14:53:57.677 +10:00 [Information]...

So how do I call a logging method off ILogger and pass the token values by name instead of position?

score 0 · Accepted Answer · answered Apr 14 '16 at 05:59

0

Instead of passing these in the .Verbose() statement, just pass the event-specific data there. The other output template properties can be added by contextualizing the logger:

var ctx = logger.ForContext("DateTimeUtc", aParams.Entry.DateTimeUtc)
                .ForContext("LevelRange", aParams.Entry.LevelRange)
                // and so-on.

ctx.Verbose("Message here...");

There's a ForContext() overload that accepts an array of PropertyEnrichers you can use to tidy things up I believe.

answered Apr 14 '16 at 05:59

Nicholas Blumhardt

30,271
4
90
101

That does the trick!! What confused me however was that the parameter list says message template when you do a ctx.Verbose(), I also noticed that I get different behaviour when dealing with exception. 1) .ForContext("Exception", aParams.Entry.Exception) I get NO text for the exception token, but if I use 2) ctx.Verbose(aParams.Entry.Exception, aParams.Entry.Message); then I get what I expect namely System.Exception: Dummy Exception. Any reason why 1) behaves as such? – TheEdge Apr 14 '16 at 06:26
Figured it out. When doing 1) need to change the format string to @Exception so that it serializes the object. All good. – TheEdge Apr 14 '16 at 06:34
Just constructing a `LogEvent` by hand and passing it to the logger's `Write()` method may turn out to be less confusing over the long run - definitely an option worth exploring. Good luck! :-) – Nicholas Blumhardt Apr 15 '16 at 04:20

Serilog property enrichment but still required in call to actual write call?

1 Answers1