Programmable text (and JSON) formatting for Serilog

TL;DR: Check out Serilog Expressions, an embeddable mini-language for filtering, enriching, and formatting Serilog events.

A Serilog event carries a timestamp, level, message, exception, and named properties that capture information about something interesting happening in an application.

One of the strongest points of Serilog’s design is that it rigidly separates the idea of what constitutes an event from how its represented and stored.

A Serilog LogEvent can end up as:

[10:00:00 INF] (Example) Text printed to a terminal or file

or:

{“@t”:“2020-10-01T00:00:00.000Z”,“@m”:“JSON in a variety of schemas”,“Application”:“Example”}

or:

| Timestamp | Message | Application |
| ——————- | ——————- | ———– |
| 2020-10-01 10:00:00 | A row in a database | Example |

or any one of dozens of other representations.

This post explores Serilog Expressions, a new library that makes it easier to control how Serilog events are formatted as plain text or JSON.

Unlike the simple “output templates” that ship with Serilog, or plug-in JSON formatters like Serilog.Formatting.Compact, Serilog Expressions templates are tiny programs that can produce a wide range of text formats.

For example, here’s a console logger configured with a standard Serilog output template. It includes the name of the type that emitted a log event (called SourceContext):

using var log = new LoggerConfiguration()
.WriteTo.Console(outputTemplate:
“[{Timestamp:HH:mm:ss} {Level:u3}] ({SourceContext}) {Message}{NewLine}{Exception}”)
.CreateLogger();

log.ForContext<Program>().Information(“Hello, world!”);
// [10:00:00 INF] (Example.Program) Hello, world!

Namespace-qualified type names can get very long, though. Can we just display SourceContext as Program, and leave out the namespace, here?

Unfortunately, we’ve gone as far as the built-in output templates can take us: substitution of properties into placeholders is 1:1. There’s some support for .NET format strings, width, and alignment specifiers, but that’s it.

Introducing ExpressionTemplate

Here’s the same format, encoded in a Serilog.Expressions.ExpressionTemplate:

// dotnet add package Serilog.Expressions -v 1.0.0-*
.WriteTo.Console(new ExpressionTemplate(
“[{@t:HH:mm:ss} {@l:u3}] ({SourceContext}) {@m}n{@x}”))

There are some small differences to note: shorter names are used in place of Timestamp, Level, Message, and Exception, and the newline is encoded in the C# string, now.

To trim down SourceContext we can use Substring():

.WriteTo.Console(new ExpressionTemplate(
“[{@t:HH:mm:ss} {@l:u3}] “ +
“({Substring(SourceContext, LastIndexOf(SourceContext, ‘.’) + 1)}) {@m}n{@x}”))

Running the example now produces:

[10:00:00 INF] (Program) Hello, world!

Does the job! So, what else is possible?

The expression language from 10,000 ft

The expression Substring(SourceContext, LastIndexOf(SourceContext, ‘.’) + 1) may be familar if you’ve seen Serilog.Filters.Expressions, which is the earlier library that Serilog Expressions is derived from. I wrote a bit about it back in 2017, and since then, it’s been useful for specifying filters in JSON and XML configuration files. Serilog Expressions has the same general flavor, but it’s more complete and better-thought-out.

To give you a 10,000-foot view: event properties like SourceContext are accessed by name; function calls use the normal syntax; string literals are ‘single-quoted’, and operators are SQL-style: Counter = 5 and Items[0].Drink <> ‘coffee’, Path like ‘/api/orders/%’, User.DisplayName is null. The supported data types, literals, functions, and operators are documented in a short language reference.

Serilog Expressions has a few fun, interesting and handy features, too.

Conditionals — expressions support if … then … else … with the usual meaning. Parentheses/braces aren’t required: if Count > 10 then ‘big’ else ‘small’, but you can parenthesize any part of the expression to show grouping.

Universal ci modifier — turn any case-sensitive comparison Drink = ‘tea’, Path like ‘/api into a case-insensitive one Drink = ‘tea’ ci, Path like ‘/api’ ci. The modifier works on function calls, too, so IndexOf(Path, ‘api’) is case-sensitive, while IndexOf(Path, ‘api’) ci is not.

Wildcard indexers — use the any ? and all * wildcards in place of an index to construct predicates over collections: Tags[?] = ‘drink’, EmailAddresses[*] like ‘%@example.com’.

