Serilog

NLog, Log4Net, MS Enterprise Library, SmartInspect, ObjectGuy, Logary. There are plenty of frameworks to choose from when it comes to logging on the .NET platform. You can even setup logging right out of the box by using System.Diagnostics.

class LogR : StreamWriter
{
	public Logger() : base(File.OpenWrite("log.txt")) { }
}

logger.Info("hello world");

Besides the new approach to log structures, it’s very easy to setup and configure via a fluent interface and it has a simple API for runtime enrichment of logged data. Data can be logged to almost anywhere via ‘sinks’, e.g. files, SQL Server, Email, etc.

Structured logging

Logging with Serilog starts with a template and some parameters:

logger.Information("User {user} unable to pay {order}", currentUser, currentOrder);

But instead of just turning the template into a string, it takes the names that you provided in the template and turns it into names with structured values. It all ends up in a logevent object, so in this case the finally structured version will look like this:

{
  "@timestamp": "2015-03-01T12:56:08.6575818+01:00",
  "level": "Information",
  "messageTemplate": "User {user} unable to pay {order}",
  "message": "User "Serilog_playground.User" unable to pay "Playground.Order"",
  "fields": {
    "user": "Playground.User",
    "order": "Playground.Order"
  }
}

While first part of the logevent, timestamp and level is pretty standard functionality across most logging frameworks, the rest is showing the cleverness of Serilog. What we can see is that it has turned our provided template into a single string to accommodate sinks that only supports that, such as flat-files, trace-output and so we are able to read the output. But it has also used the names that we provided in the template, “user” and “order” and built name-value list that we can later use for querying, business intelligence etc.

When we just provide names like {user} in the template, we instruct Serilog to just call .ToString(). But what we can also do, is to add an @ in front of the name, thereby instructing Serilog to preserve any strucutred of the supplied values, and finally the sinks to store as structured data.

Turning the code from above into this:

logger.Information("User {@user} unable to pay {@order}", currentUser, currentOrder);

Serilog calls this process destructuring, the resulting logevent will look like this:

{
  "@timestamp": "2015-03-01T14:12:16.6855736+01:00",
  "level": "Information",
  "messageTemplate": "User {@user} unable to pay {@order}",
  "message": "User User { Id: 2, Name: "Spock" } unable to pay Order
              { Id: 7, Amount: 100 }",
  "fields": {
    "user": {
      "_typeTag": "User",
      "Id": 2,
      "Name": "Spock"
    },
    "order": {
      "_typeTag": "Order",
      "Id": 7,
      "Amount": 100
    }
  }
}

Sinks

Sinks are destinations for logging output and Serilog comes with a few basic ones build in like Console for outputting on the system console, file for outputting to a file. But with separate NuGet packages logging can be done to almost every type of storage.

Also the interface for implementing your own sinks is ridiculously simple:

interface ILogEventSink
{
	void Emit(LogEvent logEvent);
}

Configuration

For configuration, Serilog provides a simple fluent interface on top of a configuration object. To get a new logger simply call:

    var logger = new LoggerConfiguration().CreateLogger();

This will create a new logger with a null object as the current sink. Great start but not so useful. To start logging to the console simply add:

var logger = new LoggerConfiguration()
	.WriteTo.Trace()
	.CreateLogger();

And my favourite, to log to Elasticsearch, simply install Serilog.Sinks.ElasticSearch and add:

var logger = new LoggerConfiguration()
	.WriteTo.Trace()
	.WriteTo.Elasticsearch(new ElasticsearchSinkOptions(new Uri("http://localhost:9200")))
	.CreateLogger();

Besides adding sinks, configuration can also be used to control which levels of events goes to each sink and you can even log to separate instances of configured loggers for more fine-grained control.

Enrichment

Serilog also comes with a concept called Enrichers, which is a way to add extra information during logging. Examples could be current logged in user, thread-id or a correlation-id that groups a set of log statements together, eg. a users flow though a website.

Again Serilog comes with a few built in like machine-name and process-id but enrichers are easy to create and there are also various NuGet packages available for further enrichment.

Context

As with other log frameworks, a logger can be supplied with a current context:

logger = logger.ForContext<MyClass>();

Which will add a field SourceContext with the full type as value to the logged output. Now the new logger is created with context from an existing logger. This does not change the original logger, as the logger and its configuration is immutable. This gives us a nice way of passing a logger though the layers of our system and making it more specific.

Unfortunately the filtering and enrichment lives on the configuration and not on the logger, so you have to decide which one you want to pass around.

Another thing I’d like to have seen is that the context was stacked. Currently, adding ForContext replaces the existing SourceContext. A stacked context could have served like a light-weight stack trace for information logging.

Serilog is a great next step if you are either fed up with the complexity of log4net configuration or you already have a document database as part of your infrastructure.

It should be noted here that the structured part of logging isn’t free, remember that Serilog will pull the entire graph from the provided objects. I’ve seen logevents as big as 3 MB – a lot more than the usual few hundred bytes that other log-frameworks would output. But if you’re already in an error situation, those 3 MB will give you a lot of valuable insight into tracking that pesky bug.

I don’t think Serilog is that widely adapted yet. According to Google trends Serilog does not seem so popular. Or maybe its just it’s simplicity that makes you google for it less:

I hope to see more use of Serilog in the future – its structured approach is one thing, but its incredibly simple configuration and usage is a strong selling point to me.