From c37cdffdf31ace657b0d6479e88dcf2be5a7066d Mon Sep 17 00:00:00 2001 From: aya Date: Tue, 11 Mar 2025 11:53:12 +0200 Subject: [PATCH] Add stress tests --- waku/nwaku_test_utils.go | 23 ++++ waku/stress_test.go | 193 +++++++++++++++++++++++++----- waku/test_repeated_start_stop.log | 62 ++++++++++ 3 files changed, 249 insertions(+), 29 deletions(-) create mode 100644 waku/test_repeated_start_stop.log diff --git a/waku/nwaku_test_utils.go b/waku/nwaku_test_utils.go index 7e319d7..1dd4754 100644 --- a/waku/nwaku_test_utils.go +++ b/waku/nwaku_test_utils.go @@ -9,6 +9,7 @@ import ( "net/http" "os" "strconv" + "strings" "time" "github.com/cenkalti/backoff/v3" @@ -255,3 +256,25 @@ func (n *WakuNode) GetStoredMessages(storeNode *WakuNode, storeRequest *common.S Debug("Store query successful, retrieved %d messages", len(*res.Messages)) return res, nil } + +func getRSSKB() (uint64, error) { + f, err := os.Open("/proc/self/statm") + if err != nil { + return 0, err + } + defer f.Close() + data, err := io.ReadAll(f) + if err != nil { + return 0, err + } + fields := strings.Fields(string(data)) + if len(fields) < 2 { + return 0, fmt.Errorf("unexpected /proc/self/statm format") + } + rssPages, err := strconv.ParseUint(fields[1], 10, 64) + if err != nil { + return 0, err + } + pageSize := os.Getpagesize() + return (rssPages * uint64(pageSize)) / 1024, nil +} diff --git a/waku/stress_test.go b/waku/stress_test.go index 0afcda7..bfff8bd 100644 --- a/waku/stress_test.go +++ b/waku/stress_test.go @@ -2,12 +2,14 @@ package waku import ( "fmt" + "io" "log" "os" "runtime" "testing" "time" + "github.com/sirupsen/logrus" "github.com/stretchr/testify/require" "github.com/waku-org/waku-go-bindings/waku/common" "google.golang.org/protobuf/proto" @@ -15,60 +17,193 @@ import ( func TestMemoryUsageForThreeNodes(t *testing.T) { logFile, err := os.OpenFile("test_logs.log", os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0666) - require.NoError(t, err, "Failed to open log file") + require.NoError(t, err) + defer logFile.Close() - multiWriter := log.MultiWriter(os.Stdout, logFile) + multiWriter := io.MultiWriter(os.Stdout, logFile) log.SetOutput(multiWriter) + logger := _getLogger() + logger.SetOutput(multiWriter) + logger.SetLevel(logrus.DebugLevel) - Debug("Starting memory usage test for three Waku nodes") + testName := t.Name() var memStats runtime.MemStats runtime.ReadMemStats(&memStats) - initialHeapAlloc := memStats.HeapAlloc - Debug("Initial memory usage before creating nodes: %d MB", initialHeapAlloc/1024/1024) + Debug("[%s] Memory usage BEFORE creating nodes: %d KB", testName, memStats.HeapAlloc/1024) - node1, err := NewWakuNode(&DefaultWakuConfig, "node1") - require.NoError(t, err, "Failed to create Node1") + node1Cfg := DefaultWakuConfig + node1Cfg.TcpPort, node1Cfg.Discv5UdpPort, err = GetFreePortIfNeeded(0, 0) + require.NoError(t, err) + node2Cfg := DefaultWakuConfig + node2Cfg.TcpPort, node2Cfg.Discv5UdpPort, err = GetFreePortIfNeeded(0, 0) + require.NoError(t, err) + node3Cfg := DefaultWakuConfig + node3Cfg.TcpPort, node3Cfg.Discv5UdpPort, err = GetFreePortIfNeeded(0, 0) + require.NoError(t, err) - node2, err := NewWakuNode(&DefaultWakuConfig, "node2") - require.NoError(t, err, "Failed to create Node2") - - node3, err := NewWakuNode(&DefaultWakuConfig, "node3") - require.NoError(t, err, "Failed to create Node3") + node1, err := NewWakuNode(&node1Cfg, "node1") + require.NoError(t, err) + node2, err := NewWakuNode(&node2Cfg, "node2") + require.NoError(t, err) + node3, err := NewWakuNode(&node3Cfg, "node3") + require.NoError(t, err) runtime.ReadMemStats(&memStats) - afterCreationHeapAlloc := memStats.HeapAlloc - Debug("Memory usage after creating nodes: %d MB", afterCreationHeapAlloc/1024/1024) + Debug("[%s] Memory usage AFTER creating nodes: %d KB", testName, memStats.HeapAlloc/1024) err = node1.Start() - require.NoError(t, err, "Failed to start Node1") - + require.NoError(t, err) err = node2.Start() - require.NoError(t, err, "Failed to start Node2") - + require.NoError(t, err) err = node3.Start() - require.NoError(t, err, "Failed to start Node3") + require.NoError(t, err) runtime.ReadMemStats(&memStats) - afterStartHeapAlloc := memStats.HeapAlloc - Debug("Memory usage after starting nodes: %d MB", afterStartHeapAlloc/1024/1024) + Debug("[%s] Memory usage AFTER starting nodes: %d KB", testName, memStats.HeapAlloc/1024) time.Sleep(2 * time.Second) - node1.Stop() - node2.Stop() - node3.Stop() + node1.StopAndDestroy() + node2.StopAndDestroy() + node3.StopAndDestroy() + + runtime.GC() + time.Sleep(1 * time.Second) + runtime.GC() runtime.ReadMemStats(&memStats) - afterStopHeapAlloc := memStats.HeapAlloc - Debug("Memory usage after stopping nodes: %d MB", afterStopHeapAlloc/1024/1024) + Debug("[%s] Memory usage AFTER destroying nodes: %d KB", testName, memStats.HeapAlloc/1024) - require.LessOrEqual(t, afterStartHeapAlloc, initialHeapAlloc*3, "Unexpected memory growth after starting nodes") + Debug("[%s] Test completed successfully", testName) +} - Debug("Test completed successfully") +func Test5Nodes1kTearDown(t *testing.T) { + logFile, err := os.OpenFile("test_repeated_start_stop.log", os.O_CREATE|os.O_WRONLY|os.O_TRUNC, 0666) + require.NoError(t, err) + defer logFile.Close() - logFile.Close() + multiWriter := io.MultiWriter(os.Stdout, logFile) + logger := _getLogger() + logger.SetOutput(multiWriter) + logger.SetLevel(logrus.DebugLevel) + + var memStats runtime.MemStats + runtime.ReadMemStats(&memStats) + initialMem := memStats.HeapAlloc + Debug("[%s] Memory usage at test START: %d KB", t.Name(), initialMem/1024) + + initialRSS, err := getRSSKB() + require.NoError(t, err) + Debug("[%s] OS-level RSS at test START: %d KB", t.Name(), initialRSS) + + //totalIterations := 3 + //for i := 1; i <= totalIterations; i++ { + var nodes []*WakuNode + cfg1 := DefaultWakuConfig + cfg1.Relay = true + node, err := StartWakuNode("node1", &cfg1) + require.NoError(t, err, "Failed to start node%d", 0) + nodes = append(nodes, node) + cfg2 := DefaultWakuConfig + cfg2.Relay = true + node2, err := StartWakuNode("node2", &cfg2) + require.NoError(t, err, "Failed to start node%d", 1) + nodes = append(nodes, node2) + time.Sleep(5 * time.Second) + + err = node.ConnectPeer(node2) + require.NoError(t, err) + err = WaitForAutoConnection(nodes) + require.NoError(t, err) + message := node.CreateMessage() + msgHash, err := node.RelayPublishNoCTX(DefaultPubsubTopic, message) + require.NoError(t, err) + time.Sleep(5 * time.Second) + err = node2.VerifyMessageReceived(message, msgHash) + require.NoError(t, err, "Node5 did not receive message from node1 at iteration %d", 0) + + //node.StopAndDestroy() + //node2.StopAndDestroy() + //time.Sleep(20 * time.Second) + cfg3 := DefaultWakuConfig + cfg3.Relay = true + node3, err := StartWakuNode("node1", &cfg3) + require.NoError(t, err, "Failed to start node%d", 0) + + cfg4 := DefaultWakuConfig + cfg4.Relay = true + node4, err := StartWakuNode("node2", &cfg4) + require.NoError(t, err, "Failed to start node%d", 1) + //nodes = append(nodes, node2) + time.Sleep(5 * time.Second) + + err = node3.ConnectPeer(node4) + require.NoError(t, err) + time.Sleep(5 * time.Second) + require.NoError(t, err) + message2 := node3.CreateMessage() + msgHash2, err := node3.RelayPublishNoCTX(DefaultPubsubTopic, message2) + require.NoError(t, err) + time.Sleep(5 * time.Second) + err = node4.VerifyMessageReceived(message2, msgHash2) + require.NoError(t, err, "Node5 did not receive message from node1 at iteration %d", 1) + + // } +} + +func TestSendMessagesInTwoPhases(t *testing.T) { + + node1Config := DefaultWakuConfig + node1Config.Relay = true + node1, err := StartWakuNode("Node1", &node1Config) + require.NoError(t, err, "Failed to start Node1") + + node2Config := DefaultWakuConfig + node2Config.Relay = true + node2, err := StartWakuNode("Node2", &node2Config) + require.NoError(t, err, "Failed to start Node2") + + err = node1.ConnectPeer(node2) + require.NoError(t, err, "Failed to connect Node1 to Node2") + + msgFromNode1 := node1.CreateMessage() + msgHash1, err := node1.RelayPublishNoCTX(DefaultPubsubTopic, msgFromNode1) + require.NoError(t, err, "Failed to publish from Node1") + + time.Sleep(500 * time.Millisecond) + + err = node2.VerifyMessageReceived(msgFromNode1, msgHash1, 2*time.Second) + require.NoError(t, err, "Node2 did not receive message from Node1") + + //node1.StopAndDestroy() + //node2.StopAndDestroy() + + node3Config := DefaultWakuConfig + node3Config.Relay = true + node3, err := StartWakuNode("Node3", &node3Config) + require.NoError(t, err, "Failed to start Node3") + + node4Config := DefaultWakuConfig + node4Config.Relay = true + node4, err := StartWakuNode("Node4", &node4Config) + require.NoError(t, err, "Failed to start Node4") + + err = node3.ConnectPeer(node4) + require.NoError(t, err, "Failed to connect Node3 to Node4") + + msgFromNode3 := node3.CreateMessage() + msgHash3, err := node3.RelayPublishNoCTX(DefaultPubsubTopic, msgFromNode3) + require.NoError(t, err, "Failed to publish from Node3") + + time.Sleep(500 * time.Millisecond) + + err = node4.VerifyMessageReceived(msgFromNode3, msgHash3, 2*time.Second) + require.NoError(t, err, "Node4 did not receive message from Node3") + + node3.StopAndDestroy() + node4.StopAndDestroy() } func TestStoreQuery5kMessagesWithPagination(t *testing.T) { diff --git a/waku/test_repeated_start_stop.log b/waku/test_repeated_start_stop.log new file mode 100644 index 0000000..a0a6272 --- /dev/null +++ b/waku/test_repeated_start_stop.log @@ -0,0 +1,62 @@ +time="2025-03-11T11:42:39+02:00" level=debug msg="[Test5Nodes1kTearDown] Memory usage at test START: 826 KB" +time="2025-03-11T11:42:39+02:00" level=debug msg="[Test5Nodes1kTearDown] OS-level RSS at test START: 19880 KB" +time="2025-03-11T11:42:39+02:00" level=debug msg="Initializing node1" +time="2025-03-11T11:42:39+02:00" level=debug msg="Creating node1" +time="2025-03-11T11:42:39+02:00" level=debug msg="Creating new WakuNode: node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully created WakuNode: node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Starting node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Starting node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully started node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully started node1" +time="2025-03-11T11:42:49+02:00" level=debug msg="Initializing node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Creating node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Creating new WakuNode: node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully created WakuNode: node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Starting node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Starting node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully started node2" +time="2025-03-11T11:42:49+02:00" level=debug msg="Successfully started node2" +time="2025-03-11T11:42:54+02:00" level=debug msg="Connecting node1 to node2" +time="2025-03-11T11:42:54+02:00" level=debug msg="Attempting connection to peer 16Uiu2HAkvcCDcUmHiFvrB2BUNjqz9uh3LuGoRHbUAddprhzjbwhG" +time="2025-03-11T11:42:59+02:00" level=debug msg="Successfully connected node1 to node2" +time="2025-03-11T11:42:59+02:00" level=debug msg="Waiting for auto-connection of nodes..." +time="2025-03-11T11:42:59+02:00" level=debug msg="Fetching connected peers for node1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Successfully fetched connected peers for node1, count: 1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Node node1 has 1 connected peers" +time="2025-03-11T11:42:59+02:00" level=debug msg="Fetching connected peers for node2" +time="2025-03-11T11:42:59+02:00" level=debug msg="Successfully fetched connected peers for node2, count: 1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Node node2 has 1 connected peers" +time="2025-03-11T11:42:59+02:00" level=debug msg="Auto-connection check completed successfully" +time="2025-03-11T11:42:59+02:00" level=debug msg="Creating a WakuMessage on node node1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Using default message format on node node1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Successfully created a default WakuMessage on node node1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Attempting to publish message via relay on node node1" +time="2025-03-11T11:42:59+02:00" level=debug msg="Successfully published message via relay on node node1, messageHash: 0x19156c2d240fafbd049a3933039de4f4f76252078f389eb138d0cb6681e659f9" +time="2025-03-11T11:43:04+02:00" level=debug msg="Verifying if the message was received on node node2, timeout: 3s" +time="2025-03-11T11:43:04+02:00" level=debug msg="Message received and verified successfully on node node2, Message: This is a default Waku message payload" +time="2025-03-11T11:43:04+02:00" level=debug msg="Initializing node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Creating node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Creating new WakuNode: node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully created WakuNode: node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Starting node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Starting node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully started node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully started node1" +time="2025-03-11T11:43:04+02:00" level=debug msg="Initializing node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Creating node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Creating new WakuNode: node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully created WakuNode: node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Starting node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Starting node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully started node2" +time="2025-03-11T11:43:04+02:00" level=debug msg="Successfully started node2" +time="2025-03-11T11:43:09+02:00" level=debug msg="Connecting node1 to node2" +time="2025-03-11T11:43:09+02:00" level=debug msg="Attempting connection to peer 16Uiu2HAmTwoeLQRdJeCYepo1ircmx2UEkgiN155PxNA4r3C12X6z" +time="2025-03-11T11:43:14+02:00" level=debug msg="Successfully connected node1 to node2" +time="2025-03-11T11:43:19+02:00" level=debug msg="Creating a WakuMessage on node node1" +time="2025-03-11T11:43:19+02:00" level=debug msg="Using default message format on node node1" +time="2025-03-11T11:43:19+02:00" level=debug msg="Successfully created a default WakuMessage on node node1" +time="2025-03-11T11:43:19+02:00" level=debug msg="Attempting to publish message via relay on node node1" +time="2025-03-11T11:43:19+02:00" level=debug msg="Successfully published message via relay on node node1, messageHash: 0xc37247e8c1729a068b1a035a85a457b34632c9d797fd287e398acd01dbd49fc0" +time="2025-03-11T11:43:24+02:00" level=debug msg="Verifying if the message was received on node node2, timeout: 3s" +time="2025-03-11T11:43:24+02:00" level=debug msg="Message received and verified successfully on node node2, Message: This is a default Waku message payload"