hs-test: various improvements

- fixed timed out/panicked tests not copying logs to CI archives
- fixed log formatting
- renamed SuiteTimeout to TestTimeout
- fixed ginkgo node leak on test timeout -> added AssertChannelClosed
- updated docs

Type: test

Change-Id: Ia71d765bd61576230a4cfd26d4b14fd1be1692c7
Signed-off-by: Adrian Villin <avillin@cisco.com>

15 files changed, 53 insertions, 42 deletions

diff --git a/extras/hs-test/README.rst b/extras/hs-test/README.rst
index 159f67908b0..c62be5a84aa 100644
--- a/extras/hs-test/README.rst
+++ b/extras/hs-test/README.rst
@@ -167,8 +167,8 @@ Modifying the framework
 
                         // Add custom setup code here
 
-                        s.ConfigureNetworkTopology("myTopology")
-                        s.LoadContainerTopology("2peerVeth")
+                        s.ConfigureNetworkTopology("myNetworkTopology")
+                        s.LoadContainerTopology("myContainerTopology")
                 }
 
 #. In suite file, implement ``SetupTest`` method which gets executed before each test. Starting containers and
@@ -216,7 +216,7 @@ Modifying the framework
         			It(testName, func(ctx SpecContext) {
         				s.Log(testName + ": BEGIN")
         				test(&s)
-        			}, SpecTimeout(SuiteTimeout))
+        			}, SpecTimeout(TestTimeout))
         		}
         	}
                 })
@@ -237,7 +237,7 @@ Modifying the framework
                         It(testName, Label("SOLO"), func(ctx SpecContext) {
                                 s.Log(testName + ": BEGIN")
 			        test(&s)
-		        }, SpecTimeout(time.Minute*5))
+		        }, SpecTimeout(TestTimeout))
                 })
 
 #. Next step is to add test cases to the suite. For that, see section `Adding a test case`_ above
