Structured logging in Go with slog

A few months ago, a proposal for adding a structured logging library in Go was introduced by Jonathan Amsterdam. At present, Go has a minimal and bare-bones log package which works all right for basic use cases. However, the current library has a few shortcomings that this proposal aims to solve:

Emitting logs with different severity/levels
Structured output: Makes parsing of logs harder
Logging a set of common fields/attributes
Difficult to have a log object inside libraries as each service could have its log implementation.

As a result, many code bases have their wrappers around the log package. Additionally, there are plenty of 3rd party libraries to choose from - including logf (which my work colleagues and I built at Zerodha).

This article is about how to get started with slog for logging in Go applications.

NOTE
Since slog is currently in the proposal state and hasn’t yet merged in the official library, the API could change in future.

🔗Architecture of slog

At a higher level, slog contains three main entities:

Logger: The user-facing API for interacting with slog. All the public methods are defined on the Logger object.
Record: Contains information about the log event itself. A standard record will have timestamp, level and message fields as default. Additional attributes and metadata like caller info can be added to the Record.
Handlers: A handler is an interface implementation. The Logger object passes the Record to a handler, and the handler can choose whatever it wants to do with the Record. This is a common approach in Go libraries, where a “provider” can be abstracted in handling that task. Currently, slog ships with two handlers: JSON and logfmt. Some projects have also created handlers for zap/logrus (popular 3rd party libraries).

🔗Initialization

This snippet initializes a Text Handler, which produces logfmt format messages on os.Stdout.

package main

import (
	"os"

	"golang.org/x/exp/slog"
)

func main() {
	log := slog.New(slog.NewTextHandler(os.Stdout))
	log.Info("Hello world")

	fakeErr := os.ErrNotExist
	log.Error("something went wrong", fakeErr, "file", "/tmp/abc.txt")
}

Log output:

time=2023-02-15T19:58:10.615+05:30 level=INFO msg="Hello world"
time=2023-02-15T19:58:10.615+05:30 level=ERROR msg="something went wrong" file=/tmp/abc.txt err="file does not exist"

🔗Customizing

You’ll notice that the caller information isn’t exposed by default. The reason could be that finding the stack trace of the calling line is a bit expensive operation. However, for libraries/apps which need it can do that by customizing the handler:

func main() {
	handler := slog.HandlerOptions{AddSource: true}
	log := slog.New(handler.NewTextHandler(os.Stdout))

	log.Info("Hello world")
}

Log Output:

time=2023-02-15T12:17:53.742+05:30 level=INFO source=/home/karan/Code/Personal/slog-examples/main.go:14 msg="Hello world"

🔗Attributes

Sometimes, it’s helpful to append specific metadata to each log line which will help in aggregating/filtering with a central log-collecting agent. E.g., you can export a component key for each sub-service of your primary application.

func main() {
	log := slog.New(slog.NewTextHandler(os.Stdout)).With("component", "demo")
	log.Info("Hello world")
}

Log Output:

time=2023-02-15T12:21:50.231+05:30 level=INFO msg="Hello world" component=demo

🔗Nested Keys

So far, we’ve seen flat keys in the log message. It may be helpful to group together specific keys together and form a nested object. In JSON, that would mean a top-level object with different fields inside. However, in logfmt, it would-be parent.child format.To use nested keys, slog.Group can be used. This example uses http as the top-level key, and all its associated fields will be nested inside.

	log.Info("Hello world", slog.Group("http",
		slog.String("method", "GET"),
		slog.Int("status", 200),
		slog.Duration("duration", 250),
		slog.String("method", "GET"),
		slog.String("path", "/api/health")))

time=2023-02-15T12:30:43.130+05:30 level=INFO msg="Hello world" component=demo http.method=GET http.status=200 http.duration=250ns http.method=GET http.path=/api/health

🔗Configurable Handlers

JSON logs are daunting and tedious to read when locally developing applications. However, it’s a great fit for machine parsing of the logs. logfmt hits the sweet spot for being machine parseable and human-readable.However, thanks to the powerful “interface” implementation approach, it’s easy to switch to any handler via user-configurable methods (like config files/env variables):

package main

import (
	"os"

	"golang.org/x/exp/slog"
)

func main() {
	var (
		env     = os.Getenv("APP_ENV")
		handler slog.Handler
	)

	switch env {
	case "production":
		handler = slog.NewJSONHandler(os.Stdout)
	default:
		handler = slog.NewTextHandler(os.Stdout)
	}

	log := slog.New(handler)
	log.Info("Hello world")
}

$ go run main.go
time=2023-02-15T12:39:45.543+05:30 level=INFO msg="Hello world"
$ APP_ENV=production go run main.go
{"time":"2023-02-15T12:39:53.523477544+05:30","level":"INFO","msg":"Hello world"}

🔗Summary

slog is an excellent proposal, and it’s high time Go gets its official structured logging library. The API is designed to be easy to use, and a clear path is given for users wanting high-performance/zero-allocs by creating their handlers and making these performance improvements.

Fin