Go (golang) Slog Package

Overview

In Go (golang) release 1.21, the slog package will be added to the standard library. It includes many useful features such as structured logging as well as level logging. In this article, we will talk about the history of logging in Go, the challenges faced, and how the new slog package will help address those challenges.

Target Audience

This article is aimed at developers that have minimum experience with Go.

In this article, we'll cover the following topics:

• Introduce the Slog package that is released in Go 1.21
• Cover the major features being introduced with this logging package
• See variations of how to use the logger in the slog package

History of Logging in Go

When Go was first released in 2012 to the public, it shipped with the very simple log package. While it was useful in a limited fashion, it lacked most of what was needed for enterprise applications.

I think many of us in the Go community expected a better logger to appear, and some did, but as of 2017, the standard library had still not included any more robust options for logging. As a result, many community members got together with the idea of solving this problem. As you can see by the document that was started and shared, the effort failed. Mostly, it simply failed because of a lack of agreement on fundamentally what a logger should even do. Should it do level logging? Should it be structured?

As a result, many third party packages evolved over time that addressed those issues in various capacities, but the standard library still only had the basic functionality included.

Thankfully, the wait is over, and Go has officially shipped the slog package!

The Basics

Unlike the basic log package, there are no Print, Printf, or Println functions. This is due to the fact that all messages need to be of a specific type, or level. The current levels are Info, Warn, Error, and Debug. Each of them have a corresponding function in the library and can be called as follows:

package main

import "log/slog"

func main() {
	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")
	slog.Debug("show some debugging output")
}

$ go run .

2024/02/16 08:42:59 INFO hello gophers
2024/02/16 08:42:59 WARN be warned!
2024/02/16 08:42:59 ERROR this is broken

--------------------------------------------------------------------------------
Go Version: go1.22.0

Notice that the Debug statement did not print? That is because the default level of the logger is Info. We will see later in this article how to enable the DEBUG statements to be logged to the output.

Creating a Logger

While you can use the basic logging methods directly, it's more likely you'll want to have more control over how your logger works. As such, you will need to create a logger to work with.

Here we create a logger, and we tell it that we want to use JSON as our output:

package main

import (
	"log/slog"
	"os"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	logger.Info("hello gophers")
	logger.Warn("be warned!")
	logger.Error("this is broken")
}

$ go run .

{"time":"2024-02-16T08:43:00.412408-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.412507-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.412509-06:00","level":"ERROR","msg":"this is broken"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Default Logger

By default, The slog package uses a default logger. You may want to actually create your own logger with specific options to use, and then set the default logger to use those settings everywhere.

The first step is to create your logger, then set it to the default logger. This will allow all other packages in your program to use these log settings.

package main

import (
	"log"
	"log/slog"
	"os"

	"training/store"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	logger.Info("hello gophers")
	logger.Warn("be warned!")
	logger.Error("this is broken")

	// Set the logger for the application
	slog.SetDefault(logger)

	s := store.New()

	// we can now use the standard logger again as it uses the options we set above
	slog.Info("new store created", "store-id", s.ID)

	// the standard logger now uses the new logger as well
	log.Println("I'm log.println, look at me!")
}

Now that we have set the default logger, we can use the standard slog package to log from any package that we create and import, and it will use the settings we just applied. Note that it also updates the standard logger from the log package, which means that all future log.Print, log.Println, and log.Printf statements use the new logger that was applied.

package store

import (
	"log/slog"
	"math/rand"
)

type Store struct {
	ID int
}

func New() *Store {
	s := &Store{
		ID: rand.Intn(100),
	}
	slog.Info("creating store", "store-id", s.ID)
	return s
}

$ go run .

{"time":"2024-02-16T08:42:59.905703-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:42:59.905827-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:42:59.905828-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:42:59.905842-06:00","level":"INFO","msg":"creating store","store-id":32}
{"time":"2024-02-16T08:42:59.905854-06:00","level":"INFO","msg":"new store created","store-id":32}
{"time":"2024-02-16T08:42:59.905879-06:00","level":"INFO","msg":"I'm log.println, look at me!"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Notice that that even though we are just using the slog.Info function in the store package, it still uses the logger we set from the main function in the main package. This feature allows us to set the logger once for our application, and any future calls from either the log or slog package will have properly formatted output.

Levels

As stated before, there are four levels of logging, Info, Warn, Error, and Debug. When creating your logger, you can set the level at which you want information to be logged.

To change the logging level, we can set it with the

package main

import (
	"log/slog"
	"os"
)

func main() {
	// Pass the loggingLevel to the new logger being created so we can change it later at any time
	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: slog.LevelDebug}))

	logger.Info("hello gophers")
	logger.Warn("be warned!")
	logger.Error("this is broken")
	logger.Debug("be warned!")
}

