From f02c72eaf90c24a907ebb7c62ff0efd4e71e0dc8 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Fri, 3 Jun 2022 13:38:06 +0200 Subject: [PATCH] pods: more tolerant checking of poll tests Under load we might skip some of the poll events, leading to less output. Now we expect only at least one output line for polling. --- test/e2e/framework/internal/output/output.go | 23 +++++++---- test/e2e/framework/pod/wait_test.go | 41 ++++++++++++++++---- 2 files changed, 50 insertions(+), 14 deletions(-) diff --git a/test/e2e/framework/internal/output/output.go b/test/e2e/framework/internal/output/output.go index 6bea574e396..f40b40711ae 100644 --- a/test/e2e/framework/internal/output/output.go +++ b/test/e2e/framework/internal/output/output.go @@ -44,14 +44,19 @@ func TestGinkgoOutput(t *testing.T, runTests func(t *testing.T, reporter ginkgo. // Now check the output. actual := normalizeReport(*reporter) - // assert.Equal prints a useful diff if the slices are not - // equal. However, the diff does not show changes inside the - // strings. Therefore we also compare the individual fields. - if !assert.Equal(t, expected, actual) { - for i := 0; i < len(expected) && i < len(actual); i++ { - assert.Equal(t, expected[i].Output, actual[i].Output, "output from test #%d (%s)", i, expected[i].Name) + if assert.Equal(t, len(expected), len(actual), "Should have %d test results, got: %v", actual) { + for i := 0; i < len(expected); i++ { + output := actual[i].Output + if expected[i].NormalizeOutput != nil { + output = expected[i].NormalizeOutput(output) + } + assert.Equal(t, expected[i].Output, output, "output from test #%d (%s)", i, expected[i].Name) assert.Equal(t, expected[i].Stack, actual[i].Stack, "stack from test #%d (%s)", i, expected[i].Name) - assert.Equal(t, expected[i].Failure, actual[i].Failure, "failure from test #%d (%s)", i, expected[i].Name) + failure := actual[i].Failure + if expected[i].NormalizeFailure != nil { + failure = expected[i].NormalizeFailure(failure) + } + assert.Equal(t, expected[i].Failure, failure, "failure from test #%d (%s)", i, expected[i].Name) } } } @@ -67,6 +72,10 @@ type TestResult struct { // Stack is a normalized version (just file names, function parametes stripped) of // Ginkgo's FullStackTrace of a failure. Empty if no failure. Stack string + // Called to normalize the actual output string before comparison if non-nil. + NormalizeOutput func(string) string + // Called to normalize the actual failure string before comparison if non-nil. + NormalizeFailure func(string) string } type SuiteResults []TestResult diff --git a/test/e2e/framework/pod/wait_test.go b/test/e2e/framework/pod/wait_test.go index 99b8d8e25c6..da09ae2730e 100644 --- a/test/e2e/framework/pod/wait_test.go +++ b/test/e2e/framework/pod/wait_test.go @@ -17,6 +17,7 @@ limitations under the License. package pod_test import ( + "strings" "testing" "time" @@ -43,7 +44,6 @@ import ( // // // -// // This must be line #47. func runTests(t *testing.T, reporter ginkgo.Reporter) { @@ -76,11 +76,11 @@ func TestFailureOutput(t *testing.T) { expected := output.SuiteResults{ output.TestResult{ Name: "[Top Level] pod not found", + // "Ignoring NotFound..." will normally occur every two seconds, + // but we reduce it to one line because it might occur less often + // on a loaded system. Output: `INFO: Waiting up to 5s for pod "no-such-pod" in namespace "default" to be "running" INFO: Ignoring NotFound error while getting pod default/no-such-pod -INFO: Ignoring NotFound error while getting pod default/no-such-pod -INFO: Ignoring NotFound error while getting pod default/no-such-pod -INFO: Ignoring NotFound error while getting pod default/no-such-pod INFO: Unexpected error: <*fmt.wrapError>: { msg: "error while waiting for pod default/no-such-pod to be running: pods \"no-such-pod\" not found", @@ -110,6 +110,9 @@ k8s.io/kubernetes/test/e2e/framework/pod_test.runTests() wait_test.go:51 `, + NormalizeOutput: func(output string) string { + return trimDuplicateLines(output, "INFO: Ignoring NotFound error while getting pod default/no-such-pod") + }, Failure: `error while waiting for pod default/no-such-pod to be running: pods "no-such-pod" not found`, Stack: `k8s.io/kubernetes/test/e2e/framework/pod_test.glob..func1.1() wait_test.go:56 @@ -119,11 +122,11 @@ k8s.io/kubernetes/test/e2e/framework/pod_test.runTests() }, output.TestResult{ Name: "[Top Level] pod not running", + // "INFO: Pod ..." will normally occur every two seconds, + // but we reduce it to one line because it might occur less often + // on a loaded system. Output: `INFO: Waiting up to 5s for pod "pending-pod" in namespace "default" to be "running" INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: -INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: -INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: -INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: INFO: Unexpected error: wait for pod pending-pod running: <*pod.timeoutError>: { msg: "timed out while waiting for pod default/pending-pod to be running", @@ -214,6 +217,9 @@ k8s.io/kubernetes/test/e2e/framework/pod_test.runTests() wait_test.go:51 `, + NormalizeOutput: func(output string) string { + return trimDuplicateLines(output, `INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: `) + }, Failure: `wait for pod pending-pod running: timed out while waiting for pod default/pending-pod to be running`, Stack: `k8s.io/kubernetes/test/e2e/framework/pod_test.glob..func1.2() wait_test.go:60 @@ -225,3 +231,24 @@ k8s.io/kubernetes/test/e2e/framework/pod_test.runTests() output.TestGinkgoOutput(t, runTests, expected) } + +func trimDuplicateLines(output, prefix string) string { + lines := strings.Split(output, "\n") + trimming := false + validLines := 0 + for i := 0; i < len(lines); i++ { + if strings.HasPrefix(lines[i], prefix) { + // Keep the first line, and only that one. + if !trimming { + trimming = true + lines[validLines] = lines[i] + validLines++ + } + } else { + trimming = false + lines[validLines] = lines[i] + validLines++ + } + } + return strings.Join(lines[0:validLines], "\n") +}