diff --git a/slogr/sloghandler.go b/slogr/sloghandler.go index 58d7e39..ec6725c 100644 --- a/slogr/sloghandler.go +++ b/slogr/sloghandler.go @@ -27,7 +27,10 @@ import ( ) type slogHandler struct { + // May be nil, in which case all logs get discarded. sink logr.LogSink + // Non-nil if sink is non-nil and implements SlogSink. + slogSink SlogSink // groupPrefix collects values from WithGroup calls. It gets added as // prefix to value keys when handling a log record. @@ -56,6 +59,14 @@ func (l *slogHandler) Enabled(ctx context.Context, level slog.Level) bool { } func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error { + if l.slogSink != nil { + // Only adjust verbosity level of log entries < slog.LevelError. + if record.Level < slog.LevelError { + record.Level -= l.levelBias + } + return l.slogSink.Handle(ctx, record) + } + // No need to check for nil sink here because Handle will only be called // when Enabled returned true. @@ -97,14 +108,20 @@ func (l *slogHandler) WithAttrs(attrs []slog.Attr) slog.Handler { if l.sink == nil || len(attrs) == 0 { return l } - 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()) + + copy := *l + if l.slogSink != nil { + copy.slogSink = l.slogSink.WithAttrs(attrs) + copy.sink = copy.slogSink + } 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()) + } } + copy.sink = l.sink.WithValues(kvList...) } - copy := *l - copy.sink = l.sink.WithValues(kvList...) return © } @@ -113,7 +130,12 @@ func (l *slogHandler) WithGroup(name string) slog.Handler { return l } copy := *l - copy.groupPrefix = copy.addGroupPrefix(name) + if l.slogSink != nil { + copy.slogSink = l.slogSink.WithGroup(name) + copy.sink = l.slogSink + } else { + copy.groupPrefix = copy.addGroupPrefix(name) + } return © } diff --git a/slogr/slogr.go b/slogr/slogr.go index 8131994..8828fd2 100644 --- a/slogr/slogr.go +++ b/slogr/slogr.go @@ -25,6 +25,7 @@ limitations under the License. package slogr import ( + "context" "log/slog" "github.com/go-logr/logr" @@ -67,5 +68,40 @@ func NewSlogHandler(logger logr.Logger) slog.Handler { return sink.handler } - return &slogHandler{sink: logger.GetSink(), levelBias: slog.Level(logger.GetV())} + handler := &slogHandler{sink: logger.GetSink(), levelBias: slog.Level(logger.GetV())} + if slogSink, ok := handler.sink.(SlogSink); ok { + handler.slogSink = slogSink + } + return handler +} + +// SlogSink is an optional interface that a LogSink can implement to support +// logging through the slog.Logger or slog.Handler APIs better. It then should +// also support special slog values like slog.Group. When used as a +// slog.Handler, the advantages are: +// +// - stack unwinding gets avoided in favor of logging the pre-recorded PC, +// as intended by slog +// - proper grouping of key/value pairs via WithGroup +// - verbosity levels > slog.LevelInfo can be recorded +// - less overhead +// +// Both APIs (logr.Logger and slog.Logger/Handler) then are supported equally +// well. Developers can pick whatever API suits them better and/or mix +// packages which use either API in the same binary with a common logging +// implementation. +// +// This interface is necessary because the type implementing the LogSink +// interface cannot also implement the slog.Handler interface due to the +// different prototype of the common Enabled method. +// +// An implementation could support both interfaces in two different types, but then +// additional interfaces would be needed to convert between those types in NewLogr +// and NewSlogHandler. +type SlogSink interface { + logr.LogSink + + Handle(ctx context.Context, record slog.Record) error + WithAttrs(attrs []slog.Attr) SlogSink + WithGroup(name string) SlogSink } diff --git a/slogr/slogr_test.go b/slogr/slogr_test.go index 1658feb..2e5f0ff 100644 --- a/slogr/slogr_test.go +++ b/slogr/slogr_test.go @@ -21,6 +21,7 @@ package slogr_test import ( "bytes" + "context" "encoding/json" "errors" "fmt" @@ -106,30 +107,78 @@ func logHelper(logger logr.Logger) { logger.WithCallDepth(1).Info("hello") } -func TestSlogHandler(t *testing.T) { - var buffer bytes.Buffer - funcrLogger := funcr.NewJSON(func(obj string) { - fmt.Fprintln(&buffer, obj) - }, funcr.Options{ - LogTimestamp: true, - Verbosity: 10, - RenderBuiltinsHook: func(kvList []any) []any { - mappedKVList := make([]any, len(kvList)) - for i := 0; i < len(kvList); i += 2 { - key := kvList[i] - switch key { - case "ts": - mappedKVList[i] = "time" - default: - mappedKVList[i] = key - } - mappedKVList[i+1] = kvList[i+1] - } - return mappedKVList - }, +func TestJSONHandler(t *testing.T) { + testSlog(t, func(buffer *bytes.Buffer) logr.Logger { + handler := slog.NewJSONHandler(buffer, nil) + sink := testSlogSink{handler: handler} + return logr.New(sink) }) - handler := slogr.NewSlogHandler(funcrLogger) +} + +var _ logr.LogSink = testSlogSink{} +var _ slogr.SlogSink = testSlogSink{} + +// testSlogSink is only used through slog and thus doesn't need to implement the +// normal LogSink methods. +type testSlogSink struct { + handler slog.Handler +} + +func (s testSlogSink) Init(logr.RuntimeInfo) {} +func (s testSlogSink) Enabled(int) bool { return true } +func (s testSlogSink) Error(error, string, ...interface{}) {} +func (s testSlogSink) Info(int, string, ...interface{}) {} +func (s testSlogSink) WithName(string) logr.LogSink { return s } +func (s testSlogSink) WithValues(...interface{}) logr.LogSink { return s } +func (s testSlogSink) Handle(ctx context.Context, record slog.Record) error { + return s.handler.Handle(ctx, record) +} +func (s testSlogSink) WithAttrs(attrs []slog.Attr) slogr.SlogSink { + return testSlogSink{handler: s.handler.WithAttrs(attrs)} +} +func (s testSlogSink) WithGroup(name string) slogr.SlogSink { + return testSlogSink{handler: s.handler.WithGroup(name)} +} + +func TestFuncrHandler(t *testing.T) { + testSlog(t, func(buffer *bytes.Buffer) logr.Logger { + logger := funcr.NewJSON(func(obj string) { + fmt.Fprintln(buffer, obj) + }, funcr.Options{ + LogTimestamp: true, + Verbosity: 10, + RenderBuiltinsHook: func(kvList []any) []any { + mappedKVList := make([]any, len(kvList)) + for i := 0; i < len(kvList); i += 2 { + key := kvList[i] + switch key { + case "ts": + mappedKVList[i] = "time" + default: + mappedKVList[i] = key + } + mappedKVList[i+1] = kvList[i+1] + } + return mappedKVList + }, + }) + return logger + }, + "a Handler should ignore a zero Record.Time", // Time is generated by sink. + "a Handler should handle Group attributes", // funcr doesn't. + "a Handler should inline the Attrs of a group with an empty key", // funcr doesn't know about groups. + "a Handler should not output groups for an empty Record", // Relies on WithGroup. Text may change, see https://go.dev/cl/516155 + "a Handler should handle the WithGroup method", // logHandler does by prefixing keys, which is not what the test expects. + "a Handler should handle multiple WithGroup and WithAttr calls", // Same. + "a Handler should call Resolve on attribute values in groups", // funcr doesn't do that and slogHandler can't do it for it. + ) +} + +func testSlog(t *testing.T, createLogger func(buffer *bytes.Buffer) logr.Logger, exceptions ...string) { + var buffer bytes.Buffer + logger := createLogger(&buffer) + handler := slogr.NewSlogHandler(logger) err := slogtest.TestHandler(handler, func() []map[string]any { var ms []map[string]any for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) { @@ -153,15 +202,7 @@ func TestSlogHandler(t *testing.T) { Unwrap() []error }); ok { for _, err := range err.Unwrap() { - if !containsOne(err.Error(), - "a Handler should ignore a zero Record.Time", // Time is generated by sink. - "a Handler should handle Group attributes", // funcr doesn't. - "a Handler should inline the Attrs of a group with an empty key", // funcr doesn't know about groups. - "a Handler should not output groups for an empty Record", // Relies on WithGroup. Text may change, see https://go.dev/cl/516155 - "a Handler should handle the WithGroup method", // logHandler does by prefixing keys, which is not what the test expects. - "a Handler should handle multiple WithGroup and WithAttr calls", // Same. - "a Handler should call Resolve on attribute values in groups", // funcr doesn't do that and slogHandler can't do it for it. - ) { + if !containsOne(err.Error(), exceptions...) { t.Errorf("Unexpected error: %v", err) } }