Slog: Zero-dependency structured logging in Go

morgenstern2573

Paul Akinyemi

Posted on November 4, 2023

Slog: Zero-dependency structured logging in Go

Structured logging is vital for all production deployments. It’s one of the few windows of insight you have into an app that isn’t running on your local machine. But what makes structured logging different from a call to log.Println(), and why does it matter?

Structured logs conform to a uniform format or share a specific structure, usually consisting of a collection of key-value pairs. The opposite of structured logging is free-form logging, with no consistent layout imposed on the log statements. Here’s an example:



// free form
"Error while running function"

// structured log
"message: 'Error while running function' level:'ERROR' time: '2023-09-17:09:52'"


Enter fullscreen mode Exit fullscreen mode

So why do you need structured logs? Programs find it easier to process structured logs than free-form logs, which is a crucial advantage when you have many statements to comb through while looking for the reason for an error because it lets you perform operations like filtering and searching.

In this article, you’ll learn how to add structured logging to your applications with the slog package, which was added to the standard library in Go 1.21. To follow along, you’ll need:

  • Go 1.21 or later installed on your machine
  • A working knowledge of Go

That’s it!

The basics of slog

To begin with slog, you only need to understand three concepts: loggers, records, and handlers. Let’s start with loggers. The logger type is the front end of slog. It's the type that owns the methods you call when you want to log something. When you call one of those methods, the logger creates an instance of another type called a record, whose only job is to store the necessary information to create a log.

Finally, the logger passes the record to an instance of the handler type. The handler type is an interface, and it’s slog’s “backend”. The code that’s responsible for actually creating the log (writing it to stdout, for example) lives in the handler.

To recap, here’s a diagram illustrating the relationship between loggers, records, and handlers:

logging diagram

Let’s look at some code. Assume you’re calling a function that returns an error, and if the error isn’t nil, you want to log it:



err := doSomething()
if err != nil {
    // log the error
}


Enter fullscreen mode Exit fullscreen mode

First, you need a logger. Slog provides a default logger that you can use by calling one of these top-level methods:

  • slog.Debug()
  • slog.Info()
  • slog.Warn()
  • slog.Error()

These methods all have the same function signature and produce the same output: a log statement whose severity matches the method's name. The Debug method has the lowest severity, and the Error method has the highest. Take a look at the signature of slog.Error():



func Error(msg string, args ...any) {
}


Enter fullscreen mode Exit fullscreen mode

It takes a string as its first argument and then an arbitrary list of key-value pairs. The keys must be strings, but the values can be any type. Calling Error() usually looks like this:



err := doSomething()
if err != nil {
  // log the error
  slog.Error("doSomething returned an error", "error", err)
}


Enter fullscreen mode Exit fullscreen mode

Here, "error" and err form the key-value pair. This code would produce output like this:



2023/09/30 17:41:57 ERROR doSomething returned an error error="random error"


Enter fullscreen mode Exit fullscreen mode

The timestamp was generated automatically by the default logger and is a part of every log record. What happens if you omit the key in the key-value pairs? This code:



slog.Error("doSomething returned an error", err, 5)


Enter fullscreen mode Exit fullscreen mode

Generates this output:



2023/09/30 17:51:32 ERROR doSomething returned an error !BADKEY="random error" !BADKEY=5


Enter fullscreen mode Exit fullscreen mode

Slog will still output the log in a structured, key-value format, but it will prefix all values without a key with a key called !BADKEY, so you must be careful you don’t omit any keys from your key-value pairs.

Slog also offers a more rigid way to create a log that removes the possibility of a !BADKEY error: the Attr type. A value of type Attr represents a single key-value pair, and slog offers you several convenient methods to create an Attr. There’s a method for each basic data type in Go, as well as a slog.Any method that will allow you to use a value of any type to create an Attr. To put this into context, this means that we can replace this method call:



slog.Error("doSomething returned an error", "error", err, 5)


Enter fullscreen mode Exit fullscreen mode

with an Attr version:



