Customized JSON formatting with Serilog

TL;DR: Another Serilog Expressions by example post, showing how to produce newline-delimited JSON logs from Serilog events.

Newline-delimited JSON is a useful format for structured logs that will be read by other applications. Serilog’s built-in JsonFormatter implements this, but to my eyes, its output is awkward and verbose.

The newer CompactJsonFormatter and RenderedCompactJsonFormatter in Serilog.Formatting.Compact produce cleaner JSON, and that format is supported by other tools in the Serilog ecosystem and beyond, so they’re a better starting point. Because they implement a standardized schema, they provide exactly zero customizability, however, so if you need to take control of how logs are represented — this is the post for you!

Systems often have precise requirements for the schema of JSON logs. Some call the timestamp timestamp, some call it TS, some time, date, or @t. Some use ISO-8601 strings, and some use milliseconds-since-epoch. Some might require UTC, while others accept a local time + offset. Log event levels, messages, stack traces and other properties introduce many more variations.

ExpressionTemplate, from Serilog.Expressions, provides a neat way to produce just about any JSON schema and is fully-extensible through user-defined functions.

This post collects all kinds of JSON formatting examples using ExpressionTemplate, and I’ll add to them as new questions come my way 🙂.

Setting up…

To use the example snippets in this post, you’ll need to dotnet add package Serilog.Expressions and add using Serilog.Templates; along with using Serilog; to the top of the file that contains your logger configuration. The examples all use ExpressionTemplate, which implements the core Serilog ITextFormatter interface that is accepted by sinks like Console() and File().

Examples

Most of these examples are variations on the same template, which approximates the output of CompactJsonFormatter:

Log.Logger = new LoggerConfiguration()
.Enrich.WithProperty(“Application”, “Example”)
.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l: if @l = ‘Information’ then undefined() else @l, @x, [email protected]} }n”))
.CreateLogger();

Log.Information(“Hello, {Name}!”, “world”);

At its core, the template constructs an object literal with properties carrying values from the log event. The constructed object is serialized back out, which produces one JSON object per event, resembling:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“Name”:“world”,“Application”:“Example”}

You can learn more about the syntax and structure of expression templates like this one in the language reference.

Tip: output to an ANSI terminal is more readable if you pass a TemplateTheme through the ExpressionTemplate constructor:

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

Which produces:

You can even plug in your own themes 😎.

📝 Always include the event’s level, even when it’s Information

The example template omits the (meaningless) Information level; to keep it, just include the @l property like any other:

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

In the template, the @l is shorthand for @l: @l — a property called @l, initialized from the value of @l, which carries the event’s LogEventLevel. The resulting JSON looks like:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“@l”:“Information”,“Name”:“world”,“Application”:“Example”}

📝 Write the timestamp in UTC

The default representation of the timestamp is an ISO-8601 date/time with offset (e.g. +10:00). To write UTC timestamps, convert @t using the UtcDateTime() function:

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

The @t property of a Serilog event is a DateTimeOffset. UtcDateTime() converts this into a UTC DateTime, and the default serialization for this in templates is ISO-8601, too:

{“@t”:“2021-06-13T10:44:01.7430455Z”,“@mt”:“Hello {Name}!”,“Name”:“world”,“Application”:“Example”}

📝 Include both the rendered message and the message template

The @mt property available to templates is the event’s raw message template. The full message, with property values substituted in, is called @m:

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

This outputs:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“@m”:“Hello world!”,“Name”:“world”,“Application”:“Example”}

📝 Rename the timestamp, level, message, and other fields

In an object literal, properties use name: value syntax. A template that calls the timestamp TS, level LVL, the message MSG, and exception EX, looks like:

.WriteTo.Console(new ExpressionTemplate(
“{ {TS: @t, MSG: @m, LVL: @l, EX: @x, [email protected]} }n”))

With the result:

