Proposal: Structured Logging

Author: Jonathan Amsterdam

Date: 2022-10-19

Issue: https://go.dev/issue/56345

Discussion: https://github.com/golang/go/discussions/54763

Preliminary implementation: https://go.googlesource.com/exp/+/refs/heads/master/slog

Package documentation: https://pkg.go.dev/golang.org/x/exp/slog

We propose adding structured logging with levels to the standard library, to reside in a new package with import path log/slog.

Structured logging is the ability to output logs with machine-readable structure, typically key-value pairs, in addition to a human-readable message. Structured logs can be parsed, filtered, searched and analyzed faster and more reliably than logs designed only for people to read. For many programs that aren't run directly by a user, like servers, logging is the main way for developers to observe the detailed behavior of the system, and often the first place they go to debug it. Logs therefore tend to be voluminous, and the ability to search and filter them quickly is essential.

In theory, one can produce structured logs with any logging package:

log.Printf(`{"message": %q, "count": %d}`, msg, count)

In practice, this is too tedious and error-prone, so structured logging packages provide an API for expressing key-value pairs. This proposal contains such an API.

We also propose generalizing the logging "backend." The log package provides control only over the io.Writer that logs are written to. In the new package, every logger has a handler that can process a log event however it wishes. Although it is possible to have a structured logger with a fixed backend (for instance, [zerolog] outputs only JSON), having a flexible backend provides several benefits: programs can display the logs in a variety of formats, convert them to an RPC message for a network logging service, store them for later processing, and add to or modify the data.

Lastly, the design incorporates levels in a way that accommodates both traditional named levels and [logr]-style verbosities.

The goals of this design are:

• Ease of use. A survey of the existing logging packages shows that programmers want an API that is light on the page and easy to understand. This proposal adopts the most popular way to express key-value pairs: alternating keys and values.

