Merge pull request #90 from jpinsonneau/test_e2e_failure

NETOBSERV-1882 test e2e faillure

.github/workflows/pull_request_e2e.yml

@@ -26,6 +26,8 @@ jobs:
         go-version: '1.22'
     - name: checkout
       uses: actions/checkout@v3
+    - name: get kernel version
+      run: uname -r
     - name: run end-to-end tests
       run: make tests-e2e
     - name: upload e2e test logs

cmd/flow_capture.go

@@ -82,29 +82,45 @@ func runFlowCaptureOnAddr(port int, filename string) {
 		log.Errorf("Create directory failed: %v", err.Error())
 		log.Fatal(err)
 	}
+	log.Trace("Created flow folder")
+
 	f, err = os.Create("./output/flow/" + filename + ".json")
 	if err != nil {
 		log.Errorf("Create file %s failed: %v", filename, err.Error())
 		log.Fatal(err)
 	}
 	defer f.Close()
+	log.Trace("Created json file")
+
+	// Initialize sqlite DB
+	db := initFlowDB(filename)
+	log.Trace("Initialized database")
 
 	flowPackets := make(chan *genericmap.Flow, 100)
 	collector, err := grpc.StartCollector(port, flowPackets)
 	if err != nil {
 		log.Error("StartCollector failed:", err.Error())
 		log.Fatal(err)
 	}
-	// Initialize sqlite DB
-	db := initFlowDB(filename)
+	log.Trace("Started collector")
+
 	go func() {
 		<-utils.ExitChannel()
+		log.Trace("Ending collector")
 		close(flowPackets)
 		collector.Close()
 		db.Close()
+		log.Trace("Done")
 	}()
+
+	log.Trace("Ready ! Waiting for flows...")
 	for fp := range flowPackets {
+		if !captureStarted {
+			log.Tracef("Received first %d flows", len(flowPackets))
+		}
+
 		if stopReceived {
+			log.Trace("Stop received")
 			return
 		}
 		// parse and display flow async
@@ -115,11 +131,18 @@ func runFlowCaptureOnAddr(port int, filename string) {
 		if err != nil {
 			log.Error("Error while writing to DB:", err.Error())
 		}
+		if !captureStarted {
+			log.Trace("Wrote flows to DB")
+		}
+
 		// append new line between each record to read file easilly
 		bytes, err := f.Write(append(fp.GenericMap.Value, []byte(",\n")...))
 		if err != nil {
 			log.Fatal(err)
 		}
+		if !captureStarted {
+			log.Trace("Wrote flows to json")
+		}
 
 		// terminate capture if max bytes reached
 		totalBytes = totalBytes + int64(bytes)
@@ -135,6 +158,8 @@ func runFlowCaptureOnAddr(port int, filename string) {
 			log.Infof("Capture reached %s, exiting now...", maxTime)
 			return
 		}
+
+		captureStarted = true
 	}
 }
 
@@ -146,6 +171,9 @@ func parseGenericMapAndDisplay(bytes []byte) {
 		return
 	}
 
+	if !captureStarted {
+		log.Tracef("Parsed genericMap %v", genericMap)
+	}
 	manageFlowsDisplay(genericMap)
 }
 

cmd/packet_capture.go

@@ -64,11 +64,15 @@ func runPacketCaptureOnAddr(port int, filename string) {
 		log.Errorf("Create directory failed: %v", err.Error())
 		log.Fatal(err)
 	}
+	log.Trace("Created pcap folder")
+
 	pw, err := pcapng.NewFileWriter("./output/pcap/" + filename + ".pcapng")
 	if err != nil {
 		log.Errorf("Create file %s failed: %v", filename, err.Error())
 		log.Fatal(err)
 	}