$ go run .

{"time":"2024-02-16T08:43:00.556027-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.556125-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.556126-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:43:00.556128-06:00","level":"DEBUG","msg":"be warned!"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

It is important to note that depending on the level, some messages may not be logged out. For instance, Debug messages are ONLY logged out if the logger level is set to slog.LevelDebug.

Level Variable

It may be useful to turn on and off debugging while your program is running. While this does require more setup, and you'll need the ability to change this option via some type of API at runtime, the following setup would enable you do to that via a variable.

package main

import (
	"log/slog"
	"os"
)

func main() {
	// create a logging level variable
	// the level is Info by default
	var loggingLevel = new(slog.LevelVar)

	// Pass the loggingLevel to the new logger being created so we can change it later at any time
	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{Level: loggingLevel}))

	loggingLevel.Set(slog.LevelDebug)

	logger.Info("hello gophers")
	logger.Warn("be warned!")
	logger.Error("this is broken")
	logger.Debug("be warned!")
}

$ go run .

{"time":"2024-02-16T08:43:00.051552-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.051661-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.051663-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:43:00.051665-06:00","level":"DEBUG","msg":"be warned!"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Grouping Values

The logger also allows you to group information for logging. For example, for an http request, you may want to log information specific to that request all in the same group.

Here is an example of using the Group feature of the logger with a JSON handler:

package main

import (
	"log"
	"log/slog"
	"net/http"
	"os"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	slog.SetDefault(logger)

	log.Println("program started")
	r, err := http.Get("https://www.gopherguides.com")
	if err != nil {
		slog.Error("error retrieving site", "err", err)
	}
	slog.Info("success", slog.Group("request", "method", r.Request.Method, "url", r.Request.URL.String()))

}

$ go run .

{"time":"2024-02-16T08:43:00.962396-06:00","level":"INFO","msg":"program started"}
{"time":"2024-02-16T08:43:01.110628-06:00","level":"INFO","msg":"success","request":{"method":"GET","url":"https://www.gopherguides.com"}}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Notice that the output for request is now a new message containing the method and the url values.

Improving Log Performance

Logging can be an expensive operation in your application. Much of that expense is due to the allocations created to hold the values before logging the output. That expense can be avoided however, if you use the convenience methods for setting key/value pairs when logging. These methods are slog.Int, slog.String, slog.Bool and slog.Any.

package main

import (
	"log"
	"log/slog"
	"net/http"
	"os"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	slog.SetDefault(logger)

	log.Println("program started")
	r, err := http.Get("https://www.gopherguides.com")
	if err != nil {
		slog.Error("error retrieving site", slog.String("err", err.Error()))
	}
	slog.Info("success",
		slog.Group(
			"request",
			slog.String("method", r.Request.Method),
			slog.String("url", r.Request.URL.String()),
		))
}

$ go run .

{"time":"2024-02-16T08:43:01.075436-06:00","level":"INFO","msg":"program started"}
{"time":"2024-02-16T08:43:01.245242-06:00","level":"INFO","msg":"success","request":{"method":"GET","url":"https://www.gopherguides.com"}}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Notice that the output didn't change, but using the Attr helpers will avoid allocations when logging which will improve the performance of your application.

Customizing Log Behavior

There may be times that you want to control how values are output by the logger. One of those times might be if you want to sanitize a value, perhaps a password. You can do this by implementing the slog.LogValuer interface.

Let's look at the following program. Currently it will output all the values for the logged data struct, even the sensitive ones such as password.

package main

import (
	"log"
	"log/slog"
	"os"
)

type User struct {
	ID       int
	Username string
	Password string
}

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	slog.SetDefault(logger)

	log.Println("program started")

	u := User{ID: 10, Username: "admin", Password: "abc123"}
	log.Println(u)
}

$ go run .

{"time":"2024-02-16T08:43:00.266943-06:00","level":"INFO","msg":"program started"}
{"time":"2024-02-16T08:43:00.267105-06:00","level":"INFO","msg":"{10 admin abc123}"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Currently, sensitive data can be leaked out to the log. If we implement the slog.LogValuer interface, we can prevent our sensitive data from leaking out to the logs.

package main

import (
	"log"
	"log/slog"
	"os"
)

type User struct {
	ID       int
	Username string
	Password string
}

func (u User) LogValue() slog.Value {
	return slog.GroupValue(
		slog.Int("ID", u.ID),
		slog.String("username", u.Username),
		slog.String("password", "TOKEN_REDACTED"),
	)
}

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	slog.SetDefault(logger)

	log.Println("program started")

	u := User{ID: 10, Username: "admin", Password: "abc123"}
	// the log package does NOT detect the `LogValuer` interface
	log.Println(u)

	// You must use the slog package to detect the `Log.Valuer`
	slog.Info("user", "user", u)

}

