e2e(harness): plumb logging instance (#7958)

Co-authored-by: mergify[bot] <37929162+mergify[bot]@users.noreply.github.com>

test/e2e/runner/benchmark.go

@@ -8,6 +8,7 @@ import (
 	"path/filepath"
 	"time"
 
+	"github.com/tendermint/tendermint/libs/log"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 	"github.com/tendermint/tendermint/types"
 )
@@ -21,7 +22,7 @@ import (
 //
 // Metrics are based of the `benchmarkLength`, the amount of consecutive blocks
 // sampled from in the testnet
-func Benchmark(ctx context.Context, testnet *e2e.Testnet, benchmarkLength int64) error {
+func Benchmark(ctx context.Context, logger log.Logger, testnet *e2e.Testnet, benchmarkLength int64) error {
 	block, err := getLatestBlock(ctx, testnet)
 	if err != nil {
 		return err

test/e2e/runner/cleanup.go

@@ -6,21 +6,22 @@ import (
 	"os"
 	"path/filepath"
 
+	"github.com/tendermint/tendermint/libs/log"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 )
 
 // Cleanup removes the Docker Compose containers and testnet directory.
-func Cleanup(testnet *e2e.Testnet) error {
-	err := cleanupDocker()
+func Cleanup(logger log.Logger, testnet *e2e.Testnet) error {
+	err := cleanupDocker(logger)
 	if err != nil {
 		return err
 	}
-	return cleanupDir(testnet.Dir)
+	return cleanupDir(logger, testnet.Dir)
 }
 
 // cleanupDocker removes all E2E resources (with label e2e=True), regardless
 // of testnet.
-func cleanupDocker() error {
+func cleanupDocker(logger log.Logger) error {
 	logger.Info("Removing Docker containers and networks")
 
 	// GNU xargs requires the -r flag to not run when input is empty, macOS
@@ -38,7 +39,7 @@ func cleanupDocker() error {
 }
 
 // cleanupDir cleans up a testnet directory
-func cleanupDir(dir string) error {
+func cleanupDir(logger log.Logger, dir string) error {
 	if dir == "" {
 		return errors.New("no directory set")
 	}

test/e2e/runner/evidence.go

@@ -14,6 +14,7 @@ import (
 	"github.com/tendermint/tendermint/crypto"
 	"github.com/tendermint/tendermint/crypto/tmhash"
 	"github.com/tendermint/tendermint/internal/test/factory"
+	"github.com/tendermint/tendermint/libs/log"
 	"github.com/tendermint/tendermint/privval"
 	tmproto "github.com/tendermint/tendermint/proto/tendermint/types"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
@@ -28,7 +29,7 @@ const lightClientEvidenceRatio = 4
 // evidence and broadcasts it to a random node through the rpc endpoint `/broadcast_evidence`.
 // Evidence is random and can be a mixture of LightClientAttackEvidence and
 // DuplicateVoteEvidence.
-func InjectEvidence(ctx context.Context, r *rand.Rand, testnet *e2e.Testnet, amount int) error {
+func InjectEvidence(ctx context.Context, logger log.Logger, r *rand.Rand, testnet *e2e.Testnet, amount int) error {
 	// select a random node
 	var targetNode *e2e.Node
 
@@ -112,7 +113,7 @@ func InjectEvidence(ctx context.Context, r *rand.Rand, testnet *e2e.Testnet, amo
 
 	// wait for the node to make progress after submitting
 	// evidence (3 (forged height) + 1 (progress))
-	_, err = waitForNode(wctx, targetNode, evidenceHeight+4)
+	_, err = waitForNode(wctx, logger, targetNode, evidenceHeight+4)
 	if err != nil {
 		return err
 	}

test/e2e/runner/load.go

@@ -7,6 +7,7 @@ import (
 	"math/rand"
 	"time"
 
+	"github.com/tendermint/tendermint/libs/log"
 	tmrand "github.com/tendermint/tendermint/libs/rand"
 	rpchttp "github.com/tendermint/tendermint/rpc/client/http"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
@@ -15,7 +16,7 @@ import (
 
 // Load generates transactions against the network until the given context is
 // canceled.
-func Load(ctx context.Context, r *rand.Rand, testnet *e2e.Testnet) error {
+func Load(ctx context.Context, logger log.Logger, r *rand.Rand, testnet *e2e.Testnet) error {
 	// Since transactions are executed across all nodes in the network, we need
 	// to reduce transaction load for larger networks to avoid using too much
 	// CPU. This gives high-throughput small networks and low-throughput large ones.

test/e2e/runner/main.go

@@ -3,6 +3,7 @@ package main
 import (
 	"context"
 	"fmt"
+	stdlog "log"
 	"math/rand"
 	"os"
 	"strconv"
@@ -16,10 +17,16 @@ import (
 
 const randomSeed = 2308084734268
 
-var logger = log.MustNewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo)
-
 func main() {
-	NewCLI().Run()
+	ctx, cancel := context.WithCancel(context.Background())
+	defer cancel()
+
+	logger, err := log.NewDefaultLogger(log.LogFormatPlain, log.LogLevelInfo)
+	if err != nil {
+		stdlog.Fatal(err)
+	}
+
+	NewCLI(logger).Run(ctx, logger)
 }
 
 // CLI is the Cobra-based command-line interface.
@@ -30,7 +37,7 @@ type CLI struct {
 }
 
 // NewCLI sets up the CLI.
-func NewCLI() *CLI {
+func NewCLI(logger log.Logger) *CLI {
 	cli := &CLI{}
 	cli.root = &cobra.Command{
 		Use:           "runner",
@@ -51,7 +58,7 @@ func NewCLI() *CLI {
 			return nil
 		},
 		RunE: func(cmd *cobra.Command, args []string) (err error) {
-			if err = Cleanup(cli.testnet); err != nil {
+			if err = Cleanup(logger, cli.testnet); err != nil {
 				return err
 			}
 			defer func() {
@@ -60,11 +67,11 @@ func NewCLI() *CLI {
 				} else if err != nil {
 					logger.Info("Preserving testnet that encountered error",
 						"err", err)
-				} else if err := Cleanup(cli.testnet); err != nil {
+				} else if err := Cleanup(logger, cli.testnet); err != nil {
 					logger.Error("error cleaning up testnet contents", "err", err)
 				}
 			}()
-			if err = Setup(cli.testnet); err != nil {
+			if err = Setup(logger, cli.testnet); err != nil {
 				return err
 			}
 
@@ -77,31 +84,31 @@ func NewCLI() *CLI {
 			lctx, loadCancel := context.WithCancel(ctx)
 			defer loadCancel()
 			go func() {
-				chLoadResult <- Load(lctx, r, cli.testnet)
+				chLoadResult <- Load(lctx, logger, r, cli.testnet)
 			}()
 			startAt := time.Now()
-			if err = Start(ctx, cli.testnet); err != nil {
+			if err = Start(ctx, logger, cli.testnet); err != nil {
 				return err
 			}
 
-			if err = Wait(ctx, cli.testnet, 5); err != nil { // allow some txs to go through
+			if err = Wait(ctx, logger, cli.testnet, 5); err != nil { // allow some txs to go through
 				return err
 			}
 
 			if cli.testnet.HasPerturbations() {
-				if err = Perturb(ctx, cli.testnet); err != nil {
+				if err = Perturb(ctx, logger, cli.testnet); err != nil {
 					return err
 				}
-				if err = Wait(ctx, cli.testnet, 5); err != nil { // allow some txs to go through
+				if err = Wait(ctx, logger, cli.testnet, 5); err != nil { // allow some txs to go through
 					return err
 				}
 			}
 
 			if cli.testnet.Evidence > 0 {
-				if err = InjectEvidence(ctx, r, cli.testnet, cli.testnet.Evidence); err != nil {
+				if err = InjectEvidence(ctx, logger, r, cli.testnet, cli.testnet.Evidence); err != nil {
 					return err
 				}
-				if err = Wait(ctx, cli.testnet, 5); err != nil { // ensure chain progress
+				if err = Wait(ctx, logger, cli.testnet, 5); err != nil { // ensure chain progress
 					return err
 				}
 			}
@@ -124,10 +131,10 @@ func NewCLI() *CLI {
 			if err = <-chLoadResult; err != nil {
 				return fmt.Errorf("transaction load failed: %w", err)
 			}
-			if err = Wait(ctx, cli.testnet, 5); err != nil { // wait for network to settle before tests
+			if err = Wait(ctx, logger, cli.testnet, 5); err != nil { // wait for network to settle before tests
 				return err
 			}
-			if err := Test(cli.testnet); err != nil {
+			if err := Test(logger, cli.testnet); err != nil {
 				return err
 			}
 			return nil
@@ -149,7 +156,7 @@ func NewCLI() *CLI {
 		Use:   "setup",
 		Short: "Generates the testnet directory and configuration",
 		RunE: func(cmd *cobra.Command, args []string) error {
-			return Setup(cli.testnet)
+			return Setup(logger, cli.testnet)
 		},
 	})
 
@@ -159,12 +166,12 @@ func NewCLI() *CLI {
 		RunE: func(cmd *cobra.Command, args []string) error {
 			_, err := os.Stat(cli.testnet.Dir)
 			if os.IsNotExist(err) {
-				err = Setup(cli.testnet)
+				err = Setup(logger, cli.testnet)
 			}
 			if err != nil {
 				return err
 			}
-			return Start(cmd.Context(), cli.testnet)
+			return Start(cmd.Context(), logger, cli.testnet)
 		},
 	})
 
@@ -172,7 +179,7 @@ func NewCLI() *CLI {
 		Use:   "perturb",
 		Short: "Perturbs the Docker testnet, e.g. by restarting or disconnecting nodes",
 		RunE: func(cmd *cobra.Command, args []string) error {
-			return Perturb(cmd.Context(), cli.testnet)
+			return Perturb(cmd.Context(), logger, cli.testnet)
 		},
 	})
 
@@ -180,7 +187,7 @@ func NewCLI() *CLI {
 		Use:   "wait",
 		Short: "Waits for a few blocks to be produced and all nodes to catch up",
 		RunE: func(cmd *cobra.Command, args []string) error {
-			return Wait(cmd.Context(), cli.testnet, 5)
+			return Wait(cmd.Context(), logger, cli.testnet, 5)
 		},
 	})
 
@@ -217,6 +224,7 @@ func NewCLI() *CLI {
 		RunE: func(cmd *cobra.Command, args []string) (err error) {
 			return Load(
 				cmd.Context(),
+				logger,
 				rand.New(rand.NewSource(randomSeed)), // nolint: gosec
 				cli.testnet,
 			)
@@ -239,6 +247,7 @@ func NewCLI() *CLI {
 
 			return InjectEvidence(
 				cmd.Context(),
+				logger,
 				rand.New(rand.NewSource(randomSeed)), // nolint: gosec
 				cli.testnet,
 				amount,
@@ -250,7 +259,7 @@ func NewCLI() *CLI {
 		Use:   "test",
 		Short: "Runs test cases against a running testnet",
 		RunE: func(cmd *cobra.Command, args []string) error {
-			return Test(cli.testnet)
+			return Test(logger, cli.testnet)
 		},
 	})
 
@@ -258,7 +267,7 @@ func NewCLI() *CLI {
 		Use:   "cleanup",
 		Short: "Removes the testnet directory",
 		RunE: func(cmd *cobra.Command, args []string) error {
-			return Cleanup(cli.testnet)
+			return Cleanup(logger, cli.testnet)
 		},
 	})
 
@@ -297,16 +306,16 @@ 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 {
+			if err := Cleanup(logger, cli.testnet); err != nil {
 				return err
 			}
 			defer func() {
-				if err := Cleanup(cli.testnet); err != nil {
+				if err := Cleanup(logger, cli.testnet); err != nil {
 					logger.Error("error cleaning up testnet contents", "err", err)
 				}
 			}()
 
-			if err := Setup(cli.testnet); err != nil {
+			if err := Setup(logger, cli.testnet); err != nil {
 				return err
 			}
 
@@ -319,19 +328,19 @@ Does not run any perbutations.
 			lctx, loadCancel := context.WithCancel(ctx)
 			defer loadCancel()
 			go func() {
-				chLoadResult <- Load(lctx, r, cli.testnet)
+				chLoadResult <- Load(lctx, logger, r, cli.testnet)
 			}()
 
-			if err := Start(ctx, cli.testnet); err != nil {
+			if err := Start(ctx, logger, cli.testnet); err != nil {
 				return err
 			}
 
-			if err := Wait(ctx, cli.testnet, 5); err != nil { // allow some txs to go through
+			if err := Wait(ctx, logger, cli.testnet, 5); err != nil { // allow some txs to go through
 				return err
 			}
 
 			// we benchmark performance over the next 100 blocks
-			if err := Benchmark(ctx, cli.testnet, 100); err != nil {
+			if err := Benchmark(ctx, logger, cli.testnet, 100); err != nil {
 				return err
 			}
 
@@ -348,8 +357,8 @@ Does not run any perbutations.
 }
 
 // Run runs the CLI.
-func (cli *CLI) Run() {
-	if err := cli.root.Execute(); err != nil {
+func (cli *CLI) Run(ctx context.Context, logger log.Logger) {
+	if err := cli.root.ExecuteContext(ctx); err != nil {
 		logger.Error(err.Error())
 		os.Exit(1)
 	}

test/e2e/runner/perturb.go

@@ -5,12 +5,13 @@ import (
 	"fmt"
 	"time"
 
+	"github.com/tendermint/tendermint/libs/log"
 	rpctypes "github.com/tendermint/tendermint/rpc/coretypes"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 )
 
 // Perturbs a running testnet.
-func Perturb(ctx context.Context, testnet *e2e.Testnet) error {
+func Perturb(ctx context.Context, logger log.Logger, testnet *e2e.Testnet) error {
 	timer := time.NewTimer(0) // first tick fires immediately; reset below
 	defer timer.Stop()
 
@@ -20,7 +21,7 @@ func Perturb(ctx context.Context, testnet *e2e.Testnet) error {
 			case <-ctx.Done():
 				return ctx.Err()
 			case <-timer.C:
-				_, err := PerturbNode(ctx, node, perturbation)
+				_, err := PerturbNode(ctx, logger, node, perturbation)
 				if err != nil {
 					return err
 				}
@@ -35,7 +36,7 @@ func Perturb(ctx context.Context, testnet *e2e.Testnet) error {
 
 // PerturbNode perturbs a node with a given perturbation, returning its status
 // after recovering.
-func PerturbNode(ctx context.Context, node *e2e.Node, perturbation e2e.Perturbation) (*rpctypes.ResultStatus, error) {
+func PerturbNode(ctx context.Context, logger log.Logger, node *e2e.Node, perturbation e2e.Perturbation) (*rpctypes.ResultStatus, error) {
 	testnet := node.Testnet
 	switch perturbation {
 	case e2e.PerturbationDisconnect:
@@ -90,7 +91,7 @@ func PerturbNode(ctx context.Context, node *e2e.Node, perturbation e2e.Perturbat
 
 	ctx, cancel := context.WithTimeout(ctx, 5*time.Minute)
 	defer cancel()
-	status, err := waitForNode(ctx, node, 0)
+	status, err := waitForNode(ctx, logger, node, 0)
 	if err != nil {
 		return nil, err
 	}

test/e2e/runner/rpc.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"time"
 
+	"github.com/tendermint/tendermint/libs/log"
 	rpchttp "github.com/tendermint/tendermint/rpc/client/http"
 	rpctypes "github.com/tendermint/tendermint/rpc/coretypes"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
@@ -127,7 +128,7 @@ func waitForHeight(ctx context.Context, testnet *e2e.Testnet, height int64) (*ty
 }
 
 // waitForNode waits for a node to become available and catch up to the given block height.
-func waitForNode(ctx context.Context, node *e2e.Node, height int64) (*rpctypes.ResultStatus, error) {
+func waitForNode(ctx context.Context, logger log.Logger, node *e2e.Node, height int64) (*rpctypes.ResultStatus, error) {
 	// If the node is the light client or seed note, we do not check for the last height.
 	// The light client and seed note can be behind the full node and validator
 	if node.Mode == e2e.ModeSeed {

test/e2e/runner/setup.go

@@ -19,6 +19,7 @@ import (
 
 	"github.com/tendermint/tendermint/config"
 	"github.com/tendermint/tendermint/crypto/ed25519"
+	"github.com/tendermint/tendermint/libs/log"
 	"github.com/tendermint/tendermint/privval"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 	"github.com/tendermint/tendermint/types"
@@ -38,7 +39,7 @@ const (
 )
 
 // Setup sets up the testnet configuration.
-func Setup(testnet *e2e.Testnet) error {
+func Setup(logger log.Logger, testnet *e2e.Testnet) error {
 	logger.Info(fmt.Sprintf("Generating testnet files in %q", testnet.Dir))
 
 	err := os.MkdirAll(testnet.Dir, os.ModePerm)

test/e2e/runner/start.go

@@ -6,10 +6,11 @@ import (
 	"sort"
 	"time"
 
+	"github.com/tendermint/tendermint/libs/log"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 )
 
-func Start(ctx context.Context, testnet *e2e.Testnet) error {
+func Start(ctx context.Context, logger log.Logger, testnet *e2e.Testnet) error {
 	if len(testnet.Nodes) == 0 {
 		return fmt.Errorf("no nodes in testnet")
 	}
@@ -51,7 +52,7 @@ func Start(ctx context.Context, testnet *e2e.Testnet) error {
 			ctx, cancel := context.WithTimeout(ctx, time.Minute)
 			defer cancel()
 
-			_, err := waitForNode(ctx, node, 0)
+			_, err := waitForNode(ctx, logger, node, 0)
 			return err
 		}(); err != nil {
 			return err
@@ -110,7 +111,7 @@ func Start(ctx context.Context, testnet *e2e.Testnet) error {
 		}
 
 		wctx, wcancel := context.WithTimeout(ctx, 8*time.Minute)
-		status, err := waitForNode(wctx, node, node.StartAt)
+		status, err := waitForNode(wctx, logger, node, node.StartAt)
 		if err != nil {
 			wcancel()
 			return err

test/e2e/runner/test.go

@@ -3,13 +3,12 @@ package main
 import (
 	"os"
 
+	"github.com/tendermint/tendermint/libs/log"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 )
 
 // Test runs test cases under tests/
-func Test(testnet *e2e.Testnet) error {
-	logger.Info("Running tests in ./tests/...")
-
+func Test(logger log.Logger, testnet *e2e.Testnet) error {
 	err := os.Setenv("E2E_MANIFEST", testnet.File)
 	if err != nil {
 		return err

test/e2e/runner/wait.go

@@ -4,21 +4,22 @@ import (
 	"context"
 	"fmt"
 
+	"github.com/tendermint/tendermint/libs/log"
 	e2e "github.com/tendermint/tendermint/test/e2e/pkg"
 )
 
 // Wait waits for a number of blocks to be produced, and for all nodes to catch
 // up with it.
-func Wait(ctx context.Context, testnet *e2e.Testnet, blocks int64) error {
+func Wait(ctx context.Context, logger log.Logger, testnet *e2e.Testnet, blocks int64) error {
 	block, err := getLatestBlock(ctx, testnet)
 	if err != nil {
 		return err
 	}
-	return WaitUntil(ctx, testnet, block.Height+blocks)
+	return WaitUntil(ctx, logger, testnet, block.Height+blocks)
 }
 
 // WaitUntil waits until a given height has been reached.
-func WaitUntil(ctx context.Context, testnet *e2e.Testnet, height int64) error {
+func WaitUntil(ctx context.Context, logger log.Logger, testnet *e2e.Testnet, height int64) error {
 	logger.Info(fmt.Sprintf("Waiting for all nodes to reach height %v...", height))
 
 	_, _, err := waitForHeight(ctx, testnet, height)