From 00614cddf1607cc090cf282e74a2d2abc83d3147 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Sun, 3 Sep 2023 20:44:32 +0200 Subject: [PATCH] klogr test: check vmodule support 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. --- contextual_test.go | 2 +- examples/go.mod | 2 +- examples/go.sum | 4 +-- go.mod | 2 +- go.sum | 4 +-- klogr.go | 3 +- klogr/klogr.go | 3 +- klogr_helper_test.go | 35 +++++++++++++++++++++ klogr_test.go | 67 ++++++++++++++++++++++++++++++++++++++++ textlogger/textlogger.go | 4 +-- 10 files changed, 112 insertions(+), 14 deletions(-) create mode 100644 klogr_helper_test.go create mode 100644 klogr_test.go diff --git a/contextual_test.go b/contextual_test.go index 80e14fa30..27aeb4e89 100644 --- a/contextual_test.go +++ b/contextual_test.go @@ -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): } func ExampleFlushLogger() { diff --git a/examples/go.mod b/examples/go.mod index 7aff88925..8d2fcf0ea 100644 --- a/examples/go.mod +++ b/examples/go.mod @@ -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 diff --git a/examples/go.sum b/examples/go.sum index bd1b6f63a..9e7639fc7 100644 --- a/examples/go.sum +++ b/examples/go.sum @@ -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= diff --git a/go.mod b/go.mod index 31aefba74..841d63b93 100644 --- a/go.mod +++ b/go.mod @@ -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 diff --git a/go.sum b/go.sum index 919fbadbc..6c918f419 100644 --- a/go.sum +++ b/go.sum @@ -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= diff --git a/klogr.go b/klogr.go index a3e5f9772..9c148dd7e 100644 --- a/klogr.go +++ b/klogr.go @@ -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{}) { diff --git a/klogr/klogr.go b/klogr/klogr.go index 73b0de25f..fe215deea 100644 --- a/klogr/klogr.go +++ b/klogr/klogr.go @@ -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{}) { diff --git a/klogr_helper_test.go b/klogr_helper_test.go new file mode 100644 index 000000000..8ae119f19 --- /dev/null +++ b/klogr_helper_test.go @@ -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.") + } +} diff --git a/klogr_test.go b/klogr_test.go new file mode 100644 index 000000000..199750318 --- /dev/null +++ b/klogr_test.go @@ -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) + } +} diff --git a/textlogger/textlogger.go b/textlogger/textlogger.go index 809b4553f..1299539d2 100644 --- a/textlogger/textlogger.go +++ b/textlogger/textlogger.go @@ -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{}) {