aboutsummaryrefslogtreecommitdiffstats
diff options
context:
space:
mode:
authorAdrian Villin <avillin@cisco.com>2024-05-06 06:55:34 -0400
committerDave Wallace <dwallacelf@gmail.com>2024-05-10 03:53:42 +0000
commit637edda1324fac88117d5520f94377e5d303128c (patch)
tree5c4af83fc975aa3a982c2992f5afc49c950914a8
parent8761095e80fd21216a669797e1d4b45a7aa388a4 (diff)
hs-test: logging improvements
Type: test Change-Id: Iffefe085e846b6ba614b0d74c4ba9907080a9a59 Signed-off-by: Adrian Villin <avillin@cisco.com>
-rw-r--r--.gitignore1
-rw-r--r--Makefile1
-rw-r--r--extras/hs-test/Makefile8
-rw-r--r--extras/hs-test/container.go2
-rw-r--r--extras/hs-test/hst_suite.go53
-rw-r--r--extras/hs-test/raw_session_test.go5
-rw-r--r--extras/hs-test/script/compress.sh34
-rw-r--r--extras/hs-test/suite_nginx_test.go9
-rw-r--r--extras/hs-test/suite_no_topo_test.go8
-rw-r--r--extras/hs-test/suite_ns_test.go8
-rw-r--r--extras/hs-test/suite_tap_test.go8
-rw-r--r--extras/hs-test/suite_veth_test.go9
-rwxr-xr-xextras/hs-test/test4
-rw-r--r--extras/hs-test/vppinstance.go6
14 files changed, 125 insertions, 31 deletions
diff --git a/.gitignore b/.gitignore
index 5c707a8364a..5537f0dd791 100644
--- a/.gitignore
+++ b/.gitignore
@@ -123,6 +123,7 @@ compile_commands.json
/extras/hs-test/hs-test
/extras/hs-test/http_server
/extras/hs-test/.build.ok
+/extras/hs-test/summary/
# ./configure
/CMakeFiles
diff --git a/Makefile b/Makefile
index edd632e42d5..6675b510153 100644
--- a/Makefile
+++ b/Makefile
@@ -86,6 +86,7 @@ DEB_DEPENDS += nasm
DEB_DEPENDS += iperf ethtool # for 'make test TEST=vm_vpp_interfaces'
DEB_DEPENDS += libpcap-dev
DEB_DEPENDS += tshark
+DEB_DEPENDS += jq # for extracting test summary from .json report (hs-test)
LIBFFI=libffi6 # works on all but 20.04 and debian-testing
diff --git a/extras/hs-test/Makefile b/extras/hs-test/Makefile
index 54b95c3d1cd..6ee89bc2770 100644
--- a/extras/hs-test/Makefile
+++ b/extras/hs-test/Makefile
@@ -95,9 +95,11 @@ build-vpp-debug:
.PHONY: test
test: .deps.ok .build.ok
- @bash ./test --persist=$(PERSIST) --verbose=$(VERBOSE) \
+ -bash ./test --persist=$(PERSIST) --verbose=$(VERBOSE) \
--unconfigure=$(UNCONFIGURE) --debug=$(DEBUG) --test=$(TEST) --cpus=$(CPUS) \
--vppsrc=$(VPPSRC) --parallel=$(PARALLEL) --repeat=$(REPEAT)
+ $(call jq-summary)
+ @bash ./script/compress.sh
.PHONY: test-debug
test-debug: .deps.ok .build_debug.ok
@@ -142,3 +144,7 @@ install-deps:
fixstyle:
@gofmt -w .
@go mod tidy
+
+# splitting this into multiple lines breaks the command
+jq-summary = @jq -r '.[0] | .SpecReports[] | select(.State == "failed") | select(.Failure != null) | "TestName: \(.LeafNodeText)\nMessage:\n\(.Failure.Message)\n Full Stack Trace:\n\(.Failure.Location.FullStackTrace)\n"' summary/report.json > summary/failed-summary.log \
+ && echo "Summary generated -> failed-summary.log"
diff --git a/extras/hs-test/container.go b/extras/hs-test/container.go
index c82f1fc03a7..45f41d26a87 100644
--- a/extras/hs-test/container.go
+++ b/extras/hs-test/container.go
@@ -77,7 +77,7 @@ func newContainer(suite *HstSuite, yamlInput ContainerConfig) (*Container, error
}
if _, ok := yamlInput["volumes"]; ok {
- workingVolumeDir := logDir + CurrentSpecReport().LeafNodeText + container.suite.pid + volumeDir
+ workingVolumeDir := logDir + CurrentSpecReport().LeafNodeText + volumeDir
workDirReplacer := strings.NewReplacer("$HST_DIR", workDir)
volDirReplacer := strings.NewReplacer("$HST_VOLUME_DIR", workingVolumeDir)
for _, volu := range yamlInput["volumes"].([]interface{}) {
diff --git a/extras/hs-test/hst_suite.go b/extras/hs-test/hst_suite.go
index bb499246bf9..725fee73f24 100644
--- a/extras/hs-test/hst_suite.go
+++ b/extras/hs-test/hst_suite.go
@@ -5,7 +5,8 @@ import (
"errors"
"flag"
"fmt"
- "log/slog"
+ "io"
+ "log"
"os"
"os/exec"
"strings"
@@ -39,9 +40,17 @@ type HstSuite struct {
cpuContexts []*CpuContext
cpuPerVpp int
pid string
+ logger *log.Logger
+ logFile *os.File
}
func (s *HstSuite) SetupSuite() {
+ s.createLogger()
+ s.log("Suite Setup")
+ RegisterFailHandler(func(message string, callerSkip ...int) {
+ s.hstFail()
+ Fail(message, callerSkip...)
+ })
var err error
s.pid = fmt.Sprint(os.Getpid())
s.cpuAllocator, err = CpuAllocator()
@@ -63,10 +72,13 @@ func (s *HstSuite) AddCpuContext(cpuCtx *CpuContext) {
}
func (s *HstSuite) TearDownSuite() {
+ defer s.logFile.Close()
+ s.log("Suite Teardown")
s.unconfigureNetworkTopology()
}
func (s *HstSuite) TearDownTest() {
+ s.log("Test Teardown")
if *isPersistent {
return
}
@@ -85,10 +97,7 @@ func (s *HstSuite) skipIfUnconfiguring() {
}
func (s *HstSuite) SetupTest() {
- RegisterFailHandler(func(message string, callerSkip ...int) {
- s.hstFail()
- Fail(message, callerSkip...)
- })
+ s.log("Test Setup")
s.skipIfUnconfiguring()
s.setupVolumes()
s.setupContainers()
@@ -110,7 +119,7 @@ func (s *HstSuite) setupContainers() {
}
}
-func logVppInstance(container *Container, maxLines int) {
+func (s *HstSuite) logVppInstance(container *Container, maxLines int) {
if container.vppInstance == nil {
return
}
@@ -136,26 +145,26 @@ func logVppInstance(container *Container, maxLines int) {
}
}
- fmt.Println("vvvvvvvvvvvvvvv " + container.name + " [VPP instance]:")
+ s.log("vvvvvvvvvvvvvvv " + container.name + " [VPP instance]:")
for _, line := range lines {
- fmt.Println(line)
+ s.log(line)
}
- fmt.Printf("^^^^^^^^^^^^^^^\n\n")
+ s.log("^^^^^^^^^^^^^^^\n\n")
}
func (s *HstSuite) hstFail() {
- fmt.Println("Containers: " + fmt.Sprint(s.containers))
+ s.log("Containers: " + fmt.Sprint(s.containers))
for _, container := range s.containers {
out, err := container.log(20)
if err != nil {
fmt.Printf("An error occured while obtaining '%s' container logs: %s\n", container.name, fmt.Sprint(err))
continue
}
- fmt.Printf("\nvvvvvvvvvvvvvvv " +
+ s.log("\nvvvvvvvvvvvvvvv " +
container.name + ":\n" +
out +
"^^^^^^^^^^^^^^^\n\n")
- logVppInstance(container, 20)
+ s.logVppInstance(container, 20)
}
}
@@ -187,9 +196,25 @@ func (s *HstSuite) assertNotEmpty(object interface{}, msgAndArgs ...interface{})
Expect(object).ToNot(BeEmpty(), msgAndArgs...)
}
+func (s *HstSuite) createLogger(){
+ suiteName := CurrentSpecReport().ContainerHierarchyTexts[0]
+ var err error
+ s.logFile, err = os.Create("summary/" + suiteName + ".log")
+ if err != nil {
+ Fail("Unable to create log file.")
+ }
+ s.logger = log.New(io.Writer(s.logFile), "", log.LstdFlags)
+}
+
+// Logs to files by default, logs to stdout when VERBOSE=true with GinkgoWriter
+// to keep console tidy
func (s *HstSuite) log(arg any) {
+ logs := strings.Split(fmt.Sprint(arg), "\n")
+ for _, line := range logs {
+ s.logger.Println(line)
+ }
if *isVerbose {
- slog.Info(fmt.Sprint(arg))
+ GinkgoWriter.Println(arg)
}
}
@@ -266,7 +291,7 @@ func (s *HstSuite) loadContainerTopology(topologyName string) {
for _, elem := range yamlTopo.Volumes {
volumeMap := elem["volume"].(VolumeConfig)
hostDir := volumeMap["host-dir"].(string)
- workingVolumeDir := logDir + CurrentSpecReport().LeafNodeText + s.pid + volumeDir
+ workingVolumeDir := logDir + CurrentSpecReport().LeafNodeText + volumeDir
volDirReplacer := strings.NewReplacer("$HST_VOLUME_DIR", workingVolumeDir)
hostDir = volDirReplacer.Replace(hostDir)
s.volumes = append(s.volumes, hostDir)
diff --git a/extras/hs-test/raw_session_test.go b/extras/hs-test/raw_session_test.go
index cf74c62cd3e..5c66df0b1ce 100644
--- a/extras/hs-test/raw_session_test.go
+++ b/extras/hs-test/raw_session_test.go
@@ -1,16 +1,15 @@
package main
func init() {
- registerVethTests(VppEchoQuicTest, VppEchoTcpTest, VppEchoUdpTest)
+ registerVethTests(VppEchoQuicTest, VppEchoTcpTest)
}
func VppEchoQuicTest(s *VethsSuite) {
s.testVppEcho("quic")
}
-// udp echo currently broken in vpp, skipping
+// TODO: udp echo currently broken in vpp
func VppEchoUdpTest(s *VethsSuite) {
- s.skip("Broken")
s.testVppEcho("udp")
}
diff --git a/extras/hs-test/script/compress.sh b/extras/hs-test/script/compress.sh
new file mode 100644
index 00000000000..92a2fbd6789
--- /dev/null
+++ b/extras/hs-test/script/compress.sh
@@ -0,0 +1,34 @@
+#!/usr/bin/env bash
+
+if [ "${COMPRESS_FAILED_TEST_LOGS}" == "yes" -a -s "${HS_SUMMARY}/failed-summary.log" ]
+then
+ echo -n "Copying docker logs..."
+ dirs=$(jq -r '.[0] | .SpecReports[] | select(.State == "failed") | .LeafNodeText' ${HS_SUMMARY}/report.json)
+ for dirName in $dirs; do
+ logDir=/tmp/hs-test/$dirName
+ if [ -d "$logDir" ]; then
+ mkdir -p $WORKSPACE/archives/summary
+ cp -r $logDir $WORKSPACE/archives/summary/
+ fi
+ done
+ echo "Done."
+
+ if [ -n "$WORKSPACE" ]
+ then
+ echo -n "Copying failed test logs into build log archive directory ($WORKSPACE/archives)... "
+ mkdir -p $WORKSPACE/archives/summary
+ cp -a ${HS_SUMMARY}/* $WORKSPACE/archives/summary
+ echo "Done."
+ fi
+
+ echo -n "Compressing files in $WORKSPACE/archives from test runs... "
+ cd $WORKSPACE/archives
+ find . -type f \( -name "*.json" -o -name "*.log" \) -exec gzip {} \;
+ echo "Done."
+
+else
+ echo "Not compressing files in temporary directories from test runs."
+ exit 0
+fi
+
+exit 1 \ No newline at end of file
diff --git a/extras/hs-test/suite_nginx_test.go b/extras/hs-test/suite_nginx_test.go
index 2d1caf152f4..c559496e71b 100644
--- a/extras/hs-test/suite_nginx_test.go
+++ b/extras/hs-test/suite_nginx_test.go
@@ -98,7 +98,9 @@ var _ = Describe("NginxSuite", Ordered, ContinueOnFailure, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
@@ -118,11 +120,14 @@ var _ = Describe("NginxSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
AfterEach(func() {
s.TearDownTest()
})
+
for _, test := range nginxSoloTests {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], Label("SOLO"), func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, Label("SOLO"), func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
diff --git a/extras/hs-test/suite_no_topo_test.go b/extras/hs-test/suite_no_topo_test.go
index 6df06c7e60e..625dca9f3cf 100644
--- a/extras/hs-test/suite_no_topo_test.go
+++ b/extras/hs-test/suite_no_topo_test.go
@@ -74,7 +74,9 @@ var _ = Describe("NoTopoSuite", Ordered, ContinueOnFailure, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
@@ -99,7 +101,9 @@ var _ = Describe("NoTopoSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], Label("SOLO"), func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, Label("SOLO"), func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
diff --git a/extras/hs-test/suite_ns_test.go b/extras/hs-test/suite_ns_test.go
index 86d9b78a010..85b90911c2f 100644
--- a/extras/hs-test/suite_ns_test.go
+++ b/extras/hs-test/suite_ns_test.go
@@ -83,7 +83,9 @@ var _ = Describe("NsSuite", Ordered, ContinueOnFailure, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
@@ -108,7 +110,9 @@ var _ = Describe("NsSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], Label("SOLO"), func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, Label("SOLO"), func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
diff --git a/extras/hs-test/suite_tap_test.go b/extras/hs-test/suite_tap_test.go
index 25c1e25a215..ebf0f9b3cbc 100644
--- a/extras/hs-test/suite_tap_test.go
+++ b/extras/hs-test/suite_tap_test.go
@@ -48,7 +48,9 @@ var _ = Describe("TapSuite", Ordered, ContinueOnFailure, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
@@ -73,7 +75,9 @@ var _ = Describe("TapSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], Label("SOLO"), func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, Label("SOLO"), func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
diff --git a/extras/hs-test/suite_veth_test.go b/extras/hs-test/suite_veth_test.go
index f4c3684f031..d47bf8c52a9 100644
--- a/extras/hs-test/suite_veth_test.go
+++ b/extras/hs-test/suite_veth_test.go
@@ -107,7 +107,9 @@ var _ = Describe("VethsSuite", Ordered, ContinueOnFailure, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
@@ -123,7 +125,6 @@ var _ = Describe("VethsSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
})
AfterAll(func() {
s.TearDownSuite()
-
})
AfterEach(func() {
s.TearDownTest()
@@ -134,7 +135,9 @@ var _ = Describe("VethsSuiteSolo", Ordered, ContinueOnFailure, Serial, func() {
test := test
pc := reflect.ValueOf(test).Pointer()
funcValue := runtime.FuncForPC(pc)
- It(strings.Split(funcValue.Name(), ".")[2], Label("SOLO"), func(ctx SpecContext) {
+ testName := strings.Split(funcValue.Name(), ".")[2]
+ It(testName, Label("SOLO"), func(ctx SpecContext) {
+ s.log(testName + ": BEGIN")
test(&s)
}, SpecTimeout(time.Minute*5))
}
diff --git a/extras/hs-test/test b/extras/hs-test/test
index 94162b87759..fd17feb2c50 100755
--- a/extras/hs-test/test
+++ b/extras/hs-test/test
@@ -86,4 +86,6 @@ if [ $single_test -eq 0 ] && [ $debug_set -eq 1 ]; then
exit 1
fi
-sudo -E go run github.com/onsi/ginkgo/v2/ginkgo --no-color --trace $ginkgo_args -- $args
+mkdir -p summary
+
+sudo -E go run github.com/onsi/ginkgo/v2/ginkgo --no-color --trace --json-report=summary/report.json $ginkgo_args -- $args
diff --git a/extras/hs-test/vppinstance.go b/extras/hs-test/vppinstance.go
index 7ddec7e0ed4..9b400cfcb77 100644
--- a/extras/hs-test/vppinstance.go
+++ b/extras/hs-test/vppinstance.go
@@ -2,6 +2,7 @@ package main
import (
"fmt"
+ "io"
"os"
"os/exec"
"os/signal"
@@ -10,6 +11,7 @@ import (
"syscall"
"time"
+ "github.com/sirupsen/logrus"
"github.com/edwarnicke/exechelper"
. "github.com/onsi/ginkgo/v2"
@@ -106,6 +108,10 @@ func (vpp *VppInstance) getEtcDir() string {
}
func (vpp *VppInstance) start() error {
+ // Replace default logger in govpp with our own
+ govppLogger := logrus.New()
+ govppLogger.SetOutput(io.MultiWriter(vpp.getSuite().logger.Writer(), GinkgoWriter))
+ core.SetLogger(govppLogger)
// Create folders
containerWorkDir := vpp.container.getContainerWorkDir()