Test: Checks for deadlocks panics in logs per each test.

This commit make sure that there is no panic or deadlocks in cilium logs
after executed the test.

The test uses `CurrentGinkgoTestDescription().Duration` to know the
current duration of the test, so the helper only search in the logs
files since test starts. (In case of any panic in log, it'll not mark
all test as failed)

The panic string example is:

```
Mar 15 16:35:50 runtime cilium-agent[8220]: panic: runtime error: invalid memory address or nil pointer dereference
Mar 15 16:35:50 runtime cilium-agent[8220]: [signal SIGSEGV: segmentation violation code=0x1 addr=0x2 pc=0x17e3b2c]
Mar 15 16:35:50 runtime cilium-agent[8220]: goroutine 58384 [running]:
```

The deadlock string example is:
```
Jan 03 00:40:09 cilium-master cilium-agent[32439]: POTENTIAL DEADLOCK:
Jan 03 00:40:09 cilium-master cilium-agent[32439]: Previous place where the lock was grabbed
Jan 03 00:40:09 cilium-master cilium-agent[32439]: goroutine 8974 lock 0xc4201b875c
```

Signed-off-by: Eloy Coto <eloy.coto@gmail.com>

test/helpers/cilium.go

@@ -27,6 +27,7 @@ import (
 	"github.com/cilium/cilium/pkg/logging/logfields"
 
 	"github.com/onsi/ginkgo"
+	"github.com/onsi/gomega"
 	"github.com/sirupsen/logrus"
 )
 
@@ -527,6 +528,21 @@ func (s *SSHMeta) ReportFailed(commands ...string) {
 	fmt.Fprint(wr, "===================== EXITING REPORT GENERATION =====================\n")
 }
 