slog.Error("doSomething returned an error", slog.String("error", err), slog.Int("id", 5)


Enter fullscreen mode Exit fullscreen mode

The convenience method you should use depends on the type of the value on the key-value pair you want to turn into an Attr. If you stick to Attrs instead of the alternating value style, you’re less likely to omit a key from your log statement. Ultimately, the top-level methods place no restrictions on you - you’re free to use alternating keys and values, Attrs, or to mix both, so it’s up to you to be careful with your log statements.

So far, we’ve focused on the default logger, but if want more control over the output format, you need a create a custom logger. Slog provides the slog.New function for this. slog.New takes a value that satisfies the handler interface and returns a logger that uses the handler you provided to it. Slog provides two types of handlers for you: a text handler and a JSON handler. You can create new loggers like this:



textLogger := slog.New(slog.NewTextHandler(os.Stdout, nil))
// or
jsonLogger := slog.New(slog.NewJSONHandler(os.Stdout, nil))


Enter fullscreen mode Exit fullscreen mode

The NewTextHandler and NewJSONHandler methods take an io.Writer and a configuration struct as arguments, and return values that satisfy the handler interface. These loggers have the same methods as the default logger, but because they use different handlers, the output they produce is different. Both loggers produce structured, key-value output, but the specific format is different. textLogger will produce a string of regular text, but jsonLogger will produce JSON output. Here’s an example. This code:



textLogger.Error("an error occurred", "error", err)

jsonLogger.Error("an error occurred", "error", err)


Enter fullscreen mode Exit fullscreen mode

Produces this output:



// text handler output
time=2023-10-02T08:12:43.634+01:00 level=ERROR msg="doSomething returned an error" error="random error"

// JSON handler output
{"time":"2023-10-02T08:12:43.634180321+01:00","level":"ERROR","msg":"doSomething returned an error","error":"random error"}


Enter fullscreen mode Exit fullscreen mode

Slog allows you to replace the default package logger with a custom logger. Calling slog.SetDefault(jsonLogger), for example, will cause the top-level methods like slog.Info() to use the jsonLogger instead of the default logger.

Customizing loggers

Slog gives you some options to change the behavior of your loggers. For example, if you have a key-value pair you want to include in all your logs like a user ID, you can use logger.With() to create a new logger that will always include that pair in your log messages. Here’s an example:



authLogger := jsonLogger.With("userId", 1)
authLogger.Error("user action failed", "error", err)
authLogger.Info("user logged in!")


Enter fullscreen mode Exit fullscreen mode

And here’s the output:



{"time":"2023-10-02T11:04:40.852885792+01:00","level":"ERROR","msg":"user action failed","userId":1,"error":"random error"}

{"time":"2023-10-02T11:04:40.852935987+01:00","level":"INFO","msg":"user logged in!","userId":1}


Enter fullscreen mode Exit fullscreen mode

Note how both logs contain the userId:1 pair, even though it wasn’t added to the calls to either Error or Info.

Slog allows you to group key-value pairs using the slog.Group function. This lets you create one value that represents multiple key-value pairs so you can save space when you want to use the group of pairs. To create a group, you need to pass a group name and one or more key-value pairs to slog.Group. Here’s an example:



userInfo := slog.Group("user-info",
  "id", 5,
  "ip-address", "180.80.80.5")


Enter fullscreen mode Exit fullscreen mode

This code creates a group named user-info, with the pairs id:5, ip-address: "180.80.80.5". You can then use the group like this:



jsonLogger.Error("user action failed", userInfo, "error", err)


Enter fullscreen mode Exit fullscreen mode

To get this result:



{"time":"2023-10-02T11:41:31.521075924+01:00","level":"ERROR","msg":"user action failed","user-info":{"id":5,"ip-address":"180.80.80.5"},"error":"random error"}


Enter fullscreen mode Exit fullscreen mode

You can also pass a group as an argument to logger.With :



authLogger := jsonLogger.With(userInfo)
authLogger.Error("user action failed", "error", err)


Enter fullscreen mode Exit fullscreen mode

To get this result:



{"time":"2023-10-02T11:48:10.436603233+01:00","level":"ERROR","msg":"user action failed","user-info":{"id":5,"ip-address":"180.80.80.5"},"error":"random error"}


Enter fullscreen mode Exit fullscreen mode

Finally, you can use the logger.WithGroup() method to prefix all key-value pairs the logger will output with a group name. This is useful in cases where other parts of your codebase might create log statements that have the same keys as the ones you’re using. The prefix allows you to identify which part of the code produced a particular log statement, even when the code uses the same keys. Here’s how it works. This code:



authLogger := jsonLogger.WithGroup("auth")
authLogger.Error("user action failed", "error", err)


Enter fullscreen mode Exit fullscreen mode

Produces this output:



{"time":"2023-10-02T14:42:41.186099512+01:00","level":"ERROR","msg":"user action failed","auth":{"error":"random error"}}


Enter fullscreen mode Exit fullscreen mode

Customizing handlers

Another way to control the output of your log statements is by customizing your handlers. With the handlers slog gives you, that’s done by passing them a HandlerOptions struct. This is the type definition of HandlerOptions:



type HandlerOptions struct {
  AddSource bool
  Level Leveler
  ReplaceAttr func(groups []string, a Attr) Attr
}


Enter fullscreen mode Exit fullscreen mode

A HandlerOptions where AddSource is true will make the log include a source key whose value is the filename, function, and line number from which the log originated. Here’s an example:



jsonLogger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true}))
jsonLogger.Error("doSomething returned an error", "error", err)


