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 .

2023/09/06 10:02:10 INFO hello gophers
2023/09/06 10:02:10 WARN be warned!
2023/09/06 10:02:10 ERROR this is broken

--------------------------------------------------------------------------------
Go Version: go1.21.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.Stdout, nil))
	logger.Info("hello gophers")
	logger.Warn("be warned!")
	logger.Error("this is broken")
}

$ go run .

{"time":"2023-09-06T10:02:10.898219-05:00","level":"INFO","msg":"hello gophers"}
{"time":"2023-09-06T10:02:10.898343-05:00","level":"WARN","msg":"be warned!"}
{"time":"2023-09-06T10:02:10.898345-05:00","level":"ERROR","msg":"this is broken"}

--------------------------------------------------------------------------------
Go Version: go1.21.0

Default Logger

By default, tThe 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.Stdout, 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":"2023-09-06T10:02:10.635254-05:00","level":"INFO","msg":"hello gophers"}
{"time":"2023-09-06T10:02:10.635564-05:00","level":"WARN","msg":"be warned!"}
{"time":"2023-09-06T10:02:10.635567-05:00","level":"ERROR","msg":"this is broken"}
{"time":"2023-09-06T10:02:10.635591-05:00","level":"INFO","msg":"creating store","store-id":74}
{"time":"2023-09-06T10:02:10.63561-05:00","level":"INFO","msg":"new store created","store-id":74}
{"time":"2023-09-06T10:02:10.635634-05:00","level":"INFO","msg":"I'm log.println, look at me!"}

--------------------------------------------------------------------------------
Go Version: go1.21.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() {
	// 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.Stdout, &slog.HandlerOptions{Level: loggingLevel}))

	// set the global logger
	slog.SetDefault(logger)
	// set the level to debug
	loggingLevel.Set(slog.LevelDebug)

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

$ go run .

{"time":"2023-09-06T10:02:10.20828-05:00","level":"INFO","msg":"hello gophers"}
{"time":"2023-09-06T10:02:10.208381-05:00","level":"WARN","msg":"be warned!"}
{"time":"2023-09-06T10:02:10.208383-05:00","level":"ERROR","msg":"this is broken"}
{"time":"2023-09-06T10:02:10.208384-05:00","level":"DEBUG","msg":"be warned!"}

--------------------------------------------------------------------------------
Go Version: go1.21.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.

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() {
	// create, configure, and set the global logger.
	var loggingLevel = new(slog.LevelVar)
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: loggingLevel}))
	slog.SetDefault(logger)
	loggingLevel.Set(slog.LevelDebug)

	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":"2023-09-06T10:02:11.221197-05:00","level":"INFO","msg":"program started"}
{"time":"2023-09-06T10:02:11.541371-05:00","level":"INFO","msg":"success","request":{"method":"GET","url":"https://www.gopherguides.com"}}

--------------------------------------------------------------------------------
Go Version: go1.21.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.Boolandslog.Any`.

package main

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

func main() {
	// create, configure, and set the global logger.
	var loggingLevel = new(slog.LevelVar)
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: loggingLevel}))
	slog.SetDefault(logger)
	loggingLevel.Set(slog.LevelDebug)

	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":"2023-09-06T10:02:11.104102-05:00","level":"INFO","msg":"program started"}
{"time":"2023-09-06T10:02:11.549409-05:00","level":"INFO","msg":"success","request":{"method":"GET","url":"https://www.gopherguides.com"}}

--------------------------------------------------------------------------------
Go Version: go1.21.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() {
	// create, configure, and set the global logger.
	var loggingLevel = new(slog.LevelVar)
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: loggingLevel}))
	slog.SetDefault(logger)
	loggingLevel.Set(slog.LevelDebug)

	log.Println("program started")

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

$ go run .

{"time":"2023-09-06T10:02:10.303863-05:00","level":"INFO","msg":"program started"}
{"time":"2023-09-06T10:02:10.304024-05:00","level":"INFO","msg":"{10 admin abc123}"}

--------------------------------------------------------------------------------
Go Version: go1.21.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() {
	// create, configure, and set the global logger.
	var loggingLevel = new(slog.LevelVar)
	logger := slog.New(slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{Level: loggingLevel}))
	slog.SetDefault(logger)
	loggingLevel.Set(slog.LevelDebug)

	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":"2023-09-06T10:02:10.534894-05:00","level":"INFO","msg":"program started"}
{"time":"2023-09-06T10:02:10.535191-05:00","level":"INFO","msg":"{10 admin abc123}"}
{"time":"2023-09-06T10:02:10.535247-05:00","level":"INFO","msg":"user","user":{"ID":10,"username":"admin","password":"TOKEN_REDACTED"}}

--------------------------------------------------------------------------------
Go Version: go1.21.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.Stdout, &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":"2023-09-06T10:02:11.007066-05:00","level":"INFO","source":{"function":"main.main","file":"./main.go","line":14},"msg":"hello gophers"}
{"time":"2023-09-06T10:02:11.007223-05:00","level":"WARN","source":{"function":"main.main","file":"./main.go","line":15},"msg":"be warned!"}
{"time":"2023-09-06T10:02:11.007227-05:00","level":"ERROR","source":{"function":"main.main","file":"./main.go","line":16},"msg":"this is broken"}
{"time":"2023-09-06T10:02:11.007231-05:00","level":"INFO","source":{"function":"training/store.New","file":"./store/store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.21.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.Stdout, &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":"2023-09-06T10:02:10.720634-05:00","level":"INFO","source":{"function":"main.main","file":"main.go","line":24},"msg":"hello gophers"}
{"time":"2023-09-06T10:02:10.720926-05:00","level":"WARN","source":{"function":"main.main","file":"main.go","line":25},"msg":"be warned!"}
{"time":"2023-09-06T10:02:10.720936-05:00","level":"ERROR","source":{"function":"main.main","file":"main.go","line":26},"msg":"this is broken"}
{"time":"2023-09-06T10:02:10.720942-05:00","level":"INFO","source":{"function":"training/store.New","file":"store.go","line":8},"msg":"starting store"}

--------------------------------------------------------------------------------
Go Version: go1.21.0

Summary

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