TEST_LOG_LEVEL inconsistent (#7128)

Author: vladikkuzn

Makefile-test.mk

@@ -65,7 +65,7 @@ endif
 
 .PHONY: test
 test: gotestsum ## Run tests.
-	$(GOTESTSUM) --junitfile $(ARTIFACTS)/junit.xml -- $(GOFLAGS) $(GO_TEST_FLAGS) $(shell $(GO_CMD) list $(GO_TEST_TARGET)/... | grep -v '/test/') -coverpkg=$(GO_TEST_TARGET)/... -coverprofile $(ARTIFACTS)/cover.out
+	TEST_LOG_LEVEL=$(TEST_LOG_LEVEL) $(GOTESTSUM) --junitfile $(ARTIFACTS)/junit.xml -- $(GOFLAGS) $(GO_TEST_FLAGS) $(shell $(GO_CMD) list $(GO_TEST_TARGET)/... | grep -v '/test/') -coverpkg=$(GO_TEST_TARGET)/... -coverprofile $(ARTIFACTS)/cover.out
 
 .PHONY: test-integration
 test-integration: gomod-download envtest ginkgo dep-crds kueuectl ginkgo-top ## Run integration tests for all singlecluster suites.

pkg/util/testing/context.go

@@ -27,6 +27,8 @@ import (
 	ctrl "sigs.k8s.io/controller-runtime"
 )
 
+const DefaultLogLevel = -3
+
 func LogLevelWithDefault(defaultLogLevel int) int {
 	level, err := strconv.Atoi(os.Getenv("TEST_LOG_LEVEL"))
 	if err != nil {
@@ -36,8 +38,15 @@ func LogLevelWithDefault(defaultLogLevel int) int {
 }
 
 func NewLogger(t *testing.T) logr.Logger {
+	// Map TEST_LOG_LEVEL to testr verbosity so that lower (more negative)
+	// values increase verbosity consistently with integration/e2e logging.
+	level := LogLevelWithDefault(DefaultLogLevel)
+	// testr expects higher Verbosity for more logs. Our convention is
+	// more negative TEST_LOG_LEVEL means more verbose. Translate by negating
+	// the level, so -3 => 3. Positive levels result in negative verbosity
+	// which effectively disables extra V logs.
 	return testr.NewWithOptions(t, testr.Options{
-		Verbosity: LogLevelWithDefault(2),
+		Verbosity: -level,
 	})
 }
 

site/content/en/docs/contribution_guidelines/testing.md

@@ -72,8 +72,18 @@ E2E_K8S_FULL_VERSION=1.34.1 make test-e2e
 For running a subset of tests, see [Running subset of tests](#running-subset-of-integration-or-e2e-tests).
 
 ## Increase logging verbosity
-You can change log level (for example, set -5 to increase verbosity) using `TEST_LOG_LEVEL` variables.
-By default, `TEST_LOG_LEVEL=-3`.
+`TEST_LOG_LEVEL` controls test logging uniformly for all targets:
+
+- `go test`, `make test` (unit tests)
+- `make test-integration` (integration tests)
+- `make test-*-e2e` (e2e tests)
+
+Use more negative values for more verbose logs and higher (positive) values for quieter logs. For example:
+```shell
+TEST_LOG_LEVEL=-5 make test-integration   # more verbose
+TEST_LOG_LEVEL=-1 make test               # less verbose than default
+```
+Default is `TEST_LOG_LEVEL=-3`.
 
 ## Debug tests in VSCode
 It is possible to debug unit and integration tests in VSCode.

site/content/zh-CN/docs/contribution_guidelines/testing.md

@@ -72,8 +72,18 @@ E2E_K8S_FULL_VERSION=1.34.1 make test-e2e
 关于运行测试子集，请参阅 [运行测试子集](#running-subset-of-integration-or-e2e-tests)。
 
 ## 增加日志详细程度 {#increase-logging-verbosity}
-你可以使用 `TEST_LOG_LEVEL` 变量更改日志级别（例如，设置 -5 来增加详细程度）。
-默认情况下，`TEST_LOG_LEVEL=-3`。
+`TEST_LOG_LEVEL` 统一控制所有测试目标的日志级别：
+
+- `go test`、`make test`（单元测试）
+- `make test-integration`（集成测试）
+- `make test-*-e2e`（端到端测试）
+
+使用更小的负数获取更详细的日志，使用更大的正数降低日志量。例如：
+```shell
+TEST_LOG_LEVEL=-5 make test-integration   # 更详细
+TEST_LOG_LEVEL=-1 make test               # 比默认更少
+```
+默认值为 `TEST_LOG_LEVEL=-3`。
 
 ## 在 VSCode 中调试测试 {#debug-tests-in-vscode}
 可以在 VSCode 中调试单元测试和集成测试。

test/util/util.go

@@ -72,17 +72,13 @@ import (
 	"sigs.k8s.io/kueue/pkg/scheduler/preemption"
 	"sigs.k8s.io/kueue/pkg/util/admissioncheck"
 	utiltas "sigs.k8s.io/kueue/pkg/util/tas"
-	"sigs.k8s.io/kueue/pkg/util/testing"
+	utiltesting "sigs.k8s.io/kueue/pkg/util/testing"
 	"sigs.k8s.io/kueue/pkg/workload"
 	"sigs.k8s.io/kueue/pkg/workloadslicing"
 )
 
-const (
-	defaultLogLevel = -3
-)
-
 var SetupLogger = sync.OnceFunc(func() {
-	ctrl.SetLogger(NewTestingLogger(ginkgo.GinkgoWriter, testing.LogLevelWithDefault(defaultLogLevel)))
+	ctrl.SetLogger(NewTestingLogger(ginkgo.GinkgoWriter))
 })
 
 type objAsPtr[T any] interface {
@@ -116,7 +112,7 @@ func expectObjectToBeDeletedWithTimeout[PtrT objAsPtr[T], T any](ctx context.Con
 	}
 	gomega.EventuallyWithOffset(2, func(g gomega.Gomega) {
 		newObj := PtrT(new(T))
-		g.Expect(k8sClient.Get(ctx, client.ObjectKeyFromObject(o), newObj)).Should(testing.BeNotFoundError())
+		g.Expect(k8sClient.Get(ctx, client.ObjectKeyFromObject(o), newObj)).Should(utiltesting.BeNotFoundError())
 	}, timeout, Interval).Should(gomega.Succeed())
 }
 
@@ -375,15 +371,15 @@ func ExpectWorkloadToFinish(ctx context.Context, k8sClient client.Client, wlKey
 	gomega.EventuallyWithOffset(1, func(g gomega.Gomega) {
 		var wl kueue.Workload
 		g.Expect(k8sClient.Get(ctx, wlKey, &wl)).To(gomega.Succeed())
-		g.Expect(wl.Status.Conditions).To(testing.HaveConditionStatusTrue(kueue.WorkloadFinished), "it's finished")
+		g.Expect(wl.Status.Conditions).To(utiltesting.HaveConditionStatusTrue(kueue.WorkloadFinished), "it's finished")
 	}, LongTimeout, Interval).Should(gomega.Succeed())
 }
 
 func ExpectPodsReadyCondition(ctx context.Context, k8sClient client.Client, wlKey client.ObjectKey) {
 	gomega.EventuallyWithOffset(1, func(g gomega.Gomega) {
 		var wl kueue.Workload
 		g.Expect(k8sClient.Get(ctx, wlKey, &wl)).To(gomega.Succeed())
-		g.Expect(wl.Status.Conditions).To(testing.HaveConditionStatusTrue(kueue.WorkloadPodsReady), "pods are ready")
+		g.Expect(wl.Status.Conditions).To(utiltesting.HaveConditionStatusTrue(kueue.WorkloadPodsReady), "pods are ready")
 	}, LongTimeout, Interval).Should(gomega.Succeed())
 }
 
@@ -1006,11 +1002,12 @@ func ExpectPreemptedCondition(ctx context.Context, k8sClient client.Client, reas
 	}, Timeout, Interval).Should(gomega.Succeed())
 }
 
-func NewTestingLogger(writer io.Writer, level int) logr.Logger {
+func NewTestingLogger(writer io.Writer) logr.Logger {
 	opts := func(o *zap.Options) {
 		o.TimeEncoder = zapcore.RFC3339NanoTimeEncoder
 		o.ZapOpts = []zaplog.Option{zaplog.AddCaller()}
 	}
+	level := utiltesting.LogLevelWithDefault(utiltesting.DefaultLogLevel)
 	return zap.New(
 		zap.WriteTo(writer),
 		zap.UseDevMode(true),
@@ -1030,7 +1027,7 @@ func ExpectClusterQueuesToBeActive(ctx context.Context, c client.Client, cqs ...
 		readCq := &kueue.ClusterQueue{}
 		for _, cq := range cqs {
 			g.Expect(c.Get(ctx, client.ObjectKeyFromObject(cq), readCq)).To(gomega.Succeed())
-			g.Expect(readCq.Status.Conditions).To(testing.HaveConditionStatusTrue(kueue.ClusterQueueActive))
+			g.Expect(readCq.Status.Conditions).To(utiltesting.HaveConditionStatusTrue(kueue.ClusterQueueActive))
 		}
 	}, Timeout, Interval).Should(gomega.Succeed())
 }
@@ -1040,7 +1037,7 @@ func ExpectLocalQueuesToBeActive(ctx context.Context, c client.Client, lqs ...*k
 		readLq := &kueue.LocalQueue{}
 		for _, lq := range lqs {
 			g.Expect(c.Get(ctx, client.ObjectKeyFromObject(lq), readLq)).To(gomega.Succeed())
-			g.Expect(readLq.Status.Conditions).To(testing.HaveConditionStatusTrue(kueue.LocalQueueActive))
+			g.Expect(readLq.Status.Conditions).To(utiltesting.HaveConditionStatusTrue(kueue.LocalQueueActive))
 		}
 	}, Timeout, Interval).Should(gomega.Succeed())
 }