Enter fullscreen mode Exit fullscreen mode

And the output:



{"time":"2023-10-02T15:04:59.905411319+01:00","level":"ERROR","source":{"function":"main.main","file":"/home/Documents/dev/slog-sandbox/main.go","line":21},"msg":"doSomething returned an error","error":"random error"}


Enter fullscreen mode Exit fullscreen mode

A note on enabling AddSource: If you have AddSource enabled and you wrap your log statement in another function, it will cause the location reported by AddSource to be off. Here’s an example:



package main
import (
  "errors"
  "log/slog"
  "os"
)

var logger *slog.Logger
var err error

func wrapper(msg string, err error) {
  logger.Error(msg, err)
}

func main() {
  logger = slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true}))
  err = errors.New("random error")
  wrapper("an error occurred", err)
}


Enter fullscreen mode Exit fullscreen mode

This code returns this output:



{"time":"2023-10-02T17:41:40.031790944+01:00","level":"ERROR","source":{"function":"main.wrapper","file":"/home/Documents/dev/slog-sandbox/main.go","line":13},"msg":"an error occurred","error":"random error"}


Enter fullscreen mode Exit fullscreen mode

And you can see the location of the log is reported as inside wrapper when we want the location where wrapper was called inside main. So what’s the fix? You have to create a record yourself with the correct source information using the runtime package. The documentation provides an example of such a function.

The Level field governs the minimum severity of the logs the Handler will accept. Any log statements with a severity less than the Level field will be ignored by the handler and not logged. But what’s up with the Leveler type? Leveler is an interface with this definition:



type Leveler interface {
  Level() Level
}


Enter fullscreen mode Exit fullscreen mode

And this is the definition of type level:



type Level int


Enter fullscreen mode Exit fullscreen mode

The higher the value of the Level, the more severe it is. The Level field is a Leveler type to allow you to provide a value that can change the Level it returns - you can read about that in the docs, but if you don’t need that, the Level type also satisfies the Leveler interface, so you can pass a static Level instead. Like so:



jsonLogger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{AddSource: true, Level: slog.Level(4)}))


Enter fullscreen mode Exit fullscreen mode

These are the values for slog’s levels:



const (
  LevelDebug Level = -4
  LevelInfo  Level = 0
  LevelWarn  Level = 4
  LevelError Level = 8
)


Enter fullscreen mode Exit fullscreen mode

Which means that jsonLogger will now log only Warn and Error statements, and ignore Info and Debug. Here's a demonstration:



jsonLogger.Debug("doSomething returned an error", "error", err)
jsonLogger.Info("doSomething returned an error", "error", err)
jsonLogger.Warn("doSomething returned an error", "error", err)
jsonLogger.Error("doSomething returned an error", "error", err)