{“TS”:“2021-06-14T08:44:01.7430455+10:00”,“MSG”:“Hello world!”,“LVL”:“Information”,“Name”:“world”,“Application”:“Example”}

📝 Add a property with a constant value

Property values can be constant strings (‘hi!’), numbers (42), Booleans (true or false), objects, ({}), arrays ([]), or null. To add a property like Subsystem with a constant value – for example, ‘net’, to every event, just include it in the object literal:

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

Here’s the result:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“Subsystem”:“net”,“Name”:“world”,“Application”:“Example”}

Most of the time, you should probably use Serilog enrichers for this kind of task – but if the property is part of the JSON format rather than a useful piece of event data attached by the source application, this technique is a good fit.

📝 Exclude/remove a specific property from the log

Object literals in expression templates are evaluated from left to right. If a property appears multiple times in the same template, it gets its value from the rightmost occurrence.

This, combined with the fact that properties with undefined values are ignored (like we’ve seen so far for @l and @x in many of the examples), means that we can effectively remove a property by explicitly giving it an undefined value.

If an event property like Application, which is added through the expansion of [email protected], is then explicitly given the value undefined(), the property won’t appear in the resulting object:

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

And that means it will be omitted from the resulting JSON:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“Name”:“world”}

📝 Use a short alias for SourceContext (or rename a property)

We can use the technique described above for removing properties to rename them, too! Because SourceContext appears so frequently in logs, it’s often the subject of requests for a shorter name, like @sc:

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

If events include SourceContext, they’ll get @sc in the resulting JSON:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“@sc”:“Sample.Program”,“Name”:“world”,“Application”:“Example”}

When SourceContext is missing, its value will be undefined, and so (handily) @sc will disappear in that case as well.

📝 Nest all properties under Properties

We’ve been using the spread-rest operator .. to inline the event’s properties into the top-level JSON object. If you’d rather nest them under a property like Properties, that’s easy, too:

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

The output for our sample event is:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“Properties”:{“Name”:“world”,“Application”:“Example”}}

📝 Nest some properties under a subobject

Nesting just some properties under a subuobject is trickier; say we want to nest source-related properties like Application under Source. That part is easy – but to avoid duplicating the same properties in the expansion of [email protected], we need to use the rest() function instead:

.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l: if @l = ‘Information’ then undefined() else @l, @x, Source: {Application}, ..rest()} }n”))

This one’s pretty awesome 😎 – rest() returns an object containing all first-class event properties that don’t appear elsewhere in the template; you can read it as “everything else”.

The result looks like:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“Hello {Name}!”,“Source”:{“Application”:“Example”},“Name”:“world”}

📝 Rename Verbose to Trace and Fatal to Critical

It’s possible to map levels to new names using the same conditional statement that appears in earlier examples:

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

Alternatively, and if you want to rename several of them, indexing into an object literal reduces verbosity a bit:

.WriteTo.Console(new ExpressionTemplate(
“{ {@t, @mt, @l: coalesce({Verbose: ‘Trace’, Fatal: ‘Critical’}[@l], @l), @x, [email protected]} }n”))

Either way, you’ll end up with events resembling:

{“@t”:“2021-06-14T08:44:01.7430455+10:00”,“@mt”:“We’ve reached the end”,“@l”:“Critical”,“Application”:“Example”}

Going further…

Serilog.Expressions has support for user-defined functions, so if what you want to do isn’t possible using built-in features, there’s every chance that you can plug something in.

Some things a user-defined function could achieve:

Use camelCase for property names
Remove $type from structured values
Write exceptions as structured data
Customize the JSON representation of a particular scalar type
Write logs in an entirely different time zone
Arbitrary string manipulation, maths, lookups …

If you’re interested in writing a user-defined function, but don’t know where to start, Stack Overflow’s serilog tag is the place to go.

If you think you have found a bug in Serilog.Expressions, or if there’s a feature you think we should include by default, please drop by the GitHub project and let us know.

Flatlogic Admin Templates banner

Leave a Reply

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