// Copyright 2023 The Go Authors. All rights reserved. // Use of this source code is governed by a BSD-style // license that can be found in the LICENSE file. // Package slogtest implements support for testing implementations of log/slog.Handler. package slogtest import ( "context" "errors" "fmt" "log/slog" "reflect" "runtime" "testing" "time" ) type testCase struct { // Subtest name. name string // If non-empty, explanation explains the violated constraint. explanation string // f executes a single log event using its argument logger. // So that mkdescs.sh can generate the right description, // the body of f must appear on a single line whose first // non-whitespace characters are "l.". f func(*slog.Logger) // If mod is not nil, it is called to modify the Record // generated by the Logger before it is passed to the Handler. mod func(*slog.Record) // checks is a list of checks to run on the result. checks []check } var cases = []testCase{ { name: "built-ins", explanation: withSource("this test expects slog.TimeKey, slog.LevelKey and slog.MessageKey"), f: func(l *slog.Logger) { l.Info("message") }, checks: []check{ hasKey(slog.TimeKey), hasKey(slog.LevelKey), hasAttr(slog.MessageKey, "message"), }, }, { name: "attrs", explanation: withSource("a Handler should output attributes passed to the logging function"), f: func(l *slog.Logger) { l.Info("message", "k", "v") }, checks: []check{ hasAttr("k", "v"), }, }, { name: "empty-attr", explanation: withSource("a Handler should ignore an empty Attr"), f: func(l *slog.Logger) { l.Info("msg", "a", "b", "", nil, "c", "d") }, checks: []check{ hasAttr("a", "b"), missingKey(""), hasAttr("c", "d"), }, }, { name: "zero-time", explanation: withSource("a Handler should ignore a zero Record.Time"), f: func(l *slog.Logger) { l.Info("msg", "k", "v") }, mod: func(r *slog.Record) { r.Time = time.Time{} }, checks: []check{ missingKey(slog.TimeKey), }, }, { name: "WithAttrs", explanation: withSource("a Handler should include the attributes from the WithAttrs method"), f: func(l *slog.Logger) { l.With("a", "b").Info("msg", "k", "v") }, checks: []check{ hasAttr("a", "b"), hasAttr("k", "v"), }, }, { name: "groups", explanation: withSource("a Handler should handle Group attributes"), f: func(l *slog.Logger) { l.Info("msg", "a", "b", slog.Group("G", slog.String("c", "d")), "e", "f") }, checks: []check{ hasAttr("a", "b"), inGroup("G", hasAttr("c", "d")), hasAttr("e", "f"), }, }, { name: "empty-group", explanation: withSource("a Handler should ignore an empty group"), f: func(l *slog.Logger) { l.Info("msg", "a", "b", slog.Group("G"), "e", "f") }, checks: []check{ hasAttr("a", "b"), missingKey("G"), hasAttr("e", "f"), }, }, { name: "inline-group", explanation: withSource("a Handler should inline the Attrs of a group with an empty key"), f: func(l *slog.Logger) { l.Info("msg", "a", "b", slog.Group("", slog.String("c", "d")), "e", "f") }, checks: []check{ hasAttr("a", "b"), hasAttr("c", "d"), hasAttr("e", "f"), }, }, { name: "WithGroup", explanation: withSource("a Handler should handle the WithGroup method"), f: func(l *slog.Logger) { l.WithGroup("G").Info("msg", "a", "b") }, checks: []check{ hasKey(slog.TimeKey), hasKey(slog.LevelKey), hasAttr(slog.MessageKey, "msg"), missingKey("a"), inGroup("G", hasAttr("a", "b")), }, }, { name: "multi-With", explanation: withSource("a Handler should handle multiple WithGroup and WithAttr calls"), f: func(l *slog.Logger) { l.With("a", "b").WithGroup("G").With("c", "d").WithGroup("H").Info("msg", "e", "f") }, checks: []check{ hasKey(slog.TimeKey), hasKey(slog.LevelKey), hasAttr(slog.MessageKey, "msg"), hasAttr("a", "b"), inGroup("G", hasAttr("c", "d")), inGroup("G", inGroup("H", hasAttr("e", "f"))), }, }, { name: "empty-group-record", explanation: withSource("a Handler should not output groups if there are no attributes"), f: func(l *slog.Logger) { l.With("a", "b").WithGroup("G").With("c", "d").WithGroup("H").Info("msg") }, checks: []check{ hasKey(slog.TimeKey), hasKey(slog.LevelKey), hasAttr(slog.MessageKey, "msg"), hasAttr("a", "b"), inGroup("G", hasAttr("c", "d")), inGroup("G", missingKey("H")), }, }, { name: "resolve", explanation: withSource("a Handler should call Resolve on attribute values"), f: func(l *slog.Logger) { l.Info("msg", "k", &replace{"replaced"}) }, checks: []check{hasAttr("k", "replaced")}, }, { name: "resolve-groups", explanation: withSource("a Handler should call Resolve on attribute values in groups"), f: func(l *slog.Logger) { l.Info("msg", slog.Group("G", slog.String("a", "v1"), slog.Any("b", &replace{"v2"}))) }, checks: []check{ inGroup("G", hasAttr("a", "v1")), inGroup("G", hasAttr("b", "v2")), }, }, { name: "resolve-WithAttrs", explanation: withSource("a Handler should call Resolve on attribute values from WithAttrs"), f: func(l *slog.Logger) { l = l.With("k", &replace{"replaced"}) l.Info("msg") }, checks: []check{hasAttr("k", "replaced")}, }, { name: "resolve-WithAttrs-groups", explanation: withSource("a Handler should call Resolve on attribute values in groups from WithAttrs"), f: func(l *slog.Logger) { l = l.With(slog.Group("G", slog.String("a", "v1"), slog.Any("b", &replace{"v2"}))) l.Info("msg") }, checks: []check{ inGroup("G", hasAttr("a", "v1")), inGroup("G", hasAttr("b", "v2")), }, }, { name: "empty-PC", explanation: withSource("a Handler should not output SourceKey if the PC is zero"), f: func(l *slog.Logger) { l.Info("message") }, mod: func(r *slog.Record) { r.PC = 0 }, checks: []check{ missingKey(slog.SourceKey), }, }, } // TestHandler tests a [slog.Handler]. // If TestHandler finds any misbehaviors, it returns an error for each, // combined into a single error with [errors.Join]. // // TestHandler installs the given Handler in a [slog.Logger] and // makes several calls to the Logger's output methods. // The Handler should be enabled for levels Info and above. // // The results function is invoked after all such calls. // It should return a slice of map[string]any, one for each call to a Logger output method. // The keys and values of the map should correspond to the keys and values of the Handler's // output. Each group in the output should be represented as its own nested map[string]any. // The standard keys [slog.TimeKey], [slog.LevelKey] and [slog.MessageKey] should be used. // // If the Handler outputs JSON, then calling [encoding/json.Unmarshal] with a `map[string]any` // will create the right data structure. // // If a Handler intentionally drops an attribute that is checked by a test, // then the results function should check for its absence and add it to the map it returns. func TestHandler(h slog.Handler, results func() []map[string]any) error { // Run the handler on the test cases. for _, c := range cases { ht := h if c.mod != nil { ht = &wrapper{h, c.mod} } l := slog.New(ht) c.f(l) } // Collect and check the results. var errs []error res := results() if g, w := len(res), len(cases); g != w { return fmt.Errorf("got %d results, want %d", g, w) } for i, got := range res { c := cases[i] for _, check := range c.checks { if problem := check(got); problem != "" { errs = append(errs, fmt.Errorf("%s: %s", problem, c.explanation)) } } } return errors.Join(errs...) } // Run exercises a [slog.Handler] on the same test cases as [TestHandler], but // runs each case in a subtest. For each test case, it first calls newHandler to // get an instance of the handler under test, then runs the test case, then // calls result to get the result. If the test case fails, it calls t.Error. func Run(t *testing.T, newHandler func(*testing.T) slog.Handler, result func(*testing.T) map[string]any) { for _, c := range cases { t.Run(c.name, func(t *testing.T) { h := newHandler(t) if c.mod != nil { h = &wrapper{h, c.mod} } l := slog.New(h) c.f(l) got := result(t) for _, check := range c.checks { if p := check(got); p != "" { t.Errorf("%s: %s", p, c.explanation) } } }) } } type check func(map[string]any) string func hasKey(key string) check { return func(m map[string]any) string { if _, ok := m[key]; !ok { return fmt.Sprintf("missing key %q", key) } return "" } } func missingKey(key string) check { return func(m map[string]any) string { if _, ok := m[key]; ok { return fmt.Sprintf("unexpected key %q", key) } return "" } } func hasAttr(key string, wantVal any) check { return func(m map[string]any) string { if s := hasKey(key)(m); s != "" { return s } gotVal := m[key] if !reflect.DeepEqual(gotVal, wantVal) { return fmt.Sprintf("%q: got %#v, want %#v", key, gotVal, wantVal) } return "" } } func inGroup(name string, c check) check { return func(m map[string]any) string { v, ok := m[name] if !ok { return fmt.Sprintf("missing group %q", name) } g, ok := v.(map[string]any) if !ok { return fmt.Sprintf("value for group %q is not map[string]any", name) } return c(g) } } type wrapper struct { slog.Handler mod func(*slog.Record) } func (h *wrapper) Handle(ctx context.Context, r slog.Record) error { h.mod(&r) return h.Handler.Handle(ctx, r) } func withSource(s string) string { _, file, line, ok := runtime.Caller(1) if !ok { panic("runtime.Caller failed") } return fmt.Sprintf("%s (%s:%d)", s, file, line) } type replace struct { v any } func (r *replace) LogValue() slog.Value { return slog.AnyValue(r.v) } func (r *replace) String() string { return fmt.Sprintf("", r.v) }