Structural comparisons — objects and arrays are compared by value, so [1, {a: 2}] = [1, {a: 2}] and [1, {a: 2}] <> [1, {a: 3}].

Spread operator — the operator .. works in objects and arrays: {a: 1, b: 2, ..c} will add all properties of c into the object, and [1, 2, ..others] will add elements of others into the array.

Object literals seemed like a minor addition, but ended up enabling one of the most interesting uses for the library.

Formatting JSON

Newline-delimited JSON is one of the primary formats for representing streams of structured log events. Unfortunately, while newline-delimited JSON is is well-specified, there’s no single schema for describing the events themselves: one format might use Timestamp, another $time, a third @t, and on and on.

Serilog includes the rather verbose JsonFormattter, and Serilog.Formatting.Compact adds a nicer, more succinct format (“CLEF”), but many applications fork and customize these, or have their own JSON formatters to support whatever schema their deployment environment requires.

Since ExpressionTemplate renders objects as JSON, it’s easy to produce newline-delimited JSON in any format you like, by putting an object literal in a template “hole”:

using var log = new LoggerConfiguration()
.WriteTo.Console(new ExpressionTemplate(
“{ {Timestamp: @t, Message: @m, Properties: @p} }n”))
.CreateLogger();

log.Information(“Hello, {Name}!”, Environment.UserName);
// {“Timestamp”:”2020-10-01T12:28:37.0074625+10:00″,”@Message”:”Hello, nblumhardt!”,
// “Properties”:{“Name”:”nblumhardt”}}

Notice that it’s necessary to include a space between the opening { in the template and the brace belonging to the object in the expression.

Mimicking CompactJsonFormatter

Let’s take a look at an event produced by Serilog’s CompactJsonFormatter (line breaks added to stay within the page width):

{“@t”:“2020-10-01T02:34:57.5495113Z”,“@mt”:“Look out, {Name}!”,“@l”:“Warning”,
“Name”:“nblumhardt”}

Including the @t (timestamp), @mt (message template), and @l (level) properties is easy; these have the same names as their expression counterparts:

.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l, @x} }n”))

I know that CompactJsonFormatter includes an exception, if present, as @x, so I’ve added it here, too. Object literals support the usual shorthand for property declarations where {@t} means {‘@t’: @t}.

How does our output compare with the original?

{“@t”:“2020-10-01T12:42:45.2890659+10:00”,“@mt”:“Look out, {Name}!”,“@l”:“Warning”}

Not bad! The timestamp is ISO 8601 with time zone offset (+10:00) specified, and the Name property is missing, but otherwise, it’s the same.

I’ll write another post soon showing how to get that timestamp into UTC, but to round out this example there are just two more changes we’ll make.

First, the compact JSON format includes properties at the top level – they’re not nested underneath a Properties property. Here’s how that can be done:

.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l, @x, [email protected]} }n”))

The .. before @p is the spread operator; it adds all properties from another object to the one being constructed. We’re now much closer to getting the output we want:

{“@t”:“2020-10-01T12:52:54.8637620+10:00”,“@mt”:“Look out, {Name}!”,“@l”:“Warning”,
“Name”:“nblumhardt”}

Second, there’s a quirk of the compact JSON format that would be nice to emulate. Since the level Information is redundant (it doesn’t add any additional meaning), the compact format leaves out the @l level property for information-level events.

.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l: if @l = ‘Information’ then undefined() else @l, @x, [email protected]} }n”))

And there we have a pretty good approximation of Serilog’s compact JSON format, constructed entirely using a template!

Is this as efficient as the heavily-optimized CompactJsonFormatter? Not at all; I’d expect that it isn’t by a fairly wide margin, but the low effort required makes ExpressionTemplate a compelling option if you need to emit a customized JSON format.

What’s next?

The plan for now is 1) get some feedback on the design (that’s where you come in!) and refine it as much as possible, 2) transfer the project to the Serilog organization, then 3) deprecate Serilog.Filters.Expressions.

Right now you can check out the source code on GitHub, and install the package from NuGet. Questions, bug reports, feature requests and PRs are all welcome.

Flatlogic Admin Templates banner

Leave a Reply

Your email address will not be published. Required fields are marked *