What Is Structured Logging and Why Developers Need It

Log files are one of the most valuable assets that a developer has. Usually, when something goes wrong in production the first thing you hear is “send me the logs”. The goal of structured logging is to bring a more defined format and details to your logging. We have been practicing structured logging at Stackify for quite a while and want to share some of our thoughts and best practices.

What is structured logging?

The problem with log files is they are unstructured text data. This makes it hard to query them for any sort of useful information. As a developer, it would be nice to be able to filter all logs by a certain customer # or transaction #. The goal of structured logging is to solve these sorts of problems and allow additional analytics.

For log files to be machine-readable more advanced functionality, they need to be written in a structured format that can be easily parsed. This could be XML, JSON, or other formats. But since virtually everything these days is JSON, you are most likely to see JSON as the standard format for structured logging.

Structured logging can be used for a couple different use cases:

1. Process log files for analytics or business intelligence – A good example of this would be processing web server access logs and doing some basic summarization and aggregates across the data.
2. Searching log files – Being able to search and correlate log messages is very valuable to development teams during the development process and for troubleshooting production problems.

Structured logging example

A simple example will probably help to make it clear as to what structured logging really is.

Normally you might write to a log file like this:

log.Debug("Incoming metrics data");

This would produce a line like this in your log:

DEBUG 2017-01-27 16:17:58 – Incoming metrics data

Depending on your logging framework, logging some additional fields would be done like this. This give you the ability to potentially easily search on these custom fields.

log.Debug("Incoming metrics data", new {clientid=54732});

This would produce a line like this in your log, now including the extra field:

DEBUG 2017-01-27 16:17:58 – Incoming metrics data {"clientid":54732}

As a separate example with the logging library NLog for .NET, you can use it and specify a JsonLayout along with what fields you want to log and it will very easily produce an all JSON log file with each line looking something like this:

{ "time": "2010-01-01 12:34:56.0000", "level": "ERROR", "message": "hello, world" }

If you were using structured logging and sending it to a log management system, it would serialize the entire message and additional metadata as JSON. This is part of the power of using structured logs and a log management system that supports them. Here is an example of what something like Stackify’s logging libraries upload to Retrace to our log management system.

[{
        "Env" : "Dev",
        "ServerName" : "LAPTOP1",
        "AppName" : "ConsoleApplication1.vshost.exe",
        "AppLoc" : "C:\BitBucket\stackify-api-dotnet\Src\ConsoleApplication1\bin\Debug\ConsoleApplication1.exe",
        "Logger" : "StackifyLib.net",
        "Platform" : ".net",
        "Msgs" : [{
                "Msg" : "Incoming metrics data",
                "data" : "{"clientid":54732}",
                "Thread" : "10",
                "EpochMs" : 1485555302470,
                "Level" : "DEBUG",
                "id" : "0c28701b-e4de-11e6-8936-8975598968a4"
            }
        ]
    }
]

It is important to know that there is no real standard to structured logging and it can be done a lot of different ways. To get the most value out of it, you need to be using a logging framework (like log4net, log4j, etc) that supports logging additional properties and then send that data to a log management system that can accept your custom fields and index them.

How to view structured logs

If you are programming with .NET or Java, you can use Prefix to view what your code is doing via transaction tracing along with your logging. Prefix can even show you any custom properties that are being logged as JSON. Prefix is free and is the best log viewer developers can get.

How we use structured logging at Stackify

At Stackify we use structured logging primarily to make it easier to search our logs. We care more about the benefits it provides for our developers from our logging system.

When we look at our logs, they look like this below. You can see all the custom fields we log because they show up as JSON.

This enables us to very easily search by any of those fields via our log management system.

A simple search like this: “clientidNumber:54732”, shows us only those logs, helping us quickly narrow down problems for a specific client. I can search across every app and server we have from one place.

TIP: Log extra fields on exceptions!

One of the best uses of structured logging is on exceptions. Trying to figure out why an exception happened is infinitely easier if you know more details about who the user was, input parameters, etc.

    try
    {
        //do something
    }
    catch (Exception ex)
    {
        log.Error("Error trying to do something", new { clientid = 54732, user = "matt" }, ex);
    }

Final thoughts on structured logging systems

It doesn’t really take any longer to log custom properties as you write your logging. These extra properties can provide more details that make it easier to troubleshoot application problems. If you are using a log management system that supports searching by these custom fields, then you can also search your logs by these new properties.

If you need help with structured logging, be sure to try out Retrace APM which includes logging at no additional cost as a standard feature.

Author

mwatson

More articles by mwatson