• High performance. The API has been designed to minimize allocation and locking. It provides an alternative to alternating keys and values that is more cumbersome but faster (similar to [Zap]'s Fields).

• Integration with runtime tracing. The Go team is developing an improved runtime tracing system. Logs from this package will be incorporated seamlessly into those traces, giving developers the ability to correlate their program's actions with the behavior of the runtime.

§ What does success look like?

Go has many popular structured logging packages, all good at what they do. We do not expect developers to rewrite their existing third-party structured logging code to use this new package. We expect existing logging packages to coexist with this one for the foreseeable future.

We have tried to provide an API that is pleasant enough that users will prefer it to existing packages in new code, if only to avoid a dependency. (Some developers may find the runtime tracing integration compelling.) We also expect newcomers to Go to encounter this package before learning third-party packages, so they will likely be most familiar with it.

But more important than any traction gained by the "frontend" is the promise of a common "backend." An application with many dependencies may find that it has linked in many logging packages. When all the logging packages support the standard handler interface proposed here, then the application can create a single handler and install it once for each logging library to get consistent logging across all its dependencies. Since this happens in the application's main function, the benefits of a unified backend can be obtained with minimal code churn. We expect that this proposal's handlers will be implemented for all popular logging formats and network protocols, and that every common logging framework will provide a shim from their own backend to a handler. Then the Go logging community can work together to build high-quality backends that all can share.

§ Prior Work

The existing log package has been in the standard library since the release of Go 1 in March 2012. It provides formatted logging, but not structured logging or levels.

Logrus, one of the first structured logging packages, showed how an API could add structure while preserving the formatted printing of the log package. It uses maps to hold key-value pairs, which is relatively inefficient.

[Zap] grew out of Uber's frustration with the slow log times of their high-performance servers. It showed how a logger that avoided allocations could be very fast.

[Zerolog] reduced allocations even further, but at the cost of reducing the flexibility of the logging backend.

All the above loggers include named levels along with key-value pairs. [Logr] and Google's own [glog] use integer verbosities instead of named levels, providing a more fine-grained approach to filtering high-detail logs.

Other popular logging packages are Go-kit's log, HashiCorp's [hclog], and klog.

§ Design

Overview

Here is a short program that uses some of the new API:

import "log/slog"

func main() {
    slog.SetDefault(slog.New(slog.NewTextHandler(os.Stderr)))
    slog.Info("hello", "name", "Al")
    slog.Error("oops", "err", net.ErrClosed, "status", 500)
    slog.LogAttrs(slog.LevelError, "oops",
        slog.Any("err", net.ErrClosed), slog.Int("status", 500))
}

This program generates the following output on standard error:

time=2022-10-24T16:05:48.054-04:00 level=INFO msg=hello name=Al
time=2022-10-24T16:05:48.054-04:00 level=ERROR err="use of closed network connection" msg=oops status=500
time=2022-10-24T16:05:48.054-04:00 level=ERROR err="use of closed network connection" msg=oops status=500

It begins by setting the default logger to one that writes log records in an easy-to-read format similar to [logfmt]. (There is also a built-in handler for JSON.)

If the slog.SetDefault line is omitted, the output is sent to the standard log package, producing mostly structured output:

2022/10/24 16:07:00 INFO hello name=Al
2022/10/24 16:07:00 ERROR oops err="use of closed network connection" status=500
2022/10/24 16:07:00 ERROR oops  err="use of closed network connection" status=500

The program outputs three log messages augmented with key-value pairs. The first logs at the Info level, passing a single key-value pair along with the message. The second logs at the Error level, passing two key-value pairs.

The third produces the same output as the second, but more efficiently. Functions like Any and Int construct slog.Attr values, which are key-value pairs that avoid memory allocation for most values.

Main Types

The slog package contains three main types:

• Logger is the frontend, providing output methods like Info and LogAttrs that developers call to produce logs.

• Each call to a Logger output method creates a Record.

• The Record is passed to a Handler for output.

We cover these bottom-up, beginning with Handler.

Handlers

A Handler describes the logging backend. It handles log records produced by a Logger.

A typical handler may print log records to standard error, or write them to a file, database or network service, or perhaps augment them with additional attributes and pass them on to another handler.

type Handler interface {
	// Enabled reports whether the handler handles records at the given level.
	// The handler ignores records whose level is lower.
	// It is called early, before any arguments are processed,
	// to save effort if the log event should be discarded.
	// The Logger's context is passed so Enabled can use its values
	// to make a decision. The context may be nil.
	Enabled(context.Context, Level) bool

	// Handle handles the Record.
	// It will only be called if Enabled returns true.
	//
	// The first argument is the context of the Logger that created the Record,
	// which may be nil.
	// It is present solely to provide Handlers access to the context's values.
	// Canceling the context should not affect record processing.
	// (Among other things, log messages may be necessary to debug a
	// cancellation-related problem.)
	//
	// Handle methods that produce output should observe the following rules:
	//   - If r.Time is the zero time, ignore the time.
	//   - If an Attr's key is the empty string and the value is not a group,
	//     ignore the Attr.
	//   - If a group's key is empty, inline the group's Attrs.
	//   - If a group has no Attrs (even if it has a non-empty key),
	//     ignore it.
	Handle(ctx context.Context, r Record) error

	// WithAttrs returns a new Handler whose attributes consist of
	// both the receiver's attributes and the arguments.
	// The Handler owns the slice: it may retain, modify or discard it.
	WithAttrs(attrs []Attr) Handler

	// WithGroup returns a new Handler with the given group appended to
	// the receiver's existing groups.
	// The keys of all subsequent attributes, whether added by With or in a
	// Record, should be qualified by the sequence of group names.
	//
	// How this qualification happens is up to the Handler, so long as
	// this Handler's attribute keys differ from those of another Handler
	// with a different sequence of group names.
	//
	// A Handler should treat WithGroup as starting a Group of Attrs that ends
	// at the end of the log event. That is,
	//
	//     logger.WithGroup("s").LogAttrs(level, msg, slog.Int("a", 1), slog.Int("b", 2))
	//
	// should behave like
	//
	//     logger.LogAttrs(level, msg, slog.Group("s", slog.Int("a", 1), slog.Int("b", 2)))
	//
	// If the name is empty, WithGroup returns the receiver.
	WithGroup(name string) Handler
}

The slog package provides two handlers, one for simple textual output and one for JSON. They are described in more detail below.

The Record Type

A Record holds information about a log event.

type Record struct {
	// The time at which the output method (Log, Info, etc.) was called.
	Time time.Time

	// The log message.
	Message string

	// The level of the event.
	Level Level

	// The program counter at the time the record was constructed, as determined
	// by runtime.Callers. If zero, no program counter is available.
	//
	// The only valid use for this value is as an argument to
	// [runtime.CallersFrames]. In particular, it must not be passed to
	// [runtime.FuncForPC].
	PC uintptr

	// Has unexported fields.
}

Records have two methods for accessing the sequence of Attrs. This API allows an efficient implementation of the Attr sequence that avoids copying and minimizes allocation.

func (r Record) Attrs(f func(Attr))
    Attrs calls f on each Attr in the Record.

func (r Record) NumAttrs() int
    NumAttrs returns the number of attributes in the Record.

So that other logging backends can wrap Handlers, it is possible to construct a Record directly and add attributes to it:

func NewRecord(t time.Time, level Level, msg string, pc uintptr) Record
    NewRecord creates a Record from the given arguments. Use Record.AddAttrs to
    add attributes to the Record.

    NewRecord is intended for logging APIs that want to support a Handler as a
    backend.

func (r *Record) AddAttrs(attrs ...Attr)
    AddAttrs appends the given Attrs to the Record's list of Attrs. It resolves
    the Attrs before doing so.

func (r *Record) Add(args ...any)
    Add converts the args to Attrs as described in Logger.Log, then appends the
    Attrs to the Record's list of Attrs. It resolves the Attrs before doing so.

Copies of a Record share state. A Record should not be modified after handing out a copy to it. Use Clone for that:

func (r Record) Clone() Record
    Clone returns a copy of the record with no shared state. The original record
    and the clone can both be modified without interfering with each other.

The Attr and Value Types

An Attr is a key-value pair.

type Attr struct {
	Key   string
	Value Value
}

There are convenience functions for constructing Attrs with various value types, as well as Equal and String methods.

func Any(key string, value any) Attr
    Any returns an Attr for the supplied value. See Value.AnyValue for how
    values are treated.

func Bool(key string, v bool) Attr
    Bool returns an Attr for a bool.

func Duration(key string, v time.Duration) Attr
    Duration returns an Attr for a time.Duration.

func Float64(key string, v float64) Attr
    Float64 returns an Attr for a floating-point number.

func Group(key string, as ...Attr) Attr
    Group returns an Attr for a Group Value. The caller must not subsequently
    mutate the argument slice.

    Use Group to collect several Attrs under a single key on a log line, or as
    the result of LogValue in order to log a single value as multiple Attrs.

func Int(key string, value int) Attr
    Int converts an int to an int64 and returns an Attr with that value.

func Int64(key string, value int64) Attr
    Int64 returns an Attr for an int64.

func String(key, value string) Attr
    String returns an Attr for a string value.

func Time(key string, v time.Time) Attr
    Time returns an Attr for a time.Time. It discards the monotonic portion.

func Uint64(key string, v uint64) Attr
    Uint64 returns an Attr for a uint64.

func (a Attr) Equal(b Attr) bool
    Equal reports whether a and b have equal keys and values.

func (a Attr) String() string

A Value can represent any Go value, but unlike type any, it can represent most small values without an allocation. In particular, integer types and strings, which account for the vast majority of values in log messages, do not require allocation. The default version of Value uses package unsafe to store any value in three machine words. The version without unsafe requires five.

There are constructor functions for common types, and a general one, AnyValue, that dispatches on its argument type.

type Value struct {
	// Has unexported fields.
}

func AnyValue(v any) Value
    AnyValue returns a Value for the supplied value.

    Given a value of one of Go's predeclared string, bool, or (non-complex)
    numeric types, AnyValue returns a Value of kind String, Bool, Uint64, Int64,
    or Float64. The width of the original numeric type is not preserved.

    Given a time.Time or time.Duration value, AnyValue returns a Value of kind
    TimeKind or DurationKind. The monotonic time is not preserved.

    For nil, or values of all other types, including named types whose
    underlying type is numeric, AnyValue returns a value of kind AnyKind.

func BoolValue(v bool) Value
    BoolValue returns a Value for a bool.

func DurationValue(v time.Duration) Value
    DurationValue returns a Value for a time.Duration.

func Float64Value(v float64) Value
    Float64Value returns a Value for a floating-point number.

func GroupValue(as ...Attr) Value
    GroupValue returns a new Value for a list of Attrs. The caller must not
    subsequently mutate the argument slice.

func Int64Value(v int64) Value
    Int64Value returns a Value for an int64.

func IntValue(v int) Value
    IntValue returns a Value for an int.

func StringValue(value string) Value
    String returns a new Value for a string.

func TimeValue(v time.Time) Value
    TimeValue returns a Value for a time.Time. It discards the monotonic
    portion.

func Uint64Value(v uint64) Value
    Uint64Value returns a Value for a uint64.

Extracting Go values from a Value is reminiscent of reflect.Value: there is a Kind method that returns an enum of type Kind, and a method for each Kind that returns the value or panics if it is the wrong kind.

type Kind int
    Kind is the kind of a Value.

const (
	AnyKind Kind = iota
	BoolKind
	DurationKind
	Float64Kind
	Int64Kind
	StringKind
	TimeKind
	Uint64Kind
	GroupKind
	LogValuerKind
)

func (v Value) Any() any
    Any returns v's value as an any.

func (v Value) Bool() bool
    Bool returns v's value as a bool. It panics if v is not a bool.

func (a Value) Duration() time.Duration
    Duration returns v's value as a time.Duration. It panics if v is not a
    time.Duration.

func (v Value) Equal(w Value) bool
    Equal reports whether v and w have equal keys and values.

func (v Value) Float64() float64
    Float64 returns v's value as a float64. It panics if v is not a float64.

func (v Value) Group() []Attr
    Group returns v's value as a []Attr. It panics if v's Kind is not GroupKind.

func (v Value) Int64() int64
    Int64 returns v's value as an int64. It panics if v is not a signed integer.

func (v Value) Kind() Kind
    Kind returns v's Kind.

func (v Value) LogValuer() LogValuer
    LogValuer returns v's value as a LogValuer. It panics if v is not a
    LogValuer.

func (v Value) Resolve() Value
    Resolve repeatedly calls LogValue on v while it implements LogValuer, and
    returns the result. If the number of LogValue calls exceeds a threshold, a
    Value containing an error is returned. Resolve's return value is guaranteed
    not to be of Kind LogValuerKind.

func (v Value) String() string
    String returns Value's value as a string, formatted like fmt.Sprint.
    Unlike the methods Int64, Float64, and so on, which panic if v is of the
    wrong kind, String never panics.

func (v Value) Time() time.Time
    Time returns v's value as a time.Time. It panics if v is not a time.Time.

func (v Value) Uint64() uint64
    Uint64 returns v's value as a uint64. It panics if v is not an unsigned
    integer.

The LogValuer interface

A LogValuer is any Go value that can convert itself into a Value for logging.

This mechanism may be used to defer expensive operations until they are needed, or to expand a single value into a sequence of components.

type LogValuer interface {
	LogValue() Value
}

Value.Resolve can be used to call the LogValue method.

func (v Value) Resolve() Value
    Resolve repeatedly calls LogValue on v while it implements LogValuer, and
    returns the result. If the number of LogValue calls exceeds a threshold, a
    Value containing an error is returned. Resolve's return value is guaranteed
    not to be of Kind LogValuerKind.

The Attrs passed to a Handler.WithAttrs, and the Attrs obtained via Record.Attrs, have already been resolved, that is, replaced with a call to Resolve.

As an example of LogValuer, a type could obscure its value in log output like so:

type Password string

func (p Password) LogValue() slog.Value {
    return slog.StringValue("REDACTED")
}

Loggers

A Logger records structured information about each call to its Log, Debug, Info, Warn, and Error methods. For each call, it creates a Record and passes it to a Handler.

type Logger struct {
	// Has unexported fields.
}

A Logger consists of a Handler. Use New to create Logger with a Handler, and the Handler method to retrieve it.

func New(h Handler) *Logger
    New creates a new Logger with the given Handler.

func (l *Logger) Handler() Handler
    Handler returns l's Handler.

There is a single, global default Logger. It can be set and retrieved with the SetDefault and Default functions.

func SetDefault(l *Logger)
    SetDefault makes l the default Logger. After this call, output from the
    log package's default Logger (as with log.Print, etc.) will be logged at
    LevelInfo using l's Handler.

func Default() *Logger
    Default returns t