Structured Logging in Go: Introduction
Go 1.21 was released in August 2023 and brought several improvements, structured logging via the log/slog package being one. I had waited for this release and delayed a proposal at work in anticipation. Such was my joy at the release that I quickly dragged that proposal to our next engineering roundtable to say that the right time had come.
I was not alone in my joy; my colleagues appreciated this release too. We had all grown weary of our bespoke logging package's flaws. For example, it did not support structured logging in any form, and it marshalled sometimes the entire context.Context value into log line. There was no standard log key for anything, so searching through logs was self hazing.
How we got into that position can only be imagined. Many man months and many strokes of the keyboard, only to end up there. It was time for a change. But change would be more than more man months and keyboard strokes. We had to examine what we did wrong and commit to doing it better. Let me take you on this journey as I experienced it.
Why Structured Logging?
You may already know what I mean by structured logging. I simply mean writing application log lines in a way that encodes a structure in them. That is, by sampling log lines from an application, you can tell definite parts to them and consistently extract those parts from any log line output by that application.
Consider the following hypothetical log lines.
Log line A:
2024-06-07T13:50:00+00 ERROR Could not bill widget order with ID 89klalkfn1hv0: billing service unreachable. User ID = yv018h1-d89.
Log line B:
time=2024-06-07T13:50:00+00 level=ERROR msg="Could not bill widget order." error="billing service unreachable" order_id=89klalkfn1hv0 user_id=yv018h1-d89
Log line A is an entire line with no clear parts. A human reader can pick out semantic parts, but it is not machine readable. Log line B on the other hand has clear labels with a syntax that you can easily parse. Every line that looks like A requires custom parsing to get the labels; every line that looks like B parses as parse_and(eat_space, word, char('='), sentence) (hypothetical parser combinators).
Log line A was what we had to deal with every day. We could only set alerts for every log line that includes the words ERROR or panic. We could not extract useful information automatically because that would require specific handling of each log line from our application. If that seems mild, imagine compound values like maps, slices, structs, and context values JSON-marshaled into the log lines. Yea, I know.
With structured logging, we can now do more to extract information from our logs with little effort. This answers the question, why structured logging?
Why Not a Community Package?
Structured logging has been available in Go through packages like logrus. Why we did not use available community packages earlier is a question that I think will never be answered. It is not the interesting question now, and I do not intend to blame anyone for the log anarchy.
A better question now is why we chose to wait for the standard library implementation instead of using community packages. It is simple. We expect the community to rally around the standard library implementation eventually. It is quite well done and lightweight. We prefer to stay close to the standard library.
Recap
Go 1.21 brought structured logging to the standard library through the log/slog package. For us, it addressed our long-had needs and fit our preference for standard library solutions. The benefits include easy log parsing, easily enforced consistency, and a budding ecosystem of solutions built around log/slog.
In successive articles, we shall explain the structure of the log/slog package, show how it works with code examples, and highlight some good practices and potential pitfalls to watch out for. Comments are welcome as we progress. If you like this series, please support me by sharing with others and following the blog.