Serilog 2.5

It’s that time again!

Update-Package Serilog

Serilog version 2.5.0 is now on NuGet. The Serilog community has been hard at work; what goodies do we have in store? Read on :-)

`{Properties}` in output templates

Text output from the console and file sinks has always supported custom properties, like {RequestId} below, but only when explicitly named in the output template:

    .WriteTo.Console("[{Timestamp:HH:mm:ss {Level:u3}] ({RequestId}) {Message} ...")

This works nicely when a single property exists on nearly all events, but it’s harder to get acceptable results when only a few events are enriched with a particular property, for example via LogContext:

using (LogContext.PushProperty("OperationId", 120))
{
    int a = 1, b = 0;
    Log.Information("Computing {A}/{B}", a, b);

In this case, especially in file output, we’d like to include the OperationId when present, but don’t want a blank space or other formatting gunk otherwise.

The {Properties} token, supported in Serilog 2.5 thanks to Yuri Pliner, covers this:

Properties Output

Here’s how it’s configured for the example:

Log.Logger = new LoggerConfiguration()
    .MinimumLevel.Debug()
    .Enrich.WithProperty("MachineName", Environment.MachineName)
    .Enrich.FromLogContext()
    .WriteTo.Console(
        outputTemplate: "[{Timestamp:hh:mm:ss} {Level:u3}] {Message,-30:lj} {Properties:j}{NewLine}{Exception}",
        theme: AnsiConsoleTheme.Grayscale)
    .CreateLogger();

The subtle “grayscale” theme is implemented by the new Console sink. Astute readers might notice two other changes in the output captured by the screenshot. Those are covered next.

Additional message formatting options

Serilog captures structured data, not formatted text, and we like to show that off ;-). The original message formatting in Serilog uses "quoted strings" to distinguish properties embedded within a message from the surrounding plain text. This hasn’t always been to everyone’s taste, and it’s somewhat redundant when colored output is used, so Serilog 2.5 includes an option to turn it off.

You can see in the configuration example above, the {Message} output token accepts some format specifiers (along with the width and alignment information). The :l specifier now writes strings out literally - no quoting or escaping is applied.

The other new 2.5 tweak is :j. This instructs Serilog to print embedded data as JSON, instead of Serilog’s C#-style pretty printing. It’s applied to both the message (where it affects embedded tokens) and {Properties} above. Although the original C#-style printing is a little cleaner, JSON is more convenient and predictable.

The updated Console sink turns both of these options on by default. For file and other sinks you’ll need to specify them in the output template explicitly.

RTM `dotnet` tooling and build/test improvements

Adam Chester and Matthew Erbs got us over the line onto RTM tooling for .NET Framework, Core, and Standard for this release. It’s going to be smooth sailing from hereon in!

New `LogContext.Clone()` method

LogContext is a powerful enrichment API that’s used in a wide variety of scenarios. Information pushed onto LogContext crosses async boundaries, but to cover some cases where work is moved between threads, or suspended and resumed using application-specific techniques, the contents of the log context can now be saved and restored explicitly:

// Save
var context = LogContext.Clone();

// Later...
using (LogContext.Push(context))
{
    // Original properties applied here
}

C# 7 `ValueTuple` support

Serilog now renders C# 7 tuples correctly:

var point = (123, 456);
Log.Information("The point is {Point}", point)
  // -> The point is [123, 456]

We chose to represent tuples internally as arrays rather than objects, because arrays are more compact when rendered out into common formats like JSON. Unfortunately, limitations in how tuples are represented in C# means that names given to the tuple fields aren’t available at runtime to Serilog, so they’d end up with names like Item1 and Item2 if we represented them as structures.

Performance improvements

In each Serilog release, we aim to push throughput up, and allocations down. This time around Sergey Komisarchik knocked an impressive number of allocations out of the capturing machinery, with some scenarios like nested Dictionary<,> capture losing nearly half the allocations and more than half of the elapsed time (4232 vs 2296 bytes in our test case, 10 µs down to less than 4 µs).

Output template rendering also got a boost. Serilog 2.5 halves the allocations required in order to format an event into text for the file or console, nearly halving elapsed time as well.

And more…

LoggerSinkConfiguration.Wrap() - this new helper method from John Du Hart makes it easier to implement wrapper sinks like Serilog.Sinks.Async
An exception raised when parsing message templates with zero-length property names was fixed

Updating

Serilog 2.5 is a backwards-compatible, in-place upgrade. No breakage is expected. (There’s one tiny performance-related change that could technically break consumers - the classes PropertyToken and TextToken are now sealed - but these parts of the message template processing machinery are very rarely used outside of Serilog itself, and no scenario in which there likely to be inherited from is known. Please shout loudly if you think this may affect you.)

Thanks everyone who contributed code and bug reports towards this version! Unfortunately, Serilog is spread over a large number of sub-projects, so many of the great contributions made that aren’t part of the base Serilog NuGet package aren’t mentioned here. Thanks also to everyone keeping the huge ecosystem of sinks, extensions and plug-ins buzzing!

Please check out the new version, and let us know if you run into any trouble.

{Properties} in output templates