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, ..@p} }\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, ..@p} }\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, ..@p} }\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, ..@p} }\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, ..@p} }\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, ..@p} }\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', ..@p} }\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 ..@p
, 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, ..@p, 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, ..@p, 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 ..@p
, 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, ..@p} }\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, ..@p} }\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.