From 948aa23b2ac845adca1062f13d5b1932ece8d629 Mon Sep 17 00:00:00 2001 From: Alejandro Pedraza Date: Fri, 13 Nov 2020 16:00:16 -0500 Subject: [PATCH] Remove logs comparisons in integration tests (#5223) The rare cases where these tests were useful don't make up for the burden of maintaing them, having different k8s version change the messages and having unexpected warnings come up that didn't affect the final convergence of the system. With this we also revert the indirection added back in #4538 that fetched unmatched warnings after a test had failed. --- test/integration/edges/edges_test.go | 2 +- test/integration/egress/egress_test.go | 2 +- test/integration/endpoints/endpoints_test.go | 2 +- .../externalissuer/external_issuer_test.go | 2 +- test/integration/inject/inject_test.go | 2 +- test/integration/install_test.go | 18 +- .../multicluster/source/source_test.go | 2 +- .../multicluster/target1/target_test.go | 2 +- .../multicluster/target2/target_test.go | 2 +- test/integration/routes/routes_test.go | 2 +- .../serviceaccounts/serviceaccounts_test.go | 2 +- .../serviceprofiles/serviceprofiles_test.go | 2 +- .../smimetrics/smi-metrics_test.go | 2 +- test/integration/stat/stat_test.go | 2 +- test/integration/tap/tap_test.go | 2 +- test/integration/tracing/tracing_test.go | 2 +- .../trafficsplit/trafficsplit_test.go | 2 +- test/integration/uninstall/uninstall_test.go | 2 +- testutil/logs_events.go | 164 ------------------ testutil/test_helper.go | 20 --- 20 files changed, 18 insertions(+), 218 deletions(-) delete mode 100644 testutil/logs_events.go diff --git a/test/integration/edges/edges_test.go b/test/integration/edges/edges_test.go index bbcd60752..60a81c89d 100644 --- a/test/integration/edges/edges_test.go +++ b/test/integration/edges/edges_test.go @@ -19,7 +19,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } // TestEdges requires that there has been traffic recently between linkerd-web diff --git a/test/integration/egress/egress_test.go b/test/integration/egress/egress_test.go index fbc8daf09..1b9f17dbe 100644 --- a/test/integration/egress/egress_test.go +++ b/test/integration/egress/egress_test.go @@ -17,7 +17,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } ////////////////////// diff --git a/test/integration/endpoints/endpoints_test.go b/test/integration/endpoints/endpoints_test.go index 05609d0ce..8c1462848 100644 --- a/test/integration/endpoints/endpoints_test.go +++ b/test/integration/endpoints/endpoints_test.go @@ -16,7 +16,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestGoodEndpoints(t *testing.T) { diff --git a/test/integration/externalissuer/external_issuer_test.go b/test/integration/externalissuer/external_issuer_test.go index 08d17a27c..e9123f4c1 100644 --- a/test/integration/externalissuer/external_issuer_test.go +++ b/test/integration/externalissuer/external_issuer_test.go @@ -25,7 +25,7 @@ func TestMain(m *testing.M) { fmt.Fprintln(os.Stdout, "Skipping as --external-issuer=false") os.Exit(0) } - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestExternalIssuer(t *testing.T) { diff --git a/test/integration/inject/inject_test.go b/test/integration/inject/inject_test.go index 77f84b0e2..8f63e04fb 100644 --- a/test/integration/inject/inject_test.go +++ b/test/integration/inject/inject_test.go @@ -27,7 +27,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } ////////////////////// diff --git a/test/integration/install_test.go b/test/integration/install_test.go index 61ddda5ab..1ed3aa9c8 100644 --- a/test/integration/install_test.go +++ b/test/integration/install_test.go @@ -24,7 +24,7 @@ var ( func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } var ( @@ -928,22 +928,6 @@ func TestCheckProxy(t *testing.T) { } } -func TestLogs(t *testing.T) { - okMessages, errs := testutil.FetchAndCheckLogs(TestHelper) - for msg := range okMessages { - t.Log(msg) - } - for err := range errs { - testutil.AnnotatedError(t, "Error checking logs", err) - } -} - -func TestEvents(t *testing.T) { - for _, err := range testutil.FetchAndCheckEvents(TestHelper) { - testutil.AnnotatedError(t, "Error checking events", err) - } -} - func TestRestarts(t *testing.T) { for deploy, spec := range testutil.LinkerdDeployReplicas { if err := TestHelper.CheckPods(context.Background(), TestHelper.GetLinkerdNamespace(), deploy, spec.Replicas); err != nil { diff --git a/test/integration/multicluster/source/source_test.go b/test/integration/multicluster/source/source_test.go index 6e1a14db6..c7ae3a9e0 100644 --- a/test/integration/multicluster/source/source_test.go +++ b/test/integration/multicluster/source/source_test.go @@ -20,7 +20,7 @@ func TestMain(m *testing.M) { fmt.Fprintln(os.Stderr, "Multicluster test disabled") os.Exit(0) } - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestGateways(t *testing.T) { diff --git a/test/integration/multicluster/target1/target_test.go b/test/integration/multicluster/target1/target_test.go index 3c94a37a2..6504f8037 100644 --- a/test/integration/multicluster/target1/target_test.go +++ b/test/integration/multicluster/target1/target_test.go @@ -17,7 +17,7 @@ func TestMain(m *testing.M) { fmt.Fprintln(os.Stderr, "Multicluster test disabled") os.Exit(0) } - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestInstallEmojivoto(t *testing.T) { diff --git a/test/integration/multicluster/target2/target_test.go b/test/integration/multicluster/target2/target_test.go index 23378c118..d0e2a72ed 100644 --- a/test/integration/multicluster/target2/target_test.go +++ b/test/integration/multicluster/target2/target_test.go @@ -18,7 +18,7 @@ func TestMain(m *testing.M) { fmt.Fprintln(os.Stderr, "Multicluster test disabled") os.Exit(0) } - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestTargetTraffic(t *testing.T) { diff --git a/test/integration/routes/routes_test.go b/test/integration/routes/routes_test.go index 7f7632a1d..1822f1645 100644 --- a/test/integration/routes/routes_test.go +++ b/test/integration/routes/routes_test.go @@ -17,7 +17,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } ////////////////////// diff --git a/test/integration/serviceaccounts/serviceaccounts_test.go b/test/integration/serviceaccounts/serviceaccounts_test.go index aa198ff92..58f46bace 100644 --- a/test/integration/serviceaccounts/serviceaccounts_test.go +++ b/test/integration/serviceaccounts/serviceaccounts_test.go @@ -13,7 +13,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } // namesMatch checks if all the expectedServiceAccountNames are present in the given list, diff --git a/test/integration/serviceprofiles/serviceprofiles_test.go b/test/integration/serviceprofiles/serviceprofiles_test.go index dc6e8a9e9..5fa59615f 100644 --- a/test/integration/serviceprofiles/serviceprofiles_test.go +++ b/test/integration/serviceprofiles/serviceprofiles_test.go @@ -28,7 +28,7 @@ type testCase struct { func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestServiceProfiles(t *testing.T) { diff --git a/test/integration/smimetrics/smi-metrics_test.go b/test/integration/smimetrics/smi-metrics_test.go index 6f93d42e6..e938a0709 100644 --- a/test/integration/smimetrics/smi-metrics_test.go +++ b/test/integration/smimetrics/smi-metrics_test.go @@ -23,7 +23,7 @@ type testCase struct { func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestSMIMetrics(t *testing.T) { diff --git a/test/integration/stat/stat_test.go b/test/integration/stat/stat_test.go index c5a30ca1f..72b9376c8 100644 --- a/test/integration/stat/stat_test.go +++ b/test/integration/stat/stat_test.go @@ -20,7 +20,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } ////////////////////// diff --git a/test/integration/tap/tap_test.go b/test/integration/tap/tap_test.go index 49a589720..6fe9d22d1 100644 --- a/test/integration/tap/tap_test.go +++ b/test/integration/tap/tap_test.go @@ -17,7 +17,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } var ( diff --git a/test/integration/tracing/tracing_test.go b/test/integration/tracing/tracing_test.go index f9219d1b7..c1fea2d5b 100644 --- a/test/integration/tracing/tracing_test.go +++ b/test/integration/tracing/tracing_test.go @@ -34,7 +34,7 @@ var TestHelper *testutil.TestHelper func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } ////////////////////// diff --git a/test/integration/trafficsplit/trafficsplit_test.go b/test/integration/trafficsplit/trafficsplit_test.go index 25f33dbf0..dd9a9c74e 100644 --- a/test/integration/trafficsplit/trafficsplit_test.go +++ b/test/integration/trafficsplit/trafficsplit_test.go @@ -17,7 +17,7 @@ const zeroRPS = "0.0rps" func TestMain(m *testing.M) { TestHelper = testutil.NewTestHelper() - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } type statTsRow struct { diff --git a/test/integration/uninstall/uninstall_test.go b/test/integration/uninstall/uninstall_test.go index 86301f6c2..cf6ef624c 100644 --- a/test/integration/uninstall/uninstall_test.go +++ b/test/integration/uninstall/uninstall_test.go @@ -17,7 +17,7 @@ func TestMain(m *testing.M) { fmt.Fprintln(os.Stderr, "Uninstall test disabled") os.Exit(0) } - os.Exit(testutil.Run(m, TestHelper)) + os.Exit(m.Run()) } func TestInstall(t *testing.T) { diff --git a/testutil/logs_events.go b/testutil/logs_events.go deleted file mode 100644 index 8ed22bd5a..000000000 --- a/testutil/logs_events.go +++ /dev/null @@ -1,164 +0,0 @@ -package testutil - -import ( - "errors" - "fmt" - "regexp" - "strings" - "time" - - "github.com/linkerd/linkerd2/pkg/k8s" - corev1 "k8s.io/api/core/v1" -) - -var ( - // Linkerd commonly logs these errors during testing, remove these once - // they're addressed: https://github.com/linkerd/linkerd2/issues/2453 - knownControllerErrorsRegex = regexp.MustCompile(strings.Join([]string{ - `.*time=".*" level=error msg="\[.*\] encountered an error: rpc error: code = Canceled desc = context canceled"`, - `.*time=".*" level=error msg="Post http://linkerd-controller-api\..*\.svc\.cluster\.local:8085/api/v1/Version: context canceled"`, - `.*time=".*" level=warning msg="failed to retrieve replicaset from indexer .*-smoke-test.*/smoke-test-.*-.*: replicaset\.apps \\"smoke-test-.*-.*\\" not found"`, - `.*time=".*" level=warning msg="failed to retrieve replicaset from indexer .* not found"`, - `.*time=".*" level=warning msg="context token ns:.* using old token format" addr=":8086" component=server`, - }, "|")) - - knownProxyErrorsRegex = regexp.MustCompile(strings.Join([]string{ - // k8s hitting readiness endpoints before components are ready - `.* ERR! \[ +\d+.\d+s\] proxy={server=in listen=0\.0\.0\.0:4143 remote=.*} linkerd2_proxy::app::errors unexpected error: an IO error occurred: Connection reset by peer \(os error 104\)`, - `.* ERR! \[ *\d+.\d+s\] proxy={server=in listen=0\.0\.0\.0:4143 remote=.*} linkerd2_proxy::(proxy::http::router service|app::errors unexpected) error: an error occurred trying to connect: Connection refused \(os error 111\) \(address: 127\.0\.0\.1:.*\)`, - `.* ERR! \[ *\d+.\d+s\] proxy={server=out listen=127\.0\.0\.1:4140 remote=.*} linkerd2_proxy::(proxy::http::router service|app::errors unexpected) error: an error occurred trying to connect: Connection refused \(os error 111\) \(address: .*\)`, - `.* ERR! \[ *\d+.\d+s\] proxy={server=out listen=127\.0\.0\.1:4140 remote=.*} linkerd2_proxy::(proxy::http::router service|app::errors unexpected) error: an error occurred trying to connect: operation timed out after 1s`, - `.* WARN \[ *\d+.\d+s\] .* linkerd2_proxy::proxy::reconnect connect error to ControlAddr .*`, - - `.* ERR! \[ *\d+.\d+s\] admin={server=metrics listen=0\.0\.0\.0:4191 remote=.*} linkerd2_proxy::control::serve_http error serving metrics: Error { kind: Shutdown, .* }`, - `.* ERR! \[ +\d+.\d+s\] admin={server=admin listen=127\.0\.0\.1:4191 remote=.*} linkerd2_proxy::control::serve_http error serving admin: Error { kind: Shutdown, cause: Os { code: 107, kind: NotConnected, message: "Transport endpoint is not connected" } }`, - - `.* WARN trust_dns_proto::xfer::dns_exchange failed to associate send_message response to the sender`, - `.* WARN \[.*\] linkerd2_proxy::proxy::canonicalize failed to refine linkerd-.*\..*\.svc\.cluster\.local: deadline has elapsed; using original name`, - - // prometheus scrape failures of control-plane - `.* ERR! \[ +\d+.\d+s\] proxy={server=out listen=127\.0\.0\.1:4140 remote=.*} linkerd2_proxy::proxy::http::router service error: an error occurred trying to connect: .*`, - }, "|")) - - knownEventWarningsRegex = regexp.MustCompile(strings.Join([]string{ - `MountVolume.SetUp failed for volume .* : couldn't propagate object cache: timed out waiting for the condition`, // pre k8s 1.16 - `MountVolume.SetUp failed for volume .* : failed to sync .* cache: timed out waiting for the condition`, // post k8s 1.16 - `MountVolume.SetUp failed for volume "tls" : secret "linkerd-.*" not found`, - `(Liveness|Readiness) probe failed: HTTP probe failed with statuscode: 50(2|3)`, - `(Liveness|Readiness) probe failed: Get http://.*: dial tcp .*: connect: connection refused`, - `(Liveness|Readiness) probe failed: Get http://.*: read tcp .*: read: connection reset by peer`, - `(Liveness|Readiness) probe failed: Get http://.*: net/http: request canceled .*\(Client\.Timeout exceeded while awaiting headers\)`, - `Failed to update endpoint .*/linkerd-.*: Operation cannot be fulfilled on endpoints "linkerd-.*": the object has been modified; please apply your changes to the latest version and try again`, - `Error updating Endpoint Slices for Service .*`, - `error killing pod: failed to "KillPodSandbox" for ".*" with KillPodSandboxError: "rpc error: code = Unknown desc`, - `failed to create containerd task: failed to start io pipe copy: unable to copy pipes: containerd-shim: opening w/o fifo "/run/containerd/io.containerd.grpc.v1.cri/containers/linkerd-proxy/io/\d+/linkerd-proxy-stdout"`, - }, "|")) -) - -// FetchAndCheckLogs retrieves the logs from the control plane containers and matches them -// to the list in knownControllerErrorsRegex and knownProxyErrorsRegex. -// It returns the list of matched entries and the list of unmatched entries (as errors). -func FetchAndCheckLogs(helper *TestHelper) ([]string, []error) { - okMessages := []string{} - errs := []error{} - - controllerRegex := regexp.MustCompile("level=(panic|fatal|error|warn)") - proxyRegex := regexp.MustCompile("(ERR|WARN)") - clientGoRegex := regexp.MustCompile("client-go@") - hasClientGoLogs := false - - for deploy, spec := range LinkerdDeployReplicas { - containers := append(spec.Containers, k8s.ProxyContainerName) - - for _, container := range containers { - container := container // pin - name := fmt.Sprintf("%s/%s", deploy, container) - - proxy := false - errRegex := controllerRegex - knownErrorsRegex := knownControllerErrorsRegex - if container == k8s.ProxyContainerName { - proxy = true - errRegex = proxyRegex - knownErrorsRegex = knownProxyErrorsRegex - } - - outputStream, err := helper.KubectlStream( - "logs", - fmt.Sprintf("deployment/%s", deploy), - container, - ) - if err != nil { - errs = append(errs, fmt.Errorf("error running command:\n%s", err)) - continue - } - defer outputStream.Stop() - // Ignore the error returned, since ReadUntil will return an error if it - // does not return 10,000 after 2 seconds. We don't need 10,000 log lines. - outputLines, _ := outputStream.ReadUntil(10000, 2*time.Second) - if len(outputLines) == 0 { - // Retry one time for 30 more seconds, in case the cluster is slow to - // produce log lines. - outputLines, _ = outputStream.ReadUntil(10000, 30*time.Second) - if len(outputLines) == 0 { - errs = append(errs, fmt.Errorf("no logs found for %s", name)) - } - } - - for _, line := range outputLines { - if errRegex.MatchString(line) { - if knownErrorsRegex.MatchString(line) { - // report all known logging errors in the output - okMessages = append(okMessages, fmt.Sprintf("found known error in %s log: %s", name, line)) - } else { - if proxy { - okMessages = append(okMessages, fmt.Sprintf("found unexpected proxy error in %s log: %s", name, line)) - } else { - errs = append(errs, fmt.Errorf("found unexpected controller error in %s log: %s", name, line)) - } - } - } - if clientGoRegex.MatchString((line)) { - hasClientGoLogs = true - } - } - } - } - if !hasClientGoLogs { - errs = append(errs, errors.New("didn't find any client-go entries")) - } - - return okMessages, errs -} - -// FetchAndCheckEvents retrieves the events from k8s for the current namespace, matches -// them against knownEventWarningsRegex and returns the list of unmatched entries -// (as errors). -func FetchAndCheckEvents(helper *TestHelper) []error { - out, err := helper.Kubectl("", - "--namespace", helper.GetLinkerdNamespace(), - "get", "events", "-ojson", - ) - if err != nil { - return []error{fmt.Errorf("'kubectl get events' command failed with %s\n%s", err, out)} - } - - events, err := ParseEvents(out) - if err != nil { - return []error{err} - } - - errs := []error{} - for _, e := range events { - if e.Type == corev1.EventTypeNormal { - continue - } - - evtStr := fmt.Errorf("found unexpected warning event: reason: [%s] Object: [%s] Message: [%s]", e.Reason, e.InvolvedObject.Name, e.Message) - if !knownEventWarningsRegex.MatchString(e.Message) { - errs = append(errs, evtStr) - } - } - - return errs -} diff --git a/testutil/test_helper.go b/testutil/test_helper.go index e79c09991..3e803b3dc 100644 --- a/testutil/test_helper.go +++ b/testutil/test_helper.go @@ -674,23 +674,3 @@ func ParseEvents(out string) ([]*corev1.Event, error) { return events, nil } - -// Run calls `m.Run()`, shows unexpected logs/events, -// and returns the exit code for the tests -func Run(m *testing.M, helper *TestHelper) int { - code := m.Run() - if code != 0 { - _, errs1 := FetchAndCheckLogs(helper) - for _, err := range errs1 { - fmt.Println(err) - } - errs2 := FetchAndCheckEvents(helper) - for _, err := range errs2 { - fmt.Println(err) - } - if len(errs1) == 0 && len(errs2) == 0 { - fmt.Println("No unexpected log entries or events found") - } - } - return code -}