Logging and Observability
Logging and Observability
The standard logger for new Go is log/slog. The boring default is a TextHandler on a developer machine and a JSONHandler in a service, with levels and attributes instead of interpolated sentences. fmt.Println is for examples. It is not a log.
Mental model
A handler writes records. A logger holds a handler plus default attributes. slog.Info, slog.Warn, slog.Error, slog.Debug are the levels you use in application code. Debug is silent unless the handler’s level includes it.
Attributes are key-value pairs: slog.Int("id", 7), slog.String("window", "A"). They survive JSON. A sentence like "printed ticket 7 at table 12" does not query well.
slog.New(handler) then logger.Info(...). logger.With(...) returns a child with extra attributes on every line (the window name, the request id).
This chapter strips timestamps with ReplaceAttr so the printed output is stable. Production logs keep time. Do not copy the strip into a service.
Worked examples
Case 1: Text handler
Save as slog_text.go.
// slog_text.go
package main
import (
"log/slog"
"os"
)
func noTime(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.TimeKey {
return slog.Attr{}
}
return a
}
func main() {
h := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime})
log := slog.New(h)
log.Info("ticket printed", slog.Int("id", 7), slog.Int("table", 12))
}Run:
go run slog_text.goOutput:
level=INFO msg="ticket printed" id=7 table=12
Keys are stable. The message is a short event name, not a paragraph.
Case 2: JSON handler
Save as slog_json.go. Same record, machine-shaped.
// slog_json.go
package main
import (
"log/slog"
"os"
)
func noTime(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.TimeKey {
return slog.Attr{}
}
return a
}
func main() {
h := slog.NewJSONHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime})
log := slog.New(h)
log.Info("ticket printed", slog.Int("id", 7), slog.Int("table", 12))
}Run:
go run slog_json.goOutput:
{"level":"INFO","msg":"ticket printed","id":7,"table":12}
Ship this shape to a collector. Do not wrap it in another JSON envelope.
Case 3: Levels
Save as slog_level.go. Debug is off. Info is on. Error is on.
// slog_level.go
package main
import (
"log/slog"
"os"
)
func noTime(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.TimeKey {
return slog.Attr{}
}
return a
}
func main() {
h := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{
Level: slog.LevelInfo,
ReplaceAttr: noTime,
})
log := slog.New(h)
log.Debug("prep detail", slog.Int("id", 7))
log.Info("ticket printed", slog.Int("id", 7))
log.Error("kitchen closed", slog.Int("table", 12))
}Run:
go run slog_level.goOutput:
level=INFO msg="ticket printed" id=7
level=ERROR msg="kitchen closed" table=12
Set Level: slog.LevelDebug when you are on the desk debugging. Leave Info in production unless you have a reason. Error is for failures that already have an error value — add slog.Any("err", err).
Case 4: With attributes
Save as slog_with.go. The window name is on every line without repeating it.
// slog_with.go
package main
import (
"log/slog"
"os"
)
func noTime(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.TimeKey {
return slog.Attr{}
}
return a
}
func main() {
h := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime})
log := slog.New(h).With(slog.String("window", "A"))
log.Info("clocked in")
log.Info("ticket printed", slog.Int("id", 7))
}Run:
go run slog_with.goOutput:
level=INFO msg="clocked in" window=A
level=INFO msg="ticket printed" window=A id=7
Bind request-scoped fields with With at the start of a handler. Do not use context.Value as your log bag.
Case 5: Default logger
Save as slog_default.go. slog.SetDefault makes package-level slog.Info use your handler.
// slog_default.go
package main
import (
"log/slog"
"os"
)
func noTime(_ []string, a slog.Attr) slog.Attr {
if a.Key == slog.TimeKey {
return slog.Attr{}
}
return a
}
func main() {
h := slog.NewTextHandler(os.Stdout, &slog.HandlerOptions{ReplaceAttr: noTime})
slog.SetDefault(slog.New(h))
slog.Info("desk open", slog.Int("tables", 12))
}Run:
go run slog_default.goOutput:
level=INFO msg="desk open" tables=12
Call SetDefault once in main. Libraries should accept a *slog.Logger argument instead of assuming the default.
The trap
Save as println_log.go. This looks like logging and is not.
// println_log.go
package main
import "fmt"
func main() {
id := 7
table := 12
fmt.Println("printed ticket", id, "at table", table)
}Run:
go run println_log.goOutput:
printed ticket 7 at table 12
No level, no keys, no timestamp, no way to filter “table 12” without grepping English. The log package (log.Printf) is the old standard library logger. It is still in the tree. New code in this book uses slog.
A second trap: logging err.Error() as the message and dropping the error value. Prefer log.Error("kitchen closed", slog.Any("err", err)) so handlers can keep the type.
The boring rule
log/slogis the default. Text locally, JSON in services.- Event name in
msg. Facts in attributes. - Levels: Debug off in production, Info for normal events, Error for failures.
Withfor fields that apply to a whole call.- Keep timestamps in real logs. Strip them only in book listings and in tests that compare strings.
- Do not
fmt.Printlnin library or server code to “log.”
Try this
- In
slog_level.go, setLevel: slog.LevelDebugand confirm the prep line appears. - In
slog_json.go, addslog.String("note", "no onions"). Confirm a new JSON key. - In
slog_with.go, createlog.With(slog.Int("id", 7))and callInfo("printed"). The id should be on the line. - Change
noTimeso it also dropsslog.LevelKey. Runslog_text.go. See thatlevel=INFOdisappears — then put the level back. You want it.