Logging, the more lightweight cousin to tracing everything, and the formalized version of printf debugging.
Anyway, if you believe in structured logging, in Go, your logger interface should be logr.Logger:
1// github.com/go-logr/logr.Logger
2type Logger interface {
3 Enabled() bool
4 Info(msg string, keysAndValues ...interface{})
5 Error(err error, msg string, keysAndValues ...interface{})
6 V(level int) Logger
7 WithValues(keysAndValues ...interface{}) Logger
8 WithName(name string) Logger
9}
Now comes the problem: you annotate errors with context, usually with something like:
1return fmt.Errorf("something went wrong foo=%q bar=%q: %w", hello, world, err)
But this doesn't fit well with structured logging, you want the key-values to be independent, not stuffed and escaped as a string in the error key.
So what can you do?
Since you already pass context.Context everywhere (you do, right?)
you might as well use it to smuggle data, ex using ctxdata
1func ExampleCtxdata(l logr.Logger) {
2 ctx := context.Background()
3 ctx, data := ctxdata.New(ctx)
4
5 err := ctxdataMid1(ctx)
6 if err != nil {
7 for _, kv := range data.GetAllSlice() {
8 l = l.WithValues(kv.Key, kv.Val)
9 }
10 l.Error(err, "some message", "example", "ctxerr")
11 }
12}
13
14func ctxdataMid1(ctx context.Context) error {
15 err := ctxdataMid2(ctx)
16 if err != nil {
17 data := ctxdata.From(ctx)
18 data.Set("mid1", "midLevel")
19 data.Set("repeated", "ctxdataMid1")
20 return err
21 }
22 return nil
23}
24
25func ctxdataMid2(ctx context.Context) error {
26 err := ctxdataDeep(ctx)
27 if err != nil {
28 return fmt.Errorf("unexpected: %w", err)
29 }
30 return nil
31}
32
33func ctxdataDeep(ctx context.Context) error {
34 data := ctxdata.From(ctx)
35 data.Set("deep", "value")
36 data.Set("repeated", "ctxdataDeep")
37 return errors.New("oops")
38}
39
results in something like: (using klogr as the logger implementation).
1E0411 11:42:37.052899 25625 ctxdata.go:21] "msg"="some message" "error"="unexpected: oops" "deep"="value" "mid1"="midLevel" "repeated"="ctxdataMid1" "example"="ctxerr"
Alternatively, you can use a custom error type that knows how to store errors:
1package sterr
2
3import "errors"
4
5type keyValuer interface {
6 KeyValues() []interface{}
7}
8
9type structuredError struct {
10 err error
11 kvs []interface{}
12}
13
14func (e *structuredError) Error() string {
15 return e.err.Error()
16}
17
18func (e *structuredError) KeyValues() []interface{} {
19 // alternatively make this smarter and do unwrapping here
20 // to support errors.As properly
21 return e.kvs
22}
23
24func (e *structuredError) Unwrap() error {
25 return e.err
26}
27
28func New(err error, keysAndValues ...interface{}) error {
29 return &structuredError{
30 err,
31 keysAndValues,
32 }
33}
34
35func FindKeyValues(err error) []interface{} {
36 var kvs []interface{}
37 if kverr, ok := err.(keyValuer); ok {
38 kvs = append(kvs, kverr.KeyValues()...)
39 }
40 for err = errors.Unwrap(err); err != nil; err = errors.Unwrap(err) {
41 if kverr, ok := err.(keyValuer); ok {
42 kvs = append(kvs, kverr.KeyValues()...)
43 }
44 }
45 return kvs
46}
and use it:
1func ExampleSterr(l logr.Logger) {
2 err := sterrMid1()
3 if err != nil {
4 l.WithValues(sterr.FindKeyValues(err)...).Error(err, "some message", "example", "sterr")
5 }
6}
7
8func sterrMid1() error {
9 err := sterrMid2()
10 if err != nil {
11 return sterr.New(err, "mid1", "midlevel", "repeated", "sterrMid1")
12 }
13 return nil
14}
15
16func sterrMid2() error {
17 err := sterrDeep()
18 if err != nil {
19 return fmt.Errorf("unexpected: %w", err)
20 }
21 return nil
22}
23
24func sterrDeep() error {
25 return sterr.New(errors.New("oops"), "deep", "value", "repeated", "sterrDeep")
26}
result, note the difference in repeated keys:
1E0411 11:42:37.052779 25625 sterr.go:14] "msg"="some message" "error"="unexpected: oops" "deep"="value" "mid1"="midlevel" "repeated"="sterrDeep" "example"="sterr"