Serilog 2.0 JSON improvements
Serilog 2.0 is out! There’s an Upgrade Guide and Release Notes already posted on the Serilog site, and a good number of first- and third-party packages have already been updated to work with the new version. Go go go! :-)
Building the new release was a team effort, and announcing it will be as well, so instead of trying to cover everything we’ve added since the 1.x series I’m going to write about a few new features I am especially interested in, and call out posts from the rest of the team as they appear.
Regarding upgrades by the way: if you get stuck, please post to Stack Overflow and tag your question with serilog – many Serilog users and contributors are there ready to help out, and by posting there you’ll help others find the information they need. Thanks!
JSON in Serilog 2.0
JSON turns out to be a good fit for storing and transporting structured log events. Practically every modern logging target of any significance requires, supports, or uses JSON in one way or another.
Serilog has always had good support for writing JSON logs, but when JsonFormatter
was introduced in Serilog 1.0 I underestimated its importance, and underestimated the breadth of scenarios in which it would be used. This left us with several longstanding pain points:
- Efficiency - the default format written by
JsonFormatter
is a straightforward mapping from Serilog’sLogEvent
type, which requires a lot more space than is strictly necessary (even for JSON!) - Flexibility - as formatting requirements expanded,
JsonFormatter
did too, eventually becoming a big ball of virtually-dispatched mud, that’s unable to evolve without breaking subclasses - Ubiquity - practically everywhere that Serilog supports plain text, JSON support is needed too, but not being comfortable with the format or implementation we’ve held back in a number of places
If you use JSON logging with Serilog, or maintain a Serilog sink that writes JSON, Serilog 2.0 has some improvements in these areas. In this post we’ll look at some new formatting infrastructure, a new compact JSON representation, and finally some API improvements that make it easier to use JSON with Serilog across the board.
Introducing JsonValueFormatter
Sinks that use JSON need to take a Serilog LogEvent
and write it out to a stream of text. There are two main tasks involved, both of which were previously the responsibility of JsonFormatter
:
- Formatting the fixed properties of
LogEvent
such asTimestamp
,Level
and the message, and - Formatting the associated property data encoded in
LogEventPropertyValue
objects.
Writing out the fixed properties is easy, but varies a lot between JSON formats. The amount of code involved is so small that, with the help of a JSON string escaping function, its cleaner and faster for implementers to hand-code than it is for Serilog to provide an infinitely-flexible generic formatter.
Writing out property data is harder – but much more consistent. For that task, Serilog 2.0 provides JsonValueFormatter
:
var formatter = new JsonValueFormatter();
LogEvent evt = // …
foreach (var property in evt.Properties)
{
formatter.Format(property.Value, Console.Out);
Console.WriteLine();
}
Given an event with properties like Name = "Alice"
and Number = 42
this snippet will produce output like:
"Alice"
42
Serilog encodes all structured data, including scalars like the ones above, arrays, dictionaries and objects, into LogEventPropertyValue
s. JsonValueFormatter
takes these values and writes the corresponding JSON. Because it’s focused on just this one task, it’s faster at it and easier to extend.
Putting JsonValueFormatter
together with hand-coded serialization for the fixed properties yields much more understandable (though also a little more verbose) formatters. Here are three different implementations for reference.
What’s the role of JsonFormatter
in the future, then?
It’s useful having JsonFormatter
around to provide an easy, sensible, default JSON format. I don’t think we should deprecate or remove it - only its extensibility story is truly problematic.
A more likely plan of attack is to deprecate its extension points, so that sinks using it to implement custom JSON formats “get the hint” and move over to the new model based on JsonValueFormatter
. Once this happens, we’ll be able to clean up and optimise JsonFormatter
so that everyone using it as-is can benefit from better performance, and code that’s now duplicated in JsonValueFormatter
can instead be reused.
Compact JSON support
Since JsonValueFormatter
makes it relatively easy to support different JSON layouts, we’ve done just that: the Serilog.Formatting.Compact package includes two new JSON formatters that blow JsonFormatter
out of the water in space and time benchmarks.
Let’s check out the “hello world”. We’ll need a few packages:
Install-Package Serilog
Install-Package Serilog.Sinks.Console
Install-Package Serilog.Formatting.Compact
The example will write the same event in both the default and compact JSON formats:
static void Main(string[] args)
{
Log.Logger = new LoggerConfiguration()
.WriteTo.Console(new JsonFormatter())
.WriteTo.Console(new CompactJsonFormatter())
.CreateLogger();
Log.Information("Hello, {Name}", Environment.UserName);
Log.CloseAndFlush();
}
2.0 tip: though it’s not required by the console sink in this example, I’ve added the call Log.CloseAndFlush()
as a reminder that you need to call this explicitly on app shutdown if you’re using any sinks that buffer events (most networked ones).
We get two lines of output. I’ve inserted some linebreaks to keep things tidy in the blog post:
{"Timestamp":"2016-07-06T12:27:19.6552446+10:00","Level":"Information","Message
Template":"Hello, {Name}","Properties":{"Name":"nblumhardt"}}
{"@t":"2016-07-06T02:27:19.6552446Z","@mt":"Hello, {Name}","Name":"nblumhardt"}
140 vs 79 bytes (56%) for the same information.
CompactJsonFormatter
is smart: built-in field names are short and prefixed with an @
so that no Properties
property is required; timestamps are converted to UTC; and, in this example the level is omitted since Information
is considered to be the default.
CompactJsonFormatter
assumes you want to work with the event as a template + properties. This isn’t always the case – many log collectors require that the message is pre-rendered into text. This is where RenderedCompactJsonFormatter
shines.
Substituting it into the example program produces an event that, at 102 bytes, is almost as compact as CompactJsonFormatter
, and still more compact than JsonFormatter
even without it working in its “rendered” mode:
{"@t":"2016-07-06T02:33:46.6978713Z","@m":"Hello, \"nblumhardt\"","@i":"5e2f8db
d","Name":"nblumhardt"}
Note how instead of @mt
we’ve now got the rendered message in @m
, and a new field, @i
, which is a computed 32-bit event type based on the message template.
You can read more about the new format here, including some benchmarks that show the new formatters beating the existing one by a healthy margin. (Another new fan of BenchmarkDotNet here.)
JSON everywhere
Finally, and you might have noticed this in the sample code above, basic sink configuration methods like Console()
now have overloads accepting an initial formatter
argument. This makes it easy to use one of the new JSON formatters with the console, file, or rolling file sinks – in the past, you had to use a less-discoverable configuration syntax in order to do this.
Here’s the JSON-rolling-file version:
Log.Logger = new LoggerConfiguration()
.WriteTo.RollingFile(new CompactJsonFormatter(), "./logs/app-{Date}.json")
.CreateLogger();
Don’t forget that here, as elsewhere in Serilog 2.0, the sink lives in its own package. Install-Package Serilog.Sinks.RollingFile
will get this example up-and-running.
Updates coming in Serilog 2.1 (grab the -Pre
version from NuGet) mean that you will soon also be able to configure a JSON rolling file using XML as well:
<appSettings>
<add key="serilog:using:RollingFile" value="Serilog.Sinks.RollingFile" />
<add key="serilog:write-to:RollingFile.pathFormat" value="./logs/myapp.json" />
<add key="serilog:write-to:RollingFile.formatter"
value="Serilog.Formattting.Compact.CompactJsonFormatter, Serilog.Formatting.Compact" />
2.0 tip: since the sinks have moved to their own packages, you’ll need serilog:using
directives like the one shown above in order for XML configuration to pick them up.
Wrapping up
Serilog 2.0 is out; as well as .NET Core support there are a lot of niceties to enjoy on all platforms. Once again, check out the Upgrade Guide and Release Notes for the full picture.
I’ve dug into JSON formatting here because the situation has annoyed me for so long :-) but there’s plenty more to tell. Interspersed with the rest of the introductory series on structured logging I’ve been working on, I hope to be able to write more soon.
In the meantime, it’d be great to hear from you if you’re already across to Serilog 2.0, or if anything is holding you back. Happy logging!