Skip to content

Commit

Permalink
klogr test: check vmodule support
Browse files Browse the repository at this point in the history
LogSink.Enabled is sensitive to stack unwinding. logr v1.2.0  gets this wrong
by calling LogSink.Enabled at different depths for Logger.Info and
Logger.Enabled, therefore this test fails with that version.

logr v1.3.0 changes the behavior to the more sane "LogSink.Enabled needs to
skip one level, regardless where it is called". The Discard log sink
implementation changed such that a discard logger doesn't have a sink at all
anymore. Go < 1.18 is no longer supported by logr.
  • Loading branch information
pohly committed Oct 26, 2023
1 parent 02e7b69 commit 00614cd
Show file tree
Hide file tree
Showing 10 changed files with 112 additions and 14 deletions.
2 changes: 1 addition & 1 deletion contextual_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ func ExampleSetLogger() {
// Output:
// logger after SetLogger: *klog.klogger
// logger after SetLoggerWithOptions with ContextualLogger(false): *klog.klogger
// logger after SetLoggerWithOptions with ContextualLogger(true): logr.discardLogSink
// logger after SetLoggerWithOptions with ContextualLogger(true): <nil>
}

func ExampleFlushLogger() {
Expand Down
2 changes: 1 addition & 1 deletion examples/go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@ module k8s.io/klog/examples
go 1.13

require (
github.com/go-logr/logr v1.2.2
github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278
github.com/go-logr/zapr v1.2.3
github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b
go.uber.org/goleak v1.1.12
Expand Down
4 changes: 2 additions & 2 deletions examples/go.sum
Original file line number Diff line number Diff line change
Expand Up @@ -3,9 +3,9 @@ github.com/benbjohnson/clock v1.1.0/go.mod h1:J11/hYXuz8f4ySSvYwY0FKfm+ezbsZBKZx
github.com/davecgh/go-spew v1.1.0/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/davecgh/go-spew v1.1.1 h1:vj9j/u1bqnvCEfJOwUhtlOARqs3+rkHYY13jYWTU97c=
github.com/davecgh/go-spew v1.1.1/go.mod h1:J7Y8YcW2NihsgmVo/mv3lAwl/skON4iLHjSsI+c5H38=
github.com/go-logr/logr v1.2.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
github.com/go-logr/logr v1.2.2 h1:ahHml/yUpnlb96Rp8HCvtYVPY8ZYpxq3g7UYchIYwbs=
github.com/go-logr/logr v1.2.2/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278 h1:BOXlp9BH2ptqvvDESrD159bFGSHogMpgREsBNEEhogM=
github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY=
github.com/go-logr/zapr v1.2.3 h1:a9vnzlIBPQBBkeaR9IuMUfmVOrQlkoC4YfPoFkX3T7A=
github.com/go-logr/zapr v1.2.3/go.mod h1:eIauM6P8qSvTw5o2ez6UEAfGjQKrxQTl5EoK+Qa2oG4=
github.com/golang/glog v0.0.0-20160126235308-23def4e6c14b h1:VKtxabqXZkF25pY9ekfRL6a582T4P37/31XEstQ5p58=
Expand Down
2 changes: 1 addition & 1 deletion go.mod
Original file line number Diff line number Diff line change
Expand Up @@ -2,4 +2,4 @@ module k8s.io/klog/v2

go 1.13

require github.com/go-logr/logr v1.2.0
require github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278
4 changes: 2 additions & 2 deletions go.sum
Original file line number Diff line number Diff line change
@@ -1,2 +1,2 @@
github.com/go-logr/logr v1.2.0 h1:QK40JKJyMdUDz+h+xvCsru/bJhvG0UxvePV0ufL/AcE=
github.com/go-logr/logr v1.2.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278 h1:BOXlp9BH2ptqvvDESrD159bFGSHogMpgREsBNEEhogM=
github.com/go-logr/logr v1.2.5-0.20230911064754-b75243e1a278/go.mod h1:9T104GzyrTigFIr8wt5mBrctHMim0Nb2HLGrmQ40KvY=
3 changes: 1 addition & 2 deletions klogr.go
Original file line number Diff line number Diff line change
Expand Up @@ -58,8 +58,7 @@ func (l *klogger) Info(level int, msg string, kvList ...interface{}) {
}

func (l *klogger) Enabled(level int) bool {
// Skip this function and logr.Logger.Info where Enabled is called.
return VDepth(l.callDepth+2, Level(level)).Enabled()
return VDepth(l.callDepth+1, Level(level)).Enabled()
}

func (l *klogger) Error(err error, msg string, kvList ...interface{}) {
Expand Down
3 changes: 1 addition & 2 deletions klogr/klogr.go
Original file line number Diff line number Diff line change
Expand Up @@ -144,8 +144,7 @@ func (l *klogger) Info(level int, msg string, kvList ...interface{}) {
}

func (l *klogger) Enabled(level int) bool {
// Skip this function and logr.Logger.Info where Enabled is called.
return klog.VDepth(l.callDepth+2, klog.Level(level)).Enabled()
return klog.VDepth(l.callDepth+1, klog.Level(level)).Enabled()
}

func (l *klogger) Error(err error, msg string, kvList ...interface{}) {
Expand Down
35 changes: 35 additions & 0 deletions klogr_helper_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
/*
Copyright 2023 The Kubernetes 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 klog_test

import (
"testing"

"k8s.io/klog/v2"
)

func testVerbosity(t *testing.T, logger klog.Logger) {
// This runs with -v=5 -vmodule=klog_helper_test=10.
logger.V(11).Info("v11 not visible from klogr_helper_test.go")
if logger.V(11).Enabled() {
t.Error("V(11).Enabled() in klogr_helper_test.go should have returned false.")
}
logger.V(10).Info("v10 visible from klogr_helper_test.go")
if !logger.V(10).Enabled() {
t.Error("V(10).Enabled() in klogr_helper_test.go should have returned true.")
}
}
67 changes: 67 additions & 0 deletions klogr_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,67 @@
/*
Copyright 2023 The Kubernetes 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 klog_test

import (
"bytes"
"flag"
"regexp"
"testing"

"k8s.io/klog/v2"
)

func TestVerbosity(t *testing.T) {
state := klog.CaptureState()
defer state.Restore()

var fs flag.FlagSet
klog.InitFlags(&fs)
if err := fs.Set("v", "5"); err != nil {
t.Fatalf("unexpected error: %v", err)
}
if err := fs.Set("vmodule", "klogr_helper_test=10"); err != nil {
t.Fatalf("unexpected error: %v", err)
}
if err := fs.Set("logtostderr", "false"); err != nil {
t.Fatalf("unexpected error: %v", err)
}
var buffer bytes.Buffer
klog.SetOutput(&buffer)
logger := klog.Background()

// -v=5 is in effect here.
logger.V(6).Info("v6 not visible from klogr_test.go")
if logger.V(6).Enabled() {
t.Error("V(6).Enabled() in klogr_test.go should have returned false.")
}
logger.V(5).Info("v5 visible from klogr_test.go")
if !logger.V(5).Enabled() {
t.Error("V(5).Enabled() in klogr_test.go should have returned true.")
}

// Now test with -v=5 -vmodule=klogr_helper_test=10.
testVerbosity(t, logger)

klog.Flush()
expected := `^.*v5 visible from klogr_test.go.*
.*v10 visible from klogr_helper_test.go.*
`
if !regexp.MustCompile(expected).Match(buffer.Bytes()) {
t.Errorf("Output did not match regular expression.\nOutput:\n%s\n\nRegular expression:\n%s\n", buffer.String(), expected)
}
}
4 changes: 1 addition & 3 deletions textlogger/textlogger.go
Original file line number Diff line number Diff line change
Expand Up @@ -77,9 +77,7 @@ func (l *tlogger) WithCallDepth(depth int) logr.LogSink {
}

func (l *tlogger) Enabled(level int) bool {
// Skip this function and the Logger.Info call, then
// also any additional stack frames from WithCallDepth.
return l.config.vstate.Enabled(verbosity.Level(level), 2+l.callDepth)
return l.config.vstate.Enabled(verbosity.Level(level), 1+l.callDepth)
}

func (l *tlogger) Info(_ int, msg string, kvList ...interface{}) {
Expand Down

0 comments on commit 00614cd

Please sign in to comment.