test: RuntimeKVStoreTest: Fix flake when validating logs

[ upstream commit e558100 ]

As for most tests, at the end of RuntimeKVStoreTest, we validate the logs
don't contain any worrisome messages with:

    vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)

CurrentGinkgoTestDescription().Duration includes the execution of all
ginkgo.BeforeEach [1]. In RuntimeKVStoreTest, one of our
ginkgo.BeforeEach stops the Cilium systemd service (because we run
cilium-agent as a standalone binary in the test itself). Stopping Cilium
can result in worrisome messages in the logs e.g., if the compilation of
BPF programs is terminated abruptly. This in turn makes the tests fail
once in a while.

To fix this, we can replace CurrentGinkgoTestDescription().Duration with
our own "time counter" that doesn't include any of the
ginkgo.BeforeEach executions.

To validate this fix, I ran the whole RuntimeKVStoreTest with this
change 60 times locally and 60 times in the CI (#12419). The tests
passed all 120 times. Before applying the fix, the Consul test would
fail ~1/30 times, both locally and in CI.

1 - https://github.com/onsi/ginkgo/blob/9c254cb251dc962dc20ca91d0279c870095cfcf9/internal/spec/spec.go#L132-L134
Fixes: #11895
Fixes: 5185789 ("Test: Checks for deadlocks panics in logs per each test.")
Related: #12419
Signed-off-by: Paul Chaignon <paul@cilium.io>

test/runtime/kvstore.go

@@ -16,6 +16,7 @@ package RuntimeTest
 
 import (
 	"context"
+	"time"
 
 	. "github.com/cilium/cilium/test/ginkgo-ext"
 	"github.com/cilium/cilium/test/helpers"
@@ -25,8 +26,8 @@ import (
 )
 
 var _ = Describe("RuntimeKVStoreTest", func() {
-
 	var vm *helpers.SSHMeta
+	var testStartTime time.Time
 
 	BeforeAll(func() {
 		vm = helpers.InitRuntimeHelper(helpers.Runtime, logger)
@@ -50,14 +51,18 @@ var _ = Describe("RuntimeKVStoreTest", func() {
 		ExpectCiliumNotRunning(vm)
 	}, 150)
 
+	JustBeforeEach(func() {
+		testStartTime = time.Now()
+	})
+
 	AfterEach(func() {
 		containers(helpers.Delete)
 		err := vm.RestartCilium()
 		Expect(err).Should(BeNil(), "restarting Cilium failed")
 	})
 
 	JustAfterEach(func() {
-		vm.ValidateNoErrorsInLogs(CurrentGinkgoTestDescription().Duration)
+		vm.ValidateNoErrorsInLogs(time.Since(testStartTime))
 	})
 
 	AfterFailed(func() {
@@ -68,8 +73,7 @@ var _ = Describe("RuntimeKVStoreTest", func() {
 		vm.CloseSSHClient()
 	})
 
-	SkipContextIf(helpers.SkipQuarantined, "KVStore tests under quarantine", func() {
-
+	Context("KVStore tests", func() {
 		It("Consul KVStore", func() {
 			ctx, cancel := context.WithCancel(context.Background())
 			defer cancel()