+// ValidateNoErrorsOnLogs checks in cilium logs since the given duration (By
+// default `CurrentGinkgoTestDescription().Duration`) that no `panic` messages
+// or `deadlocks`. In case of any of these messages, it'll mark the test as
+// failed.
+func (s *SSHMeta) ValidateNoErrorsOnLogs(duration time.Duration) {
+	logsCmd := fmt.Sprintf(`sudo journalctl -au %s --since '%v seconds ago'`,
+		DaemonName, duration.Seconds())
+	logs := s.Exec(logsCmd).Output().String()
+
+	gomega.ExpectWithOffset(1, logs).ToNot(gomega.ContainSubstring("panic: "),
+		"Found a panic in Cilium logs")
+	gomega.ExpectWithOffset(1, logs).ToNot(gomega.ContainSubstring(deadLockHeader),
+		"Found a deadlock in Cilium logs")
+}
+
 // CheckLogsForDeadlock checks if the logs for Cilium log messages that signify
 // that a deadlock has occurred.
 func (s *SSHMeta) CheckLogsForDeadlock() {

test/helpers/cons.go

@@ -154,6 +154,8 @@ const (
 
 	StableImage = "cilium/cilium:stable"
 	configMap   = "ConfigMap"
+
+	deadLockHeader = "POTENTIAL DEADLOCK:" // from github.com/sasha-s/go-deadlock/deadlock.go:header
 )
 
 var ciliumCLICommands = map[string]string{

test/helpers/kubectl.go

@@ -33,6 +33,7 @@ import (
 
 	"github.com/asaskevich/govalidator"
 	"github.com/onsi/ginkgo"
+	"github.com/onsi/gomega"
 	"github.com/sirupsen/logrus"
 	"golang.org/x/crypto/ssh"
 	"k8s.io/api/core/v1"
@@ -777,6 +778,24 @@ func (kub *Kubectl) CiliumReport(namespace string, pod string, commands ...[]str
 
 }
 
+// ValidateNoErrorsOnLogs checks in cilium logs since the given duration (By
+// default `CurrentGinkgoTestDescription().Duration`) that no `panic` messages
+// or `deadlocks`. In case of any of these messages, it'll mark the test as
+// failed.
+func (kub *Kubectl) ValidateNoErrorsOnLogs(duration time.Duration) {
+	cmd := fmt.Sprintf("%s -n %s logs --timestamps=true -l k8s-app=cilium --since=%vs",
+		KubectlCmd, KubeSystemNamespace, duration.Seconds())
+	res := kub.Exec(fmt.Sprintf("%s --previous", cmd))
+	if !res.WasSuccessful() {
+		res = kub.Exec(cmd)
+	}
+	logs := res.Output().String()
+	gomega.ExpectWithOffset(1, logs).ToNot(gomega.ContainSubstring("panic: "),
+		"Found a panic in Cilium logs")
+	gomega.ExpectWithOffset(1, logs).ToNot(gomega.ContainSubstring(deadLockHeader),
+		"Found a deadlock in Cilium logs")
+}
+
 // CheckLogsForDeadlock checks if the logs for Cilium log messages that signify
 // that a deadlock has occurred.
 func (kub *Kubectl) CheckLogsForDeadlock() {

test/k8sT/Chaos.go

@@ -61,6 +61,7 @@ var _ = Describe("K8sValidatedChaosTest", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(
 				helpers.KubeSystemNamespace, helpers.K8s1VMName())

test/k8sT/Health.go

@@ -48,6 +48,7 @@ var _ = Describe(testName, func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode("kube-system", "k8s1")
 			kubectl.CiliumReport("kube-system", ciliumPod, []string{

test/k8sT/KafkaPolicies.go

@@ -95,6 +95,7 @@ var _ = Describe("K8sValidatedKafkaPolicyTest", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{

test/k8sT/Nightly.go

@@ -80,6 +80,7 @@ var _ = Describe("NightlyEpsMeasurement", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{
@@ -291,6 +292,7 @@ var _ = Describe("NightlyEpsMeasurement", func() {
 		}
 
 		It("Test TCP Keepalive with L7 Policy", func() {
+			kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 			manifest := kubectl.ManifestGet(netcatDsManifest)
 			kubectl.Apply(manifest).ExpectSuccess("Cannot apply netcat ds")
 			defer kubectl.Delete(manifest)
@@ -348,6 +350,7 @@ var _ = Describe("NightlyExamples", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{

test/k8sT/Policies.go

@@ -81,6 +81,7 @@ var _ = Describe("K8sValidatedPolicyTest", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{
@@ -719,6 +720,7 @@ var _ = Describe("K8sValidatedPolicyTestAcrossNamespaces", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{

test/k8sT/PoliciesNightly.go

@@ -51,6 +51,7 @@ var _ = Describe("NightlyPolicies", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, "k8s1")
 			kubectl.CiliumReport("kube-system", ciliumPod, []string{

test/k8sT/Services.go

@@ -61,6 +61,7 @@ var _ = Describe("K8sValidatedServicesTest", func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode("kube-system", "k8s1")
 			kubectl.CiliumReport("kube-system", ciliumPod, []string{

test/k8sT/Tunnels.go

@@ -52,6 +52,7 @@ var _ = Describe("K8sValidatedTunnelTest", func() {
 	}, 600)
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod, []string{

test/k8sT/Updates.go

@@ -48,7 +48,14 @@ var _ = Describe("DisabledK8sValidatedUpdates", func() {
 	}
 
 	AfterEach(func() {
-
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
+		if CurrentGinkgoTestDescription().Failed {
+			ciliumPod, _ := kubectl.GetCiliumPodOnNode(
+				helpers.KubeSystemNamespace, helpers.K8s1VMName())
+			kubectl.CiliumReport("kube-system", ciliumPod, []string{
+				"cilium service list",
+				"cilium endpoint list"})
+		}
 		//This policies maybe are not loaded, (Test failed before) so no assert here.
 		kubectl.Delete(l7Policy)
 		kubectl.Delete(l3Policy)

test/k8sT/demos.go

@@ -77,8 +77,8 @@ var _ = Describe(demoTestName, func() {
 	})
 
 	AfterEach(func() {
+		kubectl.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
-			log.Debugf("======================== TEST FAILED ======================== ")
 			ciliumPod, _ := kubectl.GetCiliumPodOnNode(helpers.KubeSystemNamespace, helpers.K8s1)
 			kubectl.CiliumReport(helpers.KubeSystemNamespace, ciliumPod)
 		}

test/runtime/Policies.go

@@ -75,6 +75,8 @@ var _ = Describe("RuntimeValidatedPolicyEnforcement", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
+
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}
@@ -430,6 +432,8 @@ var _ = Describe("RuntimeValidatedPolicies", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
+
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}
@@ -1006,6 +1010,7 @@ var _ = Describe("RuntimeValidatedPolicyImportTests", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}

test/runtime/chaos.go

@@ -47,6 +47,7 @@ var _ = Describe("RuntimeValidatedChaos", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}

test/runtime/cli.go

@@ -47,6 +47,7 @@ var _ = Describe("RuntimeValidatedCLI", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed("cilium endpoint list")
 		}

test/runtime/connectivity.go

@@ -38,6 +38,7 @@ var _ = Describe("RuntimeValidatedConnectivityTest", func() {
 	}
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}
@@ -485,6 +486,7 @@ var _ = Describe("RuntimeValidatedConntrackTest", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}

test/runtime/ct.go

@@ -126,6 +126,8 @@ var _ = Describe("RuntimeDisabledValidatedConntrackTable", func() {
 	})
 
 	AfterEach(func() {
+
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed(
 				"sudo cilium bpf ct list global",

test/runtime/examples.go

@@ -44,6 +44,8 @@ var _ = Describe("RuntimeValidatedPolicyValidationTests", func() {
 	})
 
 	AfterEach(func() {
+
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}

test/runtime/kafka.go

@@ -112,6 +112,7 @@ var _ = Describe("RuntimeValidatedKafka", func() {
 	})
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed()
 		}

test/runtime/kvstore.go

@@ -54,6 +54,7 @@ var _ = Describe("RuntimeValidatedKVStoreTest", func() {
 	}, 150)
 
 	AfterEach(func() {
+		vm.ValidateNoErrorsOnLogs(CurrentGinkgoTestDescription().Duration)
 		if CurrentGinkgoTestDescription().Failed {
 			vm.ReportFailed(
 				"sudo docker ps -a",