From 311b66ada1e1382158a2b35690fce322a33e8f6a Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 17 Jul 2019 11:49:17 +0200 Subject: [PATCH 1/4] e2e: unit test for logger.go and ginkgowrapper.go MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This test runs a fake Ginkgo suite with various errors and checks how logger.go respectively ginkgowrapper.go handle this. Right now, the outcome is sub-optimal: - some test failures (those that use framework.Failf or framework.ExpectNoError) are logged immediately, Gomega failures are not - framework.ExpectNoError logs just the error, which is often useless without the additional explanation - failures that occur after some others are not reported at all; this can happen in cleanup code and while that code should better be written so that it contines instead of failing on an assertion, in practice quite a lot of code fails and when it does, the output would be useful to have - the full stack trace is odd and doesn't start with the expected function name Example output: • Failure [0.002 seconds] log /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:35 fails [It] /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:39 Jul 17 12:00:52.545: I'm failing. /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:41 Full Stack Trace /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger.go:51 +0x143 k8s.io/kubernetes/test/e2e/framework/log.Failf(...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger.go:43 k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2.1(...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:41 k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2() /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:42 +0x52 k8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync(0xc00029b020, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:65 +0x1c8 testing.tRunner(0xc000358600, 0x19818c0) /nvme/gopath/go/src/testing/testing.go:865 +0xc0 created by testing.(*T).Run /nvme/gopath/go/src/testing/testing.go:916 +0x35a ------------------------------ Jul 17 12:00:52.545: INFO: before Jul 17 12:00:52.545: INFO: I'm failing. Jul 17 12:00:52.547: INFO: after • Failure [0.002 seconds] log /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:35 asserts [It] /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:44 false is never true Expected : false to equal : true /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:45 Full Stack Trace /nvme/gopath/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:75 +0x1f1 k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To(0xc00035f6c0, 0x1b42140, 0xc000350dd0, 0xc000350de0, 0x1, 0x1, 0x42e35f) /nvme/gopath/src/k8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion/assertion.go:38 +0xc7 k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.3() /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:45 +0x17e k8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync(0xc00029b0e0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:65 +0x1c8 testing.tRunner(0xc000358600, 0x19818c0) /nvme/gopath/go/src/testing/testing.go:865 +0xc0 created by testing.(*T).Run /nvme/gopath/go/src/testing/testing.go:916 +0x35a ------------------------------ Jul 17 12:00:52.548: INFO: before Jul 17 12:00:52.549: INFO: after • Failure [0.002 seconds] log /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:35 error [It] /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:47 hard-coded error Unexpected error: <*errors.errorString | 0xc000351930>: { s: "I'm an error, nice to meet to.", } I'm an error, nice to meet to. occurred /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:49 Full Stack Trace /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/util.go:1376 +0x191 k8s.io/kubernetes/test/e2e/framework.ExpectNoError(...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/util.go:1367 k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.4() /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:49 +0xc9 k8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync(0xc00029b200, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0, ...) /nvme/gopath/src/k8s.io/kubernetes/test/e2e/framework/log/logger_test.go:65 +0x1c8 testing.tRunner(0xc000358600, 0x19818c0) /nvme/gopath/go/src/testing/testing.go:865 +0xc0 created by testing.(*T).Run /nvme/gopath/go/src/testing/testing.go:916 +0x35a ------------------------------ Jul 17 12:00:52.550: INFO: before Jul 17 12:00:52.550: INFO: Unexpected error occurred: I'm an error, nice to meet to. Jul 17 12:00:52.551: INFO: after --- test/e2e/framework/log/logger_test.go | 158 ++++++++++++++++++++++++++ 1 file changed, 158 insertions(+) create mode 100644 test/e2e/framework/log/logger_test.go diff --git a/test/e2e/framework/log/logger_test.go b/test/e2e/framework/log/logger_test.go new file mode 100644 index 00000000000..834db0457d9 --- /dev/null +++ b/test/e2e/framework/log/logger_test.go @@ -0,0 +1,158 @@ +/* +Copyright 2019 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 log_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" + + "k8s.io/kubernetes/test/e2e/framework" + "k8s.io/kubernetes/test/e2e/framework/ginkgowrapper" + "k8s.io/kubernetes/test/e2e/framework/log" +) + +var _ = ginkgo.Describe("log", func() { + ginkgo.BeforeEach(func() { + log.Logf("before") + }) + ginkgo.It("fails", func() { + func() { + log.Failf("I'm failing.") + }() + }) + ginkgo.It("asserts", func() { + gomega.Expect(false).To(gomega.Equal(true), "false is never true") + }) + ginkgo.It("error", func() { + err := errors.New("I'm an error, nice to meet to.") + framework.ExpectNoError(err, "hard-coded error") + }) + ginkgo.AfterEach(func() { + log.Logf("after") + gomega.Expect(true).To(gomega.Equal(false), "true is never false either") + }) +}) + +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(ginkgowrapper.Fail) + fakeT := &testing.T{} + reporter := reporters.NewFakeReporter() + ginkgo.RunSpecsWithDefaultAndCustomReporters(fakeT, "Logging Suite", []ginkgo.Reporter{reporter}) + + // Now check the output. + g := gomega.NewGomegaWithT(t) + g.Expect(normalizeReport(*reporter)).To(gomega.Equal(suiteResults{ + testResult{ + name: "[Top Level] log asserts", + // TODO: also log the failed assertion as it happens + output: "INFO: before\nINFO: after\n", + failure: "false is never true\nExpected\n : false\nto equal\n : true", + // TODO: ginkowrapper.Fail should also prune this stack. + stack: "\tassertion.go:75\nk8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To()\n\tassertion.go:38\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.3()\n\tlogger_test.go:46\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:66\n", + }, + testResult{ + name: "[Top Level] log error", + // TODO: the additional information about the error should be logged + output: "INFO: before\nINFO: Unexpected error occurred: I'm an error, nice to meet to.\nINFO: after\n", + failure: "hard-coded error\nUnexpected error:\n <*errors.errorString>: {\n s: \"I'm an error, nice to meet to.\",\n }\n I'm an error, nice to meet to.\noccurred", + // TODO: ginkowrapper.Fail should also prune this stack. + stack: "\tutil.go:1362\nk8s.io/kubernetes/test/e2e/framework.ExpectNoError()\n\tutil.go:1356\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.4()\n\tlogger_test.go:49\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:65\n", + }, + testResult{ + name: "[Top Level] log fails", + // TODO: why is the failure log as "INFO"? + output: "INFO: before\nINFO: I'm failing.\nINFO: after\n", + failure: "I'm failing.", + // TODO: ginkowrapper.Fail should also prune this stack. + stack: "\tlogger.go:52\nk8s.io/kubernetes/test/e2e/framework/log.Failf()\n\tlogger.go:44\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2.1(...)\n\tlogger_test.go:41\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2()\n\tlogger_test.go:42\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:65\n", + }, + })) +} + +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: 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 "\t//.go:75 +0x1f1". +var stackLocation = regexp.MustCompile(`/.*/([[:^space:]]+.go:[[:digit:]]+)( \+0x[0-9a-fA-F]+)?`) + +// functionArgs matches "(...)". +var functionArgs = regexp.MustCompile(`([[:alpha:]]+)\(.*\)`) + +// testingStackEntries matches "testing.tRunner" and "created by" entries. +var testingStackEntries = regexp.MustCompile(`(?m)(?:testing\.|created by).*\n\t.*\n`) + +// 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 = testingStackEntries.ReplaceAllString(out, "") + return out +} From 259bb3bef5403daec1bbe44c2c9413ec17b52b6e Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 17 Jul 2019 12:52:20 +0200 Subject: [PATCH 2/4] e2e: consistent failure logging All failures are worth logging immediately, not just unexpected errors. That helps understand tests that have long-running cleanup operations with their own logging, because the failure will be visible inside the test output. The logging in framework.ExpectNoError also was rather poor, because it only showed the error, but not the additional information about it. Tests suites now should use log.Fail as Gomega failure handler instead of ginkgowrapper.Fail. log.Fail will handle the logging for all failures before proceeding to record the failure in Ginkgo. Because logging is always done also after a test failure, additional failures during cleanup are now visible. Ginkgo itself just ignores them. --- test/e2e/e2e.go | 4 +-- test/e2e/framework/log/logger.go | 13 +++++++- test/e2e/framework/log/logger_test.go | 48 ++++++++++++++++----------- test/e2e/framework/util.go | 4 --- 4 files changed, 43 insertions(+), 26 deletions(-) diff --git a/test/e2e/e2e.go b/test/e2e/e2e.go index f82f557692f..38062834aa4 100644 --- a/test/e2e/e2e.go +++ b/test/e2e/e2e.go @@ -32,7 +32,7 @@ import ( "k8s.io/component-base/logs" commontest "k8s.io/kubernetes/test/e2e/common" "k8s.io/kubernetes/test/e2e/framework" - "k8s.io/kubernetes/test/e2e/framework/ginkgowrapper" + e2elog "k8s.io/kubernetes/test/e2e/framework/log" // ensure auth plugins are loaded _ "k8s.io/client-go/plugin/pkg/client/auth" @@ -71,7 +71,7 @@ func RunE2ETests(t *testing.T) { logs.InitLogs() defer logs.FlushLogs() - gomega.RegisterFailHandler(ginkgowrapper.Fail) + gomega.RegisterFailHandler(e2elog.Fail) // Disable skipped tests unless they are explicitly requested. if config.GinkgoConfig.FocusString == "" && config.GinkgoConfig.SkipString == "" { config.GinkgoConfig.SkipString = `\[Flaky\]|\[Feature:.+\]` diff --git a/test/e2e/framework/log/logger.go b/test/e2e/framework/log/logger.go index 039119e7572..c57c15d5a5d 100644 --- a/test/e2e/framework/log/logger.go +++ b/test/e2e/framework/log/logger.go @@ -48,6 +48,17 @@ func Failf(format string, args ...interface{}) { // (for example, for call chain f -> g -> FailfWithOffset(1, ...) error would be logged for "f"). func FailfWithOffset(offset int, format string, args ...interface{}) { msg := fmt.Sprintf(format, args...) - log("INFO", msg) + log("FAIL", msg) ginkgowrapper.Fail(nowStamp()+": "+msg, 1+offset) } + +// Fail is a replacement for ginkgo.Fail which logs the problem as it occurs +// and then calls ginkgowrapper.Fail. +func Fail(msg string, callerSkip ...int) { + skip := 1 + if len(callerSkip) > 0 { + skip += callerSkip[0] + } + log("FAIL", msg) + ginkgowrapper.Fail(nowStamp()+": "+msg, skip) +} diff --git a/test/e2e/framework/log/logger_test.go b/test/e2e/framework/log/logger_test.go index 834db0457d9..469a61c5c7d 100644 --- a/test/e2e/framework/log/logger_test.go +++ b/test/e2e/framework/log/logger_test.go @@ -29,7 +29,6 @@ import ( "github.com/onsi/gomega" "k8s.io/kubernetes/test/e2e/framework" - "k8s.io/kubernetes/test/e2e/framework/ginkgowrapper" "k8s.io/kubernetes/test/e2e/framework/log" ) @@ -46,7 +45,7 @@ var _ = ginkgo.Describe("log", func() { gomega.Expect(false).To(gomega.Equal(true), "false is never true") }) ginkgo.It("error", func() { - err := errors.New("I'm an error, nice to meet to.") + err := errors.New("an error with a long, useless description") framework.ExpectNoError(err, "hard-coded error") }) ginkgo.AfterEach(func() { @@ -60,39 +59,50 @@ func TestFailureOutput(t *testing.T) { // 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(ginkgowrapper.Fail) + gomega.RegisterFailHandler(log.Fail) fakeT := &testing.T{} reporter := reporters.NewFakeReporter() ginkgo.RunSpecsWithDefaultAndCustomReporters(fakeT, "Logging Suite", []ginkgo.Reporter{reporter}) // Now check the output. + // TODO: all of the stacks are currently broken because Ginkgo doesn't properly skip + // over the initial entries returned by runtime.Stack. Fix is pending in + // https://github.com/onsi/ginkgo/pull/590, "stack" texts need to be updated + // when updating to a fixed Ginkgo. g := gomega.NewGomegaWithT(t) - g.Expect(normalizeReport(*reporter)).To(gomega.Equal(suiteResults{ + actual := normalizeReport(*reporter) + expected := suiteResults{ testResult{ - name: "[Top Level] log asserts", - // TODO: also log the failed assertion as it happens - output: "INFO: before\nINFO: after\n", + name: "[Top Level] log asserts", + output: "INFO: before\nFAIL: false is never true\nExpected\n : false\nto equal\n : true\nINFO: after\nFAIL: true is never false either\nExpected\n : true\nto equal\n : false\n", failure: "false is never true\nExpected\n : false\nto equal\n : true", - // TODO: ginkowrapper.Fail should also prune this stack. - stack: "\tassertion.go:75\nk8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To()\n\tassertion.go:38\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.3()\n\tlogger_test.go:46\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:66\n", + // TODO: should start with k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.3() + stack: "\tassertion.go:75\nk8s.io/kubernetes/vendor/github.com/onsi/gomega/internal/assertion.(*Assertion).To()\n\tassertion.go:38\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.3()\n\tlogger_test.go:45\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:65\n", }, testResult{ - name: "[Top Level] log error", - // TODO: the additional information about the error should be logged - output: "INFO: before\nINFO: Unexpected error occurred: I'm an error, nice to meet to.\nINFO: after\n", - failure: "hard-coded error\nUnexpected error:\n <*errors.errorString>: {\n s: \"I'm an error, nice to meet to.\",\n }\n I'm an error, nice to meet to.\noccurred", - // TODO: ginkowrapper.Fail should also prune this stack. + name: "[Top Level] log error", + output: "INFO: before\nFAIL: hard-coded error\nUnexpected error:\n <*errors.errorString>: {\n s: \"an error with a long, useless description\",\n }\n an error with a long, useless description\noccurred\nINFO: after\nFAIL: true is never false either\nExpected\n : true\nto equal\n : false\n", + failure: "hard-coded error\nUnexpected error:\n <*errors.errorString>: {\n s: \"an error with a long, useless description\",\n }\n an error with a long, useless description\noccurred", + // TODO: should start with k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.4() stack: "\tutil.go:1362\nk8s.io/kubernetes/test/e2e/framework.ExpectNoError()\n\tutil.go:1356\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.4()\n\tlogger_test.go:49\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:65\n", }, testResult{ - name: "[Top Level] log fails", - // TODO: why is the failure log as "INFO"? - output: "INFO: before\nINFO: I'm failing.\nINFO: after\n", + name: "[Top Level] log fails", + output: "INFO: before\nFAIL: I'm failing.\nINFO: after\nFAIL: true is never false either\nExpected\n : true\nto equal\n : false\n", failure: "I'm failing.", - // TODO: ginkowrapper.Fail should also prune this stack. + // TODO: should start with k8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2.1(...) stack: "\tlogger.go:52\nk8s.io/kubernetes/test/e2e/framework/log.Failf()\n\tlogger.go:44\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2.1(...)\n\tlogger_test.go:41\nk8s.io/kubernetes/test/e2e/framework/log_test.glob..func1.2()\n\tlogger_test.go:42\nk8s.io/kubernetes/vendor/github.com/onsi/ginkgo/internal/leafnodes.(*runner).runSync()\n\tlogger_test.go:65\n", }, - })) + } + // Compare individual fields. Comparing the slices leads to unreadable error output when there is any mismatch. + g.Expect(len(actual)).To(gomega.Equal(len(expected)), "%d entries in %v", len(expected), actual) + for i, a := range actual { + b := expected[i] + g.Expect(a.name).To(gomega.Equal(b.name), "name in %d", i) + g.Expect(a.output).To(gomega.Equal(b.output), "output in %d", i) + g.Expect(a.failure).To(gomega.Equal(b.failure), "failure in %d", i) + g.Expect(a.stack).To(gomega.Equal(b.stack), "stack in %d", i) + } } type testResult struct { diff --git a/test/e2e/framework/util.go b/test/e2e/framework/util.go index 4891cbfc3bc..46a0aef671f 100644 --- a/test/e2e/framework/util.go +++ b/test/e2e/framework/util.go @@ -1359,10 +1359,6 @@ func ExpectNoError(err error, explain ...interface{}) { // ExpectNoErrorWithOffset checks if "err" is set, and if so, fails assertion while logging the error at "offset" levels above its caller // (for example, for call chain f -> g -> ExpectNoErrorWithOffset(1, ...) error would be logged for "f"). func ExpectNoErrorWithOffset(offset int, err error, explain ...interface{}) { - if err != nil { - e2elog.Logf("Unexpected error occurred: %v", err) - debug.PrintStack() - } gomega.ExpectWithOffset(1+offset, err).NotTo(gomega.HaveOccurred(), explain...) } From f021d6590e63742dbcbc4409bf96d61aa4ad8955 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Wed, 17 Jul 2019 15:08:49 +0200 Subject: [PATCH 3/4] bazel update --- test/e2e/BUILD | 1 - test/e2e/framework/log/BUILD | 15 ++++++++++++++- 2 files changed, 14 insertions(+), 2 deletions(-) diff --git a/test/e2e/BUILD b/test/e2e/BUILD index d9573888c86..348d404fd89 100644 --- a/test/e2e/BUILD +++ b/test/e2e/BUILD @@ -65,7 +65,6 @@ go_library( "//test/e2e/common:go_default_library", "//test/e2e/framework:go_default_library", "//test/e2e/framework/auth:go_default_library", - "//test/e2e/framework/ginkgowrapper:go_default_library", "//test/e2e/framework/log:go_default_library", "//test/e2e/framework/pod:go_default_library", "//test/e2e/framework/providers/aws:go_default_library", diff --git a/test/e2e/framework/log/BUILD b/test/e2e/framework/log/BUILD index 74015368eca..f0ea02bfb32 100644 --- a/test/e2e/framework/log/BUILD +++ b/test/e2e/framework/log/BUILD @@ -1,4 +1,4 @@ -load("@io_bazel_rules_go//go:def.bzl", "go_library") +load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test") go_library( name = "go_default_library", @@ -24,3 +24,16 @@ filegroup( tags = ["automanaged"], visibility = ["//visibility:public"], ) + +go_test( + name = "go_default_test", + srcs = ["logger_test.go"], + embed = [":go_default_library"], + deps = [ + "//test/e2e/framework:go_default_library", + "//vendor/github.com/onsi/ginkgo:go_default_library", + "//vendor/github.com/onsi/ginkgo/config:go_default_library", + "//vendor/github.com/onsi/ginkgo/reporters:go_default_library", + "//vendor/github.com/onsi/gomega:go_default_library", + ], +) From cdaba2bea349ce142bd7eb602a16c58a55952320 Mon Sep 17 00:00:00 2001 From: Patrick Ohly Date: Tue, 23 Jul 2019 13:15:08 +0200 Subject: [PATCH 4/4] e2e logger test: handle paths in Kubernetes CI Source code paths during //test/e2e/framework/log:go_default_test in the Kubernetes CI start with relative paths. To avoid too broad matching of the regex, those paths that occur in practice are named explicitly as alternatives to the leading slash. --- test/e2e/framework/log/logger_test.go | 5 +++-- 1 file changed, 3 insertions(+), 2 deletions(-) diff --git a/test/e2e/framework/log/logger_test.go b/test/e2e/framework/log/logger_test.go index 469a61c5c7d..76439c06298 100644 --- a/test/e2e/framework/log/logger_test.go +++ b/test/e2e/framework/log/logger_test.go @@ -148,8 +148,9 @@ func stripAddresses(in string) string { return instanceAddr.ReplaceAllString(in, ">") } -// stackLocation matches "\t//.go:75 +0x1f1". -var stackLocation = regexp.MustCompile(`/.*/([[:^space:]]+.go:[[:digit:]]+)( \+0x[0-9a-fA-F]+)?`) +// 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:]]+)\(.*\)`)