Skip to content

Commit

Permalink
Use same call depth for Enabled, Info, Error
Browse files Browse the repository at this point in the history
klog does stack unwinding in `LogSink.Enabled` to implement per-source code
verbosity thresholds (`-vmodule`). This worked for `logger.Info` and
`logger.Error` because the code was written such that it matches how logr is
implemented (Logger.Info -> Logger.Enabled -> LogSink.Enabled).

It did not work for direct calls (`if logger.Enabled`) because then the call
chain is `Logger.Enabled -> LogSink.Enabled`.  Now it uses the same
depth (as passed to LogSink.Init) for all paths to Enabled.
  • Loading branch information
pohly authored and thockin committed Sep 4, 2023
1 parent 7bf6c82 commit 6754e58
Show file tree
Hide file tree
Showing 2 changed files with 51 additions and 1 deletion.
8 changes: 7 additions & 1 deletion logr.go
Original file line number Diff line number Diff line change
Expand Up @@ -258,6 +258,12 @@ type Logger struct {
// Enabled tests whether this Logger is enabled. For example, commandline
// flags might be used to set the logging verbosity and disable some info logs.
func (l Logger) Enabled() bool {
// Some implementations of LogSink look at the caller in Enabled (e.g.
// different verbosity levels per package or file), but we only pass one
// CallDepth in (via Init). This means that all calls from Logger to the
// LogSink's Enabled, Info, and Error methods must have the same number of
// frames. In other words, Logger methods can't call other Logger methods
// which call these LogSink methods unless we do it the same in all paths.
return l.sink != nil && l.sink.Enabled(l.level)
}

Expand All @@ -271,7 +277,7 @@ func (l Logger) Info(msg string, keysAndValues ...any) {
if l.sink == nil {
return
}
if l.Enabled() {
if l.sink.Enabled(l.level) { // see comment in Enabled
if withHelper, ok := l.sink.(CallStackHelperLogSink); ok {
withHelper.GetCallStackHelper()()
}
Expand Down
44 changes: 44 additions & 0 deletions logr_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@ import (
"errors"
"fmt"
"reflect"
"runtime"
"testing"
)

Expand Down Expand Up @@ -443,6 +444,49 @@ func TestZeroValue(t *testing.T) {
_, _ = l.WithCallStackHelper()
}

func TestCallDepthConsistent(t *testing.T) {
sink := &testLogSink{}

depth := 0
expect := "github.com/go-logr/logr.TestCallDepthConsistent"
sink.fnInit = func(ri RuntimeInfo) {
depth = ri.CallDepth + 1 // 1 for these function pointers
if caller := getCaller(depth); caller != expect {
t.Errorf("identified wrong caller %q", caller)
}

}
sink.fnEnabled = func(_ int) bool {
if caller := getCaller(depth); caller != expect {
t.Errorf("identified wrong caller %q", caller)
}
return true
}
sink.fnError = func(_ error, _ string, _ ...any) {
if caller := getCaller(depth); caller != expect {
t.Errorf("identified wrong caller %q", caller)
}
}
l := New(sink)

l.Enabled()
l.Info("msg")
l.Error(nil, "msg")
}

func getCaller(depth int) string {
// +1 for this frame, +1 for Info/Error/Enabled.
pc, _, _, ok := runtime.Caller(depth + 2)
if !ok {
return "<runtime.Caller failed>"
}
if fp := runtime.FuncForPC(pc); fp == nil {
return "<runtime.FuncForPC failed>"
} else {

Check warning on line 485 in logr_test.go

View workflow job for this annotation

GitHub Actions / lint

indent-error-flow: if block ends with a return statement, so drop this else and outdent its block (move short variable declaration to its own line if necessary) (revive)
return fp.Name()
}
}

func expectEqual[T comparable](tb testing.TB, msg string, expected, actual T) bool {
if expected == actual {
return true
Expand Down

0 comments on commit 6754e58

Please sign in to comment.