From a742ae493ff59a71131706500ce53f85477897f0 Mon Sep 17 00:00:00 2001 From: Jonathan Amsterdam Date: Fri, 4 Aug 2023 13:33:35 -0400 Subject: [PATCH] testing/slogtest: add Run to run cases as subtests This is an implementation of proposal #61758. It adds a function to slogtest that runs each test case in a subtest, instead of running them all at once. That allows the caller to control which cases are run. Fixes #61706. Fixes #61758. Change-Id: I95108b7b753675203ca7f0f00ccbc242bd9c2a9f Reviewed-on: https://go-review.googlesource.com/c/go/+/516076 Reviewed-by: Alan Donovan TryBot-Result: Gopher Robot Run-TryBot: Jonathan Amsterdam --- api/next/61758.txt | 1 + src/go/build/deps_test.go | 6 +- src/testing/slogtest/run_test.go | 31 +++ src/testing/slogtest/slogtest.go | 385 +++++++++++++++++-------------- 4 files changed, 248 insertions(+), 175 deletions(-) create mode 100644 api/next/61758.txt create mode 100644 src/testing/slogtest/run_test.go diff --git a/api/next/61758.txt b/api/next/61758.txt new file mode 100644 index 0000000000000..35bd2249655ae --- /dev/null +++ b/api/next/61758.txt @@ -0,0 +1 @@ +pkg testing/slogtest, func Run(*testing.T, func(*testing.T) slog.Handler, func(*testing.T) map[string]interface{}) #61758 diff --git a/src/go/build/deps_test.go b/src/go/build/deps_test.go index 2388b3b8ad5f3..ca0c4089a2e50 100644 --- a/src/go/build/deps_test.go +++ b/src/go/build/deps_test.go @@ -572,15 +572,15 @@ var depsRules = ` < testing/iotest < testing/fstest; - log/slog - < testing/slogtest; - FMT, flag, math/rand < testing/quick; FMT, DEBUG, flag, runtime/trace, internal/sysinfo, math/rand < testing; + log/slog, testing + < testing/slogtest; + FMT, crypto/sha256, encoding/json, go/ast, go/parser, go/token, internal/godebug, math/rand, encoding/hex, crypto/sha256 < internal/fuzz; diff --git a/src/testing/slogtest/run_test.go b/src/testing/slogtest/run_test.go new file mode 100644 index 0000000000000..c82da10cc2774 --- /dev/null +++ b/src/testing/slogtest/run_test.go @@ -0,0 +1,31 @@ +// 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_test + +import ( + "bytes" + "encoding/json" + "log/slog" + "testing" + "testing/slogtest" +) + +func TestRun(t *testing.T) { + var buf bytes.Buffer + + newHandler := func(*testing.T) slog.Handler { + buf.Reset() + return slog.NewJSONHandler(&buf, nil) + } + result := func(t *testing.T) map[string]any { + m := map[string]any{} + if err := json.Unmarshal(buf.Bytes(), &m); err != nil { + t.Fatal(err) + } + return m + } + + slogtest.Run(t, newHandler, result) +} diff --git a/src/testing/slogtest/slogtest.go b/src/testing/slogtest/slogtest.go index 255d8bb9648bd..e60e8438d4972 100644 --- a/src/testing/slogtest/slogtest.go +++ b/src/testing/slogtest/slogtest.go @@ -12,10 +12,13 @@ import ( "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. @@ -30,6 +33,191 @@ type testCase struct { 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")), + }, + }, +} + // TestHandler tests a [slog.Handler]. // If TestHandler finds any misbehaviors, it returns an error for each, // combined into a single error with errors.Join. @@ -50,176 +238,6 @@ type testCase struct { // 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 { - cases := []testCase{ - { - 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"), - }, - }, - { - 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"), - }, - }, - { - 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"), - }, - }, - { - 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), - }, - }, - { - 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"), - }, - }, - { - 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"), - }, - }, - { - 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"), - }, - }, - { - 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"), - }, - }, - { - 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")), - }, - }, - { - 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"))), - }, - }, - { - 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")), - }, - }, - { - 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")}, - }, - { - 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")), - }, - }, - { - 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")}, - }, - { - 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")), - }, - }, - } - // Run the handler on the test cases. for _, c := range cases { ht := h @@ -239,14 +257,37 @@ func TestHandler(h slog.Handler, results func() []map[string]any) error { for i, got := range results() { c := cases[i] for _, check := range c.checks { - if p := check(got); p != "" { - errs = append(errs, fmt.Errorf("%s: %s", p, c.explanation)) + 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 {