ligang/vpp
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

hs-test: logging improvements

Browse Source 
Type: test

Change-Id: Iffefe085e846b6ba614b0d74c4ba9907080a9a59
Signed-off-by: Adrian Villin <avillin@cisco.com>
This commit is contained in:
Adrian Villin
2024-05-06 06:55:34 -04:00
committed by Dave Wallace
parent 8761095e80
commit 637edda132
14 changed files with 125 additions and 31 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
.gitignore vendored
View File

@ -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

1
Makefile
View File

@ -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

8
extras/hs-test/Makefile
View File

@ -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"

2
extras/hs-test/container.go
View File

@ -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{}) {

53
extras/hs-test/hst_suite.go
View File

@ -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)

5
extras/hs-test/raw_session_test.go
View File

@ -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")
}

34
extras/hs-test/script/compress.sh Normal file
View File

@ -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

9
extras/hs-test/suite_nginx_test.go
View File

@ -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))
}

8
extras/hs-test/suite_no_topo_test.go
View File

@ -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))
}

8
extras/hs-test/suite_ns_test.go
View File

@ -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))
}

8
extras/hs-test/suite_tap_test.go
View File

@ -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))
}

9
extras/hs-test/suite_veth_test.go
View File

@ -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))
}

4
extras/hs-test/test
View File

@ -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

6
extras/hs-test/vppinstance.go
View File

@ -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()