Skip to content

Commit

Permalink
slogr: add glue code for logging to slog.Handler and with slog.Logger
Browse files Browse the repository at this point in the history
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.
  • Loading branch information
pohly authored and thockin committed Aug 22, 2023
1 parent 50e47a6 commit b785b9f
Show file tree
Hide file tree
Showing 6 changed files with 626 additions and 1 deletion.
27 changes: 26 additions & 1 deletion README.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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?

Expand Down
103 changes: 103 additions & 0 deletions slogr/example/main.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,103 @@
//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 main is an example of using slogr.
package main

import (
"context"
"fmt"
"log/slog"
"os"

"github.com/go-logr/logr"
"github.com/go-logr/logr/funcr"
"github.com/go-logr/logr/slogr"
)

type e struct {
str string
}

func (e e) Error() string {
return e.str
}

func logrHelper(log logr.Logger, msg string) {
logrHelper2(log, msg)
}

func logrHelper2(log logr.Logger, msg string) {
log.WithCallDepth(2).Info(msg)
}

func slogHelper(log *slog.Logger, msg string) {
slogHelper2(log, msg)
}

func slogHelper2(log *slog.Logger, msg string) {
// slog.Logger has no API for skipping helper functions, so this gets logged as call location.
log.Info(msg)
}

func main() {
opts := slog.HandlerOptions{
AddSource: true,
Level: slog.Level(-1),
}
handler := slog.NewJSONHandler(os.Stderr, &opts)
logrLogger := slogr.NewLogr(handler)
logrExample(logrLogger)

logrLogger = funcr.NewJSON(
func(obj string) { fmt.Println(obj) },
funcr.Options{
LogCaller: funcr.All,
LogTimestamp: true,
Verbosity: 1,
})
slogLogger := slog.New(slogr.NewSlogHandler(logrLogger))
slogExample(slogLogger)
}

func logrExample(log logr.Logger) {
log = log.WithName("my")
log = log.WithName("logger")
log = log.WithName("name")
log = log.WithValues("saved", "value")
log.Info("1) hello", "val1", 1, "val2", map[string]int{"k": 1})
log.V(1).Info("2) you should see this")
log.V(1).V(1).Info("you should NOT see this")
log.Error(nil, "3) uh oh", "trouble", true, "reasons", []float64{0.1, 0.11, 3.14})
log.Error(e{"an error occurred"}, "4) goodbye", "code", -1)
logrHelper(log, "5) thru a helper")
}

func slogExample(log *slog.Logger) {
// There's no guarantee that this logs the right source code location.
// It works for Go 1.21.0 by compensating in slogr.NewSlogHandler
// for the additional callers, but those might change.
log = log.With("saved", "value")
log.Info("1) hello", "val1", 1, "val2", map[string]int{"k": 1})
log.Log(context.TODO(), slog.Level(-1), "2) you should see this")
log.Log(context.TODO(), slog.Level(-2), "you should NOT see this")
log.Error("3) uh oh", "trouble", true, "reasons", []float64{0.1, 0.11, 3.14})
log.Error("4) goodbye", "code", -1, "err", e{"an error occurred"})
slogHelper(log, "5) thru a helper")
}
123 changes: 123 additions & 0 deletions slogr/sloghandler.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,123 @@
//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 collects values from WithGroup calls. It gets added as
// prefix to value keys when handling a log record.
groupPrefix string

// levelBias can be set when constructing the handler to influence the
// slog.Level of log records. A positive levelBias reduces the
// slog.Level value. slog has no API to influence this value after the
// handler got created, so it can only be set indirectly through
// Logger.V.
levelBias 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.
//
// Some example usage:
// logrV0 := getMyLogger()
// logrV2 := logrV0.V(2)
// slogV2 := slog.New(slogr.NewSlogHandler(logrV2))
// slogV2.Debug("msg") // =~ logrV2.V(4) =~ logrV0.V(6)
// slogV2.Info("msg") // =~ logrV2.V(0) =~ logrV0.V(2)
// slogv2.Warn("msg") // =~ logrV2.V(-4) =~ logrV0.V(0)
func (l *slogHandler) levelFromSlog(level slog.Level) int {
result := -level
result += l.levelBias // in case the original logr.Logger had a V level
if result < 0 {
result = 0 // because logr.LogSink doesn't expect negative V levels
}
return int(result)
}
66 changes: 66 additions & 0 deletions slogr/slogr.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,66 @@
//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.
//
// The logr verbosity level is mapped to slog levels such that V(0) becomes
// slog.LevelInfo and 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 level of
// the logr.Logger:
//
// logger := <some logr.Logger with 0 as verbosity level>
// slog.New(NewSlogHandler(logger.V(10))).Error(...) -> logSink.Error(...)
//
// The level of all other records gets reduced by the verbosity
// level of the logr.Logger and the result is negated. If it happens
// to be negative, then it gets replaced by zero because a LogSink
// is not expected to handled negative levels:
//
// slog.New(NewSlogHandler(logger)).Debug(...) -> logger.GetSink().Info(level=4, ...)
// slog.New(NewSlogHandler(logger)).Warning(...) -> logger.GetSink().Info(level=0, ...)
// slog.New(NewSlogHandler(logger)).Info(...) -> logger.GetSink().Info(level=0, ...)
// slog.New(NewSlogHandler(logger.V(4))).Info(...) -> logger.GetSink().Info(level=4, ...)
func NewSlogHandler(logger logr.Logger) slog.Handler {
// This offset currently (Go 1.21.0) works for slog.New(NewSlogHandler(...)).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(), levelBias: slog.Level(logger.GetV())}
}

0 comments on commit b785b9f

Please sign in to comment.