e2e: refactor Ginkgo output testing

The helper code will be useful for testing other parts of the e2e framework.

test/e2e/framework/internal/output/output.go

@@ -0,0 +1,130 @@
+/*
+Copyright 2022 The Kubernetes Authors.
+
+Licensed under the Apache License, Version 2.0 (the "License");
+you may not use this file except in compliance with the License.
+You may obtain a copy of the License at
+
+    http://www.apache.org/licenses/LICENSE-2.0
+
+Unless required by applicable law or agreed to in writing, software
+distributed under the License is distributed on an "AS IS" BASIS,
+WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+See the License for the specific language governing permissions and
+limitations under the License.
+*/
+
+package output
+
+import (
+	"regexp"
+	"sort"
+	"strings"
+	"testing"
+
+	"github.com/onsi/ginkgo"
+	"github.com/onsi/ginkgo/config"
+	"github.com/onsi/ginkgo/reporters"
+	"github.com/onsi/gomega"
+	"github.com/stretchr/testify/assert"
+
+	"k8s.io/kubernetes/test/e2e/framework"
+)
+
+func TestGinkgoOutput(t *testing.T, runTests func(t *testing.T, reporter ginkgo.Reporter), expected SuiteResults) {
+	// Run the Ginkgo suite with output collected by a custom
+	// reporter in adddition to the default one. To see what the full
+	// Ginkgo report looks like, run this test with "go test -v".
+	config.DefaultReporterConfig.FullTrace = true
+	gomega.RegisterFailHandler(framework.Fail)
+	fakeT := &testing.T{}
+	reporter := reporters.NewFakeReporter()
+	runTests(fakeT, reporter)
+
+	// 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)
+			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)
+		}
+	}
+}
+
+// TestResult is the outcome of one It spec.
+type TestResult struct {
+	// Name is the full string for a Ginkgo It, including the "[Top Level]" prefix.
+	Name string
+	// Output written to GinkgoWriter during test.
+	Output string
+	// Failure is SpecSummary.Failure.Message with varying parts stripped.
+	Failure string
+	// Stack is a normalized version (just file names, function parametes stripped) of
+	// Ginkgo's FullStackTrace of a failure. Empty if no failure.
+	Stack string
+}
+
+type SuiteResults []TestResult
+
+func normalizeReport(report reporters.FakeReporter) SuiteResults {
+	var results SuiteResults
+	for _, spec := range report.SpecSummaries {
+		results = append(results, TestResult{
+			Name:    strings.Join(spec.ComponentTexts, " "),
+			Output:  normalizeLocation(stripAddresses(stripTimes(spec.CapturedOutput))),
+			Failure: stripAddresses(stripTimes(spec.Failure.Message)),
+			Stack:   normalizeLocation(spec.Failure.Location.FullStackTrace),
+		})
+	}
+	sort.Slice(results, func(i, j int) bool {
+		return strings.Compare(results[i].Name, results[j].Name) < 0
+	})
+	return results
+}
+
+// timePrefix matches "Jul 17 08:08:25.950: " at the beginning of each line.
+var timePrefix = regexp.MustCompile(`(?m)^[[:alpha:]]{3} +[[:digit:]]{1,2} +[[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}.[[:digit:]]{3}: `)
+
+func stripTimes(in string) string {
+	out := timePrefix.ReplaceAllString(in, "")
+	return out
+}
+
+// instanceAddr matches " | 0xc0003dec60>"
+var instanceAddr = regexp.MustCompile(` \| 0x[0-9a-fA-F]+>`)
+
+func stripAddresses(in string) string {
+	return instanceAddr.ReplaceAllString(in, ">")
+}
+
+// stackLocation matches "<some path>/<file>.go:75 +0x1f1" after a slash (built
+// locally) or one of a few relative paths (built in the Kubernetes CI).
+var stackLocation = regexp.MustCompile(`(?:/|vendor/|test/|GOROOT/).*/([[:^space:]]+.go:[[:digit:]]+)( \+0x[0-9a-fA-F]+)?`)
+
+// functionArgs matches "<function name>(...)".
+var functionArgs = regexp.MustCompile(`([[:alpha:]]+)\(.*\)`)
+
+// testFailureOutput matches TestFailureOutput() and its source followed by additional stack entries:
+//
+// k8s.io/kubernetes/test/e2e/framework/pod/pod_test.TestFailureOutput(0xc000558800)
+//	/nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/pod/wait_test.go:73 +0x1c9
+// testing.tRunner(0xc000558800, 0x1af2848)
+// 	/nvme/gopath/go/src/testing/testing.go:865 +0xc0
+// created by testing.(*T).Run
+//	/nvme/gopath/go/src/testing/testing.go:916 +0x35a
+var testFailureOutput = regexp.MustCompile(`(?m)^k8s.io/kubernetes/test/e2e/framework/internal/output\.TestGinkgoOutput\(.*\n\t.*(\n.*\n\t.*)*`)
+
+// normalizeLocation removes path prefix and function parameters and certain stack entries
+// that we don't care about.
+func normalizeLocation(in string) string {
+	out := in
+	out = stackLocation.ReplaceAllString(out, "$1")
+	out = functionArgs.ReplaceAllString(out, "$1()")
+	out = testFailureOutput.ReplaceAllString(out, "")
+	return out
+}