$ go run .

{"time":"2024-02-16T08:43:00.122423-06:00","level":"INFO","msg":"program started"}
{"time":"2024-02-16T08:43:00.12258-06:00","level":"INFO","msg":"{10 admin abc123}"}
{"time":"2024-02-16T08:43:00.122582-06:00","level":"INFO","msg":"user","user":{"ID":10,"username":"admin","password":"TOKEN_REDACTED"}}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Note that while the standard log package will work well in most cases with the new slog package, it does NOT detect the slog.LogValuer interface and therefor should be avoided if you need that functinality.

Adding Source File Information

Many times, the hardest part of finding a bug is determining which file and which line the log message originated from. In the slog package, this is simplified by setting the AddSource option when creating the handler options.

package main

import (
	"log/slog"
	"os"
	"training/store"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{AddSource: true}))
	// Set the logger for the application
	slog.SetDefault(logger)

	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")

	_ = store.New()
}

$ go run .

{"time":"2024-02-16T08:43:00.697306-06:00","level":"INFO","source":{"function":"main.main","file":"./main.go","line":14},"msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.69744-06:00","level":"WARN","source":{"function":"main.main","file":"./main.go","line":15},"msg":"be warned!"}
{"time":"2024-02-16T08:43:00.697444-06:00","level":"ERROR","source":{"function":"main.main","file":"./main.go","line":16},"msg":"this is broken"}
{"time":"2024-02-16T08:43:00.697447-06:00","level":"INFO","source":{"function":"training/store.New","file":"./store/store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Notice that you get the fully qualified path. This is likely not what you want, so we can also use the ReplaceAttr option as well to create the desired output:

package main

import (
	"log/slog"
	"os"
	"path/filepath"

	"training/store"
)

func main() {
	replacer := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.SourceKey {
			source := a.Value.Any().(*slog.Source)
			source.File = filepath.Base(source.File)
		}
		return a
	}

	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{AddSource: true, ReplaceAttr: replacer}))
	// Set the logger for the application
	slog.SetDefault(logger)

	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")

	_ = store.New()
}

$ go run .

{"time":"2024-02-16T08:43:00.62628-06:00","level":"INFO","source":{"function":"main.main","file":"main.go","line":24},"msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.626472-06:00","level":"WARN","source":{"function":"main.main","file":"main.go","line":25},"msg":"be warned!"}
{"time":"2024-02-16T08:43:00.626476-06:00","level":"ERROR","source":{"function":"main.main","file":"main.go","line":26},"msg":"this is broken"}
{"time":"2024-02-16T08:43:00.626479-06:00","level":"INFO","source":{"function":"training/store.New","file":"store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Relative Source File Information

While the previous examples work, having the absolute path to a file or just the file name isn't exactly what we want. Typically, you want the path to the file from the root of the project. To do that, we can add just a few extra lines to our replacer function to strip out the current working directory.

package main

import (
	"log"
	"log/slog"
	"os"
	"strings"

	"training/store"
)

func main() {
	// we only want to calculate the working directory once
	// not every time we log
	wd, err := os.Getwd()
	if err != nil {
		log.Fatal("unable to determine working directory")
	}

	replacer := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.SourceKey {
			source := a.Value.Any().(*slog.Source)
			// remove current working directory and only leave the relative path to the program
			if file, ok := strings.CutPrefix(source.File, wd); ok {
				source.File = file
			}
		}
		return a
	}

	logger := slog.New(slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{AddSource: true, ReplaceAttr: replacer}))
	// Set the logger for the application
	slog.SetDefault(logger)

	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")

	_ = store.New()
}

$ go run .

