slogr: add glue code for logging to slog.Handler and with slog.Logger

Interoperability with log/slog from Go 1.21 includes the ability to use a
slog.Handler as backend with logr.Logger as frontend and vice versa.

This is only the initial step. In particular writing with slog.Logger to
a logr.LogSink is not working well (time stamp and call site from
record get ignored). Further work is needed to improve this.

README.md

@@ -74,6 +74,29 @@ received:
 If the Go standard library had defined an interface for logging, this project
 probably would not be needed.  Alas, here we are.
 
+When the Go developers started developing such an interface with
+[slog](https://github.com/golang/go/issues/56345), they adopted some of the
+logr design but also left out some parts and changed others:
+
+| Feature | logr | slog |
+|---------|------|------|
+| High-level API | `Logger` (passed by value) | `Logger` (passed by [pointer](https://github.com/golang/go/issues/59126)) |
+| Low-level API | `LogSink` | `Handler` |
+| Stack unwinding | done by `LogSink` | done by `Logger` |
+| Skipping helper functions | `WithCallDepth`, `WithCallStackHelper` | [not supported by Logger](https://github.com/golang/go/issues/59145) |
+| Generating a value for logging on demand | `Marshaler` | `LogValuer` |
+| Log levels | >= 0, higher meaning "less important" | positive and negative, with 0 for "info" and higher meaning "more important" |
+| Error log entries | always logged, don't have a verbosity level | normal log entries with level >= `LevelError` |
+| Passing logger via context | `NewContext`, `FromContext` | no API |
+| Adding a name to a logger | `WithName` | no API |
+| Modify verbosity of log entries in a call chain | `V` | no API |
+| Grouping of key/value pairs | not supported | `WithGroup`, `GroupValue` |
+
+The high-level slog API is explicitly meant to be one of many different APIs
+that can be layered on top of a shared `slog.Handler`. logr is one such
+alternative API, with interoperability provided by the [`slogr`](slogr)
+package.
+
 ### Inspiration
 
 Before you consider this package, please read [this blog post by the
@@ -242,7 +265,9 @@ Otherwise, you can start out with `0` as "you always want to see this",
 
 Then gradually choose levels in between as you need them, working your way
 down from 10 (for debug and trace style logs) and up from 1 (for chattier
-info-type logs.)
+info-type logs). For reference, slog pre-defines -4 for debug logs
+(corresponds to 4 in logr), which matches what is
+[recommended for Kubernetes](https://github.com/kubernetes/community/blob/master/contributors/devel/sig-instrumentation/logging.md#what-method-to-use).
 
 #### How do I choose my keys?
 

slogr/sloghandler.go

@@ -0,0 +1,105 @@
+//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 slogr
+
+import (
+	"context"
+	"log/slog"
+
+	"github.com/go-logr/logr"
+)
+
+type slogHandler struct {
+	sink        logr.LogSink
+	groupPrefix string
+	level       slog.Level
+}
+
+var _ slog.Handler = &slogHandler{}
+
+// groupSeparator is used to concatenate WithGroup names and attribute keys.
+const groupSeparator = "."
+
+func (l *slogHandler) Enabled(ctx context.Context, level slog.Level) bool {
+	return l.sink != nil && (level >= slog.LevelError || l.sink.Enabled(l.levelFromSlog(level)))
+}
+
+func (l *slogHandler) Handle(ctx context.Context, record slog.Record) error {
+	// No need to check for nil sink here because Handle will only be called
+	// when Enabled returned true.
+
+	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())
+		}
+		return true
+	})
+	if record.Level >= slog.LevelError {
+		l.sink.Error(nil, record.Message, kvList...)
+	} else {
+		level := l.levelFromSlog(record.Level)
+		l.sink.Info(level, record.Message, kvList...)
+	}
+	return nil
+}
+
+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
+	copy.sink = l.sink.WithValues(kvList...)
+	return &copy
+}
+
+func (l *slogHandler) WithGroup(name string) slog.Handler {
+	if l.sink == nil {
+		return l
+	}
+	copy := *l
+	copy.groupPrefix = copy.addGroupPrefix(name)
+	return &copy
+}
+
+func (l *slogHandler) addGroupPrefix(name string) string {
+	if l.groupPrefix == "" {
+		return name
+	}
+	return l.groupPrefix + groupSeparator + name
+}
+
+// levelFromSlog adjusts the level by the logger's verbosity and negates it.
+// It ensures that the result is >= 0. This is necessary because the result is
+// passed to a logr.LogSink and that API did not historically document whether
+// levels could be negative or what that meant.
+func (l *slogHandler) levelFromSlog(level slog.Level) int {
+	level -= l.level
+	if level >= 0 {
+		return 0
+	}
+	return int(-level)
+}

slogr/slogr.go

