e2e: Increase logging detail to improve traceability

Author: maru-ava

tests/e2e/banff/suites.go

@@ -29,7 +29,7 @@ var _ = ginkgo.Describe("[Banff]", func() {
 		),
 		func() {
 			keychain := e2e.Env.NewKeychain(1)
-			wallet := e2e.Env.NewWallet(keychain)
+			wallet := e2e.Env.NewWallet(keychain, e2e.Env.GetRandomNodeURI())
 
 			// Get the P-chain and the X-chain wallets
 			pWallet := wallet.P()

tests/e2e/c/interchain_workflow.go

@@ -32,6 +32,11 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 	)
 
 	ginkgo.It("should ensure that funds can be transferred from the C-Chain to the X-Chain and the P-Chain", func() {
+		// Select a random node URI to use for both the eth client and
+		// the wallet to avoid having to verify that all nodes are at
+		// the same height before initializing the wallet.
+		nodeURI := e2e.Env.GetRandomNodeURI()
+
 		ginkgo.By("allocating a pre-funded key to send from and a recipient key to deliver to")
 		senderKey := e2e.Env.AllocateFundedKey()
 		senderEthAddress := evm.GetEthAddress(senderKey)
@@ -40,11 +45,7 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 		require.NoError(err)
 		recipientEthAddress := evm.GetEthAddress(recipientKey)
 
-		// Select a random node URI to use for both the eth client and
-		// the wallet to avoid having to verify that all nodes are at
-		// the same height before initializing the wallet.
-		nodeURI := e2e.Env.GetRandomNodeURI()
-		ethClient := e2e.Env.NewEthClientForURI(nodeURI)
+		ethClient := e2e.Env.NewEthClient(nodeURI)
 
 		ginkgo.By("sending funds from one address to another on the C-Chain", func() {
 			// Create transaction
@@ -68,7 +69,7 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 			signedTx, err := types.SignTx(tx, signer, senderKey.ToECDSA())
 			require.NoError(err)
 
-			require.NoError(ethClient.SendTransaction(e2e.DefaultContext(), signedTx))
+			_ = e2e.SendEthTransaction(ethClient, signedTx)
 
 			ginkgo.By("waiting for the C-Chain recipient address to have received the sent funds")
 			e2e.Eventually(func() bool {
@@ -83,7 +84,7 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 		// matches on-chain state.
 		ginkgo.By("initializing a keychain and associated wallet")
 		keychain := secp256k1fx.NewKeychain(senderKey, recipientKey)
-		baseWallet := e2e.Env.NewWalletForURI(keychain, nodeURI)
+		baseWallet := e2e.Env.NewWallet(keychain, nodeURI)
 		xWallet := baseWallet.X()
 		cWallet := baseWallet.C()
 		pWallet := baseWallet.P()
@@ -111,21 +112,23 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 		}
 
 		ginkgo.By("exporting AVAX from the C-Chain to the X-Chain", func() {
-			_, err := cWallet.IssueExportTx(
-				xWallet.BlockchainID(),
-				exportOutputs,
-				e2e.WithDefaultContext(),
+			e2e.LogTxAndCheck(
+				cWallet.IssueExportTx(
+					xWallet.BlockchainID(),
+					exportOutputs,
+					e2e.WithDefaultContext(),
+				),
 			)
-			require.NoError(err)
 		})
 
 		ginkgo.By("importing AVAX from the C-Chain to the X-Chain", func() {
-			_, err := xWallet.IssueImportTx(
-				cWallet.BlockchainID(),
-				&recipientOwner,
-				e2e.WithDefaultContext(),
+			e2e.LogTxAndCheck(
+				xWallet.IssueImportTx(
+					cWallet.BlockchainID(),
+					&recipientOwner,
+					e2e.WithDefaultContext(),
+				),
 			)
-			require.NoError(err)
 		})
 
 		ginkgo.By("checking that the recipient address has received imported funds on the X-Chain", func() {
@@ -137,21 +140,23 @@ var _ = e2e.DescribeCChain("[Interchain Workflow]", func() {
 		})
 
 		ginkgo.By("exporting AVAX from the C-Chain to the P-Chain", func() {
-			_, err := cWallet.IssueExportTx(
-				constants.PlatformChainID,
-				exportOutputs,
-				e2e.WithDefaultContext(),
+			e2e.LogTxAndCheck(
+				cWallet.IssueExportTx(
+					constants.PlatformChainID,
+					exportOutputs,
+					e2e.WithDefaultContext(),
+				),
 			)
-			require.NoError(err)
 		})
 
 		ginkgo.By("importing AVAX from the C-Chain to the P-Chain", func() {
-			_, err = pWallet.IssueImportTx(
-				cWallet.BlockchainID(),
-				&recipientOwner,
-				e2e.WithDefaultContext(),
+			e2e.LogTxAndCheck(
+				pWallet.IssueImportTx(
+					cWallet.BlockchainID(),
+					&recipientOwner,
+					e2e.WithDefaultContext(),
+				),
 			)
-			require.NoError(err)
 		})
 
 		ginkgo.By("checking that the recipient address has received imported funds on the P-Chain", func() {

tests/e2e/e2e.go

@@ -7,6 +7,7 @@ package e2e
 import (
 	"context"
 	"encoding/json"
+	"errors"
 	"fmt"
 	"math/rand"
 	"strings"
@@ -16,8 +17,13 @@ import (
 
 	"github.com/stretchr/testify/require"
 
+	"github.com/ava-labs/coreth/core/types"
 	"github.com/ava-labs/coreth/ethclient"
+	"github.com/ava-labs/coreth/interfaces"
 
+	"golang.org/x/exp/maps"
+
+	"github.com/ava-labs/avalanchego/ids"
 	"github.com/ava-labs/avalanchego/tests"
 	"github.com/ava-labs/avalanchego/tests/fixture"
 	"github.com/ava-labs/avalanchego/tests/fixture/testnet"
@@ -58,7 +64,7 @@ type TestEnvironment struct {
 	// The directory where the test network configuration is stored
 	NetworkDir string
 	// URIs used to access the API endpoints of nodes of the network
-	URIs []string
+	URIs map[ids.NodeID]string
 	// The URI used to access the http server that allocates test data
 	TestDataServerURI string
 
@@ -78,7 +84,11 @@ func InitTestEnvironment(envBytes []byte) {
 // nodes.
 func (te *TestEnvironment) GetRandomNodeURI() string {
 	r := rand.New(rand.NewSource(time.Now().Unix())) //#nosec G404
-	return te.URIs[r.Intn(len(te.URIs))]
+	nodeIDs := maps.Keys(te.URIs)
+	nodeID := nodeIDs[r.Intn(len(nodeIDs))]
+	uri := te.URIs[nodeID]
+	tests.Outf("{{blue}} targeting node %s with URI: %s{{/}}\n", nodeID, uri)
+	return uri
 }
 
 // Retrieve the network to target for testing.
@@ -92,6 +102,7 @@ func (te *TestEnvironment) GetNetwork() testnet.Network {
 func (te *TestEnvironment) AllocateFundedKeys(count int) []*secp256k1.PrivateKey {
 	keys, err := fixture.AllocateFundedKeys(te.TestDataServerURI, count)
 	te.require.NoError(err)
+	tests.Outf("{{blue}} allocated funded key(s): %+v{{/}}\n", keys)
 	return keys
 }
 
@@ -102,19 +113,14 @@ func (te *TestEnvironment) AllocateFundedKey() *secp256k1.PrivateKey {
 
 // Create a new keychain with the specified number of test keys.
 func (te *TestEnvironment) NewKeychain(count int) *secp256k1fx.Keychain {
-	tests.Outf("{{blue}} initializing keychain with %d keys {{/}}\n", count)
 	keys := te.AllocateFundedKeys(count)
+	tests.Outf("{{blue}} initializing keychain with %d key(s) {{/}}\n", count)
 	return secp256k1fx.NewKeychain(keys...)
 }
 
-// Create a new wallet for the provided keychain against a random node URI.
-func (te *TestEnvironment) NewWallet(keychain *secp256k1fx.Keychain) primary.Wallet {
-	return te.NewWalletForURI(keychain, te.GetRandomNodeURI())
-}
-
 // Create a new wallet for the provided keychain against the specified node URI.
-func (te *TestEnvironment) NewWalletForURI(keychain *secp256k1fx.Keychain, uri string) primary.Wallet {
-	tests.Outf("{{blue}} initializing a new wallet {{/}}\n")
+func (te *TestEnvironment) NewWallet(keychain *secp256k1fx.Keychain, uri string) primary.Wallet {
+	tests.Outf("{{blue}} initializing a new wallet for URI: %s {{/}}\n", uri)
 	wallet, err := primary.MakeWallet(DefaultContext(), &primary.WalletConfig{
 		URI:          uri,
 		AVAXKeychain: keychain,
@@ -124,13 +130,9 @@ func (te *TestEnvironment) NewWalletForURI(keychain *secp256k1fx.Keychain, uri s
 	return wallet
 }
 
-// Create a new eth client targeting a random node.
-func (te *TestEnvironment) NewEthClient() ethclient.Client {
-	return te.NewEthClientForURI(te.GetRandomNodeURI())
-}
-
 // Create a new eth client targeting the specified node URI.
-func (te *TestEnvironment) NewEthClientForURI(nodeURI string) ethclient.Client {
+func (te *TestEnvironment) NewEthClient(nodeURI string) ethclient.Client {
+	tests.Outf("{{blue}} initializing a new eth client for URI: %s {{/}}\n", nodeURI)
 	nodeAddress := strings.Split(nodeURI, "//")[1]
 	uri := fmt.Sprintf("ws://%s/ext/bc/C/ws", nodeAddress)
 	client, err := ethclient.Dial(uri)
@@ -198,3 +200,51 @@ func WaitForHealthy(node testnet.Node) {
 	defer cancel()
 	require.NoError(ginkgo.GinkgoT(), testnet.WaitForHealthy(ctx, node))
 }
+
+// Interface to allow logging any type of transaction that has an ID method.
+type LoggableTx interface {
+	ID() ids.ID
+}
+
+// Ensures transaction id is logged if the transaction is non-nil. Should be
+// called before checking for an error to ensure traceability in the event
+// of a transaction being submitted but failing to be accepted.
+func LogTx(tx LoggableTx) {
+	if tx != nil {
+		tests.Outf(" tx id: %s\n", tx.ID())
+	}
+}
+
+// Ensures transaction id is logged if the transaction is non-nil and check
+// if an error occurred.
+func LogTxAndCheck(tx LoggableTx, err error) {
+	LogTx(tx)
+	require.NoError(ginkgo.GinkgoT(), err)
+}
+
+// Sends an eth transaction, waits for the transaction receipt to be issued
+// and checks that the receipt indicates success.
+func SendEthTransaction(ethClient ethclient.Client, signedTx *types.Transaction) *types.Receipt {
+	require := require.New(ginkgo.GinkgoT())
+
+	txID := signedTx.Hash()
+	tests.Outf(" eth tx id: %s\n", txID)
+
+	require.NoError(ethClient.SendTransaction(DefaultContext(), signedTx))
+
+	// Wait for the receipt
+	var receipt *types.Receipt
+	Eventually(func() bool {
+		var err error
+		receipt, err = ethClient.TransactionReceipt(DefaultContext(), txID)
+		if errors.Is(err, interfaces.NotFound) {
+			return false // Transaction is still pending
+		}
+		require.NoError(err)
+		return true
+	}, DefaultTimeout, DefaultPollingInterval, "failed to see transaction acceptance before timeout")
+
+	// Retrieve the contract address
+	require.Equal(receipt.Status, types.ReceiptStatusSuccessful)
+	return receipt
+}