+	log.Trace("Created pcapng file")
+
 	// write pcap file header
 	so := types.SectionHeaderOptions{
 		Comment:     filename,
@@ -79,33 +83,52 @@ func runPacketCaptureOnAddr(port int, filename string) {
 		log.Fatal(err)
 	}
 	defer f.Close()
+	log.Trace("Wrote pcap section header")
 
 	flowPackets := make(chan *genericmap.Flow, 100)
 	collector, err := grpc.StartCollector(port, flowPackets)
 	if err != nil {
 		log.Error("StartCollector failed:", err.Error())
 		log.Fatal(err)
 	}
+	log.Trace("Started collector")
+
 	go func() {
 		<-utils.ExitChannel()
+		log.Trace("Ending collector")
 		close(flowPackets)
 		collector.Close()
+		log.Trace("Done")
 	}()
+
+	log.Trace("Ready ! Waiting for packets...")
 	for fp := range flowPackets {
+		if !captureStarted {
+			log.Tracef("Received first %d packets", len(flowPackets))
+		}
+
 		if stopReceived {
+			log.Trace("Stop received")
 			return
 		}
+
 		genericMap := config.GenericMap{}
 		err := json.Unmarshal(fp.GenericMap.Value, &genericMap)
 		if err != nil {
 			log.Error("Error while parsing json", err)
 			return
 		}
+		if !captureStarted {
+			log.Tracef("Parsed genericMap %v", genericMap)
+		}
 
 		data, ok := genericMap["Data"]
 		if ok {
 			// clear generic map data
 			delete(genericMap, "Data")
+			if !captureStarted {
+				log.Trace("Deleted data")
+			}
 
 			// display as flow async
 			go manageFlowsDisplay(genericMap)
@@ -129,6 +152,10 @@ func runPacketCaptureOnAddr(port int, filename string) {
 				log.Fatal(err)
 			}
 		} else {
+			if !captureStarted {
+				log.Trace("Data is missing")
+			}
+
 			// display as flow async
 			go manageFlowsDisplay(genericMap)
 		}
@@ -147,6 +174,8 @@ func runPacketCaptureOnAddr(port int, filename string) {
 			log.Infof("Capture reached %s, exiting now...", maxTime)
 			return
 		}
+
+		captureStarted = true
 	}
 }
 

cmd/root.go

@@ -4,7 +4,9 @@ import (
 	"bytes"
 	"fmt"
 	"os"
+	"os/exec"
 	"os/signal"
+	"strings"
 	"sync"
 	"syscall"
 	"time"
@@ -50,10 +52,11 @@ var (
 		},
 	}
 
-	captureType   = "Flow"
-	outputBuffer  *bytes.Buffer
-	stopReceived  = false
-	keyboardError = ""
+	captureType    = "Flow"
+	outputBuffer   *bytes.Buffer
+	captureStarted = false
+	stopReceived   = false
+	keyboardError  = ""
 )
 
 // Execute executes the root command.
@@ -97,4 +100,17 @@ func initConfig() {
 	}
 
 	log.Infof("Running network-observability-cli\nLog level: %s\nFilter(s): %s", logLevel, filter)
+	showKernelVersion()
+}
+
+func showKernelVersion() {
+	output, err := exec.Command("uname", "-r").Output()
+	if err != nil {
+		log.Errorf("Can't get kernel version: %v", err)
+	}
+	if len(output) == 0 {
+		log.Infof("Kernel version not found")
+	} else {
+		log.Infof("Kernel version: %s", strings.TrimSpace(string(output)))
+	}
 }

e2e/capture_test.go

