CI monitor reading #10859

raybejjani · 2020-04-06T11:05:20Z

We see flakes in tests that read from monitor. These are structured to search monitor output for specific substrings. Since monitor may take some time to start up, we can change how we read its output. The 3 tests now read this incrementally, and fail on a timeout. This should allow it to pass when monitor was simply slow to print.

I haven't seen the specific flake in a bunch of testing with this PR. Most test runs have failed, however, often in other tests. I'm fairly confident that I didn't break anything but I would prefer more clean passes. It does do better on GKE and that is where we see the flake the most, however.

@joestringer I think we once discussed this flake in a PR, so I pulled you in for review. Feel free to unassign yourself.

maintainer-s-little-helper · 2020-04-06T11:05:22Z

Please set the appropriate release note label.

maintainer-s-little-helper · 2020-04-06T11:05:22Z

Please set the appropriate release note label.

maintainer-s-little-helper · 2020-04-06T11:05:22Z

Please set the appropriate release note label.

maintainer-s-little-helper · 2020-04-06T11:05:22Z

Please set the appropriate release note label.

raybejjani · 2020-04-06T11:05:36Z

test-focus K8sDatapathConfig.*

coveralls · 2020-04-06T11:47:31Z

Coverage increased (+0.03%) to 46.803% when pulling 204c05b on raybejjani:ci-monitor-reading into e92fd24 on cilium:master.

raybejjani · 2020-04-06T12:42:52Z

test-focus K8sDatapathConfig.*

raybejjani · 2020-04-06T13:40:32Z

test-me-please

raybejjani · 2020-04-06T13:40:36Z

test-gke

raybejjani · 2020-04-06T16:22:08Z

test-gke

raybejjani · 2020-04-06T16:22:12Z

test-me-please

raybejjani · 2020-04-06T16:52:50Z

test-gke

raybejjani · 2020-04-06T16:52:53Z

test-gke

raybejjani · 2020-04-06T16:53:00Z

test-me-please

raybejjani · 2020-04-07T10:02:06Z

test-me-please

raybejjani · 2020-04-07T10:02:10Z

test-gke

raybejjani · 2020-04-07T10:41:17Z

test-me-please

raybejjani · 2020-04-07T10:41:22Z

test-gke

nebril

Two comments inline, good stuff overall

nebril · 2020-04-07T12:42:16Z

test/k8sT/DatapathConfiguration.go

