diff --git a/tests/fixture/e2e/helpers.go b/tests/fixture/e2e/helpers.go index 8ec84a5d692e..7a6bbbbc378b 100644 --- a/tests/fixture/e2e/helpers.go +++ b/tests/fixture/e2e/helpers.go @@ -19,7 +19,6 @@ import ( "go.uber.org/zap" "github.com/ava-labs/avalanchego/config" - "github.com/ava-labs/avalanchego/ids" "github.com/ava-labs/avalanchego/tests" "github.com/ava-labs/avalanchego/tests/fixture/tmpnet" "github.com/ava-labs/avalanchego/utils/crypto/secp256k1" @@ -76,13 +75,9 @@ func NewWallet(tc tests.TestContext, keychain *secp256k1fx.Keychain, nodeURI tmp require.NoError(tc, err) wallet := primary.NewWalletWithOptions( baseWallet, - common.WithPostIssuanceFunc( - func(id ids.ID) { - tc.Log().Info("issued transaction", - zap.Stringer("txID", id), - ) - }, - ), + common.WithLoggedIssuranceAndConfirmation(tc.Log()), + // Use a low poll frequency to ensure more accurate determination of confirmation duration + common.WithPollFrequency(10*time.Millisecond), ) OutputWalletBalances(tc, wallet) return wallet diff --git a/vms/platformvm/txs/txstest/wallet.go b/vms/platformvm/txs/txstest/wallet.go index b022ca3abcb9..649bdde366c6 100644 --- a/vms/platformvm/txs/txstest/wallet.go +++ b/vms/platformvm/txs/txstest/wallet.go @@ -7,6 +7,7 @@ import ( "context" "math" "testing" + "time" "github.com/stretchr/testify/require" @@ -126,9 +127,9 @@ func (c *client) IssueTx( options ...common.Option, ) error { ops := common.NewOptions(options) - if f := ops.PostIssuanceFunc(); f != nil { + if f := ops.PostIssuanceHandler(); f != nil { txID := tx.ID() - f(txID) + f(common.PChainAlias, txID, time.Duration(0)) } ctx := ops.Context() return c.backend.AcceptTx(ctx, tx) diff --git a/wallet/chain/c/wallet.go b/wallet/chain/c/wallet.go index 65c15e6533a0..46abae310b86 100644 --- a/wallet/chain/c/wallet.go +++ b/wallet/chain/c/wallet.go @@ -149,13 +149,15 @@ func (w *wallet) IssueAtomicTx( ) error { ops := common.NewOptions(options) ctx := ops.Context() + startTime := time.Now() txID, err := w.avaxClient.IssueTx(ctx, tx.SignedBytes()) + issuanceDuration := time.Since(startTime) if err != nil { return err } - if f := ops.PostIssuanceFunc(); f != nil { - f(txID) + if f := ops.PostIssuanceHandler(); f != nil { + f(common.PChainAlias, txID, issuanceDuration) } if ops.AssumeDecided() { @@ -165,6 +167,12 @@ func (w *wallet) IssueAtomicTx( if err := awaitTxAccepted(w.avaxClient, ctx, txID, ops.PollFrequency()); err != nil { return err } + totalDuration := time.Since(startTime) + issuanceToConfirmationDuration := totalDuration - issuanceDuration + + if f := ops.PostConfirmationHandler(); f != nil { + f(common.CChainAlias, txID, totalDuration, issuanceToConfirmationDuration) + } return w.Backend.AcceptAtomicTx(ctx, tx) } diff --git a/wallet/chain/p/client.go b/wallet/chain/p/client.go index 6575f5deed75..180040b2b06f 100644 --- a/wallet/chain/p/client.go +++ b/wallet/chain/p/client.go @@ -4,6 +4,8 @@ package p import ( + "time" + "github.com/ava-labs/avalanchego/vms/platformvm" "github.com/ava-labs/avalanchego/vms/platformvm/txs" "github.com/ava-labs/avalanchego/wallet/chain/p/wallet" @@ -12,6 +14,8 @@ import ( var _ wallet.Client = (*Client)(nil) +const chainAlias = "P" + func NewClient( c platformvm.Client, b wallet.Backend, @@ -33,13 +37,15 @@ func (c *Client) IssueTx( ) error { ops := common.NewOptions(options) ctx := ops.Context() + startTime := time.Now() txID, err := c.client.IssueTx(ctx, tx.Bytes()) + issuanceDuration := time.Since(startTime) if err != nil { return err } - if f := ops.PostIssuanceFunc(); f != nil { - f(txID) + if f := ops.PostIssuanceHandler(); f != nil { + f(chainAlias, txID, issuanceDuration) } if ops.AssumeDecided() { @@ -49,6 +55,12 @@ func (c *Client) IssueTx( if err := platformvm.AwaitTxAccepted(c.client, ctx, txID, ops.PollFrequency()); err != nil { return err } + totalDuration := time.Since(startTime) + issuanceToConfirmationDuration := totalDuration - issuanceDuration + + if f := ops.PostConfirmationHandler(); f != nil { + f(chainAlias, txID, totalDuration, issuanceToConfirmationDuration) + } return c.backend.AcceptTx(ctx, tx) } diff --git a/wallet/chain/x/wallet.go b/wallet/chain/x/wallet.go index a5bac3e8b6ce..d8c7fc6e9afc 100644 --- a/wallet/chain/x/wallet.go +++ b/wallet/chain/x/wallet.go @@ -4,6 +4,8 @@ package x import ( + "time" + "github.com/ava-labs/avalanchego/ids" "github.com/ava-labs/avalanchego/vms/avm" "github.com/ava-labs/avalanchego/vms/avm/txs" @@ -293,13 +295,15 @@ func (w *wallet) IssueTx( ) error { ops := common.NewOptions(options) ctx := ops.Context() + startTime := time.Now() txID, err := w.client.IssueTx(ctx, tx.Bytes()) + issuanceDuration := time.Since(startTime) if err != nil { return err } - if f := ops.PostIssuanceFunc(); f != nil { - f(txID) + if f := ops.PostIssuanceHandler(); f != nil { + f(common.XChainAlias, txID, issuanceDuration) } if ops.AssumeDecided() { @@ -309,6 +313,12 @@ func (w *wallet) IssueTx( if err := avm.AwaitTxAccepted(w.client, ctx, txID, ops.PollFrequency()); err != nil { return err } + totalDuration := time.Since(startTime) + issuanceToConfirmationDuration := totalDuration - issuanceDuration + + if f := ops.PostConfirmationHandler(); f != nil { + f(common.XChainAlias, txID, totalDuration, issuanceToConfirmationDuration) + } return w.backend.AcceptTx(ctx, tx) } diff --git a/wallet/subnet/primary/common/options.go b/wallet/subnet/primary/common/options.go index d6803825ca1d..ab8576091b60 100644 --- a/wallet/subnet/primary/common/options.go +++ b/wallet/subnet/primary/common/options.go @@ -8,18 +8,47 @@ import ( "math/big" "time" + "go.uber.org/zap" + "github.com/ava-labs/avalanchego/ids" + "github.com/ava-labs/avalanchego/utils/logging" "github.com/ava-labs/avalanchego/utils/set" "github.com/ava-labs/avalanchego/vms/secp256k1fx" ethcommon "github.com/ethereum/go-ethereum/common" ) -const defaultPollFrequency = 100 * time.Millisecond +type PrimaryChainAlias string + +const ( + PChainAlias PrimaryChainAlias = "P" + XChainAlias PrimaryChainAlias = "X" + CChainAlias PrimaryChainAlias = "C" -// Signature of the function that will be called after a transaction -// has been issued with the ID of the issued transaction. -type PostIssuanceFunc func(ids.ID) + defaultPollFrequency = 100 * time.Millisecond +) + +// Signature of the function that will be called after a transaction has been issued. +type TxIssuanceHandler func( + // Identifies the primary chain ("P", "X" or "C") + chainAlias PrimaryChainAlias, + // ID of the confirmed transaction + txID ids.ID, + // The time from initiation to issuance + duration time.Duration, +) + +// Signature of the function that will be called after a transaction has been confirmed. +type TxConfirmationHandler func( + // Identifies the primary chain ("P", "X" or "C") + chainAlias PrimaryChainAlias, + // ID of the confirmed transaction + txID ids.ID, + // The time from initiation to confirmation (includes duration of issuance) + totalDuration time.Duration, + // The time from issuance to confirmation (does not include duration of issuance) + issuanceToConfirmationDuration time.Duration, +) type Option func(*Options) @@ -48,7 +77,8 @@ type Options struct { pollFrequencySet bool pollFrequency time.Duration - postIssuanceFunc PostIssuanceFunc + postIssuanceHandler TxIssuanceHandler + postConfirmationHandler TxConfirmationHandler } func NewOptions(ops []Option) *Options { @@ -132,8 +162,12 @@ func (o *Options) PollFrequency() time.Duration { return defaultPollFrequency } -func (o *Options) PostIssuanceFunc() PostIssuanceFunc { - return o.postIssuanceFunc +func (o *Options) PostIssuanceHandler() TxIssuanceHandler { + return o.postIssuanceHandler +} + +func (o *Options) PostConfirmationHandler() TxConfirmationHandler { + return o.postConfirmationHandler } func WithContext(ctx context.Context) Option { @@ -200,8 +234,38 @@ func WithPollFrequency(pollFrequency time.Duration) Option { } } -func WithPostIssuanceFunc(f PostIssuanceFunc) Option { +func WithPostIssuanceHandler(f TxIssuanceHandler) Option { + return func(o *Options) { + o.postIssuanceHandler = f + } +} + +func WithPostConfirmationHandler(f TxConfirmationHandler) Option { + return func(o *Options) { + o.postConfirmationHandler = f + } +} + +func WithLoggedIssuranceAndConfirmation(log logging.Logger) Option { return func(o *Options) { - o.postIssuanceFunc = f + WithPostIssuanceHandler( + func(chainAlias PrimaryChainAlias, txID ids.ID, duration time.Duration) { + log.Info("issued transaction", + zap.String("chainAlias", string(chainAlias)), + zap.Stringer("txID", txID), + zap.Duration("duration", duration), + ) + }, + )(o) + WithPostConfirmationHandler( + func(chainAlias PrimaryChainAlias, txID ids.ID, totalDuration time.Duration, issuanceToConfirmationDuration time.Duration) { + log.Info("confirmed transaction", + zap.String("chainAlias", string(chainAlias)), + zap.Stringer("txID", txID), + zap.Duration("totalDuration", totalDuration), + zap.Duration("issuanceToConfirmationDuration", issuanceToConfirmationDuration), + ) + }, + )(o) } }