How to log errors with `log/slog`

Question

The official docs show how to use the new structured logging package but seem to omit how to log errors.

https://pkg.go.dev/log/slog

package main

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

func demoFunction() error {
    return fmt.Errorf("oh no: %v", 123)
}

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

    slog.Info("info demo", "count", 3)
    slog.Warn("warn demo", slog.String("somekey", "somevalue"))
    slog.Error("error demo", slog.Int("someintkey", 123))
    err := demoFunction()
    if err != nil {
        // Here I'm logging the error as a string, but I presume there is a better way
        // possibly that will log stack trace info as well.
        slog.Error("the demo function got an error.", slog.String("error", err.Error()))
    }
}

Answer 1

Someone opened up a proposal and closed it. Thought is it ends up being unnecessary syntax sugar.

It appears some people have decided to wrap the slog.Any call

func ErrAttr(err error) slog.Attr {
    return slog.Any("error", err)
}

Answer 2

The ReplaceAttr callback of slog.HandlerOptions can be used for all sorts of customized attribute logging, including extracting stack traces from errors that provide them.

Here is an example for how you could log traces of errors from the github.com/pkg/errors package. The fmtErr and traceLines functions can be easily adapted for other stack trace implementations.

package main

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

    "github.com/pkg/errors"
)

func main() {
    handler := slog.NewJSONHandler(os.Stderr, &slog.HandlerOptions{
        ReplaceAttr: replaceAttr,
    })

    slog.SetDefault(slog.New(handler))

    if err := f(); err != nil {
        slog.Info("something went wrong", slog.Any("err", err))
    }
}

func f() error {
    return g()
}

func g() error {
    return errors.New("test error")
}

func replaceAttr(groups []string, a slog.Attr) slog.Attr {
    switch a.Value.Kind() {
    // other cases

    case slog.KindAny:
        switch v := a.Value.Any().(type) {
        case error:
            a.Value = fmtErr(v)
        }
    }

    return a
}

// fmtErr returns a slog.GroupValue with keys "msg" and "trace". If the error
// does not implement interface { StackTrace() errors.StackTrace }, the "trace"
// key is omitted.
func fmtErr(err error) slog.Value {
    var groupValues []slog.Attr

    groupValues = append(groupValues, slog.String("msg", err.Error()))

    type StackTracer interface {
        StackTrace() errors.StackTrace
    }

    // Find the trace to the location of the first errors.New,
    // errors.Wrap, or errors.WithStack call.
    var st StackTracer
    for err := err; err != nil; err = errors.Unwrap(err) {
        if x, ok := err.(StackTracer); ok {
            st = x
        }
    }

    if st != nil {
        groupValues = append(groupValues,
            slog.Any("trace", traceLines(st.StackTrace())),
        )
    }

    return slog.GroupValue(groupValues...)
}

func traceLines(frames errors.StackTrace) []string {
    traceLines := make([]string, len(frames))

    // Iterate in reverse to skip uninteresting, consecutive runtime frames at
    // the bottom of the trace.
    var skipped int
    skipping := true
    for i := len(frames) - 1; i >= 0; i-- {
        // Adapted from errors.Frame.MarshalText(), but avoiding repeated
        // calls to FuncForPC and FileLine.
        pc := uintptr(frames[i]) - 1
        fn := runtime.FuncForPC(pc)
        if fn == nil {
            traceLines[i] = "unknown"
            skipping = false
            continue
        }

        name := fn.Name()

        if skipping && strings.HasPrefix(name, "runtime.") {
            skipped++
            continue
        } else {
            skipping = false
        }

        filename, lineNr := fn.FileLine(pc)

        traceLines[i] = fmt.Sprintf("%s %s:%d", name, filename, lineNr)
    }

    return traceLines[:len(traceLines)-skipped]
}

Output (formatted for readability):

{
  "time": "2009-11-10T23:00:00Z",
  "level": "INFO",
  "msg": "something went wrong",
  "err": {
    "msg": "test error",
    "trace": [
      "main.g /tmp/sandbox1599816903/prog.go:30",
      "main.f /tmp/sandbox1599816903/prog.go:26",
      "main.main /tmp/sandbox1599816903/prog.go:20"
    ]
  }
}

Try it on the playground: https://go.dev/play/p/0yJNk065ftB