@@ -0,0 +1,63 @@
+//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 slogr enables usage of a slog.Handler with logr.Logger as front-end
+// API and of a logr.LogSink through the slog.Handler and thus slog.Logger
+// APIs.
+//
+// Both approaches are currently experimental and need further work.
+
+package slogr
+
+import (
+	"log/slog"
+
+	"github.com/go-logr/logr"
+)
+
+// NewLogr returns a logr.Logger which writes to the slog.Handler.
+//
+// In the output the logr verbosity level gets negated, so V(4) becomes
+// slog.LevelDebug.
+func NewLogr(handler slog.Handler) logr.Logger {
+	return logr.New(&slogSink{handler: handler})
+}
+
+// NewSlogHandler returns a slog.Handler which writes to the same sink as the logr.Logger.
+//
+// The returned logger writes all records with level >= slog.LevelError as
+// error log entries with LogSink.Error, regardless of the verbosity of the
+// logr.Logger. The level of all other records gets reduced by the verbosity
+// level of the logr.Logger, so a slog.Logger.Info call gets written with
+// slog.LevelDebug when using a logr.Logger where verbosity was modified with
+// V(4).
+func NewSlogHandler(logger logr.Logger) slog.Handler {
+	// This offset currently (Go 1.21.0) works for slog.New(NewSlog(...)).Info.
+	// There's no guarantee that the call chain won't change and wrapping
+	// the handler will also break unwinding, but it's still better than not
+	// adjusting at all.
+	logger = logger.WithCallDepth(2)
+	return &slogHandler{sink: logger.GetSink(), level: slog.Level(logger.GetV())}
+}
+
+// Underlier is implemented by the LogSink returned by NewLogr.
+type Underlier interface {
+	// GetUnderlying returns the Handler used by the LogSink.
+	GetUnderlying() slog.Handler
+}

slogr/slogr_test.go

@@ -0,0 +1,186 @@
+//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 slogr_test
+
+import (
+	"bytes"
+	"encoding/json"
+	"errors"
+	"fmt"
+	"log/slog"
+	"os"
+	"path"
+	"runtime"
+	"strings"
+	"testing"
+	"testing/slogtest"
+
+	"github.com/go-logr/logr"
+	"github.com/go-logr/logr/funcr"
+	"github.com/go-logr/logr/slogr"
+)
+
+var debugWithoutTime = &slog.HandlerOptions{
+	ReplaceAttr: func(groups []string, a slog.Attr) slog.Attr {
+		if a.Key == "time" {
+			return slog.Attr{}
+		}
+		return a
+	},
+	Level: slog.LevelDebug,
+}
+
+func ExampleNew() {
+	logger := slogr.NewLogr(slog.NewTextHandler(os.Stdout, debugWithoutTime))
+
+	logger.Info("hello world")
+	logger.Error(errors.New("fake error"), "ignore me")
+	logger.WithValues("x", 1, "y", 2).WithValues("str", "abc").WithName("foo").WithName("bar").V(4).Info("with values, verbosity and name")
+
+	// Output:
+	// level=INFO msg="hello world"
+	// level=ERROR msg="ignore me" err="fake error"
+	// level=DEBUG msg="with values, verbosity and name" x=1 y=2 str=abc logger=foo/bar
+}
+
+func ExampleNewSlogLogger() {
+	funcrLogger := funcr.New(func(prefix, args string) {
+		if prefix != "" {
+			fmt.Fprintln(os.Stdout, prefix, args)
+		} else {
+			fmt.Fprintln(os.Stdout, args)
+		}
+	}, funcr.Options{
+		Verbosity: 10,
+	})
+
+	logger := slog.New(slogr.NewSlogHandler(funcrLogger))
+	logger.Info("hello world")
+	logger.Error("ignore me", "err", errors.New("fake error"))
+	logger.With("x", 1, "y", 2).WithGroup("group").With("str", "abc").Warn("with values and group")
+
+	logger = slog.New(slogr.NewSlogHandler(funcrLogger.V(int(-slog.LevelDebug))))
+	logger.Info("info message reduced to debug level")
+
+	// Output:
+	// "level"=0 "msg"="hello world"
+	// "msg"="ignore me" "error"=null "err"="fake error"
+	// "level"=0 "msg"="with values and group" "x"=1 "y"=2 "group.str"="abc"
+	// "level"=4 "msg"="info message reduced to debug level"
+}
+
+func TestWithCallDepth(t *testing.T) {
+	debugWithCaller := *debugWithoutTime
+	debugWithCaller.AddSource = true
+	var buffer bytes.Buffer
+	logger := slogr.NewLogr(slog.NewTextHandler(&buffer, &debugWithCaller))
+
+	logHelper(logger)
+	_, file, line, _ := runtime.Caller(0)
+	expectedSource := fmt.Sprintf("%s:%d", path.Base(file), line-1)
+	actual := buffer.String()
+	if !strings.Contains(actual, expectedSource) {
+		t.Errorf("expected log entry with %s as caller source code location, got instead:\n%s", expectedSource, actual)
+	}
+}
+
+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
+		},
+	})
+	handler := slogr.NewSlogHandler(funcrLogger)
+
+	err := slogtest.TestHandler(handler, func() []map[string]any {
+		var ms []map[string]any
+		for _, line := range bytes.Split(buffer.Bytes(), []byte{'\n'}) {
+			if len(line) == 0 {
+				continue
+			}
+			var m map[string]any
+			if err := json.Unmarshal(line, &m); err != nil {
+				t.Fatal(err)
+			}
+			ms = append(ms, m)
+		}
+		return ms
+	})
+
+	// Correlating failures with individual test cases is hard with the current API.
+	// See https://github.com/golang/go/issues/61758
+	t.Logf("Output:\n%s", buffer.String())
+	if err != nil {
+		if err, ok := err.(interface {
+			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.
+				) {
+					t.Errorf("Unexpected error: %v", err)
+				}
+			}
+		} else {
+			// Shouldn't be reached, errors from errors.Join can be split up.
+			t.Errorf("Unexpected errors:\n%v", err)
+		}
+	}
+}
+
+func containsOne(hay string, needles ...string) bool {
+	for _, needle := range needles {
+		if strings.Contains(hay, needle) {
+			return true
+		}
+	}
+	return false
+}
+
+func TestDiscard(t *testing.T) {
+	logger := slog.New(slogr.NewSlogHandler(logr.Discard()))
+	logger.WithGroup("foo").With("x", 1).Info("hello")
+}