+
+			var monitorOutput []byte // Accumulate output here over time
+			body := func() bool {
+				monitorOutput = append(monitorOutput, monitorRes.CombineOutput().Bytes()...)


won't this end up appending the same beginning of output over and over again, as we are not consuming the bytes that were already read. This may be ok if we just want to find "bad" lines, but I think it would be enough to just monitorOutput = monitorRes.CombineOutput().Bytes(). The same applies to all similar lines below (196, 890 in Policies.go).

You're right. For some reason I thought that there was a .Read call on a bytes.Buffer somewhere but that doesn't seem to be the case. I've switch it out. A bit less code too! I realised that we already have a WaitUntilMatch already on CmdRes.

nebril · 2020-04-07T12:43:25Z

test/k8sT/Policies.go

+					monitorOutput = append(monitorOutput, monitorRes.CombineOutput().Bytes()...)
+
+					// Let the monitor get started since it is started in the background.
+					time.Sleep(2 * time.Second)


We can drop the sleeps since we are using a timeout anyway (we can return false if exec is not successful)

I switched this to not use WithTimeout.

raybejjani · 2020-04-15T12:58:32Z

test-focus K8sDatapathConfiguration.* (https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated-Focus/66/)

raybejjani · 2020-04-15T13:27:02Z

test-focus K8sDatapathConfiguration.* (https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated-Focus/66)

raybejjani · 2020-04-15T14:14:29Z

test-focus K8sDatapathConfiguration.* (this passed but failed on artefact collection :/ https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated-Focus/71/)

raybejjani · 2020-04-15T14:37:22Z

test-focus K8sDatapathConfiguration.*

raybejjani · 2020-04-15T15:10:26Z

test-focus K8sDatapathConfig.*

raybejjani · 2020-04-15T16:08:05Z

test-me-please (timeout :/ https://jenkins.cilium.io/job/Cilium-PR-Ginkgo-Tests-Validated/18791/)

joestringer

This is awesome, thanks for picking this up!

Minor nits below around calling of the cancel function.

joestringer · 2020-04-15T20:38:50Z

test/k8sT/DatapathConfiguration.go

+
+			err := helpers.WithTimeout(body, "monitor aggregation did not send notifications", &helpers.TimeoutConfig{Timeout: helpers.HelperTimeout})
+			Expect(err).To(BeNil(), "Could not read monitor log")
+			monitorCancel()


monitorCancel won't be run if the Expect(err) fails one line above.

Good catch. I remember thinking that I had to do it this way but I can't see why now (maybe I though it was created inside the body function? clearly it isn't #codingmysteries).

nebril

Agreed with Joe's comment, aside from that LGTM!

Exposing writing to a file allows us to be more consistent with these artifacts. Signed-off-by: Ray Bejjani <[email protected]>

We previously started monitor, ran some traffic, then stopped monitor and checked the output. This could race and sometimes missed packets, failing tests. We now accumulate the monitor output over time, and pass only when the output contents meet the test requirements, failing after a timeout has passed. Signed-off-by: Ray Bejjani <[email protected]>

raybejjani · 2020-04-16T16:05:36Z

test-me-please (timeout)

raybejjani · 2020-04-16T16:05:43Z

test-gke

joestringer

LGTM, assuming Expect() doesn't do anything weird that might cause the defer to be skipped.

raybejjani · 2020-04-16T22:38:38Z

test-me-please

raybejjani · 2020-04-17T10:25:43Z

I tested by adding a forced fail and some prints. I see the prints on fail and pass so Expect doesn't short-circuit something to bypass defers.

I'm going to merge this since. The test failures I do see are wholly unrelated (including test timeouts).

raybejjani added wip area/CI-improvement Topic or proposal to improve the Continuous Integration workflow labels Apr 6, 2020

maintainer-s-little-helper bot added dont-merge/needs-release-note labels Apr 6, 2020

raybejjani force-pushed the ci-monitor-reading branch from 4d209a7 to 9d8e6fd Compare April 6, 2020 16:20

raybejjani force-pushed the ci-monitor-reading branch from 9d8e6fd to fc5b553 Compare April 6, 2020 16:52

raybejjani force-pushed the ci-monitor-reading branch from fc5b553 to 02c2936 Compare April 7, 2020 10:41

nebril reviewed Apr 7, 2020

View reviewed changes

raybejjani force-pushed the ci-monitor-reading branch 2 times, most recently from e70ee15 to 13b7314 Compare April 8, 2020 12:46

raybejjani requested a review from nebril April 15, 2020 14:40

raybejjani added pending-review and removed wip labels Apr 15, 2020

raybejjani requested a review from joestringer April 15, 2020 14:44

raybejjani marked this pull request as ready for review April 15, 2020 14:47

raybejjani requested a review from a team as a code owner April 15, 2020 14:47

raybejjani added release-note/ci This PR makes changes to the CI. and removed dont-merge/debug-only labels Apr 15, 2020

raybejjani changed the title ~~Ci monitor reading~~ CI monitor reading Apr 15, 2020

joestringer requested changes Apr 15, 2020

View reviewed changes

nebril approved these changes Apr 16, 2020

View reviewed changes

raybejjani added 2 commits April 16, 2020 18:01

CI: Split MonitorStart into MonitorStart and WriteToReportFile

854743c

Exposing writing to a file allows us to be more consistent with these artifacts. Signed-off-by: Ray Bejjani <[email protected]>

raybejjani force-pushed the ci-monitor-reading branch from cb00ba4 to 204c05b Compare April 16, 2020 16:04

raybejjani requested a review from joestringer April 16, 2020 16:05

joestringer approved these changes Apr 16, 2020

View reviewed changes

raybejjani merged commit 9fbd820 into cilium:master Apr 17, 2020

raybejjani deleted the ci-monitor-reading branch April 17, 2020 10:25

CI monitor reading #10859

CI monitor reading #10859

Conversation

raybejjani commented Apr 6, 2020 • edited Loading

maintainer-s-little-helper bot commented Apr 6, 2020

maintainer-s-little-helper bot commented Apr 6, 2020

maintainer-s-little-helper bot commented Apr 6, 2020

maintainer-s-little-helper bot commented Apr 6, 2020

raybejjani commented Apr 6, 2020

coveralls commented Apr 6, 2020 • edited Loading

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 6, 2020

raybejjani commented Apr 7, 2020

raybejjani commented Apr 7, 2020

raybejjani commented Apr 7, 2020

raybejjani commented Apr 7, 2020

nebril left a comment

Choose a reason for hiding this comment

nebril Apr 7, 2020

Choose a reason for hiding this comment

raybejjani Apr 7, 2020

Choose a reason for hiding this comment

nebril Apr 7, 2020

Choose a reason for hiding this comment

raybejjani Apr 8, 2020

Choose a reason for hiding this comment

raybejjani commented Apr 15, 2020 • edited Loading

raybejjani commented Apr 15, 2020 • edited Loading

raybejjani commented Apr 15, 2020 • edited Loading

raybejjani commented Apr 15, 2020

raybejjani commented Apr 15, 2020

raybejjani commented Apr 15, 2020 • edited Loading

joestringer left a comment

Choose a reason for hiding this comment

joestringer Apr 15, 2020

Choose a reason for hiding this comment

raybejjani Apr 16, 2020

Choose a reason for hiding this comment

nebril left a comment

Choose a reason for hiding this comment

raybejjani commented Apr 16, 2020 • edited Loading

raybejjani commented Apr 16, 2020

joestringer left a comment

Choose a reason for hiding this comment

raybejjani commented Apr 16, 2020

raybejjani commented Apr 17, 2020

raybejjani commented Apr 6, 2020 •

edited

Loading

coveralls commented Apr 6, 2020 •

edited

Loading

raybejjani commented Apr 15, 2020 •

edited

Loading

raybejjani commented Apr 15, 2020 •

edited

Loading

raybejjani commented Apr 15, 2020 •

edited

Loading

raybejjani commented Apr 15, 2020 •

edited

Loading

raybejjani commented Apr 16, 2020 •

edited

Loading