@@ -9,6 +9,7 @@ import (
 	"path"
 	"path/filepath"
 	"testing"
+	"time"
 
 	"github.com/netobserv/network-observability-cli/e2e/cluster"
 	"github.com/stretchr/testify/assert"
@@ -21,6 +22,7 @@ import (
 const (
 	clusterNamePrefix = "netobserv-cli-e2e-test-cluster"
 	namespace         = "default"
+	ExportLogsTimeout = 30 * time.Second
 )
 
 var (
@@ -42,7 +44,14 @@ func TestMain(m *testing.M) {
 func TestFlowCapture(t *testing.T) {
 	f1 := features.New("flow capture").Setup(
 		func(ctx context.Context, t *testing.T, cfg *envconf.Config) context.Context {
-			output, err := RunCommand(clog, "oc-netobserv", "flows")
+			timer := time.AfterFunc(ExportLogsTimeout, func() {
+				agentLogs := testCluster.GetAgentLogs()
+				err := os.WriteFile(path.Join(testCluster.GetLogsDir(), StartupDate+"-flowAgentLogs"), []byte(agentLogs), 0666)
+				assert.Nil(t, err)
+			})
+			defer timer.Stop()
+
+			output, err := RunCommand(clog, "oc-netobserv", "flows", "--log-level=trace")
 			// TODO: find a way to avoid error here; this is probably related to SIGTERM instead of CTRL + C call
 			//assert.Nil(t, err)
 
@@ -113,7 +122,14 @@ func TestFlowCapture(t *testing.T) {
 func TestPacketCapture(t *testing.T) {
 	f1 := features.New("packet capture").Setup(
 		func(ctx context.Context, t *testing.T, cfg *envconf.Config) context.Context {
-			output, err := RunCommand(clog, "oc-netobserv", "packets", "--protocol=TCP", "--port=6443")
+			timer := time.AfterFunc(ExportLogsTimeout, func() {
+				agentLogs := testCluster.GetAgentLogs()
+				err := os.WriteFile(path.Join(testCluster.GetLogsDir(), StartupDate+"-packetAgentLogs"), []byte(agentLogs), 0666)
+				assert.Nil(t, err)
+			})
+			defer timer.Stop()
+
+			output, err := RunCommand(clog, "oc-netobserv", "packets", "--log-level=trace", "--protocol=TCP", "--port=6443")
 			// TODO: find a way to avoid error here; this is probably related to SIGTERM instead of CTRL + C call
 			//assert.Nil(t, err)
 

e2e/cluster/kind.go

@@ -2,6 +2,7 @@ package cluster
 
 import (
 	"context"
+	"fmt"
 	"os"
 	"path"
 	"runtime"
@@ -18,7 +19,7 @@ import (
 
 const (
 	cliContainerName = "localhost/netobserv-cli:test"
-	kindImage        = "kindest/node:v1.29.2"
+	kindImage        = "kindest/node:v1.31.0"
 	logsSubDir       = "e2e-logs"
 	localArchiveName = "cli-e2e-img.tar"
 )
@@ -73,10 +74,19 @@ func (k *Kind) Run(m *testing.M) {
 	klog.WithField("returnCode", code).Info("tests finished run")
 }
 
+func (k *Kind) GetLogsDir() string {
+	logsDir := path.Join(k.baseDir, logsSubDir)
+	err := os.MkdirAll(logsDir, 0700)
+	if err != nil {
+		klog.Error(err)
+	}
+	return logsDir
+}
+
 // export logs into the e2e-logs folder of the base directory.
 func (k *Kind) exportLogs() env.Func {
 	return func(ctx context.Context, config *envconf.Config) (context.Context, error) {
-		logsDir := path.Join(k.baseDir, logsSubDir)
+		logsDir := k.GetLogsDir()
 		klog.WithField("directory", logsDir).Info("exporting cluster logs")
 		exe := gexe.New()
 		out := exe.Run("kind export logs " + logsDir + " --name " + k.clusterName)
@@ -92,6 +102,14 @@ func (k *Kind) exportLogs() env.Func {
 	}
 }
 
+func (k *Kind) GetAgentLogs() string {
+	exe := gexe.New()
+	contextOut := exe.Run("kubectl cluster-info --context " + k.clusterName)
+	logsOut := exe.Run("kubectl logs -l app=netobserv-cli -n netobserv-cli --tail -1")
+
+	return fmt.Sprintf("Set context: %s\n\nLogs: %s", contextOut, logsOut)
+}
+
 // delete netobserv-cli namespace
 func (k *Kind) deleteNamespace() env.Func {
 	return func(ctx context.Context, config *envconf.Config) (context.Context, error) {

e2e/common.go

@@ -10,7 +10,7 @@ import (
 )
 
 const (
-	CommandTimeout = 30 * time.Second
+	CommandTimeout = 60 * time.Second
 )
 
 var (

scripts/kind-cluster.sh

@@ -8,7 +8,7 @@ K8S_CLI_BIN=$( basename "${K8S_CLI_BIN_PATH}" )
 DIR=$( cd -- "$( dirname -- "${BASH_SOURCE[0]}" )" &> /dev/null && cd ../ && pwd )
 
 KIND_CLUSTER_NAME="netobserv-cli-cluster"
-KIND_IMAGE="kindest/node:v1.29.2"
+KIND_IMAGE="kindest/node:v1.31.0"
 
 # deploy_kind installs the kind cluster
 deploy_kind() {