Enter fullscreen mode Exit fullscreen mode

Will output:



{"time":"2023-10-02T17:21:58.740882837+01:00","level":"WARN","source":{"function":"main.main","file":"/home/Documents/dev/slog-sandbox/main.go","line":23},"msg":"doSomething returned an error","error":"random error"}

{"time":"2023-10-02T17:21:58.740946987+01:00","level":"ERROR","source":{"function":"main.main","file":"/home/Documents/dev/slog-sandbox/main.go","line":24},"msg":"doSomething returned an error","error":"random error"}


Enter fullscreen mode Exit fullscreen mode

We won’t delve into the ReplaceAttr function, but its purpose is to allow you to transform both the keys and values of every key-value pair. You can use ReplaceAttr to remove key-value pairs, change the key names, or modify the value in any way you desire.

Optimizing for performance

If you do a quick Google search, you’ll see the primary culprit for performance issues when logging in Golang is something called allocation. Allocation is the process of reserving computer memory for your program’s use. That memory can be reserved from the stack or the heap. Allocating memory on the stack is straightforward, but allocating memory on the heap is much more complicated, and thus consumes more computational power and time.

So when people say allocations are making a server slower, they mean that executing some log statements is forcing the program to do a lot of heap allocation, and thus slowing it down. Now that you understand what allocation is and why it’s bad for performance, how can you minimize allocations while using slog?

The first thing you should do is use Attrs in all your log statements. Creating an Attr allows your log statement to avoid an allocation when executing for that key-value pair. Taking it one step further, slog provides the Logger.LogAttrs() method. The fact that it accepts only Attrs means that it can avoid allocations even further. According to the documentation,

The call logger.LogAttrs(ctx, slog.LevelInfo, "hello", slog.Int("count", 3))
is the most efficient way to achieve the same output as slog.Info("hello", "count", 3)

logAttrs requires a context as its first argument, which is a value that contains information about the code’s environment that can be passed between functions. Its other arguments are a Level for the log statement, a string, and then an arbitrarily long list of Attrs. You can find a list of other performance considerations in the documentation.

Extending slog

Because slog is split into a front end and a back end, it’s possible to further customize slog while keeping its interface the same, by changing the back end. While slog only provides two built-in handlers, because handler is an interface, you can write a custom implementation to have complete control over the output.

A guide covering how to write custom handlers is out of scope for this post, but you can find one such guide written by the author of slog here. Thankfully, you don’t need to write a handler from scratch to use one. There are several community-contributed handlers, including handlers that allow you to output colored logs, and a handler that lets you implement sampling. You can find a full list here.

Context in slog

Sometimes, handlers may need access to the context of the function where the log statement was called, so slog provides methods that allow you to pass that context as part of the log statement.
The Logger.LogAttr() method takes a context as the first parameter, and all the log statements have alternate versions that let you provide a context. That means that there’s a logger.{Level}Context method for each of slog’s built-in severity levels.

Slog vs Zap vs ZeroLog

To help you decide whether you’d want to use slog in your next project, here’s a table comparing slog to some of the most popular alternatives for structured logging.

Slog (with built-in handlers) Zap ZeroLog
Community and Support Part of Go’s stdlib Owned by Uber No org. backing it
Performance Slower than Zap Slower than ZeroLog Fatest
Extensibility Most extensible Decently extensible Least extensible
Output Format Plain text or JSON JSON JSON or CBOR only

You can find benchmarks for slog, zap, and zeroLog here.

Conclusion

Structured logging is a feature all production applications should have, to provide the developer as much insight into the running of the application as possible. Slog is a new addition to the Golang standard library that provides convenient, efficient, and easily extensible structured logging.

Slog can meet the most common use cases for structured logging with its built-in handlers, but if you need more control or have a niche requirement, it allows you to use third-party handlers, or write your own. I hope you enjoyed the article, and happy coding!

💖 💪 🙅 🚩
morgenstern2573
Paul Akinyemi

Posted on November 4, 2023

Join Our Newsletter. No Spam, Only the good stuff.

Sign up to receive the latest update from our blog.

Related