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