From 0e0e51d79257837b57c6b087f23b2cf46bdffb0e Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 11 May 2022 17:55:22 +0200 Subject: [PATCH] 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 | 130 ++++++++++++++++ test/e2e/framework/log_test.go | 149 ++++--------------- 2 files changed, 160 insertions(+), 119 deletions(-) create mode 100644 test/e2e/framework/internal/output/output.go diff --git a/test/e2e/framework/internal/output/output.go b/test/e2e/framework/internal/output/output.go new file mode 100644 index 00000000000..8cd51d1d8ca --- /dev/null +++ b/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 "/.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 "(...)". +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 +} diff --git a/test/e2e/framework/log_test.go b/test/e2e/framework/log_test.go index 84c17dea7db..ab14cc315ba 100644 --- a/test/e2e/framework/log_test.go +++ b/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{ - testResult{ - name: "[Top Level] log asserts", - output: `INFO: before + expected := output.SuiteResults{ + output.TestResult{ + Name: "[Top Level] log asserts", + Output: `INFO: before FAIL: false is never true Expected : 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 : false to equal : 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{ - name: "[Top Level] log equal", - output: `INFO: before + output.TestResult{ + Name: "[Top Level] log equal", + Output: `INFO: before FAIL: of course it's not equal... Expected : 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 : 0 to equal : 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{ - name: "[Top Level] log error", - output: `INFO: before + output.TestResult{ + Name: "[Top Level] log error", + 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{ - name: "[Top Level] log fails", - output: `INFO: before + output.TestResult{ + Name: "[Top Level] log fails", + 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.", - stack: `k8s.io/kubernetes/test/e2e/framework_test.glob..func1.2() + Failure: "I'm failing.", + 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 - // 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 "/.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 "(...)". -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 + + output.TestGinkgoOutput(t, runTests, expected) }