Structured Logging, A Blessing or a Curse?
For developers working together on a project, the introduction of structured logging can either be a freeing gift, or a burdensome curse. At my previous company, it was the latter. This is Part 1 of a 2-Part series on Structured Logging. Read the second blog post here.
I will never forget the day our project lead asked me to make sure that all of my logs were structured as JSON. “Please don’t forget to add the application name and version, the environment, timestamp, request URL, etc. to all of your logs.”
The implementation was simple... and terrible. “Cut and paste this code into every place where you need to log something,” he said, and messaged me a large example. Producing a log message that met all the requirements was tedious, and negatively impacted performance as well.
Developers generally opted not to log anything at all, rather than writing blocks of code that look like this:
Metaprogramming is the key to creating a system developers will not find intrusive. By definition, metaprogramming is when you leverage frameworks to add relevant information automatically so that developers don’t have to.
At TruSTAR, we use a Java stack built on top of Spring Boot, with Logback as our logging framework. Logback offers a class called JsonLayout, which logs all messages as JSON, and can be extended to customize the fields in each log message.
The greatest tool Logback offers for this purpose is the Mapped Diagnostic Context. This object is a set of key-value pairs associated with a thread (and thus with an HTTP request). We implemented a Spring Filter that intercepts every request as it comes in, extracts relevant information such as the URL, source IP address, etc., and adds them to this context. Every log produced during this request will now contain this information.
As the response leaves the system, the filter can extract more information, such as the HTTP status code, and produce a single log message that summarizes the entire request. In doing this, be careful not to extract arbitrary information that may contain sensitive or personally-identifiable data.
A basic example of the filter might look something like this:
In a microservices architecture, it’s crucial to be able to correlate logs across different services as a transaction makes its journey throughout the network. When a user request first hits the system, generate a correlation ID that uniquely identifies the transaction, and propagate it to the other services involved in handling the transaction.
In our case, a load balancer sitting at the boundary of our system has already generated an ID which it forwards along with the request. Using this as our transaction ID, we can also correlate our application logs with the load balancer’s.
The most critical application of logs is debugging errors, and the last thing you need in a JSON log is a giant stack trace crammed into a single field. Within our JsonLayout implementation, we extract the error from the log event and parse the stacktrace, traversing the tree and converting it to JSON.
Our in-house “Sumo Logic Ninjas” have utilized these formatted error messages to produce beautiful graphs that help us monitor our system for common errors (which often lead to Jira tickets being assigned to me).
Finding Freedom Through Structure: Why Structured Logging Is Worth It
When implemented with care, a structured logging system can produce a consistent, normalized view of the inner-workings of your system that will save you time and stress. It means less developer time spent writing logs, because the logs are generated automatically. It means less time spent reading logs, because the relevant messages are found quickly with a targeted query. And most importantly, it means fewer errors, because bugs are discovered by automatic log monitoring and their causes determined systematically.
As your company grows, structured logs will quickly shift from a luxury to a necessity for employees all across the business.
This is Part 1 of a 2-Part series on Structured Logging. Read the second blog post here.
Interested in learning more about TruSTAR Engineering? Drop us a line at firstname.lastname@example.org.