{"time":"2024-02-16T08:43:00.844151-06:00","level":"INFO","source":{"function":"main.main","file":"/main.go","line":35},"msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.844408-06:00","level":"WARN","source":{"function":"main.main","file":"/main.go","line":36},"msg":"be warned!"}
{"time":"2024-02-16T08:43:00.844412-06:00","level":"ERROR","source":{"function":"main.main","file":"/main.go","line":37},"msg":"this is broken"}
{"time":"2024-02-16T08:43:00.844415-06:00","level":"INFO","source":{"function":"training/store.New","file":"/store/store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Source Only with Debug

Since adding source to the log output can not only degrade system performance, its just plain noisy a lot of times. As such, we can change our program to only allow for the source to be present if we our logging level is set to debug. For this example, we'll use an environment variable to control the change.

package main

import (
	"log"
	"log/slog"
	"os"
	"strings"

	"training/store"
)

func main() {
	var loggingLevel = new(slog.LevelVar)

	// we only want to calculate the working directory once
	// not every time we log
	wd, err := os.Getwd()
	if err != nil {
		log.Fatal("unable to determine working directory")
	}

	replacer := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.SourceKey {
			source := a.Value.Any().(*slog.Source)
			// remove current working directory and only leave the relative path to the program
			if file, ok := strings.CutPrefix(source.File, wd); ok {
				source.File = file
			}
		}
		return a
	}

	options := &slog.HandlerOptions{
		Level:       loggingLevel,
		ReplaceAttr: replacer,
	}
	// if debug is present, turn on logging level and source for logs
	if os.Getenv("loglevel") == "debug" {
		loggingLevel.Set(slog.LevelDebug)
		options.AddSource = true
	}

	logger := slog.New(slog.NewJSONHandler(os.Stderr, options))

	// Set the logger for the application
	slog.SetDefault(logger)
	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")
	slog.Debug("this is a debug")

	_ = store.New()
}

Here is the output without source and no debug:

$ go run .

{"time":"2024-02-16T08:43:00.485333-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.485549-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.485551-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:43:00.485553-06:00","level":"INFO","msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Here is the output with debug turned on (environment variable loglevel set to debug:

$ go run .

{"time":"2024-02-16T08:43:00.338433-06:00","level":"INFO","source":{"function":"main.main","file":"/main.go","line":47},"msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.338616-06:00","level":"WARN","source":{"function":"main.main","file":"/main.go","line":48},"msg":"be warned!"}
{"time":"2024-02-16T08:43:00.33862-06:00","level":"ERROR","source":{"function":"main.main","file":"/main.go","line":49},"msg":"this is broken"}
{"time":"2024-02-16T08:43:00.338623-06:00","level":"DEBUG","source":{"function":"main.main","file":"/main.go","line":50},"msg":"this is a debug"}
{"time":"2024-02-16T08:43:00.338626-06:00","level":"INFO","source":{"function":"training/store.New","file":"/store/store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

With

In a larger code base, it's very common to have several subsystems. In those cases, it's common to pass the logger to the constructor for those systems, and then those constructors can use the With method to identify all logs that came from those systems. This relieves the need to identify in every call to the logger what the context of the system was when the logging occurred. This is very helpful when parsing and searching logs.

package main

import (
	"log/slog"
	"os"
	"training/store"
)

func main() {
	logger := slog.New(slog.NewJSONHandler(os.Stderr, nil))
	// Set the logger for the application
	slog.SetDefault(logger)

	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")

	_ = store.New(logger)
}

$ go run .

{"time":"2024-02-16T08:43:00.769448-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.769556-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.769558-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:43:00.76956-06:00","level":"INFO","msg":"starting store","sys":"store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Putting it all together

Now that we have seen several different ways to use the new slog package, here is an example of what a production level logger configuration might look like.

Main Code:

package main

import (
	"log"
	"log/slog"
	"os"
	"strings"
	"training/store"
)

func main() {
	var loggingLevel = new(slog.LevelVar)

	wd, err := os.Getwd()
	if err != nil {
		log.Fatal("unable to determine working directory")
	}

	replacer := func(groups []string, a slog.Attr) slog.Attr {
		if a.Key == slog.SourceKey {
			source := a.Value.Any().(*slog.Source)
			if file, ok := strings.CutPrefix(source.File, wd); ok {
				source.File = file
			}
		}
		return a
	}

	options := &slog.HandlerOptions{
		Level:       loggingLevel,
		ReplaceAttr: replacer,
	}

	if os.Getenv("loglevel") == "debug" {
		loggingLevel.Set(slog.LevelDebug)
		options.AddSource = true
	}

	logger := slog.New(slog.NewJSONHandler(os.Stderr, options))

	slog.SetDefault(logger)

	slog.Info("hello gophers")
	slog.Warn("be warned!")
	slog.Error("this is broken")

	_ = store.New(logger)
}

Store Code:

package store

import "log/slog"

type Store struct {
	log *slog.Logger
}

func New(log *slog.Logger) *Store {
	s := &Store{
		log: log.With("sys", "store"),
	}
	s.log.Info("starting store")
	s.log.Debug("using custom logger")
	return s
}

$ go run .

{"time":"2024-02-16T08:43:00.194963-06:00","level":"INFO","msg":"hello gophers"}
{"time":"2024-02-16T08:43:00.195116-06:00","level":"WARN","msg":"be warned!"}
{"time":"2024-02-16T08:43:00.195119-06:00","level":"ERROR","msg":"this is broken"}
{"time":"2024-02-16T08:43:00.195122-06:00","level":"INFO","msg":"starting store","sys":"store"}

--------------------------------------------------------------------------------
Go Version: go1.22.0

Summary

The slog package has added many great convenience features to the standard library that bring it up to date with most modern logging philosophies. Making use of these features will allow you to create enterprise applications in the future.