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

@@ -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

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: <elapsed>
-INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed>
-INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <elapsed>
-INFO: Pod "pending-pod": Phase="", Reason="", readiness=false. Elapsed: <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: <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")
+}