Structured logging is the modern way of logging. To put it simply, instead of traditional log with log messages only, structured logs contain extra information for context. To give you an example, a traditional log may look like this:

DEBUG 2024-01-01 12:34:56 User (id:1234) transaction start

while the structured version may look like this:

{
    "Environment" : "Dev",
    "MachineName" : "SERVER01",
    "AppName" : "MyApp",
    "Messages" : [{
        "Message" : "User (id:1234) transaction start",
        "MessageTemplate" : "User (id:{userId}}) transaction start",
        "data" : "{"userId":1234}",
        "Thread" : "3"
    }]
}

Structured logging is good because you can enrich your log with contextual information for better observability. In this post, I am going to show you how to do structured logging in C# with Serilog following dependency injection pattern to inject ILogger<T>. I am only focusing on implementing structured logging in this post. For the basic setup, please check out my other post: Clean setup of Serilog with seq and Application Insights in .NET 8 Worker service

Push custom properties to single log message

Let’s start with the basic. If I have a like the sample before, how do I push userId as a property in the log. With ILogger<T>, you typically write to log like this:

_logger.LogDebug($"User (id:{userId}) transaction start");

In order for Serilog to pick up userId as a property, you need to follow the message template pattern. So it will look like this instead:

_logger.LogDebug("User (id:{userId}) transaction start", userId);

So instead of doing string interpolate with $, you should pass userId as a parameter to the string template. If you have more than one property you can keep adding placeholder in the string template and pass in more parameter. One thing to keep in mind is that the order of the parameter determine which property name it got assign to, not the variable name. So you need to follow the order, like this:

_logger.LogDebug("User (id:{userId}, department:{department}, name: {userName}) transaction start", userId, department, userName);

but not this:

_logger.LogDebug("User (id:{userId}, department:{department}, name: {userName}) transaction start", department, userName, userId);

The other thing to keep in mind is that you cannot use . in the placeholder. So you can not do this:

_logger.LogDebug("User (id:{user.Id}) transaction start", user.Id);

instead you need to remove the ., like this:

_logger.LogDebug("User (id:{userId}) transaction start", user.Id);

Push custom properties to multiple log messages

You sometimes may want to add properties to all logs in some part of your code. Maybe because you are doing some operation and the information apply to all logs in that operation. To archive that, the first thing you need to do is enable LogContext for Serilog. You can do it in code during configuration or in appsettings.json (need Serilog.Settings.Configuration) which I prefer, like this:

{
  "Serilog": {
    "Enrich": [ "FromLogContext" ]
  }
}

After that before writing logs, you will need to call BeginScope() on the logger to add properties to the logger.

using var logScope = _logger.BeginScope(new Dictionary<string, object>
{
    { "userId", user.Id },
    { "department", user.Department },
    { "userName", user.Name }
});

_logger.LogDebug("Begin operation");

...

_logger.LogDebug("End operation");

I am using using declaration here but you can use the classical using () {...}. Logs you write inside the scope of the logScope will have the same properties unless you override it later.

Enrich exceptions log

One thing that structured logging is very useful is logging exceptions. Exceptions usually have a complex structure with lots of information. Instead of trying to extract it yourself. One simple way to do it is just use Serilog.Exceptions. After installing the package, you can add this enricher like how we added LogContext earlier:

{
  "Serilog": {
    "Using": [ "Serilog.Exceptions" ],
    "Enrich": [ "WithExceptionDetails" ]
  }
}

When logging the exception, just pass the exception with a log message.

catch (Exception ex)
{
    _logger.LogError(ex, "operation failed.");
}

You can add properties to this error log message as well just like before. However, be careful if you catch is outside of the scope of your log scope if you are using that. Properties in that scope will be lost. You will need to re-apply the properties you want in this case.

Other Serilog enrichers

Beside Serilog.Exceptions, Serilog also provides other enrichers that you can just use to populate log with more information. Some of the enricher that I found useful are Serilog.Enrichers.Environment, Serilog.Enrichers.Thread, Serilog.AspNetCore, etc. These add different generically information to your logs.

Conclusion

Structured logging is a very useful technique and mastering it will help you a lot during development and debugging. Good observability plays a big role in maintaining healthy applications.