From 766e7e07da99c4e08876b0087f1ab05f5af0f56e Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Mon, 14 Nov 2022 14:58:02 +0100 Subject: [PATCH] e2e framework: verify JUnit result, not the in-memory structs The old tests were no longer passing with Ginkgo v2.5.0. Instead of keeping the old approach of checking recorded spec results, now the tests actually cover what we care about most: the results recorded in JUnit. This also gets rid of having to repeat the stack backtrace twice (once as part of the output, once for the separate backtrace field). --- test/e2e/framework/internal/output/output.go | 135 +++++---- .../unittests/cleanup/cleanup_test.go | 103 ++++--- test/e2e/framework/log_test.go | 277 ++++++++++++------ test/e2e/framework/pod/wait_test.go | 88 +++--- test/e2e/framework/skipper/skipper_test.go | 28 +- 5 files changed, 385 insertions(+), 246 deletions(-) diff --git a/test/e2e/framework/internal/output/output.go b/test/e2e/framework/internal/output/output.go index cb70e9cd912..cc26c079677 100644 --- a/test/e2e/framework/internal/output/output.go +++ b/test/e2e/framework/internal/output/output.go @@ -17,84 +17,103 @@ limitations under the License. package output import ( + "encoding/xml" + "io/ioutil" + "path" "regexp" - "sort" - "strings" "testing" + "github.com/google/go-cmp/cmp" + "github.com/google/go-cmp/cmp/cmpopts" "github.com/onsi/ginkgo/v2" + "github.com/onsi/ginkgo/v2/reporters" "github.com/onsi/gomega" - "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" "k8s.io/kubernetes/test/e2e/framework" + "k8s.io/kubernetes/test/e2e/framework/internal/junit" ) -func TestGinkgoOutput(t *testing.T, expected SuiteResults, runSpecsArgs ...interface{}) { - // Run the Ginkgo suite with spec results collected via ReportAfterEach - // in adddition to the default one. To see what the full - // Ginkgo output looks like, run this test with "go test -v". +// TestGinkgoOutput runs the current suite and verifies that the generated +// JUnit file matches the expected result. +// +// The Ginkgo output on the console (aka the test suite log) does not get +// checked. It is usually less important for the CI and more relevant when +// using test suite interactively. To see what that Ginkgo output looks like, +// run tests with "go test -v". +func TestGinkgoOutput(t *testing.T, expected TestResult, runSpecsArgs ...interface{}) { + tmpdir := t.TempDir() + junitFile := path.Join(tmpdir, "junit.xml") gomega.RegisterFailHandler(framework.Fail) - var report []ginkgo.SpecReport - ginkgo.ReportAfterEach(func(spec ginkgo.SpecReport) { - report = append(report, spec) + ginkgo.ReportAfterSuite("write JUnit file", func(report ginkgo.Report) { + junit.WriteJUnitReport(report, junitFile) }) fakeT := &testing.T{} ginkgo.RunSpecs(fakeT, "Logging Suite", runSpecsArgs...) - // Now check the output. - actual := normalizeReport(report) + var actual reporters.JUnitTestSuites + data, err := ioutil.ReadFile(junitFile) + require.NoError(t, err) + err = xml.Unmarshal(data, &actual) + require.NoError(t, err) - 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 - 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) - 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) - } + if len(actual.TestSuites) != 1 { + t.Fatalf("expected one test suite, got %d, JUnit content:\n%s", len(actual.TestSuites), string(data)) + } + diff := cmp.Diff(expected.Suite, actual.TestSuites[0], + // Time varies. + // Name and Classname are "Logging Suite". + // Package includes a varying path, not interesting. + // Properties also too complicated to compare. + cmpopts.IgnoreFields(reporters.JUnitTestSuite{}, "Time", "Timestamp", "Name", "Package", "Properties"), + cmpopts.IgnoreFields(reporters.JUnitTestCase{}, "Time", "Classname"), + cmpopts.SortSlices(func(tc1, tc2 reporters.JUnitTestCase) bool { + return tc1.Name < tc2.Name + }), + cmpopts.AcyclicTransformer("simplify", func(in string) any { + out := simplify(in, expected) + // Sometimes cmp.Diff does not print the full string when it is long. + // Uncommenting this here may help debug differences. + // if len(out) > 100 { + // t.Logf("%s\n---------------------------------------\n%s\n", in, out) + // } + + // Same idea as in + // https://github.com/google/go-cmp/issues/192#issuecomment-605346277: + // it forces cmp.Diff to diff strings line-by-line, + // even when it normally wouldn't. The downside is + // that the output is harder to turn back into the + // expected reference string. + // if len(out) > 50 { + // return strings.Split(out, "\n") + // } + + return out + }), + ) + if diff != "" { + t.Fatalf("Simplified JUnit report not as expected (-want, +got):\n%s\n\nFull XML:\n%s", diff, string(data)) } } -// TestResult is the outcome of one It spec. +// TestResult is the expected outcome of the suite, with additional parameters that +// determine equality. 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 parameters 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. + // Called to normalize all output strings 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 + + // All test cases and overall suite results. + Suite reporters.JUnitTestSuite } -type SuiteResults []TestResult - -func normalizeReport(report []ginkgo.SpecReport) SuiteResults { - var results SuiteResults - for _, spec := range report { - results = append(results, TestResult{ - Name: strings.Join(spec.ContainerHierarchyTexts, " ") + " " + spec.LeafNodeText, - Output: normalizeLocation(stripAddresses(stripTimes(spec.CapturedGinkgoWriterOutput))), - Failure: stripAddresses(stripTimes(spec.Failure.Message)), - Stack: normalizeLocation(spec.Failure.Location.FullStackTrace), - }) +func simplify(in string, expected TestResult) string { + out := normalizeLocation(in) + out = stripTimes(out) + out = stripAddresses(out) + if expected.NormalizeOutput != nil { + out = expected.NormalizeOutput(out) } - sort.Slice(results, func(i, j int) bool { - return strings.Compare(results[i].Name, results[j].Name) < 0 - }) - return results + return out } // timePrefix matches "Jul 17 08:08:25.950: " at the beginning of each line. @@ -103,13 +122,13 @@ var timePrefix = regexp.MustCompile(`(?m)^[[:alpha:]]{3} +[[:digit:]]{1,2} +[[:d // elapsedSuffix matches "Elapsed: 16.189µs" var elapsedSuffix = regexp.MustCompile(`Elapsed: [[:digit:]]+(\.[[:digit:]]+)?(µs|ns|ms|s|m)`) -// timeSuffix matches "09/06/22 15:36:43.445" as printed by Ginkgo v2 for log output. -var timeSuffix = regexp.MustCompile(`(?m)[[:space:]][[:digit:]]{2}/[[:digit:]]{2}/[[:digit:]]{2} [[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}(\.[[:digit:]]{1,3})?$`) +// timeSuffix matches "@ 09/06/22 15:36:43.44 (5.001s)" as printed by Ginkgo v2 for log output, with the duration being optional. +var timeSuffix = regexp.MustCompile(`(?m)@[[:space:]][[:digit:]]{2}/[[:digit:]]{2}/[[:digit:]]{2} [[:digit:]]{2}:[[:digit:]]{2}:[[:digit:]]{2}(\.[[:digit:]]{1,3})?( \([[:digit:]]+(\.[[:digit:]]+)?(µs|ns|ms|s|m)\))?$`) func stripTimes(in string) string { out := timePrefix.ReplaceAllString(in, "") out = elapsedSuffix.ReplaceAllString(out, "Elapsed: ") - out = timeSuffix.ReplaceAllString(out, "") + out = timeSuffix.ReplaceAllString(out, "