feat(e2e): add latency report to withdrawal performance tests

e2e/e2etests/test_stress_eth_withdraw.go

@@ -4,9 +4,10 @@ import (
 	"fmt"
 	"math/big"
 	"strconv"
+	"sync"
 	"time"
 
-	ethtypes "github.com/ethereum/go-ethereum/core/types"
+	"github.com/montanaflynn/stats"
 	"github.com/stretchr/testify/require"
 	"golang.org/x/sync/errgroup"
 
@@ -36,6 +37,10 @@ func TestStressEtherWithdraw(r *runner.E2ERunner, args []string) {
 	// create a wait group to wait for all the withdraws to complete
 	var eg errgroup.Group
 
+	// store durations as float64 seconds like prometheus
+	withdrawDurations := []float64{}
+	withdrawDurationsLock := sync.Mutex{}
+
 	// send the withdraws
 	for i := 0; i < numWithdraws; i++ {
 		i := i
@@ -49,29 +54,42 @@ func TestStressEtherWithdraw(r *runner.E2ERunner, args []string) {
 		r.Logger.Print("index %d: starting withdraw, tx hash: %s", i, tx.Hash().Hex())
 
 		eg.Go(func() error {
-			return monitorEtherWithdraw(r, tx, i, time.Now())
+			startTime := time.Now()
+			cctx := utils.WaitCctxMinedByInboundHash(r.Ctx, tx.Hash().Hex(), r.CctxClient, r.Logger, r.ReceiptTimeout)
+			if cctx.CctxStatus.Status != crosschaintypes.CctxStatus_OutboundMined {
+				return fmt.Errorf(
+					"index %d: withdraw cctx failed with status %s, message %s, cctx index %s",
+					i,
+					cctx.CctxStatus.Status,
+					cctx.CctxStatus.StatusMessage,
+					cctx.Index,
+				)
+			}
+			timeToComplete := time.Since(startTime)
+			r.Logger.Print("index %d: withdraw cctx success in %s", i, timeToComplete.String())
+
+			withdrawDurationsLock.Lock()
+			withdrawDurations = append(withdrawDurations, timeToComplete.Seconds())
+			withdrawDurationsLock.Unlock()
+
+			return nil
 		})
 	}
 
-	require.NoError(r, eg.Wait())
+	err = eg.Wait()
 
-	r.Logger.Print("all withdraws completed")
-}
+	desc, _ := stats.Describe(withdrawDurations, false, &[]float64{50.0, 75.0, 90.0, 95.0})
 
-// monitorEtherWithdraw monitors the withdraw of ether, returns once the withdraw is complete
-func monitorEtherWithdraw(r *runner.E2ERunner, tx *ethtypes.Transaction, index int, startTime time.Time) error {
-	cctx := utils.WaitCctxMinedByInboundHash(r.Ctx, tx.Hash().Hex(), r.CctxClient, r.Logger, r.ReceiptTimeout)
-	if cctx.CctxStatus.Status != crosschaintypes.CctxStatus_OutboundMined {
-		return fmt.Errorf(
-			"index %d: withdraw cctx failed with status %s, message %s, cctx index %s",
-			index,
-			cctx.CctxStatus.Status,
-			cctx.CctxStatus.StatusMessage,
-			cctx.Index,
-		)
+	r.Logger.Print("Latency report:")
+	r.Logger.Print("min:  %.2f", desc.Min)
+	r.Logger.Print("max:  %.2f", desc.Max)
+	r.Logger.Print("mean: %.2f", desc.Mean)
+	r.Logger.Print("std:  %.2f", desc.Std)
+	for _, p := range desc.DescriptionPercentiles {
+		r.Logger.Print("p%.0f:  %.2f", p.Percentile, p.Value)
 	}
-	timeToComplete := time.Since(startTime)
-	r.Logger.Print("index %d: withdraw cctx success in %s", index, timeToComplete.String())
 
-	return nil
+	require.NoError(r, err)
+
+	r.Logger.Print("all withdraws completed")
 }

e2e/utils/zetacore.go

@@ -81,7 +81,7 @@ func WaitCctxsMinedByInboundHash(
 		timedOut := time.Since(startTime) > timeout
 		require.False(t, timedOut, "waiting cctx timeout, cctx not mined, inbound hash: %s", inboundHash)
 
-		time.Sleep(1 * time.Second)
+		time.Sleep(500 * time.Millisecond)
 
 		// We use InTxHashToCctxData instead of InboundTrackerAllByChain to able to run these tests with the previous version
 		// for the update tests
@@ -90,7 +90,7 @@ func WaitCctxsMinedByInboundHash(
 		res, err := client.InTxHashToCctxData(ctx, in)
 		if err != nil {
 			// prevent spamming logs
-			if i%10 == 0 {
+			if i%20 == 0 {
 				logger.Info("Error getting cctx by inboundHash: %s", err.Error())
 			}
 			continue
@@ -113,7 +113,7 @@ func WaitCctxsMinedByInboundHash(
 			cctx := cctx
 			if !IsTerminalStatus(cctx.CctxStatus.Status) {
 				// prevent spamming logs
-				if i%10 == 0 {
+				if i%20 == 0 {
 					logger.Info(
 						"waiting for cctx index %d to be mined by inboundHash: %s, cctx status: %s, message: %s",
 						j,

go.mod

@@ -340,6 +340,7 @@ require (
 
 require (
 	github.com/decred/dcrd/crypto/blake256 v1.0.1 // indirect
+	github.com/montanaflynn/stats v0.7.1 // indirect
 	github.com/oasisprotocol/curve25519-voi v0.0.0-20220328075252-7dd334e3daae // indirect
 	github.com/sagikazarmark/locafero v0.4.0 // indirect
 	github.com/sagikazarmark/slog-shim v0.1.0 // indirect

go.sum

@@ -3321,6 +3321,8 @@ github.com/modern-go/reflect2 v1.0.2/go.mod h1:yWuevngMOJpCy52FWWMvUC8ws7m/LJsjY
 github.com/modocache/gover v0.0.0-20171022184752-b58185e213c5/go.mod h1:caMODM3PzxT8aQXRPkAt8xlV/e7d7w8GM5g0fa5F0D8=
 github.com/mohae/deepcopy v0.0.0-20170929034955-c48cc78d4826/go.mod h1:TaXosZuwdSHYgviHp1DAtfrULt5eUgsSMsZf+YrPgl8=
 github.com/montanaflynn/stats v0.0.0-20171201202039-1bf9dbcd8cbe/go.mod h1:wL8QJuTMNUDYhXwkmfOly8iTdp5TEcJFWZD2D7SIkUc=
+github.com/montanaflynn/stats v0.7.1 h1:etflOAAHORrCC44V+aR6Ftzort912ZU+YLiSTuV8eaE=
+github.com/montanaflynn/stats v0.7.1/go.mod h1:etXPPgVO6n31NxCd9KQUMvCM+ve0ruNzt6R8Bnaayow=
 github.com/moricho/tparallel v0.2.1/go.mod h1:fXEIZxG2vdfl0ZF8b42f5a78EhjjD5mX8qUplsoSU4k=
 github.com/morikuni/aec v1.0.0/go.mod h1:BbKIizmSmc5MMPqRYbxO4ZU0S0+P200+tUnFx7PXmsc=
 github.com/mostynb/zstdpool-freelist v0.0.0-20201229113212-927304c0c3b1 h1:mPMvm6X6tf4w8y7j9YIt6V9jfWhL6QlbEc7CCmeQlWk=