test/e2e/framework/log_test.go

@@ -18,18 +18,12 @@ package framework_test
 
 import (
 	"errors"
-	"regexp"
-	"sort"
-	"strings"
 	"testing"
 
 	"github.com/onsi/ginkgo"
-	"github.com/onsi/ginkgo/config"
-	"github.com/onsi/ginkgo/reporters"
-	"github.com/onsi/gomega"
-	"github.com/stretchr/testify/assert"
 
 	"k8s.io/kubernetes/test/e2e/framework"
+	"k8s.io/kubernetes/test/e2e/framework/internal/output"
 )
 
 // The line number of the following code is checked in TestFailureOutput below.
@@ -40,6 +34,12 @@ import (
 //
 //
 //
+//
+//
+//
+//
+//
+//
 // This must be line #43.
 
 func runTests(t *testing.T, reporter ginkgo.Reporter) {
@@ -73,18 +73,6 @@ var _ = ginkgo.Describe("log", func() {
 })
 
 func TestFailureOutput(t *testing.T) {
-	// Run the Ginkgo suite with output collected by a custom
-	// reporter in adddition to the default one. To see what the full
-	// Ginkgo report looks like, run this test with "go test -v".
-	config.DefaultReporterConfig.FullTrace = true
-	gomega.RegisterFailHandler(framework.Fail)
-	fakeT := &testing.T{}
-	reporter := reporters.NewFakeReporter()
-	runTests(fakeT, reporter)
-
-	// Now check the output.
-	actual := normalizeReport(*reporter)
-
 	// output from AfterEach
 	commonOutput := `
 
@@ -104,10 +92,10 @@ k8s.io/kubernetes/test/e2e/framework_test.runTests()
 `
 
 	// Sorted by name!
-	expected := suiteResults{
+	expected := output.SuiteResults{
-		testResult{
+		output.TestResult{
-			name: "[Top Level] log asserts",
+			Name: "[Top Level] log asserts",
-			output: `INFO: before
+			Output: `INFO: before
 FAIL: false is never true
 Expected
     <bool>: false
@@ -119,20 +107,20 @@ k8s.io/kubernetes/test/e2e/framework_test.glob..func1.3()
 	log_test.go:60
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47` + commonOutput,
-			failure: `false is never true
+			Failure: `false is never true
 Expected
     <bool>: false
 to equal
     <bool>: true`,
-			stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.3()
+			Stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.3()
 	log_test.go:60
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47
 `,
 		},
-		testResult{
+		output.TestResult{
-			name: "[Top Level] log equal",
+			Name: "[Top Level] log equal",
-			output: `INFO: before
+			Output: `INFO: before
 FAIL: of course it's not equal...
 Expected
     <int>: 0
@@ -144,20 +132,20 @@ k8s.io/kubernetes/test/e2e/framework_test.glob..func1.5()
 	log_test.go:67
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47` + commonOutput,
-			failure: `of course it's not equal...
+			Failure: `of course it's not equal...
 Expected
     <int>: 0
 to equal
     <int>: 1`,
-			stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.5()
+			Stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.5()
 	log_test.go:67
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47
 `,
 		},
-		testResult{
+		output.TestResult{
-			name: "[Top Level] log error",
+			Name: "[Top Level] log error",
-			output: `INFO: before
+			Output: `INFO: before
 FAIL: hard-coded error
 Unexpected error:
     <*errors.errorString>: {
@@ -171,22 +159,22 @@ k8s.io/kubernetes/test/e2e/framework_test.glob..func1.4()
 	log_test.go:64
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47` + commonOutput,
-			failure: `hard-coded error
+			Failure: `hard-coded error
 Unexpected error:
     <*errors.errorString>: {
         s: "an error with a long, useless description",
     }
     an error with a long, useless description
 occurred`,
-			stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.4()
+			Stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.4()
 	log_test.go:64
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47
 `,
 		},
-		testResult{
+		output.TestResult{
-			name: "[Top Level] log fails",
+			Name: "[Top Level] log fails",
-			output: `INFO: before
+			Output: `INFO: before
 FAIL: I'm failing.
 
 Full Stack Trace
@@ -194,91 +182,14 @@ k8s.io/kubernetes/test/e2e/framework_test.glob..func1.2()
 	log_test.go:57
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47` + commonOutput,
-			failure: "I'm failing.",
+			Failure: "I'm failing.",
-			stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.2()
+			Stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.2()
 	log_test.go:57
 k8s.io/kubernetes/test/e2e/framework_test.runTests()
 	log_test.go:47
 `,
 		},
 	}
-	// assert.Equal prints a useful diff if the slices are not
+
-	// equal. However, the diff does not show changes inside the
+	output.TestGinkgoOutput(t, runTests, expected)
-	// 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)
-			assert.Equal(t, expected[i].stack, actual[i].stack, "stack from test #%d: %s", i, expected[i].name)
-		}
-	}
-}
-
-type testResult struct {
-	name string
-	// output written to GinkgoWriter during test.
-	output string
-	// failure is SpecSummary.Failure.Message with varying parts stripped.
-	failure string
-	// stack is a normalized version (just file names, function parametes stripped) of
-	// Ginkgo's FullStackTrace of a failure. Empty if no failure.
-	stack string
-}
-
-type suiteResults []testResult
-
-func normalizeReport(report reporters.FakeReporter) suiteResults {
-	var results suiteResults
-	for _, spec := range report.SpecSummaries {
-		results = append(results, testResult{
-			name:    strings.Join(spec.ComponentTexts, " "),
-			output:  normalizeLocation(stripAddresses(stripTimes(spec.CapturedOutput))),
-			failure: stripAddresses(stripTimes(spec.Failure.Message)),
-			stack:   normalizeLocation(spec.Failure.Location.FullStackTrace),
-		})
-	}
-	sort.Slice(results, func(i, j int) bool {
-		return strings.Compare(results[i].name, results[j].name) < 0
-	})
-	return results
-}
-
-// timePrefix matches "Jul 17 08:08:25.950: " at the beginning of each line.
-var timePrefix = regexp.MustCompile(`(?m)^[[:alpha:]]{3} +[[:digit:]]{1,2} +[[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}.[[:digit:]]{3}: `)
-
-func stripTimes(in string) string {
-	return timePrefix.ReplaceAllString(in, "")
-}
-
-// instanceAddr matches " | 0xc0003dec60>"
-var instanceAddr = regexp.MustCompile(` \| 0x[0-9a-fA-F]+>`)
-
-func stripAddresses(in string) string {
-	return instanceAddr.ReplaceAllString(in, ">")
-}
-
-// stackLocation matches "<some path>/<file>.go:75 +0x1f1" after a slash (built
-// locally) or one of a few relative paths (built in the Kubernetes CI).
-var stackLocation = regexp.MustCompile(`(?:/|vendor/|test/|GOROOT/).*/([[:^space:]]+.go:[[:digit:]]+)( \+0x[0-9a-fA-F]+)?`)
-
-// functionArgs matches "<function name>(...)".
-var functionArgs = regexp.MustCompile(`([[:alpha:]]+)\(.*\)`)
-
-// testFailureOutput matches TestFailureOutput() and its source followed by additional stack entries:
-//
-// k8s.io/kubernetes/test/e2e/framework_test.TestFailureOutput(0xc000558800)
-//	/nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/log_test.go:73 +0x1c9
-// testing.tRunner(0xc000558800, 0x1af2848)
-// 	/nvme/gopath/go/src/testing/testing.go:865 +0xc0
-// created by testing.(*T).Run
-//	/nvme/gopath/go/src/testing/testing.go:916 +0x35a
-var testFailureOutput = regexp.MustCompile(`(?m)^k8s.io/kubernetes/test/e2e/framework_test\.TestFailureOutput\(.*\n\t.*(\n.*\n\t.*)*`)
-
-// normalizeLocation removes path prefix and function parameters and certain stack entries
-// that we don't care about.
-func normalizeLocation(in string) string {
-	out := in
-	out = stackLocation.ReplaceAllString(out, "$1")
-	out = functionArgs.ReplaceAllString(out, "$1()")
-	out = testFailureOutput.ReplaceAllString(out, "")
-	return out
 }