diff --git a/test/e2e/e2e.go b/test/e2e/e2e.go index f587ce054dc..626ddd46a72 100644 --- a/test/e2e/e2e.go +++ b/test/e2e/e2e.go @@ -95,8 +95,18 @@ var _ = ginkgo.SynchronizedAfterSuite(func() { // generated in this directory, and cluster logs will also be saved. // This function is called on each Ginkgo node in parallel mode. func RunE2ETests(t *testing.T) { + // InitLogs disables contextual logging, without a way to enable it again + // in the E2E test suite because it has no feature gates. It used to have a + // misleading --feature-gates parameter but that didn't do what users + // and developers expected (define which features the cluster supports) + // and therefore got removed. + // + // Because contextual logging is useful and should get tested, it gets + // re-enabled here unconditionally. logs.InitLogs() defer logs.FlushLogs() + klog.EnableContextualLogging(true) + progressReporter = e2ereporters.NewProgressReporter(framework.TestContext.ProgressReportURL) gomega.RegisterFailHandler(framework.Fail) diff --git a/test/e2e/framework/internal/output/output.go b/test/e2e/framework/internal/output/output.go index cc1d503dc19..c778a72576e 100644 --- a/test/e2e/framework/internal/output/output.go +++ b/test/e2e/framework/internal/output/output.go @@ -44,7 +44,7 @@ func TestGinkgoOutput(t *testing.T, expected SuiteResults, runSpecsArgs ...inter // Now check the output. actual := normalizeReport(report) - if assert.Equal(t, len(expected), len(actual), "Should have %d test results, got: %v", actual) { + if assert.Equal(t, len(expected), len(actual), "Should have %d test results, got: %v", len(expected), actual) { for i := 0; i < len(expected); i++ { assert.Equal(t, expected[i].Name, actual[i].Name, "name from test #%d", i) output := actual[i].Output @@ -127,6 +127,9 @@ var stackLocation = regexp.MustCompile(`(?:/|vendor/|test/|GOROOT/).*/([[:^space // functionArgs matches "(...)". var functionArgs = regexp.MustCompile(`([[:alpha:]]+)\(.*\)`) +// klogPrefix matches "I0822 16:10:39.343790 989127 " +var klogPrefix = regexp.MustCompile(`(?m)^[IEF][[:digit:]]{4} [[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}\.[[:digit:]]{6}[[:space:]]+[[:digit:]]+ `) + // testFailureOutput matches TestFailureOutput() and its source followed by additional stack entries: // // k8s.io/kubernetes/test/e2e/framework/pod/pod_test.TestFailureOutput(0xc000558800) @@ -149,5 +152,6 @@ func normalizeLocation(in string) string { out = stackLocation.ReplaceAllString(out, "$1") out = functionArgs.ReplaceAllString(out, "$1()") out = testFailureOutput.ReplaceAllString(out, "") + out = klogPrefix.ReplaceAllString(out, " ") return out } diff --git a/test/e2e/framework/log_test.go b/test/e2e/framework/log_test.go index 5009b597682..e1efb52131b 100644 --- a/test/e2e/framework/log_test.go +++ b/test/e2e/framework/log_test.go @@ -18,10 +18,15 @@ package framework_test import ( "errors" + "os" + "path" "testing" "github.com/onsi/ginkgo/v2" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + "k8s.io/klog/v2" "k8s.io/kubernetes/test/e2e/framework" "k8s.io/kubernetes/test/e2e/framework/internal/output" ) @@ -31,11 +36,6 @@ import ( // Here are some intentionally blank lines that can be removed to compensate // for future additional import statements. // -// -// -// -// -// // This must be line #39. // This is included in a stack backtrace. @@ -69,6 +69,10 @@ var _ = ginkgo.Describe("log", func() { ginkgo.It("fails with helper", func() { failHelper("I'm failing with helper.") }) + ginkgo.It("redirects klog", func() { + klog.Info("hello world") + klog.Error(nil, "not really an error") + }) }) func TestFailureOutput(t *testing.T) { @@ -172,7 +176,43 @@ k8s.io/kubernetes/test/e2e/framework_test.glob..func1.7() k8s.io/kubernetes/test/e2e/framework_test.glob..func1.7() log_test.go:70`, }, + output.TestResult{ + Name: "log redirects klog", + Output: `INFO: before + log_test.go:73] hello world + log_test.go:74] not really an error` + commonOutput, + Failure: `true is never false either +Expected + : true +to equal + : false`, + Stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.2() + log_test.go:52`, + }, } + // Simulate the test setup as in a normal e2e test which uses the + // framework, but remember to restore klog settings when we are done. + state := klog.CaptureState() + defer state.Restore() + var testContext framework.TestContextType + framework.AfterReadingAllFlags(&testContext) + + oldStderr := os.Stderr + tmp := t.TempDir() + filename := path.Join(tmp, "stderr.log") + f, err := os.Create(filename) + require.NoError(t, err, "create temporary file") + os.Stderr = f + defer func() { + os.Stderr = oldStderr + + err := f.Close() + require.NoError(t, err, "close temporary file") + actual, err := os.ReadFile(filename) + require.NoError(t, err, "read temporary file") + assert.Empty(t, string(actual), "no output on stderr") + }() + output.TestGinkgoOutput(t, expected) } diff --git a/test/e2e/framework/test_context.go b/test/e2e/framework/test_context.go index f4bb80e0d8a..97413dd01b8 100644 --- a/test/e2e/framework/test_context.go +++ b/test/e2e/framework/test_context.go @@ -453,6 +453,7 @@ func AfterReadingAllFlags(t *TestContextType) { fs.Set("logtostderr", "false") fs.Set("alsologtostderr", "false") fs.Set("one_output", "true") + fs.Set("stderrthreshold", "10" /* higher than any of the severities -> none pass the threshold */) klog.SetOutput(ginkgo.GinkgoWriter) // Only set a default host if one won't be supplied via kubeconfig