🔠Want to centralize and monitor your Go application logs?
Head over to Logtail and start ingesting your logs in 5 minutes.
Structured logging involves producing log records in a well-defined format (usually JSON), which adds a level of organization and consistency to application logs, making them easier to process. Such log records are composed of key-value pairs that capture relevant contextual information about the event being logged, such as the severity level, timestamp, source code location, user ID, or any other relevant metadata.
This article will delve deep into the world of structured logging in Go, with a specific focus on recently accepted slog proposal which aims to bring high performance structured logging with levels to the standard library.
We will begin by examining the existing log
package in Go and its limitations,
then do a deep dive on slog
by covering all its most important concepts. We
will also briefly discuss some of the most widely-used structured logging
libraries in the Go ecosystem.
Head over to Logtail and start ingesting your logs in 5 minutes.
Before we discuss the new
structured logging proposal, let's briefly examine
the standard library log
which provides a simple way to write log messages to
the console, a file or any type that implements the io.Writer
interface.
Here's the most basic way to write log messages in Go:
package main
import "log"
func main() {
log.Println("Hello from Go application!")
}
2023/03/08 11:43:09 Hello from Go application!
The output contains the log message and a timestamp in the local time zone that
indicates when the entry was generated. The Println()
method is one of methods
accessible on the preconfigured global Logger
, and it prints to the standard
error. The following other methods are available:
log.Print()
log.Printf()
log.Fatal()
log.Fatalf()
log.Fatalln()
log.Panic()
log.Panicf()
log.Panicln()
The difference between the Fatal
and Panic
methods above is that the former
calls os.Exit(1)
after logging a message, while the latter calls panic()
.
You can customize the default Logger
by retrieving it through the
log.Default()
method. Afterward, call the relevant method on the returned
Logger
. The example below configures the default logger to write to the
standard output instead of the standard error:
func main() {
defaultLogger := log.Default()
defaultLogger.SetOutput(os.Stdout)
log.Println("Hello from Go application!")
}
You can also create a completely custom logger through the log.New()
method
which has the following signature:
func New(out io.Writer, prefix string, flag int) *Logger
The first argument is the destination of the log messages produced by the
Logger
, which can be anything that implements the io.Writer
interface. The
second is a prefix that is prepended to each log message, while the third
specifies a set of constants that is
used to add details to each log message.
package main
import (
"log"
"os"
)
func main() {
logger := log.New(os.Stdout, "", log.LstdFlags)
logger.Println("Hello from Go application!")
}
The above logger is configured to print to the standard output, and it uses the initial values for the default logger. Therefore, the output remains the same as before:
2023/03/08 11:44:17 Hello from Go application!
Let's customize it further by adding the application name, file name, and line number to the each log entry. We'll also add microseconds to the timestamp and record the UTC time instead of the local time:
logger := log.New(
os.Stderr,
"MyApplication: ",
log.Ldate|log.Ltime|log.Lmicroseconds|log.LUTC|log.Lshortfile,
)
MyApplication: 2023/03/08 10:47:12.348478 main.go:14: Hello from Go application!
The MyApplication:
prefix appears at the beginning of each log entry, and the
UTC timestamp now includes microseconds. The file name and line number are also
included in the output to help you locate the source of each entry in the
codebase.
Although the log
package in Go provides a convenient way to initiate logging,
it is not ideal for production use due to several limitations, such as the
following:
Lack of log levels: log levels are one of the
staple features in most logging packages, but they are missing from the log
package in Go. All log messages are treated the same way, making it difficult
to filter or separate log messages based on their importance or severity.
No support for structured logging: the log
package in Go only outputs
plain text messages. It does not support structured logging, where the events
being recorded are represented in a structured format (usually JSON), which
can be subsequently parsed and analyzed programmatically for monitoring,
alerting, auditing, creating dashboards, and other forms of analysis.
No context-aware logging: the log
package does not support
context-aware logging, making it difficult to attach contextual information
(such as request IDs, User IDs, and other variables) to log messages
automatically.
No support for log sampling: log sampling is a useful feature for
reducing the volume of logs in high-throughput applications. Third-party
logging libraries often provide this functionality, but it is missing from
the built-in log
package in Go.
Limited configuration options: the log
package only supports basic
configuration options, such as setting the log output destination and prefix
are supported. Advanced logging libraries offer way more configuration
opportunities, such as custom log formats, filtering, automatically adding
contextual data, enabling asynchronous logging, error handling behavior, and
more!
In light of the aforementioned limitations, a new logging package called slog
has been
proposed
to fill the existing gap in Go's standard library. This package aims to enhance
logging capabilities in the language by introducing structured logging with
levels, and create a standard interface for logging that other packages can
extend freely.
The slog
package has its origins in this
discussion led by Jonathan
Amsterdam which later led to the
proposal describing the exact
design of the package which is expected to reside at log/slog
once it is
finalized and implemented in a Go release. Until then, you can find the
preliminary implementation of slog
at
golang.org/x/exp/slog.
Let's begin our discussion of slog
by walking through its design and
architecture. The package provides three main types that you should be familiar
with:
Logger
: the main API for structured logging with slog
. It provides level
methods such as (Info()
and Error()
) for recording events of interest.Record
: represents a self-contained log record object created by a Logger
.Handler
: an interface that, once implemented, determines the formatting and
destination of a log Record
. Two handlers are provided with the slog
package by default: TextHandler
and JSONHandler
.In the following sections of this article, we will provide a more detailed overview of each of these types (with examples). It's worth noting that, while the proposal has been accepted, there is a possibility that some details may be subject to change prior to the final release.
To follow along with the examples presented in this article, you can install
slog
into your project using the following command:
go get golang.org/x/exp/[email protected]
The slog
package exposes a default Logger
accessible through top-level
functions on the package. This logger defaults to the INFO
level and logs a
plain text output to the standard output (similar to the log
package):
package main
import (
"errors"
"golang.org/x/exp/slog"
)
func main() {
slog.Debug("Debug message")
slog.Info("Info message")
slog.Warn("Warning message")
slog.Error("Error message")
}
2023/03/15 12:55:56 INFO Info message
2023/03/15 12:55:56 WARN Warning message
2023/03/15 12:55:56 ERROR Error message
You can also create your own Logger
instance through the slog.New()
method.
It accepts a non-nil Handler
interface which determines how the logs are
formatted and where they are written to. Here's an example that uses the
built-in JSONHandler
type to format log records as JSON and send them to the
standard output:
package main
import (
"errors"
"os"
"golang.org/x/exp/slog"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout))
logger.Debug("Debug message")
logger.Info("Info message")
logger.Warn("Warning message")
logger.Error("Error message")
}
{"time":"2023-03-15T12:59:22.227408691+01:00","level":"INFO","msg":"Info message"}
{"time":"2023-03-15T12:59:22.227468972+01:00","level":"WARN","msg":"Warning message"}
{"time":"2023-03-15T12:59:22.227472149+01:00","level":"ERROR","msg":"Error message","!BADKEY":"an error"}
Notice that the custom logger also defaults to INFO
, and that's why the
DEBUG
entry is suppressed. If you opt for TextHandler
instead, each log
record will formatted according to the
logfmt standard:
logger := slog.New(slog.NewTextHandler(os.Stdout))
time=2023-03-15T13:00:11.333+01:00 level=INFO msg="Info message"
time=2023-03-15T13:00:11.333+01:00 level=WARN msg="Warning message"
time=2023-03-15T13:00:11.333+01:00 level=ERROR msg="Error message"
If you want to configure the default Logger
, the easiest way is to use the
slog.SetDefault()
method to replace the default logger with a custom one:
package main
import (
"os"
"golang.org/x/exp/slog"
)
func main() {
logger := slog.New(slog.NewJSONHandler(os.Stdout))
slog.SetDefault(logger)
slog.Info("Info message")
}
You should now observe that each record produced by the package's top-level
logging methods are now being routed through the JSONHandler
:
{"time":"2023-03-15T13:07:39.105777557+01:00","level":"INFO","msg":"Info message"}
Note that the SetDefault()
method also updates the default logger used by the
log
package so that existing applications using log.Printf()
and related
methods can switch to structured logging:
logger := slog.New(slog.NewJSONHandler(os.Stdout))
slog.SetDefault(logger)
log.Println("Hello from old logger")
{"time":"2023-03-16T15:20:33.783681176+01:00","level":"INFO","msg":"Hello from old logger"}
The slog.NewLogLogger()
method is also available for converting an
slog.Logger
to a log.Logger
when you need to utilize APIs that necessitate
the use of a log.Logger
(such as http.Server.ErrorLog
):
handler := slog.NewJSONHandler(os.Stdout)
logger := slog.NewLogLogger(handler, slog.LevelError)
server := http.Server{
ErrorLog: logger,
}
One of the key advantages of logging in a structured format is the ability to add arbitrary attributes to log records in the form of key/value pairs. These attributes add context about the log event being recorded which could be useful for troubleshooting, generating metrics, or a variety of other purposes. Here's an example of how it works:
logger.Info(
"incoming request",
"method", "GET",
"time_taken_ms", 158,
"path", "/hello/world?q=search",
"status", 200,
"user_agent", "Googlebot/2.1 (+http://www.google.com/bot.html)",
)
{
"time":"2023-02-24T11:52:49.554074496+01:00",
"level":"INFO",
"msg":"incoming request",
"method":"GET",
"time_taken_ms":158,
"path":"/hello/world?q=search",
"status":200,
"user_agent":"Googlebot/2.1 (+http://www.google.com/bot.html)"
}
All the level methods (Info()
, Debug()
, etc) take the log message as their
first argument, and an unlimited number of loosely-typed key/value pairs. This
is similar to
zap's SugaredLogger
API as
it prioritises brevity at the cost of additional allocations. It can also lead
to problems if you're not careful. Most notably, unbalanced key/value pairs will
yield a problematic output.
logger.Info(
"incoming request",
"method", "GET",
"time_taken_ms",
)
Since the time_taken_ms
key does not have a corresponding value, it will be
treated as a value with key !BADKEY
:
{
"time": "2023-03-15T13:15:29.956566795+01:00",
"level": "INFO",
"msg": "incoming request",
"method": "GET",
"!BADKEY": "time_taken_ms"
}
This isn't great because a property misalignment could lead to bad entries being created, and you may not know it until you need to use the logs. While the proposal suggests a vet check to catch missing key/value problems in methods where they can occur, extra care will also needs to be taken during the review process to ensure that each key/value pair in the entry is balanced and that the types are correct.
To prevent such mistakes, it's best to use strongly typed contextual attributes as shown below:
logger.Info(
"incoming request",
slog.String("method", "GET"),
slog.Int("time_taken_ms", 158),
slog.String("path", "/hello/world?q=search"),
slog.Int("status", 200),
slog.String(
"user_agent",
"Googlebot/2.1 (+http://www.google.com/bot.html)",
),
)
This is much better as every attribute will be checked for the correct type at compile time (see the full list of supported types here. However, it's not fool-proof as there's nothing stopping you from mixing strongly-typed and loosely-typed key/value pairs like this:
logger.Info(
"incoming request",
"method", "GET",
slog.Int("time_taken_ms", 158),
slog.String("path", "/hello/world?q=search"),
"status", 200,
slog.String(
"user_agent",
"Googlebot/2.1 (+http://www.google.com/bot.html)",
),
)
To guarantee type safety when adding contextual attributes to your records, you
must use the LogAttrs()
method like this:
logger.LogAttrs(
context.Background(),
slog.LevelInfo,
"incoming request",
slog.String("method", "GET"),
slog.Int("time_taken_ms", 158),
slog.String("path", "/hello/world?q=search"),
slog.Int("status", 200),
slog.String(
"user_agent",
"Googlebot/2.1 (+http://www.google.com/bot.html)",
),
)
This method only accepts the slog.Attr
type for custom attributes so its not
possible to have an unbalanced key/value pair. However, its API is more
convoluted as you always need to pass a context (or nil
) and the log level to
the method in addition to the log message and custom attributes.
Slog also provides the ability to group multiple attributes under a single name
name. The way it is displayed depends on the Handler
in use. For example, with
JSONHandler
, the group is treated as a separate JSON object:
logger.LogAttrs(
context.Background(),
slog.LevelInfo,
"image uploaded",
slog.Int("id", 23123),
slog.Group("properties",
slog.Int("width", 4000),
slog.Int("height", 3000),
slog.String("format", "jpeg"),
),
)
{
"time":"2023-02-24T12:03:12.175582603+01:00",
"level":"INFO",
"msg":"image uploaded",
"id":23123,
"properties":{
"width":4000,
"height":3000,
"format":"jpeg"
}
}
When your logs are formatted as a sequence of key=value
pairs, the group name
will be set as a prefix on each key like this:
time=2023-02-24T12:06:20.249+01:00 level=INFO msg="image uploaded" id=23123
properties.width=4000 properties.height=3000 properties.format=jpeg
It's sometimes helpful to include the same attributes in all the records produced within a given scope of a program, so that they are present in all the records without being repeated at log point. This is where child loggers come in handy as they create a new logging context that inherits from their parents, but with additional fields.
Creating child loggers in slog
is done through the Logger.With()
method
which accepts a mix of strongly-typed and loosely-typed key/value pairs and
returns a new Logger
instance. For example, here's a snippet that adds the
program's process ID and the Go version used to compile it to each log record in
a program_info
property:
handler := slog.NewJSONHandler(os.Stdout)
buildInfo, _ := debug.ReadBuildInfo()
logger := slog.New(handler).With(
slog.Group("program_info",
slog.Int("pid", os.Getpid()),
slog.String("go_version", buildInfo.GoVersion),
),
)
With this configuration in place, all records created by the logger
will
contain the specified attributes under the program_info
property as long as it
is not overridden at log point:
logger.Info("image upload successful", slog.String("image_id", "39ud88"))
logger.Warn(
"storage is 90% full",
slog.String("available_space", "900.1 MB"),
)
{
"time": "2023-02-26T19:26:46.046793623+01:00",
"level": "INFO",
"msg": "image upload successful",
"program_info": {
"pid": 229108,
"go_version": "go1.20"
},
"image_id": "39ud88"
}
{
"time": "2023-02-26T19:26:46.046847902+01:00",
"level": "WARN",
"msg": "storage is 90% full",
"program_info": {
"pid": 229108,
"go_version": "go1.20"
},
"available_space": "900.1 MB"
}
You can also use the WithGroup()
method to create a child logger that starts a
group such that all attributes added to the logger (including those added at log
point) will be nested under the group name:
handler := slog.NewJSONHandler(os.Stdout)
buildInfo, _ := debug.ReadBuildInfo()
logger := slog.New(handler).WithGroup("program_info")
child := logger.With(
slog.Int("pid", os.Getpid()),
slog.String("go_version", buildInfo.GoVersion),
)
child.Info("image upload successful", slog.String("image_id", "39ud88"))
child.Warn(
"storage is 90% full",
slog.String("available_space", "900.1 MB"),
)
{
"time": "2023-02-26T19:25:35.977851358+01:00",
"level": "INFO",
"msg": "image upload successful",
"group_name": {
"pid": 227404,
"go_version": "go1.20",
"image_id": "39ud88"
}
}
{
"time": "2023-02-26T19:25:35.977899791+01:00",
"level": "WARN",
"msg": "storage is 90% full",
"group_name": {
"pid": 227404,
"go_version": "go1.20",
"available_space": "900.1 MB"
}
}
The slog
package provides four log levels by default, and each one is
associated with an integer value: DEBUG
(-4), INFO
(0), WARN
(4), and
ERROR
(8). The gap of 4 between each level is a deliberate design decision
made to accommodate logging schemes with custom levels between the default ones.
For example, you can create a custom NOTICE
level between INFO
and WARN
with a value of 1, 2, or 3.
You've probably noticed that Logger
s are configured to log at the INFO
level
by default, and this causes events logged at a lower severity (such as DEBUG
)
to be suppressed. You can customize this behaviour through the
HandlerOptions struct
as shown below:
package main
import (
"os"
"golang.org/x/exp/slog"
)
func main() {
opts := slog.HandlerOptions{
Level: slog.LevelDebug,
}
logger := slog.New(opts.NewJSONHandler(os.Stdout))
logger.Debug("Debug message")
logger.Info("Info message")
logger.Warn("Warning message")
logger.Error("Error message", errors.New("an error"))
}
{"time":"2023-03-15T13:43:54.949861653+01:00","level":"DEBUG","msg":"Debug message"}
{"time":"2023-03-15T13:43:54.949924059+01:00","level":"INFO","msg":"Info message"}
{"time":"2023-03-15T13:43:54.949927126+01:00","level":"WARN","msg":"Warning message"}
{"time":"2023-03-15T13:43:54.949929822+01:00","level":"ERROR","msg":"Error message"}
Note that this approach fixes the minimum level of the handler throughout its
lifetime. If you need the minimum level to be dynamically varied, you must use
the LevelVar
type as illustrated below:
logLevel := &slog.LevelVar{} // INFO
opts := slog.HandlerOptions{
Level: logLevel,
}
// you can change the level anytime like this
logLevel.Set(slog.LevelDebug)
If you need custom levels beyond what slog provides by default, you can create them by implementing the Leveler interface which is defined by a single method:
type Leveler interface {
Level() Level
}
It's easy to implement the Leveler
interface through the Level
type as shown
below (since Level
itself implements Leveler
):
const (
LevelTrace = slog.Level(-8)
LevelNotice = slog.Level(2)
LevelFatal = slog.Level(12)
)
Once you've defined custom levels as above, you can use them as follows:
opts := slog.HandlerOptions{
Level: LevelTrace,
}
logger := slog.New(opts.NewJSONHandler(os.Stdout))
ctx := context.Background()
logger.Log(ctx, LevelTrace, "Trace message")
logger.Log(ctx, LevelNotice, "Notice message")
logger.Log(ctx, LevelFatal, "Fatal level")
{"time":"2023-02-24T09:26:41.666493901+01:00","level":"DEBUG-4","msg":"Trace level"}
{"time":"2023-02-24T09:26:41.66659754+01:00","level":"INFO+2","msg":"Notice level"}
{"time":"2023-02-24T09:26:41.666602404+01:00","level":"ERROR+4","msg":"Fatal level"}
Notice how the level
property for each custom level is labelled in terms of
the defaults. This probably isn't what you want so you must use customize the
level names through the HandlerOptions
type:
. . .
var LevelNames = map[slog.Leveler]string{
LevelTrace: "TRACE",
LevelNotice: "NOTICE",
LevelFatal: "FATAL",
}
func main() {
opts := slog.HandlerOptions{
Level: LevelTrace,
ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
if a.Key == slog.LevelKey {
level := a.Value.Any().(slog.Level)
levelLabel, exists := LevelNames[level]
if !exists {
levelLabel = level.String()
}
a.Value = slog.StringValue(levelLabel)
}
return a
},
}
. . .
}
The ReplaceAttr()
function is used to customize how each key/value pair in a
Record
is handled by a Handler
. It can be used to customize the name of the
key, or transform the value in some way. In the above example, it is used to map
the custom log levels to labels. The defaults are left as is, but the custom
ones are given labels of TRACE
, NOTICE
, and FATAL
respectively.
{"time":"2023-02-24T09:27:51.747625912+01:00","level":"TRACE","msg":"Trace level"}
{"time":"2023-02-24T09:27:51.747732118+01:00","level":"NOTICE","msg":"Notice level"}
{"time":"2023-02-24T09:27:51.747737319+01:00","level":"FATAL","msg":"Fatal level"}
As mentioned earlier, both TextHandler
and JSONHandler
can be customized
using the HandlerOptions
type. You've already learned how to adjust the
minimum level and modify attributes before they are logged. Another
customization that can be accomplished through HandlerOptions
is adding the
source of the log message, if required:
opts := slog.HandlerOptions{
AddSource: true,
Level: slog.LevelDebug,
}
{"time":"2023-02-24T10:28:50.751111921+01:00","level":"DEBUG","source":"/home/betterstack/go-logging/main.go:55","msg":"Debug message"}
{"time":"2023-02-24T10:28:50.75120862+01:00","level":"INFO","source":"/home/betterstack/go-logging/main.go:56","msg":"Info message"}
{"time":"2023-02-24T10:28:50.751215229+01:00","level":"WARN","source":"/home/betterstack/go-logging/main.go:57","msg":"Warning message"}
{"time":"2023-02-24T10:28:50.751222025+01:00","level":"ERROR","source":"/home/betterstack/go-logging/main.go:60","msg":"Error message"}
It's also easy to switch handlers based on the application environment. For
example, you might prefer to use the TextHandler
for your development logs
since its a little easier to read, and then switch to JSONHandler
in
production for greater compatibility with various logging tools, you can easily
enable this behaviour through an environmental variable:
package main
import (
"os"
"golang.org/x/exp/slog"
)
var appEnv = os.Getenv("APP_ENV")
func main() {
opts := slog.HandlerOptions{
Level: slog.LevelDebug,
}
var handler slog.Handler = opts.NewTextHandler(os.Stdout)
if appEnv == "production" {
handler = opts.NewJSONHandler(os.Stdout)
}
logger := slog.New(handler)
logger.Info("Info message")
}
go run main.go
time=2023-02-24T10:36:39.697+01:00 level=INFO msg="Info message"
APP_ENV=production go run main.go
{"time":"2023-02-24T10:35:16.964821548+01:00","level":"INFO","msg":"Info message"}
Since Handler
is an interface, you can easily define one for formatting the
logs in a different way or writing them to some destination. The interface is as
follows:
type Handler interface {
Enabled(context.Context, Level) bool
Handle(r Record) error
WithAttrs(attrs []Attr) Handler
WithGroup(name string) Handler
}
Here's what each of these methods do:
Enabled()
is used to determine if a log record should be handled or
discarded based on its level. The context
can also used to make a decision.Handle()
processes the each log record sent to the handler. It is called
only if Enabled()
returns true
.WithAttrs()
creates a new handler from an existing one and adds the
specified attributes to the handler.WithGroup()
creates a new handler from an existing one and adds theHere's an example that uses the log
, json
, and
color to implement a prettified development
output for log records:
// NOTE: Not well tested, just an illustration of what's possible
package main
import (
"context"
"encoding/json"
"io"
"log"
"github.com/fatih/color"
"golang.org/x/exp/slog"
)
type PrettyHandlerOptions struct {
SlogOpts slog.HandlerOptions
}
type PrettyHandler struct {
opts PrettyHandlerOptions
slog.Handler
l *log.Logger
}
func (h *PrettyHandler) Handle(ctx context.Context, r slog.Record) error {
level := r.Level.String() + ":"
switch r.Level {
case slog.LevelDebug:
level = color.MagentaString(level)
case slog.LevelInfo:
level = color.BlueString(level)
case slog.LevelWarn:
level = color.YellowString(level)
case slog.LevelError:
level = color.RedString(level)
}
fields := make(map[string]interface{}, r.NumAttrs())
r.Attrs(func(a slog.Attr) {
fields[a.Key] = a.Value.Any()
})
b, err := json.MarshalIndent(fields, "", " ")
if err != nil {
return err
}
timeStr := r.Time.Format("[15:05:05.000]")
msg := color.CyanString(r.Message)
h.l.Println(timeStr, level, msg, color.WhiteString(string(b)))
return nil
}
func (opts PrettyHandlerOptions) NewPrettyHandler(
out io.Writer,
) *PrettyHandler {
h := &PrettyHandler{
Handler: opts.SlogOpts.NewJSONHandler(out),
l: log.New(out, "", 0),
}
return h
}
When you use the PrettyHandler
in your code like this:
package main
import (
"os"
"golang.org/x/exp/slog"
)
func main() {
opts := PrettyHandlerOptions{
SlogOpts: slog.HandlerOptions{
Level: slog.LevelDebug,
},
}
handler := opts.NewPrettyHandler(os.Stdout)
logger := slog.New(handler)
logger.Debug(
"executing database query",
slog.String("query", "SELECT * FROM users"),
)
logger.Info("image upload successful", slog.String("image_id", "39ud88"))
logger.Warn(
"storage is 90% full",
slog.String("available_space", "900.1 MB"),
)
logger.Error(
"An error occurred while processing the request",
slog.String("url", "https://example.com"),
)
}
You will observe the following colorized output:
The LogValuer
interface allows any Go type to convert itself into a
slog.Value
for logging by implementing the LogValue()
method shown below:
type LogValuer interface {
LogValue() Value
}
You can use this to specify the output what should be produced when your custom types are logged:
package main
import (
"os"
"golang.org/x/exp/slog"
)
// User does not implement `LogValuer`
type User struct {
ID string `json:"id"`
FirstName string `json:"first_name"`
LastName string `json:"last_name"`
Email string `json:"email"`
Password string `json:"password"`
}
func main() {
handler := slog.NewJSONHandler(os.Stdout)
logger := slog.New(handler)
u := &User{
ID: "user-12234",
FirstName: "Jan",
LastName: "Doe",
Email: "[email protected]",
Password: "pass-12334",
}
logger.Info("info", "user", u)
}
{
"time": "2023-02-26T22:11:30.080656774+01:00",
"level": "INFO",
"msg": "info",
"user": {
"id": "user-12234",
"first_name": "Jan",
"last_name": "Doe",
"email": "[email protected]",
"password": "pass-12334"
}
}
Without implementing the LogValuer
interface, the entire User
type will be
added to the record as shown above. This can be problematic if the type contains
secret fields that should not be present in the logs (such as passwords) and it
can also make your logs unnecessarily verbose.
You can fix this by specifying how you'd like the type to be handled in the
logs. For example, you may specify that only the ID
field should be logged:
// implement the `LogValuer` interface
func (u *User) LogValue() slog.Value {
return slog.StringValue(u.ID)
}
You will now observe the following output:
{
"time": "2023-02-26T22:43:28.184363059+01:00",
"level": "INFO",
"msg": "info",
"user": "user-12234"
}
You can also group attributes together like this:
func (u *User) LogValue() slog.Value {
return slog.GroupValue(
slog.String("id", u.ID),
slog.String("name", u.FirstName+" "+u.LastName),
)
}
{
"time": "2023-03-15T14:44:24.223381036+01:00",
"level": "INFO",
"msg": "info",
"user": {
"id": "user-12234",
"name": "Jan Doe"
}
}
As alluded to earlier in this article, many developers opt to use third-party libraries to implement structured logging in their applications. This section covers some of the most popular ones:
Zerolog is a structured logging package for Go that features a great development experience and impressive performance when compared to alternative libraries. It offers a chaining API that allows you to specify the type of each field added to a log entry which helps with avoiding unnecessary allocations and reflection. Zerolog only supports JSON or the lesser-known Concise Binary Object Representation (CBOR) format, but it also provides a native way to prettify its output in development environments.
package main
import (
"github.com/rs/zerolog"
)
func main() {
logger := zerolog.New(os.Stdout)
loger.Info().
Str("name", "John").
Int("age", 9).
Msg("hello from zerolog")
}
{"level":"info","name":"John","age":9,"time":"2022-08-11T21:28:12+01:00","message":"hello from zerolog"}
You can import a pre-configured global logger or use zerolog.New()
to create a
customizable logger instance as shown above. You can also create child loggers
with additional context similar to how its done in slog
. Zerolog also helps
you adequately log errors by providing the ability to include a formatted
stacktrace through its integration with the popular
errors package. It also provides several
helper functions for
better integration with HTTP handlers.
If you're interested in learning more, check out our guide to production logging with Zerolog.
Uber's Zap librarywas a trailblazer in the
reflection-free, zero-allocation logging approach that Zerolog later adopted. It
also offers a more flexible, loosely typed API suitable for situations where
ergonomics and adaptability take precedence over performance and memory
allocations. The less verbose API (zap.SugaredLogger
) accommodates both
structured and string formatted logs, while the base zap.Logger
type defaults
to supports only structured logging. The good news is that you don't have to
pick one or the other throughout your codebase. You can use both and convert
between the two freely at any time.
package main
import (
"fmt"
"time"
"go.uber.org/zap"
)
func main() {
// returns zap.Logger, a strongly typed logging API
logger, _ := zap.NewProduction()
start := time.Now()
logger.Info("Hello from zap Logger",
zap.String("name", "John"),
zap.Int("age", 9),
zap.String("email", "[email protected]"),
)
// convert zap.Logger to zap.SugaredLogger for a more flexible and loose API
// that's still faster than most other structured logging implementations
sugar := logger.Sugar()
sugar.Warnf("something bad is about to happen")
sugar.Errorw("something bad happened",
"error", fmt.Errorf("oh no!"),
)
"answer", 42,
// you can freely convert back to the base `zap.Logger` type at the boundaries
// of performance-sensitive operations.
logger = sugar.Desugar()
logger.Warn("the operation took longer than expected",
zap.Int64("time_taken_ms", time.Since(start).Milliseconds()),
)
}
{"level":"info","ts":1660252436.0265622,"caller":"random/main.go:16","msg":"Hello from zap Logger","name":"John","age":9,"email":"[email protected]"}
{"level":"warn","ts":1660252436.0271666,"caller":"random/main.go:24","msg":"something bad is about to happen"}
{"level":"error","ts":1660252436.0275867,"caller":"random/main.go:25","msg":"something bad happened","error":"oh no!","answer":42,"stacktrace":"main.main\n\t/home/ayo/dev/demo/random/main.go:25\nruntime.main\n\t/usr/local/go/src/runtime/proc.go:250"}
{"level":"warn","ts":1660252436.0280342,"caller":"random/main.go:33","msg":"the operation took longer than expected","time_taken_ms":1}
Unlike Zerolog, Zap does not provide a functioning global logger by default but
you can configure one yourself through its
ReplaceGlobals()
function. Another difference between the two is that Zap
does not support the TRACE
log level
at the time of writing, which may be a deal-breaker for some, although you can
try to
add one yourself
In Zap's favor, you can greatly customize its behavior by implementing the interfaces in the Zapcore package. For example, you can output your logs in a different format (like lgofmt), or transport them directly to a log aggregation and monitoring service like Logtail.
Logrus served as the go-to structured
logging framework for Go until it was eventually outperformed by Zap and
Zerolog. Its primary advantage is its API compatibility with the standard
library log
package, offering structured and leveled logging in JSON or
other formats.
package main
import (
"os"
"github.com/sirupsen/logrus"
)
func main() {
log := logrus.New()
log.Out = os.Stdout
// Log as JSON instead of the default ASCII formatter.
log.SetFormatter(&logrus.JSONFormatter{})
log.WithFields(logrus.Fields{
"player": "haaland",
"goals": "40",
}).Info("Hello from Logrus!")
}
{"goals":"40","level":"info","msg":"Hello from Logrus!","player":"haaland","time":"2023-03-15T16:47:49+01:00"}
Presently, Logrus is in maintenance mode, meaning that no new features will be added. However, it will still receive updates for security, bug fixes, and performance enhancements where feasible.
As you can see, there are already several structured logging solutions in the Go
ecosystem. However, this wide range of APIs can make it difficult to support
logging in a provider-agnostic manner, often necessitating the use of
abstractions to avoid coupling the logging implementation to a specific package.
The slog
proposal also addresses this issue by providing a common interface in
the standard library that can be implemented by these third-party packages. With
such set up in place, you'll be able to switch between implementations as
necessary, and thus thus the burden of supporting diverse logging packages is
eliminated.
We hope this post has provided you with an understanding of the slog
package
proposal, including its objectives and potential benefits. If you want to
explore this topic further, I recommend checking out the proposal here and
additional discussions here.
Thanks for reading, and happy logging!