The Essential Guide to Structured Logging: Best Practices and Benefits
Best practices and benefits of structured logging to understand your app. Practical insights and strategies on how to implement structured logging.
What is Structured Logging?
Structured logging is the application of a consistent format to logs, allowing them to be treating as data sets which can be easily searched and analysed, giving insights into application behaviour.
Structured vs. Unstructured Logs
Unstructured logs have messages in plain text containing all log data in a single string.
Structured logs record log events in a standardised, machine-readable format with key value pairs, usually in JSON format.
Structured Logging Example
Unstructured Logs in Rails
In the code:
job = ...
Rails.logger.info("Performed #{job.class} in #{job.duration}")
In the logs:
[2022-04-01 14:35.0154] [Sidekiq] Performed Mailer::PasswordReset in 1436.451
Most traditional logs look like this. It stores unstructured data. Any log data in plain text can go in the message. It's not easily parsed by machines - we need regular expressions.
😡 Unstructured logs are difficult to work with.
Structured Logs in Rails
In the code:
job = ...
Rails.logger.info(
message: "Performed #{job.class} in #{job.duration}",
event: {
name: "app.job.performed",
},
code: {
namespace: job.class,
},
duration: job.duration,
messaging: {
active_job: {
adapter: {
name: job.adapter
}
}
}
)This outputs the following JSON in the logs:
{
"level": "info",
"message": "Performed Mailer::PasswordReset in 1436.451",
"event": {
"name": "app.job.performed"
},
"code": {
"namespace": "Mailer::PasswordReset",
},
"duration": 1436.451,
"messaging": {
"active_job": {
"adapter": {
"name": "sidekiq"
}
}
}
}The code for structured logging looks more unfamiliar. Note how the log message is separated. We get contextual information. We can detect patterns in our logs. The log data has a consistent format in key value pairs.
😍 Structured logs are easy to parse, search and aggregate.
What can I do with Structured Logs vs Unstructured Logs?
Structured logs allow engineers to search and aggregate more easily.
What use cases do structured logs support?
Search for Exact Match of a Single Field
Example: All Mailer::DeliverPasswordReset jobs
- Structured Logs Difficulty: Easy
- Unstructured Logs Difficulty: Easy
Search for Substring Match of a Single Field
Example: All `Mailer::*` jobs
- Structured Logs Difficulty: Easy
- Unstructured Logs Difficulty: Medium
Search for Exact Match of Two Fields
Example: All jobs performed for `Mailer::DeliverPasswordReset` jobs
- Structured Logs Difficulty: Easy
- Unstructured Logs Difficulty: Medium
Search for Equality Conditions
Example: Jobs performed with a duration of over 1 second
- Structured Logs Difficulty: Easy
- Unstructured Logs Difficulty: Impossible
Search for Aggregations (Average, Minimum, Maximum, P99, P95, P90)
Example: Jobs performed with a P95 over 3 seconds
- Structured Logs Difficulty: Medium
- Unstructured Logs Difficulty: Impossible
Group by a Field
Example: Graph duration of jobs grouped by job class
- Structured Logs Difficulty: Medium
- Unstructured Logs Difficulty: Impossible
Benefits of Structured Logs
Structured logging has allowed me to:
Analyse and understand my application behaviour
Resolve production incidents quickly
Supply critical business intelligence to other departments
Aggregate performance data - easily graph percentiles, averages, minimum and maximums
Create visuals like graphs inside my observability tool
Diagnose problems 10-100 times faster than with plain text log data
Structured Logging Best Practices
Here's what's worked for me over the years:
Select a library that supports structured logging and integrates with your web framework
Establish a consistent format for logs across all services - OpenTelemetry is valuable for this
Use unique identifiers to trace requests across multiple services
Convert unstructured logs outside the application into structured logs (apache, nginx, cloud provider)
Structured Logging Libraries
Depending on the tool and framework, here are some logging frameworks that implement structured logging in your software system:
Javascript - winston, pino, bunyan
C# - serilog, nlog
Java - log4j, tinylog
Python - contextual_logger
Ruby - semantic_logger
Implementing Structured Logging
Set a specific goal - example - "why are background jobs failing?"
Initial goal - focus on migrating existing unstructured logs to a structured format
Deal with existing dependencies - do engineers use unstructured logs or are there other systems that depend on this format?
Select a library that supports structured logging
Patch framework to use the structured logging library chosen above
Test logs locally - keep existing format so as not to confuse other engineers
Integrate and test with observability tool in staging environment - are structured logs coming through? Are they being parsed correctly?
Deploy changes to the log data
Use structured logs and list defects - focus on the specific goal - what’s missing or not in the right format?
Improve structured logs and redeploy
Use Cases for Structured Logging
Structured logging is great for debugging, troubleshooting, monitoring application performance, auditing security and compliance requirements, and more.
It is particularly useful in complex distributed systems where the log entry needs to be standardized and correlated.
Structured logs can be used to feed log data into a log management tool that allows for querying, correlating, and visualizing log data across all dimensions.
Working with Structured Log Data
Use a log management tool that allows JSON data to be sent.
For unstructured text data from other systems use log parsing tools to transform into structured data with a standard format.
Establish a unified schema for attribute names and values across all log sources to facilitate seamless correlation and cross-analysis of log data.
Overcoming Common Challenges
One of the main challenges of structured logging is ensuring all application logs are standardized and use the same structured format. For this I'd suggest OpenTelemetry's semantic conventions.
Another challenge is the potential performance overhead due to the additional formatting, but modern logging libraries are highly optimized.
Existing unstructured logs from systems with no control over the logging framework can be difficult to work with. We can reformat into a consistent log format using an ingestion pipeline or custom scripts.
Real-World Example of Structured Logging
We received a Slack alert - "log volume is projected to breach quota".
This was a monitor we'd set up in our observability tool to stop cost overages. A lot of structured data was being sent into our logs. That's strange.
Question - when are the number of structured logs spiking?
Looking into log analysis tool, we could see a huge spike in log levels at 3:17pm.
Question - what's generating those logs?
Grouping the structured logs by event name, we see the majority of these events are job.performed.
Question - what jobs are being performed?
Filtering by event name of job.performed, then grouping by job class we see the culprit - GeoDecodingJob
Question - why are there a surge of GeoDecodingJobs?
Graphing the number of retries of GeoDecodingJobs, we can see that these jobs were repeatedly being retried and all the retries were mounting up
Question - why were the jobs retrying?
The API was down for an hour and so all our jobs were retrying.
Action - tweak exponential backoff algorithm of the background job to be more lazy so the same number of jobs wouldn't mount up in the same way again.
Fixed!
With unstructured log data we wouldn't have been able to answer the first question, let alone the others.
Unlike unstructured logs, any data we've recorded in our instrumentation is available to search, sort, filter and group on.
Conclusion
Structured logging is part of essential best practices for any team that wants to improve their log management and analysis capabilities.
By following best practices and using the right tools, companies can overcome common challenges and reap the benefits of structured logging.
With structured logs, I've gained valuable insights into the performance and health of my application, and I've made data-driven decisions to help the software development process.