From 8bb85856d0f8ad8e22b8c5cb191180d04687a012 Mon Sep 17 00:00:00 2001 From: "mergify[bot]" <37929162+mergify[bot]@users.noreply.github.com> Date: Fri, 5 Mar 2021 15:30:18 +0100 Subject: [PATCH] e2e: add benchmarking functionality (bp #6210) (#6216) --- test/e2e/README.md | 10 ++ test/e2e/runner/benchmark.go | 192 +++++++++++++++++++++++++++++++++++ test/e2e/runner/main.go | 57 +++++++++++ test/e2e/runner/wait.go | 8 +- 4 files changed, 266 insertions(+), 1 deletion(-) create mode 100644 test/e2e/runner/benchmark.go diff --git a/test/e2e/README.md b/test/e2e/README.md index 50f248c51..fb8e42158 100644 --- a/test/e2e/README.md +++ b/test/e2e/README.md @@ -50,6 +50,8 @@ The test runner has the following stages, which can also be executed explicitly * `cleanup`: removes configuration files and Docker containers/networks. +Auxiliary commands: + * `logs`: outputs all node logs. * `tail`: tails (follows) node logs until cancelled. @@ -119,3 +121,11 @@ Docker does not enable IPv6 by default. To do so, enter the following in "fixed-cidr-v6": "2001:db8:1::/64" } ``` + +## Benchmarking testnets + +It is also possible to run a simple benchmark on a testnet. This is done through the `benchmark` command. This manages the entire process: setting up the environment, starting the test net, waiting for a considerable amount of blocks to be used (currently 100), and then returning the following metrics from the sample of the blockchain: + +- Average time to produce a block +- Standard deviation of producing a block +- Minimum and maximum time to produce a block diff --git a/test/e2e/runner/benchmark.go b/test/e2e/runner/benchmark.go new file mode 100644 index 000000000..545fb773d --- /dev/null +++ b/test/e2e/runner/benchmark.go @@ -0,0 +1,192 @@ +package main + +import ( + "context" + "fmt" + "math" + "time" + + e2e "github.com/tendermint/tendermint/test/e2e/pkg" + "github.com/tendermint/tendermint/types" +) + +// Benchmark is a simple function for fetching, calculating and printing +// the following metrics: +// 1. Average block production time +// 2. Block interval standard deviation +// 3. Max block interval (slowest block) +// 4. Min block interval (fastest block) +// +// Metrics are based of the `benchmarkLength`, the amount of consecutive blocks +// sampled from in the testnet +func Benchmark(testnet *e2e.Testnet, benchmarkLength int64) error { + block, _, err := waitForHeight(testnet, 0) + if err != nil { + return err + } + + logger.Info("Beginning benchmark period...", "height", block.Height) + + // wait for the length of the benchmark period in blocks to pass. We allow 5 seconds for each block + // which should be sufficient. + waitingTime := time.Duration(benchmarkLength*5) * time.Second + endHeight, err := waitForAllNodes(testnet, block.Height+benchmarkLength, waitingTime) + if err != nil { + return err + } + + logger.Info("Ending benchmark period", "height", endHeight) + + // fetch a sample of blocks + blocks, err := fetchBlockChainSample(testnet, benchmarkLength) + if err != nil { + return err + } + + // slice into time intervals and collate data + timeIntervals := splitIntoBlockIntervals(blocks) + testnetStats := extractTestnetStats(timeIntervals) + testnetStats.startHeight = blocks[0].Header.Height + testnetStats.endHeight = blocks[len(blocks)-1].Header.Height + + // print and return + logger.Info(testnetStats.String()) + return nil +} + +type testnetStats struct { + startHeight int64 + endHeight int64 + + // average time to produce a block + mean time.Duration + // standard deviation of block production + std float64 + // longest time to produce a block + max time.Duration + // shortest time to produce a block + min time.Duration +} + +func (t *testnetStats) String() string { + return fmt.Sprintf(`Benchmarked from height %v to %v + Mean Block Interval: %v + Standard Deviation: %f + Max Block Interval: %v + Min Block Interval: %v + `, + t.startHeight, + t.endHeight, + t.mean, + t.std, + t.max, + t.min, + ) +} + +// fetchBlockChainSample waits for `benchmarkLength` amount of blocks to pass, fetching +// all of the headers for these blocks from an archive node and returning it. +func fetchBlockChainSample(testnet *e2e.Testnet, benchmarkLength int64) ([]*types.BlockMeta, error) { + var blocks []*types.BlockMeta + + // Find the first archive node + archiveNode := testnet.ArchiveNodes()[0] + c, err := archiveNode.Client() + if err != nil { + return nil, err + } + + // find the latest height + ctx := context.Background() + s, err := c.Status(ctx) + if err != nil { + return nil, err + } + + to := s.SyncInfo.LatestBlockHeight + from := to - benchmarkLength + 1 + if from <= testnet.InitialHeight { + return nil, fmt.Errorf("tesnet was unable to reach required height for benchmarking (latest height %d)", to) + } + + // Fetch blocks + for from < to { + // fetch the blockchain metas. Currently we can only fetch 20 at a time + resp, err := c.BlockchainInfo(ctx, from, min(from+19, to)) + if err != nil { + return nil, err + } + + blockMetas := resp.BlockMetas + // we receive blocks in descending order so we have to add them in reverse + for i := len(blockMetas) - 1; i >= 0; i-- { + if blockMetas[i].Header.Height != from { + return nil, fmt.Errorf("node gave us another header. Wanted %d, got %d", + from, + blockMetas[i].Header.Height, + ) + } + from++ + blocks = append(blocks, blockMetas[i]) + } + } + + return blocks, nil +} + +func splitIntoBlockIntervals(blocks []*types.BlockMeta) []time.Duration { + intervals := make([]time.Duration, len(blocks)-1) + lastTime := blocks[0].Header.Time + for i, block := range blocks { + // skip the first block + if i == 0 { + continue + } + + intervals[i-1] = block.Header.Time.Sub(lastTime) + lastTime = block.Header.Time + } + return intervals +} + +func extractTestnetStats(intervals []time.Duration) testnetStats { + var ( + sum, mean time.Duration + std float64 + max = intervals[0] + min = intervals[0] + ) + + for _, interval := range intervals { + sum += interval + + if interval > max { + max = interval + } + + if interval < min { + min = interval + } + } + mean = sum / time.Duration(len(intervals)) + + for _, interval := range intervals { + diff := (interval - mean).Seconds() + std += math.Pow(diff, 2) + } + std = math.Sqrt(std / float64(len(intervals))) + + return testnetStats{ + mean: mean, + std: std, + max: max, + min: min, + } +} + +func min(a, b int64) int64 { + if a > b { + return b + } + return a +} diff --git a/test/e2e/runner/main.go b/test/e2e/runner/main.go index d55fd95f2..989936001 100644 --- a/test/e2e/runner/main.go +++ b/test/e2e/runner/main.go @@ -204,6 +204,63 @@ func NewCLI() *CLI { }, }) + cli.root.AddCommand(&cobra.Command{ + Use: "benchmark", + Short: "Benchmarks testnet", + Long: `Benchmarks the following metrics: + Mean Block Interval + Standard Deviation + Min Block Interval + Max Block Interval +over a 100 block sampling period. + +Does not run any perbutations. + `, + RunE: func(cmd *cobra.Command, args []string) error { + if err := Cleanup(cli.testnet); err != nil { + return err + } + if err := Setup(cli.testnet); err != nil { + return err + } + + chLoadResult := make(chan error) + ctx, loadCancel := context.WithCancel(context.Background()) + defer loadCancel() + go func() { + err := Load(ctx, cli.testnet) + if err != nil { + logger.Error(fmt.Sprintf("Transaction load failed: %v", err.Error())) + } + chLoadResult <- err + }() + + if err := Start(cli.testnet); err != nil { + return err + } + + if err := Wait(cli.testnet, 5); err != nil { // allow some txs to go through + return err + } + + // we benchmark performance over the next 100 blocks + if err := Benchmark(cli.testnet, 100); err != nil { + return err + } + + loadCancel() + if err := <-chLoadResult; err != nil { + return err + } + + if err := Cleanup(cli.testnet); err != nil { + return err + } + + return nil + }, + }) + return cli } diff --git a/test/e2e/runner/wait.go b/test/e2e/runner/wait.go index 8e9030856..232d230d9 100644 --- a/test/e2e/runner/wait.go +++ b/test/e2e/runner/wait.go @@ -20,9 +20,15 @@ func Wait(testnet *e2e.Testnet, blocks int64) error { // WaitUntil waits until a given height has been reached. func WaitUntil(testnet *e2e.Testnet, height int64) error { logger.Info(fmt.Sprintf("Waiting for all nodes to reach height %v...", height)) - _, err := waitForAllNodes(testnet, height, 20*time.Second) + _, err := waitForAllNodes(testnet, height, waitingTime(len(testnet.Nodes))) if err != nil { return err } return nil } + +// waitingTime estimates how long it should take for a node to reach the height. +// More nodes in a network implies we may expect a slower network and may have to wait longer. +func waitingTime(nodes int) time.Duration { + return time.Duration(20+(nodes*2)) * time.Second +}