diff --git a/ktesting/helper_test.go b/ktesting/helper_test.go new file mode 100644 index 00000000..e011861c --- /dev/null +++ b/ktesting/helper_test.go @@ -0,0 +1,17 @@ +/* +Copyright 2025 The Kubernetes Authors. + +SPDX-License-Identifier: Apache-2.0 +*/ + +package ktesting_test + +import ( + "k8s.io/klog/v2" +) + +func callDepthHelper(logger klog.Logger, msg string) { + helper, logger := logger.WithCallStackHelper() + helper() + logger.Info(msg) +} diff --git a/ktesting/main_test.go b/ktesting/main_test.go new file mode 100644 index 00000000..0f523f47 --- /dev/null +++ b/ktesting/main_test.go @@ -0,0 +1,19 @@ +/* +Copyright 2025 The Kubernetes Authors. + +SPDX-License-Identifier: Apache-2.0 +*/ + +package ktesting_test + +import ( + "flag" + "testing" + + _ "k8s.io/klog/v2/ktesting/init" +) + +func TestMain(m *testing.M) { + flag.Parse() + m.Run() +} diff --git a/ktesting/testinglogger.go b/ktesting/testinglogger.go index 31569357..e8ffd411 100644 --- a/ktesting/testinglogger.go +++ b/ktesting/testinglogger.go @@ -307,7 +307,7 @@ func (l tlogger) Info(level int, msg string, kvList ...interface{}) { } func (l tlogger) Enabled(level int) bool { - return l.shared.config.vstate.Enabled(verbosity.Level(level), 1) + return l.shared.config.vstate.Enabled(verbosity.Level(level), l.shared.callDepth+1) } func (l tlogger) Error(err error, msg string, kvList ...interface{}) { diff --git a/ktesting/testinglogger_test.go b/ktesting/testinglogger_test.go index fc22e62b..d35401d1 100644 --- a/ktesting/testinglogger_test.go +++ b/ktesting/testinglogger_test.go @@ -12,8 +12,10 @@ import ( "errors" "flag" "fmt" + "os/exec" "regexp" "runtime" + "strings" "sync" "testing" "time" @@ -136,9 +138,36 @@ func TestInfo(t *testing.T) { } } -func TestCallDepth(t *testing.T) { - logger := ktesting.NewLogger(t, ktesting.NewConfig()) +// TestCallDepthOutput produces output which gets checked by TestCallDepthVerify. +func TestCallDepthOutput(t *testing.T) { + logger := ktesting.NewLogger(t, ktesting.DefaultConfig) logger.Info("hello world") + logger.V(1).Info("you shouldn't see this with -testing.v=0") + callDepthHelper(logger.V(1), "you should see this with -testing.v=0 -testing.vmodule=helper_test=1") +} + +// TestCallDepthVerify runs TestCallDepth with appropriate flags and checks the output. +// +// Invoking `go test` is necessary because we want to verify that it correctly unwinds the stack, +// which means that we have to let it print output. We cannot intercept that log output from +// within a test. +func TestCallDepthVerify(t *testing.T) { + cmd, args := "go", "test -v -run=TestCallDepthOutput k8s.io/klog/v2/ktesting -args -testing.v=0 -testing.vmodule=helper_test=1" + output, err := exec.Command("go", strings.Split(args, " ")...).CombinedOutput() + if err != nil { + t.Fatalf("failed to %s %s: %v", cmd, args, err) + } + t.Log("Got output:\n", string(output)) + + expect := `(?m)^[[:space:]]*testinglogger_test.go:.*hello world$ +^[[:space:]]*testinglogger_test.go:.*you should see this` + matched, err := regexp.MatchString(expect, string(output)) + if err != nil { + t.Fatalf("failed to parse regexp: %v\n\n%s", err, expect) + } + if !matched { + t.Fatalf("expected output\n%s\n\nto match regexp\n%s", string(output), expect) + } } type logToBuf struct {