diff --git a/extras/hs-test/framework_test.go b/extras/hs-test/framework_test.go
index 0671d75fcae..a578fb15573 100644
--- a/extras/hs-test/framework_test.go
+++ b/extras/hs-test/framework_test.go
@@ -15,9 +15,9 @@ import (
 func TestHst(t *testing.T) {
 	if *IsVppDebug {
 		// 30 minute timeout so that the framework won't timeout while debugging
-		SuiteTimeout = time.Minute * 30
+		TestTimeout = time.Minute * 30
 	} else {
-		SuiteTimeout = time.Minute * 5
+		TestTimeout = time.Minute * 5
 	}
 
 	output, err := os.ReadFile("/sys/devices/system/node/online")
diff --git a/extras/hs-test/infra/container.go b/extras/hs-test/infra/container.go
index d4ef693c1c0..cc79a5cbb18 100644
--- a/extras/hs-test/infra/container.go
+++ b/extras/hs-test/infra/container.go
@@ -328,7 +328,6 @@ func (c *Container) getVolumesAsSlice() []string {
 	}
 
 	core_pattern, err := sysctl.Read("kernel.core_pattern")
-	core_pattern = strings.ReplaceAll(core_pattern, "%", "%%")
 	if err == nil {
 		if len(core_pattern) > 0 && core_pattern[0] != '|' {
 			index := strings.LastIndex(core_pattern, "/")
diff --git a/extras/hs-test/infra/hst_suite.go b/extras/hs-test/infra/hst_suite.go
index 435001afba7..3aeeb24d14e 100644
--- a/extras/hs-test/infra/hst_suite.go
+++ b/extras/hs-test/infra/hst_suite.go
@@ -43,7 +43,7 @@ var IsLeakCheck = flag.Bool("leak_check", false, "run leak-check tests")
 var ParallelTotal = flag.Lookup("ginkgo.parallel.total")
 var DryRun = flag.Bool("dryrun", false, "set up containers but don't run tests")
 var NumaAwareCpuAlloc bool
-var SuiteTimeout time.Duration
+var TestTimeout time.Duration
 
 type HstSuite struct {
 	Containers        map[string]*Container
@@ -310,6 +310,10 @@ func (s *HstSuite) AssertHttpBody(resp *http.Response, expectedBody string, msgA
 	ExpectWithOffset(2, resp).To(HaveHTTPBody(expectedBody), msgAndArgs...)
 }
 
+func (s *HstSuite) AssertChannelClosed(timeout time.Duration, channel chan error) {
+	EventuallyWithOffset(2, channel).WithTimeout(timeout).Should(BeClosed())
+}
+
 func (s *HstSuite) CreateLogger() {
 	suiteName := s.GetCurrentSuiteName()
 	var err error
@@ -323,12 +327,19 @@ func (s *HstSuite) CreateLogger() {
 // Logs to files by default, logs to stdout when VERBOSE=true with GinkgoWriter
 // to keep console tidy
 func (s *HstSuite) Log(log any, arg ...any) {
-	logs := strings.Split(fmt.Sprintf(fmt.Sprint(log), arg...), "\n")
+	var logStr string
+	if len(arg) == 0 {
+		logStr = fmt.Sprint(log)
+	} else {
+		logStr = fmt.Sprintf(fmt.Sprint(log), arg...)
+	}
+	logs := strings.Split(logStr, "\n")
+
 	for _, line := range logs {
 		s.Logger.Println(line)
 	}
 	if *IsVerbose {
-		GinkgoWriter.Println(fmt.Sprintf(fmt.Sprint(log), arg...))
+		GinkgoWriter.Println(logStr)
 	}
 }
 
diff --git a/extras/hs-test/infra/suite_cpu_pinning.go b/extras/hs-test/infra/suite_cpu_pinning.go
index 4adfe16d05e..57efbe7f4f0 100644
--- a/extras/hs-test/infra/suite_cpu_pinning.go
+++ b/extras/hs-test/infra/suite_cpu_pinning.go
@@ -83,7 +83,7 @@ var _ = Describe("CpuPinningSuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -112,7 +112,7 @@ var _ = Describe("CpuPinningSuiteSolo", Ordered, ContinueOnFailure, Serial, func
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_envoy_proxy.go b/extras/hs-test/infra/suite_envoy_proxy.go
index 9b1ae1fc808..50ffd11898e 100644
--- a/extras/hs-test/infra/suite_envoy_proxy.go
+++ b/extras/hs-test/infra/suite_envoy_proxy.go
@@ -191,7 +191,7 @@ var _ = Describe("EnvoyProxySuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -220,7 +220,7 @@ var _ = Describe("EnvoyProxySuiteSolo", Ordered, ContinueOnFailure, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_iperf_linux.go b/extras/hs-test/infra/suite_iperf_linux.go
index 728429b505f..fb685f9ad96 100644
--- a/extras/hs-test/infra/suite_iperf_linux.go
+++ b/extras/hs-test/infra/suite_iperf_linux.go
@@ -61,7 +61,7 @@ var _ = Describe("IperfSuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -90,7 +90,7 @@ var _ = Describe("IperfSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_ldp.go b/extras/hs-test/infra/suite_ldp.go
index 45f55ce859e..6294fab0dd6 100644
--- a/extras/hs-test/infra/suite_ldp.go
+++ b/extras/hs-test/infra/suite_ldp.go
@@ -163,7 +163,7 @@ var _ = Describe("LdpSuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -193,7 +193,7 @@ var _ = Describe("LdpSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_nginx_proxy.go b/extras/hs-test/infra/suite_nginx_proxy.go
index 476631ecea8..9d81f70720c 100644
--- a/extras/hs-test/infra/suite_nginx_proxy.go
+++ b/extras/hs-test/infra/suite_nginx_proxy.go
@@ -200,7 +200,7 @@ var _ = Describe("NginxProxySuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -229,7 +229,7 @@ var _ = Describe("NginxProxySuiteSolo", Ordered, ContinueOnFailure, Serial, func
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_no_topo.go b/extras/hs-test/infra/suite_no_topo.go
index 590bd2b2852..068c43b14d0 100644
--- a/extras/hs-test/infra/suite_no_topo.go
+++ b/extras/hs-test/infra/suite_no_topo.go
@@ -166,7 +166,7 @@ var _ = Describe("NoTopoSuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -195,7 +195,7 @@ var _ = Describe("NoTopoSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_veth.go b/extras/hs-test/infra/suite_veth.go
index 03640c419f3..cbbd7ee2694 100644
--- a/extras/hs-test/infra/suite_veth.go
+++ b/extras/hs-test/infra/suite_veth.go
@@ -120,7 +120,7 @@ var _ = Describe("VethsSuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -150,7 +150,7 @@ var _ = Describe("VethsSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/infra/suite_vpp_proxy.go b/extras/hs-test/infra/suite_vpp_proxy.go
index 25bc6a6c8da..16c6115bc23 100644
--- a/extras/hs-test/infra/suite_vpp_proxy.go
+++ b/extras/hs-test/infra/suite_vpp_proxy.go
@@ -184,7 +184,7 @@ var _ = Describe("VppProxySuite", Ordered, ContinueOnFailure, func() {
 			It(testName, func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
@@ -213,7 +213,7 @@ var _ = Describe("VppProxySuiteSolo", Ordered, ContinueOnFailure, func() {
 			It(testName, Label("SOLO"), func(ctx SpecContext) {
 				s.Log(testName + ": BEGIN")
 				test(&s)
-			}, SpecTimeout(SuiteTimeout))
+			}, SpecTimeout(TestTimeout))
 		}
 	}
 })
diff --git a/extras/hs-test/iperf_linux_test.go b/extras/hs-test/iperf_linux_test.go
index 14422fe5efa..b2b52a758ed 100644
--- a/extras/hs-test/iperf_linux_test.go
+++ b/extras/hs-test/iperf_linux_test.go
@@ -2,6 +2,7 @@ package main
 
 import (
 	"fmt"
+	"time"
 
 	. "fd.io/hs-test/infra"
 	. "github.com/onsi/ginkgo/v2"
@@ -41,8 +42,6 @@ func IperfLinuxTest(s *IperfSuite) {
 			" -u -l 1460 -b 10g -p " + s.GetPortFromPpid()
 		s.StartClientApp(clientContainer, cmd, clnCh, clnRes)
 	}()
-
+	s.AssertChannelClosed(time.Minute*3, clnCh)
 	s.Log(<-clnRes)
-	err = <-clnCh
-	s.AssertNil(err, "err: '%s'", err)
 }
diff --git a/extras/hs-test/ldp_test.go b/extras/hs-test/ldp_test.go
index 03636b11191..e72fac4fbba 100644
--- a/extras/hs-test/ldp_test.go
+++ b/extras/hs-test/ldp_test.go
@@ -2,6 +2,7 @@ package main
 
 import (
 	"fmt"
+	"time"
 
 	. "fd.io/hs-test/infra"
 	. "github.com/onsi/ginkgo/v2"
@@ -24,6 +25,10 @@ func LDPreloadIperfVppTest(s *LdpSuite) {
 	clnCh := make(chan error)
 	clnRes := make(chan string, 1)
 
+	defer func() {
+		stopServerCh <- struct{}{}
+	}()
+
 	go func() {
 		defer GinkgoRecover()
 		cmd := "iperf3 -4 -s -p " + s.GetPortFromPpid()
@@ -39,14 +44,9 @@ func LDPreloadIperfVppTest(s *LdpSuite) {
 		cmd := "iperf3 -c " + serverVethAddress + " -u -l 1460 -b 10g -p " + s.GetPortFromPpid()
 		s.StartClientApp(clientContainer, cmd, clnCh, clnRes)
 	}()
-	s.Log(<-clnRes)
-
-	// wait for client's result
-	err = <-clnCh
-	s.AssertNil(err, fmt.Sprint(err))
 
-	// stop server
-	stopServerCh <- struct{}{}
+	s.AssertChannelClosed(time.Minute*3, clnCh)
+	s.Log(<-clnRes)
 }
 
 func RedisBenchmarkTest(s *LdpSuite) {
@@ -61,6 +61,10 @@ func RedisBenchmarkTest(s *LdpSuite) {
 	clnCh := make(chan error)
 	clnRes := make(chan string, 1)
 
+	defer func() {
+		doneSrv <- struct{}{}
+	}()
+
 	go func() {
 		defer GinkgoRecover()
 		cmd := "redis-server --daemonize yes --protected-mode no --bind " + serverVethAddress
@@ -79,12 +83,10 @@ func RedisBenchmarkTest(s *LdpSuite) {
 			cmd = "redis-benchmark --threads " + fmt.Sprint(*NConfiguredCpus) + "-h " + serverVethAddress
 		}
 		s.StartClientApp(clientContainer, cmd, clnCh, clnRes)
+
 	}()
 
+	// 4.5 minutes
+	s.AssertChannelClosed(time.Second*270, clnCh)
 	s.Log(<-clnRes)
-	// wait for client's result
-	err = <-clnCh
-	s.AssertNil(err, fmt.Sprint(err))
-	// stop server
-	doneSrv <- struct{}{}
 }
diff --git a/extras/hs-test/script/compress.sh b/extras/hs-test/script/compress.sh
index 3a4642ea65a..ebc60d25779 100755
--- a/extras/hs-test/script/compress.sh
+++ b/extras/hs-test/script/compress.sh
@@ -11,7 +11,7 @@ then
     if [ -n "${WORKSPACE}" ]
     then
         echo -n "Copying docker logs..."
-        dirs=$(jq -r '.[0] | .SpecReports[] | select(.State == "failed") | .LeafNodeText | split("/")[1]' ${HS_ROOT}/summary/report.json)
+        dirs=$(jq -r '.[0] | .SpecReports[] | select((.State == "failed") or (.State == "timedout") or (.State == "panicked")) | .LeafNodeText | split("/")[1]' ${HS_ROOT}/summary/report.json)
         for dirName in $dirs; do
             logDir=/tmp/hs-test/$dirName
             if [ -d "$logDir" ]; then