From 0dd6551a8c11337714e4c142e3c6582c34da8f1e Mon Sep 17 00:00:00 2001 From: Tim Hockin Date: Wed, 6 Dec 2023 09:33:32 -0800 Subject: [PATCH] Clean up slog testing and restore coverage --- logr_noslog_test.go | 23 ----- logr_slog_test.go | 218 ----------------------------------------- logr_test.go | 79 --------------- sloghandler.go | 45 +++++++-- slogr_test.go | 93 +++++++++++++++++- testimpls_slog_test.go | 140 ++++++++++++++++++++++++++ testimpls_test.go | 92 +++++++++++++++++ 7 files changed, 356 insertions(+), 334 deletions(-) delete mode 100644 logr_noslog_test.go delete mode 100644 logr_slog_test.go create mode 100644 testimpls_slog_test.go create mode 100644 testimpls_test.go diff --git a/logr_noslog_test.go b/logr_noslog_test.go deleted file mode 100644 index c449810..0000000 --- a/logr_noslog_test.go +++ /dev/null @@ -1,23 +0,0 @@ -//go:build !go1.21 -// +build !go1.21 - -/* -Copyright 2023 The logr Authors. - -Licensed under the Apache License, Version 2.0 (the "License"); -you may not use this file except in compliance with the License. -You may obtain a copy of the License at - - http://www.apache.org/licenses/LICENSE-2.0 - -Unless required by applicable law or agreed to in writing, software -distributed under the License is distributed on an "AS IS" BASIS, -WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -See the License for the specific language governing permissions and -limitations under the License. -*/ - -package logr - -//nolint:unused -type testSlogSink struct{} diff --git a/logr_slog_test.go b/logr_slog_test.go deleted file mode 100644 index 7712235..0000000 --- a/logr_slog_test.go +++ /dev/null @@ -1,218 +0,0 @@ -//go:build go1.21 -// +build go1.21 - -/* -Copyright 2023 The logr Authors. - -Licensed under the Apache License, Version 2.0 (the "License"); -you may not use this file except in compliance with the License. -You may obtain a copy of the License at - - http://www.apache.org/licenses/LICENSE-2.0 - -Unless required by applicable law or agreed to in writing, software -distributed under the License is distributed on an "AS IS" BASIS, -WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -See the License for the specific language governing permissions and -limitations under the License. -*/ - -package logr - -import ( - "bytes" - "context" - "log/slog" - "testing" - "time" -) - -var _ SlogSink = &testLogSink{} - -// testSlogSink gets embedded in testLogSink to add slog-specific fields -// which are only available when slog is supported by Go. -type testSlogSink struct { - attrs []slog.Attr - groups []string - - fnHandle func(l *testLogSink, ctx context.Context, record slog.Record) - fnWithAttrs func(l *testLogSink, attrs []slog.Attr) - fnWithGroup func(l *testLogSink, name string) -} - -func (l *testLogSink) Handle(ctx context.Context, record slog.Record) error { - if l.fnHandle != nil { - l.fnHandle(l, ctx, record) - } - return nil -} - -func (l *testLogSink) WithAttrs(attrs []slog.Attr) SlogSink { - if l.fnWithAttrs != nil { - l.fnWithAttrs(l, attrs) - } - out := *l - n := len(out.attrs) - out.attrs = append(out.attrs[:n:n], attrs...) - return &out -} - -func (l *testLogSink) WithGroup(name string) SlogSink { - if l.fnWithGroup != nil { - l.fnWithGroup(l, name) - } - out := *l - n := len(out.groups) - out.groups = append(out.groups[:n:n], name) - return &out -} - -func withAttrs(record slog.Record, attrs ...slog.Attr) slog.Record { - record = record.Clone() - record.AddAttrs(attrs...) - return record -} - -func toJSON(record slog.Record) string { - var buffer bytes.Buffer - record.Time = time.Time{} - handler := slog.NewJSONHandler(&buffer, nil) - if err := handler.Handle(context.Background(), record); err != nil { - return err.Error() - } - return buffer.String() -} - -func TestToSlogHandler(t *testing.T) { - lvlThreshold := 0 - actualCalledHandle := 0 - var actualRecord slog.Record - - sink := &testLogSink{} - logger := New(sink) - - sink.fnEnabled = func(lvl int) bool { - return lvl <= lvlThreshold - } - - sink.fnHandle = func(l *testLogSink, ctx context.Context, record slog.Record) { - actualCalledHandle++ - - // Combine attributes from sink and call. Ordering of WithValues and WithAttrs - // is wrong, but good enough for test cases. - var values slog.Record - values.Add(l.withValues...) - var attrs []any - add := func(attr slog.Attr) bool { - attrs = append(attrs, attr) - return true - } - values.Attrs(add) - record.Attrs(add) - for _, attr := range l.attrs { - attrs = append(attrs, attr) - } - - // Wrap them in groups - not quite correct for WithValues that - // follows WithGroup, but good enough for test cases. - for i := len(l.groups) - 1; i >= 0; i-- { - attrs = []any{slog.Group(l.groups[i], attrs...)} - } - - actualRecord = slog.Record{ - Level: record.Level, - Message: record.Message, - } - actualRecord.Add(attrs...) - } - - verify := func(t *testing.T, expectedRecord slog.Record) { - actual := toJSON(actualRecord) - expected := toJSON(expectedRecord) - if expected != actual { - t.Errorf("JSON dump did not match, expected:\n%s\nGot:\n%s\n", expected, actual) - } - } - - reset := func() { - lvlThreshold = 0 - actualCalledHandle = 0 - actualRecord = slog.Record{} - } - - testcases := map[string]struct { - run func() - expectedRecord slog.Record - }{ - "simple": { - func() { slog.New(ToSlogHandler(logger)).Info("simple") }, - slog.Record{Message: "simple"}, - }, - - "disabled": { - func() { slog.New(ToSlogHandler(logger.V(1))).Info("") }, - slog.Record{}, - }, - - "enabled": { - func() { - lvlThreshold = 1 - slog.New(ToSlogHandler(logger.V(1))).Info("enabled") - }, - slog.Record{Level: -1, Message: "enabled"}, - }, - - "error": { - func() { slog.New(ToSlogHandler(logger.V(100))).Error("error") }, - slog.Record{Level: slog.LevelError, Message: "error"}, - }, - - "with-parameters": { - func() { slog.New(ToSlogHandler(logger)).Info("", "answer", 42, "foo", "bar") }, - withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), - }, - - "with-values": { - func() { slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).Info("") }, - withAttrs(slog.Record{}, slog.Int("answer", 42), slog.String("foo", "bar")), - }, - - "with-group": { - func() { slog.New(ToSlogHandler(logger)).WithGroup("group").Info("", "answer", 42, "foo", "bar") }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-values-and-group": { - func() { - slog.New(ToSlogHandler(logger.WithValues("answer", 42, "foo", "bar"))).WithGroup("group").Info("") - }, - // Behavior of testLogSink is not quite correct here. - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-group-and-values": { - func() { - slog.New(ToSlogHandler(logger)).WithGroup("group").With("answer", 42, "foo", "bar").Info("") - }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - - "with-group-and-logr-values": { - func() { - slogLogger := slog.New(ToSlogHandler(logger)).WithGroup("group") - logrLogger := FromSlogHandler(slogLogger.Handler()).WithValues("answer", 42, "foo", "bar") - slogLogger = slog.New(ToSlogHandler(logrLogger)) - slogLogger.Info("") - }, - withAttrs(slog.Record{}, slog.Group("group", slog.Int("answer", 42), slog.String("foo", "bar"))), - }, - } - - for name, tc := range testcases { - t.Run(name, func(t *testing.T) { - tc.run() - verify(t, tc.expectedRecord) - reset() - }) - } -} diff --git a/logr_test.go b/logr_test.go index 354f038..dc33cc2 100644 --- a/logr_test.go +++ b/logr_test.go @@ -24,85 +24,6 @@ import ( "testing" ) -// testLogSink is a Logger just for testing that calls optional hooks on each method. -type testLogSink struct { - fnInit func(ri RuntimeInfo) - fnEnabled func(lvl int) bool - fnInfo func(lvl int, msg string, kv ...any) - fnError func(err error, msg string, kv ...any) - fnWithValues func(kv ...any) - fnWithName func(name string) - - withValues []any - - // testSlogSink contains some additional fields if (and only if) slog is supported by Go. - // See logr_slog_test.go. - //nolint:unused // Only unused with Go < 1.21. - testSlogSink -} - -var _ LogSink = &testLogSink{} - -func (l *testLogSink) Init(ri RuntimeInfo) { - if l.fnInit != nil { - l.fnInit(ri) - } -} - -func (l *testLogSink) Enabled(lvl int) bool { - if l.fnEnabled != nil { - return l.fnEnabled(lvl) - } - return false -} - -func (l *testLogSink) Info(lvl int, msg string, kv ...any) { - if l.fnInfo != nil { - l.fnInfo(lvl, msg, kv...) - } -} - -func (l *testLogSink) Error(err error, msg string, kv ...any) { - if l.fnError != nil { - l.fnError(err, msg, kv...) - } -} - -func (l *testLogSink) WithValues(kv ...any) LogSink { - if l.fnWithValues != nil { - l.fnWithValues(kv...) - } - out := *l - n := len(out.withValues) - out.withValues = append(out.withValues[:n:n], kv...) - return &out -} - -func (l *testLogSink) WithName(name string) LogSink { - if l.fnWithName != nil { - l.fnWithName(name) - } - out := *l - return &out -} - -type testCallDepthLogSink struct { - testLogSink - callDepth int - fnWithCallDepth func(depth int) -} - -var _ CallDepthLogSink = &testCallDepthLogSink{} - -func (l *testCallDepthLogSink) WithCallDepth(depth int) LogSink { - if l.fnWithCallDepth != nil { - l.fnWithCallDepth(depth) - } - out := *l - out.callDepth += depth - return &out -} - func TestNew(t *testing.T) { calledInit := 0 diff --git a/sloghandler.go b/sloghandler.go index f2c96fd..82d1ba4 100644 --- a/sloghandler.go +++ b/sloghandler.go @@ -70,9 +70,7 @@ func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error { kvList := make([]any, 0, 2*record.NumAttrs()) record.Attrs(func(attr slog.Attr) bool { - if attr.Key != "" { - kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any()) - } + kvList = attrToKVs(attr, l.groupPrefix, kvList) return true }) if record.Level >= slog.LevelError { @@ -114,9 +112,7 @@ func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { } else { kvList := make([]any, 0, 2*len(attrs)) for _, attr := range attrs { - if attr.Key != "" { - kvList = append(kvList, l.addGroupPrefix(attr.Key), attr.Value.Resolve().Any()) - } + kvList = attrToKVs(attr, l.groupPrefix, kvList) } clone.sink = l.sink.WithValues(kvList...) } @@ -127,21 +123,50 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { if l.sink == nil { return l } + if name == "" { + // slog says to inline empty groups + return l + } clone := *l if l.slogSink != nil { clone.slogSink = l.slogSink.WithGroup(name) clone.sink = clone.slogSink } else { - clone.groupPrefix = clone.addGroupPrefix(name) + clone.groupPrefix = addPrefix(clone.groupPrefix, name) } return &clone } -func (l *slogHandler) addGroupPrefix(name string) string { - if l.groupPrefix == "" { +// attrToKVs appends a slog.Attr to a logr-style kvList. It handle slog Groups +// and other details of slog. +func attrToKVs(attr slog.Attr, groupPrefix string, kvList []any) []any { + attrVal := attr.Value.Resolve() + if attrVal.Kind() == slog.KindGroup { + groupVal := attrVal.Group() + grpKVs := make([]any, 0, 2*len(groupVal)) + prefix := groupPrefix + if attr.Key != "" { + prefix = addPrefix(groupPrefix, attr.Key) + } + for _, attr := range groupVal { + grpKVs = attrToKVs(attr, prefix, grpKVs) + } + kvList = append(kvList, grpKVs...) + } else if attr.Key != "" { + kvList = append(kvList, addPrefix(groupPrefix, attr.Key), attrVal.Any()) + } + + return kvList +} + +func addPrefix(prefix, name string) string { + if prefix == "" { return name } - return l.groupPrefix + groupSeparator + name + if name == "" { + return prefix + } + return prefix + groupSeparator + name } // levelFromSlog adjusts the level by the logger's verbosity and negates it. diff --git a/slogr_test.go b/slogr_test.go index 332c7e9..2b00a50 100644 --- a/slogr_test.go +++ b/slogr_test.go @@ -24,6 +24,7 @@ import ( "fmt" "io" "log/slog" + "os" "path" "runtime" "strings" @@ -32,6 +33,58 @@ import ( "github.com/go-logr/logr/internal/testhelp" ) +func TestToSlogHandler(t *testing.T) { + t.Run("from simple Logger", func(t *testing.T) { + logger := New(&testLogSink{}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slogHandler); !ok { + t.Errorf("expected type *slogHandler, got %T", handler) + } + }) + + t.Run("from slog-enabled Logger", func(t *testing.T) { + logger := New(&testSlogSink{}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slogHandler); !ok { + t.Errorf("expected type *slogHandler, got %T", handler) + } + }) + + t.Run("from slogSink Logger", func(t *testing.T) { + logger := New(&slogSink{handler: slog.NewJSONHandler(os.Stderr, nil)}) + handler := ToSlogHandler(logger) + if _, ok := handler.(*slog.JSONHandler); !ok { + t.Errorf("expected type *slog.JSONHandler, got %T", handler) + } + }) +} + +func TestFromSlogHandler(t *testing.T) { + t.Run("from slog Handler", func(t *testing.T) { + handler := slog.NewJSONHandler(os.Stderr, nil) + logger := FromSlogHandler(handler) + if _, ok := logger.sink.(*slogSink); !ok { + t.Errorf("expected type *slogSink, got %T", logger.sink) + } + }) + + t.Run("from simple slogHandler Handler", func(t *testing.T) { + handler := &slogHandler{sink: &testLogSink{}} + logger := FromSlogHandler(handler) + if _, ok := logger.sink.(*testLogSink); !ok { + t.Errorf("expected type *testSlogSink, got %T", logger.sink) + } + }) + + t.Run("from discard slogHandler Handler", func(t *testing.T) { + handler := &slogHandler{} + logger := FromSlogHandler(handler) + if logger != Discard() { + t.Errorf("expected type *testSlogSink, got %T", logger.sink) + } + }) +} + var debugWithoutTime = &slog.HandlerOptions{ ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr { if a.Key == "time" { @@ -61,13 +114,45 @@ func TestWithCallDepth(t *testing.T) { } } -func TestRunSlogTestsOnSlogSink(t *testing.T) { - // This proves that slogSink passes slog's own tests. +func TestRunSlogTestsOnSlogHandlerLogSink(t *testing.T) { + // This proves that slogHandler passes slog's own tests when given a + // non-SlogSink LogSink. + exceptions := []string{ + // logr sinks handle time themselves + "a Handler should ignore a zero Record.Time", + // slogHandler does not do groups "properly", so these all fail with + // "missing group". It's looking for `"G":{"a":"b"}` and getting + // `"G.a": "b"`. + "a Handler should handle Group attributes", + "a Handler should handle the WithGroup method", + "a Handler should handle multiple WithGroup and WithAttr calls", + "a Handler should not output groups for an empty Record", + "a Handler should call Resolve on attribute values in groups", + "a Handler should call Resolve on attribute values in groups from WithAttrs", + } testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + // We want a known-good Logger that emits JSON but is not a slogHandler + // or SlogSink (since those get special treatment). We can trust that + // the slog JSONHandler works. handler := slog.NewJSONHandler(buffer, nil) - logger := FromSlogHandler(handler) + sink := &passthruLogSink{handler: handler} + logger := New(sink) return ToSlogHandler(logger) - }) + }, exceptions...) +} + +func TestRunSlogTestsOnSlogHandlerSlogSink(t *testing.T) { + // This proves that slogHandler passes slog's own tests when given a + // SlogSink. + exceptions := []string{} + testhelp.RunSlogTests(t, func(buffer *bytes.Buffer) slog.Handler { + // We want a known-good Logger that emits JSON and implements SlogSink, + // to cover those paths. We can trust that the slog JSONHandler works. + handler := slog.NewJSONHandler(buffer, nil) + sink := &passthruSlogSink{handler: handler} + logger := New(sink) + return ToSlogHandler(logger) + }, exceptions...) } func TestSlogSinkOnDiscard(_ *testing.T) { diff --git a/testimpls_slog_test.go b/testimpls_slog_test.go new file mode 100644 index 0000000..5ae2690 --- /dev/null +++ b/testimpls_slog_test.go @@ -0,0 +1,140 @@ +//go:build go1.21 +// +build go1.21 + +/* +Copyright 2023 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package logr + +import ( + "context" + "log/slog" + "time" +) + +var _ SlogSink = &testSlogSink{} + +// testSlogSink is a trivial SlogSink implementation, just for testing, which +// calls (optional) hooks on each method. +type testSlogSink struct { + // embed a plain LogSink + testLogSink + + attrs []slog.Attr + groups []string + + fnHandle func(ss *testSlogSink, ctx context.Context, record slog.Record) + fnWithAttrs func(ss *testSlogSink, attrs []slog.Attr) + fnWithGroup func(ss *testSlogSink, name string) +} + +func (ss *testSlogSink) Handle(ctx context.Context, record slog.Record) error { + if ss.fnHandle != nil { + ss.fnHandle(ss, ctx, record) + } + return nil +} + +func (ss *testSlogSink) WithAttrs(attrs []slog.Attr) SlogSink { + if ss.fnWithAttrs != nil { + ss.fnWithAttrs(ss, attrs) + } + out := *ss + n := len(out.attrs) + out.attrs = append(out.attrs[:n:n], attrs...) + return &out +} + +func (ss *testSlogSink) WithGroup(name string) SlogSink { + if ss.fnWithGroup != nil { + ss.fnWithGroup(ss, name) + } + out := *ss + n := len(out.groups) + out.groups = append(out.groups[:n:n], name) + return &out +} + +// passthruLogSink is a trivial LogSink implementation, which implements the +// logr.LogSink methods in terms of a slog.Handler. +type passthruLogSink struct { + handler slog.Handler +} + +func (pl passthruLogSink) Init(RuntimeInfo) {} + +func (pl passthruLogSink) Enabled(int) bool { return true } + +func (pl passthruLogSink) Error(_ error, msg string, kvList ...interface{}) { + var record slog.Record + record.Message = msg + record.Level = slog.LevelError + record.Time = time.Now() + record.Add(kvList...) + _ = pl.handler.Handle(context.Background(), record) +} + +func (pl passthruLogSink) Info(_ int, msg string, kvList ...interface{}) { + var record slog.Record + record.Message = msg + record.Level = slog.LevelInfo + record.Time = time.Now() + record.Add(kvList...) + _ = pl.handler.Handle(context.Background(), record) +} + +func (pl passthruLogSink) WithName(string) LogSink { return &pl } + +func (pl passthruLogSink) WithValues(kvList ...interface{}) LogSink { + var values slog.Record + values.Add(kvList...) + var attrs []slog.Attr + add := func(attr slog.Attr) bool { + attrs = append(attrs, attr) + return true + } + values.Attrs(add) + + pl.handler = pl.handler.WithAttrs(attrs) + return &pl +} + +// passthruSlogSink is a trivial SlogSink implementation, which stubs out the +// logr.LogSink methods and passes Logr.SlogSink thru to a slog.Handler. +type passthruSlogSink struct { + handler slog.Handler +} + +func (ps passthruSlogSink) Init(RuntimeInfo) {} +func (ps passthruSlogSink) Enabled(int) bool { return true } +func (ps passthruSlogSink) Error(error, string, ...interface{}) {} +func (ps passthruSlogSink) Info(int, string, ...interface{}) {} +func (ps passthruSlogSink) WithName(string) LogSink { return &ps } +func (ps passthruSlogSink) WithValues(...interface{}) LogSink { return &ps } + +func (ps *passthruSlogSink) Handle(ctx context.Context, record slog.Record) error { + return ps.handler.Handle(ctx, record) +} + +func (ps passthruSlogSink) WithAttrs(attrs []slog.Attr) SlogSink { + ps.handler = ps.handler.WithAttrs(attrs) + return &ps +} + +func (ps passthruSlogSink) WithGroup(name string) SlogSink { + ps.handler = ps.handler.WithGroup(name) + return &ps +} diff --git a/testimpls_test.go b/testimpls_test.go new file mode 100644 index 0000000..08571db --- /dev/null +++ b/testimpls_test.go @@ -0,0 +1,92 @@ +/* +Copyright 2021 The logr Authors. + +Licensed under the Apache License, Version 2.0 (the "License"); +you may not use this file except in compliance with the License. +You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + +Unless required by applicable law or agreed to in writing, software +distributed under the License is distributed on an "AS IS" BASIS, +WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +See the License for the specific language governing permissions and +limitations under the License. +*/ + +package logr + +// testLogSink is a trivial LogSink implementation, just for testing, which +// calls (optional) hooks on each method. +type testLogSink struct { + fnInit func(ri RuntimeInfo) + fnEnabled func(lvl int) bool + fnInfo func(lvl int, msg string, kv ...any) + fnError func(err error, msg string, kv ...any) + fnWithValues func(kv ...any) + fnWithName func(name string) + + withValues []any +} + +var _ LogSink = &testLogSink{} + +func (ls *testLogSink) Init(ri RuntimeInfo) { + if ls.fnInit != nil { + ls.fnInit(ri) + } +} + +func (ls *testLogSink) Enabled(lvl int) bool { + if ls.fnEnabled != nil { + return ls.fnEnabled(lvl) + } + return false +} + +func (ls *testLogSink) Info(lvl int, msg string, kv ...any) { + if ls.fnInfo != nil { + ls.fnInfo(lvl, msg, kv...) + } +} + +func (ls *testLogSink) Error(err error, msg string, kv ...any) { + if ls.fnError != nil { + ls.fnError(err, msg, kv...) + } +} + +func (ls *testLogSink) WithValues(kv ...any) LogSink { + if ls.fnWithValues != nil { + ls.fnWithValues(kv...) + } + out := *ls + n := len(out.withValues) + out.withValues = append(out.withValues[:n:n], kv...) + return &out +} + +func (ls *testLogSink) WithName(name string) LogSink { + if ls.fnWithName != nil { + ls.fnWithName(name) + } + out := *ls + return &out +} + +type testCallDepthLogSink struct { + testLogSink + callDepth int + fnWithCallDepth func(depth int) +} + +var _ CallDepthLogSink = &testCallDepthLogSink{} + +func (ls *testCallDepthLogSink) WithCallDepth(depth int) LogSink { + if ls.fnWithCallDepth != nil { + ls.fnWithCallDepth(depth) + } + out := *ls + out.callDepth += depth + return &out +}