From bc7e3365a081250a880be1285f1a8e686cd16da3 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Mon, 16 Sep 2024 17:15:55 +0200 Subject: [PATCH 01/11] add trace logs --- cmd/flow_capture.go | 16 ++++++++++++++-- cmd/packet_capture.go | 12 ++++++++++++ e2e/capture_test.go | 4 ++-- e2e/common.go | 2 +- 4 files changed, 29 insertions(+), 5 deletions(-) diff --git a/cmd/flow_capture.go b/cmd/flow_capture.go index 00af9a5a..33c40010 100644 --- a/cmd/flow_capture.go +++ b/cmd/flow_capture.go @@ -82,12 +82,19 @@ 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) @@ -95,16 +102,21 @@ func runFlowCaptureOnAddr(port int, filename string) { 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 stopReceived { + log.Trace("Stop received") return } // parse and display flow async diff --git a/cmd/packet_capture.go b/cmd/packet_capture.go index 82ee4f95..213c46c7 100644 --- a/cmd/packet_capture.go +++ b/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,6 +83,7 @@ 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) @@ -86,13 +91,20 @@ func runPacketCaptureOnAddr(port int, filename string) { 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 stopReceived { + log.Trace("Stop received") return } genericMap := config.GenericMap{} diff --git a/e2e/capture_test.go b/e2e/capture_test.go index e58e5f4f..fe46d9b1 100644 --- a/e2e/capture_test.go +++ b/e2e/capture_test.go @@ -42,7 +42,7 @@ 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") + 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 +113,7 @@ 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") + 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) diff --git a/e2e/common.go b/e2e/common.go index b1cba018..97f3e25f 100644 --- a/e2e/common.go +++ b/e2e/common.go @@ -10,7 +10,7 @@ import ( ) const ( - CommandTimeout = 30 * time.Second + CommandTimeout = 60 * time.Second ) var ( From 67f6c5b97d50a17efb24f98dcc2c5a2b03003ed5 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Mon, 16 Sep 2024 17:47:01 +0200 Subject: [PATCH 02/11] dig into first data --- cmd/flow_capture.go | 16 ++++++++++++++++ cmd/packet_capture.go | 17 +++++++++++++++++ cmd/root.go | 9 +++++---- 3 files changed, 38 insertions(+), 4 deletions(-) diff --git a/cmd/flow_capture.go b/cmd/flow_capture.go index 33c40010..a30ee1b1 100644 --- a/cmd/flow_capture.go +++ b/cmd/flow_capture.go @@ -115,6 +115,10 @@ func runFlowCaptureOnAddr(port int, filename string) { 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 @@ -127,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) @@ -147,6 +158,8 @@ func runFlowCaptureOnAddr(port int, filename string) { log.Infof("Capture reached %s, exiting now...", maxTime) return } + + captureStarted = true } } @@ -158,6 +171,9 @@ func parseGenericMapAndDisplay(bytes []byte) { return } + if !captureStarted { + log.Tracef("Parsed genericMap %v", genericMap) + } manageFlowsDisplay(genericMap) } diff --git a/cmd/packet_capture.go b/cmd/packet_capture.go index 213c46c7..3ef6e1c3 100644 --- a/cmd/packet_capture.go +++ b/cmd/packet_capture.go @@ -103,21 +103,32 @@ func runPacketCaptureOnAddr(port int, filename string) { 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) @@ -141,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) } @@ -159,6 +174,8 @@ func runPacketCaptureOnAddr(port int, filename string) { log.Infof("Capture reached %s, exiting now...", maxTime) return } + + captureStarted = true } } diff --git a/cmd/root.go b/cmd/root.go index ce9e577d..6f86de08 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -50,10 +50,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. From 4786268ef0c8990ef4067a048a914be7fd7d913e Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 09:54:23 +0200 Subject: [PATCH 03/11] missing filters --- res/packet-capture.yml | 18 ++++++++++++++++++ 1 file changed, 18 insertions(+) diff --git a/res/packet-capture.yml b/res/packet-capture.yml index e9118d69..832da6b1 100644 --- a/res/packet-capture.yml +++ b/res/packet-capture.yml @@ -31,6 +31,22 @@ spec: value: "false" - name: LOG_LEVEL value: info + - name: INTERFACES + value: "" + - name: EXCLUDE_INTERFACES + value: "lo" + - name: SAMPLING + value: "1" + - name: ENABLE_RTT + value: "false" + - name: ENABLE_PKT_DROPS + value: "false" + - name: ENABLE_DNS_TRACKING + value: "false" + - name: ENABLE_NETWORK_EVENTS_MONITORING + value: "false" + - name: ENABLE_FLOW_FILTER + value: "false" - name: FILTER_DIRECTION value: "" - name: FILTER_IP_CIDR @@ -55,6 +71,8 @@ spec: value: "" - name: FILTER_PEER_IP value: "" + - name: FILTER_TCP_FLAGS + value: "" - name: FILTER_ACTION value: "Accept" - name: EXPORT From 89296a5846b039bff26022449ff7853c6c94f8cc Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 10:23:39 +0200 Subject: [PATCH 04/11] rollback ebpf agent version --- Makefile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Makefile b/Makefile index 323bef61..411a71a4 100644 --- a/Makefile +++ b/Makefile @@ -44,7 +44,7 @@ IMAGE_TAG_BASE ?= quay.io/$(IMAGE_ORG)/$(NAME) IMAGE ?= $(IMAGE_TAG_BASE):$(VERSION) PULL_POLICY ?=Always # Agent image URL to deploy -AGENT_IMAGE ?= quay.io/netobserv/netobserv-ebpf-agent:main +AGENT_IMAGE ?= quay.io/netobserv/netobserv-ebpf-agent:c6f33c1 OCI_BUILD_OPTS ?= # Image building tool (docker / podman) - docker is preferred in CI From a0531fbbc75f3939d3f215d1f8c43a146d8175c7 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 10:41:44 +0200 Subject: [PATCH 05/11] show kernel version --- .github/workflows/pull_request_e2e.yml | 2 ++ 1 file changed, 2 insertions(+) diff --git a/.github/workflows/pull_request_e2e.yml b/.github/workflows/pull_request_e2e.yml index 4fe3b235..d7540122 100644 --- a/.github/workflows/pull_request_e2e.yml +++ b/.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 From a97b0211ed457ec1462699355b54392807acf3a8 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 10:49:15 +0200 Subject: [PATCH 06/11] display kernel version --- cmd/root.go | 15 +++++++++++++++ 1 file changed, 15 insertions(+) diff --git a/cmd/root.go b/cmd/root.go index 6f86de08..a6f1bf44 100644 --- a/cmd/root.go +++ b/cmd/root.go @@ -4,7 +4,9 @@ import ( "bytes" "fmt" "os" + "os/exec" "os/signal" + "strings" "sync" "syscall" "time" @@ -98,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))) + } } From a081eceb7cc45e29c22004844c373f95a4277628 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 11:13:11 +0200 Subject: [PATCH 07/11] update kind cluster --- scripts/kind-cluster.sh | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/scripts/kind-cluster.sh b/scripts/kind-cluster.sh index c5481227..6f447861 100755 --- a/scripts/kind-cluster.sh +++ b/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() { From a744296462ce38f464c8afdddf5aebfafb57d13f Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 12:07:05 +0200 Subject: [PATCH 08/11] agent logs --- e2e/capture_test.go | 16 ++++++++++++++++ e2e/cluster/kind.go | 20 +++++++++++++++++++- 2 files changed, 35 insertions(+), 1 deletion(-) diff --git a/e2e/capture_test.go b/e2e/capture_test.go index fe46d9b1..981df25f 100644 --- a/e2e/capture_test.go +++ b/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,6 +44,13 @@ 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 { + 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,6 +122,13 @@ 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 { + 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) diff --git a/e2e/cluster/kind.go b/e2e/cluster/kind.go index 6c7604ca..e6bfde6c 100644 --- a/e2e/cluster/kind.go +++ b/e2e/cluster/kind.go @@ -2,6 +2,7 @@ package cluster import ( "context" + "fmt" "os" "path" "runtime" @@ -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) { From 1ef364440d2e04b8a28ed5b6ac7ec0344620ad84 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 12:15:05 +0200 Subject: [PATCH 09/11] restore ebpf main tag --- Makefile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Makefile b/Makefile index 411a71a4..323bef61 100644 --- a/Makefile +++ b/Makefile @@ -44,7 +44,7 @@ IMAGE_TAG_BASE ?= quay.io/$(IMAGE_ORG)/$(NAME) IMAGE ?= $(IMAGE_TAG_BASE):$(VERSION) PULL_POLICY ?=Always # Agent image URL to deploy -AGENT_IMAGE ?= quay.io/netobserv/netobserv-ebpf-agent:c6f33c1 +AGENT_IMAGE ?= quay.io/netobserv/netobserv-ebpf-agent:main OCI_BUILD_OPTS ?= # Image building tool (docker / podman) - docker is preferred in CI From 6ad84b0f072ab78baf083416b9dc5d007c741cfb Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 15:12:30 +0200 Subject: [PATCH 10/11] update kind image --- e2e/cluster/kind.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/e2e/cluster/kind.go b/e2e/cluster/kind.go index e6bfde6c..56d732ca 100644 --- a/e2e/cluster/kind.go +++ b/e2e/cluster/kind.go @@ -19,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" ) From 06068df3ee304ea3e372ba591be489dc339fac23 Mon Sep 17 00:00:00 2001 From: Julien Pinsonneau Date: Tue, 17 Sep 2024 15:37:54 +0200 Subject: [PATCH 11/11] revert packet capture yaml --- res/packet-capture.yml | 18 ------------------ 1 file changed, 18 deletions(-) diff --git a/res/packet-capture.yml b/res/packet-capture.yml index 832da6b1..e9118d69 100644 --- a/res/packet-capture.yml +++ b/res/packet-capture.yml @@ -31,22 +31,6 @@ spec: value: "false" - name: LOG_LEVEL value: info - - name: INTERFACES - value: "" - - name: EXCLUDE_INTERFACES - value: "lo" - - name: SAMPLING - value: "1" - - name: ENABLE_RTT - value: "false" - - name: ENABLE_PKT_DROPS - value: "false" - - name: ENABLE_DNS_TRACKING - value: "false" - - name: ENABLE_NETWORK_EVENTS_MONITORING - value: "false" - - name: ENABLE_FLOW_FILTER - value: "false" - name: FILTER_DIRECTION value: "" - name: FILTER_IP_CIDR @@ -71,8 +55,6 @@ spec: value: "" - name: FILTER_PEER_IP value: "" - - name: FILTER_TCP_FLAGS - value: "" - name: FILTER_ACTION value: "Accept" - name: EXPORT