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.
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.
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
<bool>: false
to equal
<bool>: 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
This makes sub packages of e2e test framework to use log functions
of core framework instead for avoiding circular dependencies.
NOTE: subpackage pod would make circular dependency if changing here.
So we need to take care of it with another PR.
PrintPerfData is called at e2e node tests and it depends on e2elog
and e2emetrics. This moves the function to the place which calls
the function for removing unnecessary dependencies from e2e node
subpackage.
This makes sub packages of e2e test framework to use log functions
of core framework instead for avoiding circular dependencies.
NOTE: test/e2e/framework/kubelet, test/e2e/framework/metrics and
test/e2e/framework/node will make circular dependencies if
updating them. It is necessary to solve them in advance before
this work.
Skips IPv6 tests on Windows.
Skips sysctl tests on Windows.
Skips network policy tests on Windows.
Skips RunAsUser / FSGroup / file permissions related tests, as those are
not supported on Windows.
Skips the test "should preserve source pod IP for traffic thru service cluster IP"
on Windows, as it creates a Pod with HostNetwork=true, which is unsupported.
What works and what doesn't work on Windows has been documented here:
https://github.com/kubernetes/community/blob/master/contributors/devel/sig-architecture/conformance-tests.md#windows--linux-considerations
HandleFlags() was used at e2e package and it depends on sub e2e
framework "config" in core e2e framework. That was invalid dependency.
So this moves HandleFlags() to e2e package for simple dependency.
We tried to separate logger functionality as subpackage of e2e test
framework, but we've recognized that should be core functionality
and we should keep it as core of e2e test framework after facing
circular dependency issues.
So this adds log.go back to core of e2e test framework. In addition,
this makes volume sub package use the core logger as a sample.
ConfirmStatefulPodCount() was used at e2e statefulset test only,
and that added dependency on another sub framework to statefulset
sub framework. This moves ConfirmStatefulPodCount() to the e2e test
for clean dependency.
Every caller of ReadOrDie() specified ginkgo.Fail as fail argument,
and that was intentional to avoid depending on Ginkgo.
However that just spreaded the dependency on Ginkgo to caller sides.
Especially that was unnecessary e2e test framework "ingress" depended
on Ginkgo only for the above reason.
Now we are cleaning up the dependencies on e2e tests, so let's just
remove such dependencies.
GetGPUDevicePluginImage() was called in some e2e node test only.
So it is not worth keeping the function as a part of e2e test
framework. This moves GetGPUDevicePluginImage() to the e2e node
test for code cleanup.
In e2e test framework, ProxyRequest() is called in kubelet e2e test
framework only. In addition, the function works for kubelet as tests
which call the function do. So this moves the function into kubelet
e2e test framework to make the dependency simple.
The core e2e framework contains BusyBoxImage. The sub e2e "pod"
framework also contains it but not used at all.
So this removes this unused BusyBoxImage for code cleanup.
WaitForEndpoint() of the endpoints e2e framework was used in
test/e2e/network/proxy.go only. In addition, the endpoints e2e
framework imported the core of e2e framework only for the function.
So this moves the function into test/e2e/network/proxy.go then we
can remove dependency of core framework from the sub e2e framework.
