Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

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

Merged
merged 2 commits into from
Aug 22, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Jump to
Jump to file
Failed to load files.
Diff view
Diff view
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" |
thockin marked this conversation as resolved.
Show resolved Hide resolved
| 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
7 changes: 7 additions & 0 deletions logr.go
Original file line number Diff line number Diff line change
Expand Up @@ -314,6 +314,13 @@ func (l Logger) V(level int) Logger {
return l
}

// GetV returns the verbosity level of the logger. If the logger's LogSink is
// nil as in the Discard logger, this will always return 0.
func (l Logger) GetV() int {
thockin marked this conversation as resolved.
Show resolved Hide resolved
// 0 if l.sink nil because of the if check in V above.
return l.level
}

// WithValues returns a new Logger instance with additional key/value pairs.
// See Info for documentation on how key/value pairs work.
func (l Logger) WithValues(keysAndValues ...any) Logger {
Expand Down
46 changes: 29 additions & 17 deletions logr_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -172,23 +172,26 @@ func TestError(t *testing.T) {
}

func TestV(t *testing.T) {
sink := &testLogSink{}
logger := New(sink)

if l := logger.V(0); l.level != 0 {
t.Errorf("expected level 0, got %d", l.level)
}
if l := logger.V(93); l.level != 93 {
t.Errorf("expected level 93, got %d", l.level)
}
if l := logger.V(70).V(6); l.level != 76 {
t.Errorf("expected level 76, got %d", l.level)
}
if l := logger.V(-1); l.level != 0 {
t.Errorf("expected level 0, got %d", l.level)
}
if l := logger.V(1).V(-1); l.level != 1 {
t.Errorf("expected level 1, got %d", l.level)
for name, logger := range map[string]Logger{
"testLogSink": New(&testLogSink{}),
"Discard": Discard(),
"Zero": {},
} {
t.Run(name, func(t *testing.T) {
adjust := func(level int) int {
if logger.GetSink() == nil {
// The Discard and the zero Logger short-cut the V call and don't
thockin marked this conversation as resolved.
Show resolved Hide resolved
// change the verbosity level.
return 0
}
return level
}
expectEqual(t, "V(0)", 0, logger.V(0).GetV())
expectEqual(t, "V(93)", adjust(93), logger.V(93).GetV())
expectEqual(t, "V(70).V(6)", adjust(76), logger.V(70).V(6).GetV())
expectEqual(t, "V(-1)", 0, logger.V(-1).GetV())
expectEqual(t, "V(1).V(-1)", adjust(1), logger.V(1).V(-1).GetV())
})
}
}

Expand Down Expand Up @@ -439,3 +442,12 @@ func TestZeroValue(t *testing.T) {
l2.Error(errors.New("bar"), "some error")
_, _ = l.WithCallStackHelper()
}

func expectEqual[T comparable](tb testing.TB, msg string, expected, actual T) bool {
if expected == actual {
return true
}
tb.Helper()
tb.Errorf("Failure: %s: expected to get %v, got %v instead", msg, expected, actual)
return false
}
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())
thockin marked this conversation as resolved.
Show resolved Hide resolved
}
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
thockin marked this conversation as resolved.
Show resolved Hide resolved
}
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())
thockin marked this conversation as resolved.
Show resolved Hide resolved
}
}
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 {
thockin marked this conversation as resolved.
Show resolved Hide resolved
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)
}