From 5e6f77f04150b9e9049bc8c328cba092c7cc2632 Mon Sep 17 00:00:00 2001 From: Charlie Chen Date: Fri, 2 Aug 2024 18:06:23 -0500 Subject: [PATCH] refactor and fix evm outbound tracker reporter to avoid invalid hashes; print log when outbound tracker is full of invalid hashes --- pkg/constant/constant.go | 6 + zetaclient/chains/base/observer.go | 11 +- zetaclient/chains/evm/constant.go | 7 +- zetaclient/chains/evm/observer/outbound.go | 108 +++++++++++------ zetaclient/chains/evm/rpc/rpc.go | 52 +++++++++ zetaclient/chains/evm/rpc/rpc_live_test.go | 45 +++++++ .../evm/signer/outbound_tracker_reporter.go | 86 ++++++++++++++ zetaclient/chains/evm/signer/signer.go | 110 ------------------ .../signer/outbound_tracker_reporter.go | 23 ++-- zetaclient/logs/fields.go | 33 ++++++ zetaclient/orchestrator/orchestrator.go | 4 +- 11 files changed, 322 insertions(+), 163 deletions(-) create mode 100644 zetaclient/chains/evm/rpc/rpc.go create mode 100644 zetaclient/chains/evm/rpc/rpc_live_test.go create mode 100644 zetaclient/chains/evm/signer/outbound_tracker_reporter.go create mode 100644 zetaclient/logs/fields.go diff --git a/pkg/constant/constant.go b/pkg/constant/constant.go index 6aba0f4dea..b296be7654 100644 --- a/pkg/constant/constant.go +++ b/pkg/constant/constant.go @@ -1,6 +1,12 @@ package constant +import "time" + const ( + // ZetaBlockTime is the block time of the ZetaChain network + // It's a rough estimate that can be used in non-critical path to estimate the time of a block + ZetaBlockTime = 6000 * time.Millisecond + // DonationMessage is the message for donation transactions // Transaction sent to the TSS or ERC20 Custody address containing this message are considered as a donation DonationMessage = "I am rich!" diff --git a/zetaclient/chains/base/observer.go b/zetaclient/chains/base/observer.go index 428946f0bf..23d2f13a76 100644 --- a/zetaclient/chains/base/observer.go +++ b/zetaclient/chains/base/observer.go @@ -17,6 +17,7 @@ import ( observertypes "github.com/zeta-chain/zetacore/x/observer/types" "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" "github.com/zeta-chain/zetacore/zetaclient/db" + "github.com/zeta-chain/zetacore/zetaclient/logs" "github.com/zeta-chain/zetacore/zetaclient/metrics" clienttypes "github.com/zeta-chain/zetacore/zetaclient/types" "github.com/zeta-chain/zetacore/zetaclient/zetacore" @@ -295,13 +296,13 @@ func (ob *Observer) Logger() *ObserverLogger { // WithLogger attaches a new logger to the observer. func (ob *Observer) WithLogger(logger Logger) *Observer { - chainLogger := logger.Std.With().Int64("chain", ob.chain.ChainId).Logger() + chainLogger := logger.Std.With().Int64(logs.FieldChain, ob.chain.ChainId).Logger() ob.logger = ObserverLogger{ Chain: chainLogger, - Inbound: chainLogger.With().Str("module", "inbound").Logger(), - Outbound: chainLogger.With().Str("module", "outbound").Logger(), - GasPrice: chainLogger.With().Str("module", "gasprice").Logger(), - Headers: chainLogger.With().Str("module", "headers").Logger(), + Inbound: chainLogger.With().Str(logs.FieldModule, logs.ModNameInbound).Logger(), + Outbound: chainLogger.With().Str(logs.FieldModule, logs.ModNameOutbound).Logger(), + GasPrice: chainLogger.With().Str(logs.FieldModule, logs.ModNameGasPrice).Logger(), + Headers: chainLogger.With().Str(logs.FieldModule, logs.ModNameHeaders).Logger(), Compliance: logger.Compliance, } return ob diff --git a/zetaclient/chains/evm/constant.go b/zetaclient/chains/evm/constant.go index b754d57f30..beaeb6143f 100644 --- a/zetaclient/chains/evm/constant.go +++ b/zetaclient/chains/evm/constant.go @@ -3,12 +3,13 @@ package evm import "time" const ( - // ZetaBlockTime is the block time of the Zeta network - ZetaBlockTime = 6500 * time.Millisecond - // OutboundInclusionTimeout is the timeout for waiting for an outbound to be included in a block OutboundInclusionTimeout = 20 * time.Minute + // ReorgProtectBlockCount is confirmations count to protect against reorg + // Short 1~2 block reorgs could happen often on Ethereum due to network congestion or block production race conditions + ReorgProtectBlockCount = 2 + // OutboundTrackerReportTimeout is the timeout for waiting for an outbound tracker report OutboundTrackerReportTimeout = 10 * time.Minute diff --git a/zetaclient/chains/evm/observer/outbound.go b/zetaclient/chains/evm/observer/outbound.go index 680fb4e3af..fe4ee300c2 100644 --- a/zetaclient/chains/evm/observer/outbound.go +++ b/zetaclient/chains/evm/observer/outbound.go @@ -19,6 +19,7 @@ import ( "github.com/zeta-chain/zetacore/pkg/chains" "github.com/zeta-chain/zetacore/pkg/coin" + crosschainkeeper "github.com/zeta-chain/zetacore/x/crosschain/keeper" crosschaintypes "github.com/zeta-chain/zetacore/x/crosschain/types" "github.com/zeta-chain/zetacore/zetaclient/chains/evm" "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" @@ -30,8 +31,15 @@ import ( // WatchOutbound watches evm chain for outgoing txs status // TODO(revamp): move ticker function to ticker file -// TODO(revamp): move inner logic to a separate function func (ob *Observer) WatchOutbound(ctx context.Context) error { + // get app context + app, err := zctx.FromContext(ctx) + if err != nil { + return err + } + + // create outbound ticker + chainID := ob.Chain().ChainId ticker, err := clienttypes.NewDynamicTicker( fmt.Sprintf("EVM_WatchOutbound_%d", ob.Chain().ChainId), ob.GetChainParams().OutboundTicker, @@ -41,11 +49,6 @@ func (ob *Observer) WatchOutbound(ctx context.Context) error { return err } - app, err := zctx.FromContext(ctx) - if err != nil { - return err - } - ob.Logger().Outbound.Info().Msgf("WatchOutbound started for chain %d", ob.Chain().ChainId) sampledLogger := ob.Logger().Outbound.Sample(&zerolog.BasicSampler{N: 10}) defer ticker.Stop() @@ -57,38 +60,16 @@ func (ob *Observer) WatchOutbound(ctx context.Context) error { Msgf("WatchOutbound: outbound observation is disabled for chain %d", ob.Chain().ChainId) continue } - trackers, err := ob.ZetacoreClient(). - GetAllOutboundTrackerByChain(ctx, ob.Chain().ChainId, interfaces.Ascending) + + // process outbound trackers + err := ob.ProcessOutboundTrackers(ctx) if err != nil { - continue - } - for _, tracker := range trackers { - nonceInt := tracker.Nonce - if ob.IsTxConfirmed(nonceInt) { // Go to next tracker if this one already has a confirmed tx - continue - } - txCount := 0 - var outboundReceipt *ethtypes.Receipt - var outbound *ethtypes.Transaction - for _, txHash := range tracker.HashList { - if receipt, tx, ok := ob.checkConfirmedTx(ctx, txHash.TxHash, nonceInt); ok { - txCount++ - outboundReceipt = receipt - outbound = tx - ob.Logger().Outbound.Info(). - Msgf("WatchOutbound: confirmed outbound %s for chain %d nonce %d", txHash.TxHash, ob.Chain().ChainId, nonceInt) - if txCount > 1 { - ob.Logger().Outbound.Error().Msgf( - "WatchOutbound: checkConfirmedTx passed, txCount %d chain %d nonce %d receipt %v transaction %v", txCount, ob.Chain().ChainId, nonceInt, outboundReceipt, outbound) - } - } - } - if txCount == 1 { // should be only one txHash confirmed for each nonce. - ob.SetTxNReceipt(nonceInt, outboundReceipt, outbound) - } else if txCount > 1 { // should not happen. We can't tell which txHash is true. It might happen (e.g. glitchy/hacked endpoint) - ob.Logger().Outbound.Error().Msgf("WatchOutbound: confirmed multiple (%d) outbound for chain %d nonce %d", txCount, ob.Chain().ChainId, nonceInt) - } + ob.Logger(). + Outbound.Error(). + Err(err). + Msgf("WatchOutbound: error ProcessOutboundTrackers for chain %d", chainID) } + ticker.UpdateInterval(ob.GetChainParams().OutboundTicker, ob.Logger().Outbound) case <-ob.StopChannel(): ob.Logger().Outbound.Info().Msg("WatchOutbound: stopped") @@ -97,6 +78,61 @@ func (ob *Observer) WatchOutbound(ctx context.Context) error { } } +// ProcessOutboundTrackers processes outbound trackers +func (ob *Observer) ProcessOutboundTrackers(ctx context.Context) error { + chainID := ob.Chain().ChainId + trackers, err := ob.ZetacoreClient().GetAllOutboundTrackerByChain(ctx, ob.Chain().ChainId, interfaces.Ascending) + if err != nil { + return errors.Wrap(err, "GetAllOutboundTrackerByChain error") + } + + // prepare logger fields + logger := ob.Logger().Outbound.With(). + Str("method", "ProcessOutboundTrackers"). + Int64("chain", chainID). + Logger() + + // process outbound trackers + for _, tracker := range trackers { + // go to next tracker if this one already has a confirmed tx + nonce := tracker.Nonce + if ob.IsTxConfirmed(nonce) { + continue + } + + // check each txHash and save tx and receipt if it's legit and confirmed + txCount := 0 + var outboundReceipt *ethtypes.Receipt + var outbound *ethtypes.Transaction + for _, txHash := range tracker.HashList { + if receipt, tx, ok := ob.checkConfirmedTx(ctx, txHash.TxHash, nonce); ok { + txCount++ + outboundReceipt = receipt + outbound = tx + logger.Info().Msgf("confirmed outbound %s for chain %d nonce %d", txHash.TxHash, chainID, nonce) + if txCount > 1 { + logger.Error(). + Msgf("checkConfirmedTx passed, txCount %d chain %d nonce %d receipt %v tx %v", txCount, chainID, nonce, receipt, tx) + } + } + } + + // should be only one txHash confirmed for each nonce. + if txCount == 1 { + ob.SetTxNReceipt(nonce, outboundReceipt, outbound) + } else if txCount > 1 { + // should not happen. We can't tell which txHash is true. It might happen (e.g. bug, glitchy/hacked endpoint) + ob.Logger().Outbound.Error().Msgf("WatchOutbound: confirmed multiple (%d) outbound for chain %d nonce %d", txCount, chainID, nonce) + } else { + if len(tracker.HashList) == crosschainkeeper.MaxOutboundTrackerHashes { + ob.Logger().Outbound.Error().Msgf("WatchOutbound: outbound tracker is full of invalid hashes for chain %d nonce %d", chainID, nonce) + } + } + } + + return nil +} + // PostVoteOutbound posts vote to zetacore for the confirmed outbound func (ob *Observer) PostVoteOutbound( ctx context.Context, diff --git a/zetaclient/chains/evm/rpc/rpc.go b/zetaclient/chains/evm/rpc/rpc.go new file mode 100644 index 0000000000..6fcc3d007c --- /dev/null +++ b/zetaclient/chains/evm/rpc/rpc.go @@ -0,0 +1,52 @@ +package rpc + +import ( + "context" + + ethcommon "github.com/ethereum/go-ethereum/common" + "github.com/pkg/errors" + + "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" +) + +// IsTxConfirmed checks if the transaction is confirmed with given confirmations +func IsTxConfirmed( + ctx context.Context, + client interfaces.EVMRPCClient, + txHash string, + confirmations uint64, +) (bool, error) { + // query the tx + _, isPending, err := client.TransactionByHash(ctx, ethcommon.HexToHash(txHash)) + if err != nil { + return false, errors.Wrapf(err, "error getting transaction for tx %s", txHash) + } + if isPending { + return false, nil + } + + // query receipt + receipt, err := client.TransactionReceipt(ctx, ethcommon.HexToHash(txHash)) + if err != nil { + return false, errors.Wrapf(err, "error getting transaction receipt for tx %s", txHash) + } + + // should not happen + if receipt == nil { + return false, errors.Errorf("receipt is nil for tx %s", txHash) + } + + // query last block height + lastHeight, err := client.BlockNumber(ctx) + if err != nil { + return false, errors.Wrap(err, "error getting block number") + } + + // check confirmations + if lastHeight < receipt.BlockNumber.Uint64() { + return false, nil + } + blocks := lastHeight - receipt.BlockNumber.Uint64() + 1 + + return blocks >= confirmations, nil +} diff --git a/zetaclient/chains/evm/rpc/rpc_live_test.go b/zetaclient/chains/evm/rpc/rpc_live_test.go new file mode 100644 index 0000000000..0c420c830e --- /dev/null +++ b/zetaclient/chains/evm/rpc/rpc_live_test.go @@ -0,0 +1,45 @@ +package rpc_test + +import ( + "context" + "math" + + "github.com/ethereum/go-ethereum/ethclient" + "github.com/stretchr/testify/require" + "github.com/zeta-chain/zetacore/zetaclient/chains/evm/rpc" + + "testing" +) + +const ( + URLEthMainnet = "https://rpc.ankr.com/eth" + URLEthSepolia = "https://rpc.ankr.com/eth_sepolia" + URLBscMainnet = "https://rpc.ankr.com/bsc" + URLPolygonMainnet = "https://rpc.ankr.com/polygon" +) + +// Test_EVMRPCLive is a phony test to run each live test individually +func Test_EVMRPCLive(t *testing.T) { + // LiveTest_IsTxConfirmed(t) +} + +func LiveTest_IsTxConfirmed(t *testing.T) { + client, err := ethclient.Dial(URLEthMainnet) + require.NoError(t, err) + + // check if the transaction is confirmed + ctx := context.Background() + txHash := "0xd2eba7ac3da1b62800165414ea4bcaf69a3b0fb9b13a0fc32f4be11bfef79146" + + t.Run("should confirm tx", func(t *testing.T) { + confirmed, err := rpc.IsTxConfirmed(ctx, client, txHash, 12) + require.NoError(t, err) + require.True(t, confirmed) + }) + + t.Run("should not confirm tx if confirmations is not enough", func(t *testing.T) { + confirmed, err := rpc.IsTxConfirmed(ctx, client, txHash, math.MaxUint64) + require.NoError(t, err) + require.False(t, confirmed) + }) +} diff --git a/zetaclient/chains/evm/signer/outbound_tracker_reporter.go b/zetaclient/chains/evm/signer/outbound_tracker_reporter.go new file mode 100644 index 0000000000..d0584c74d2 --- /dev/null +++ b/zetaclient/chains/evm/signer/outbound_tracker_reporter.go @@ -0,0 +1,86 @@ +// Package signer implements the ChainSigner interface for EVM chains +package signer + +import ( + "context" + "time" + + "github.com/rs/zerolog" + + "github.com/zeta-chain/zetacore/zetaclient/chains/evm" + "github.com/zeta-chain/zetacore/zetaclient/chains/evm/rpc" + "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" + "github.com/zeta-chain/zetacore/zetaclient/logs" +) + +// reportToOutboundTracker reports outboundHash to tracker only when tx receipt is available +func (signer *Signer) reportToOutboundTracker( + ctx context.Context, + zetacoreClient interfaces.ZetacoreClient, + chainID int64, + nonce uint64, + outboundHash string, + logger zerolog.Logger, +) { + // prepare logger + logger = logger.With(). + Str(logs.FieldMethod, "reportToOutboundTracker"). + Int64(logs.FieldChain, chainID). + Uint64(logs.FieldNonce, nonce). + Str(logs.FieldTx, outboundHash). + Logger() + + // set being reported flag to avoid duplicate reporting + alreadySet := signer.Signer.SetBeingReportedFlag(outboundHash) + if alreadySet { + logger.Info(). + Msgf("outbound %s for chain %d nonce %d is being reported", outboundHash, chainID, nonce) + return + } + + // launch a goroutine to monitor tx confirmation status + go func() { + defer func() { + signer.Signer.ClearBeingReportedFlag(outboundHash) + }() + + // try monitoring tx inclusion status for 20 minutes + tStart := time.Now() + for { + // take a rest between each check + time.Sleep(10 * time.Second) + + // give up (forget about the tx) after 20 minutes of monitoring, there are 2 reasons: + // 1. the gas stability pool should have kicked in and replaced the tx by then. + // 2. even if there is a chance that the tx is included later, most likely it's going to be a false tx hash (either replaced or dropped). + if time.Since(tStart) > evm.OutboundInclusionTimeout { + logger.Info(). + Msgf("timeout waiting outbound %s inclusion for chain %d nonce %d", outboundHash, chainID, nonce) + return + } + + // check tx confirmation status + confirmed, err := rpc.IsTxConfirmed(ctx, signer.client, outboundHash, evm.ReorgProtectBlockCount) + if err != nil { + logger.Err(err). + Msgf("unable to check confirmation status for chain %d nonce %d outbound %s", chainID, nonce, outboundHash) + } + if !confirmed { + continue + } + + // report outbound hash to tracker + zetaHash, err := zetacoreClient.AddOutboundTracker(ctx, chainID, nonce, outboundHash, nil, "", -1) + if err != nil { + logger.Err(err). + Msgf("error adding outbound %s to tracker for chain %d nonce %d", outboundHash, chainID, nonce) + } else if zetaHash != "" { + logger.Info().Msgf("added outbound %s to tracker for chain %d nonce %d; zeta txhash %s", outboundHash, chainID, nonce, zetaHash) + } else { + // exit goroutine until the tracker contains the hash (reported by either this or other signers) + logger.Info().Msgf("outbound %s now exists in tracker for chain %d nonce %d", outboundHash, chainID, nonce) + return + } + } + }() +} diff --git a/zetaclient/chains/evm/signer/signer.go b/zetaclient/chains/evm/signer/signer.go index 9c928face1..6bfddf9c5e 100644 --- a/zetaclient/chains/evm/signer/signer.go +++ b/zetaclient/chains/evm/signer/signer.go @@ -24,7 +24,6 @@ import ( "github.com/zeta-chain/zetacore/pkg/chains" "github.com/zeta-chain/zetacore/pkg/coin" "github.com/zeta-chain/zetacore/pkg/constant" - crosschainkeeper "github.com/zeta-chain/zetacore/x/crosschain/keeper" "github.com/zeta-chain/zetacore/x/crosschain/types" "github.com/zeta-chain/zetacore/zetaclient/chains/base" "github.com/zeta-chain/zetacore/zetaclient/chains/evm" @@ -749,115 +748,6 @@ func (signer *Signer) SignMigrateTssFundsCmd(ctx context.Context, txData *Outbou return tx, nil } -// reportToOutboundTracker reports outboundHash to tracker only when tx receipt is available -// TODO(revamp): move outbound tracker function to a outbound tracker file -func (signer *Signer) reportToOutboundTracker( - ctx context.Context, - zetacoreClient interfaces.ZetacoreClient, - chainID int64, - nonce uint64, - outboundHash string, - logger zerolog.Logger, -) { - // set being reported flag to avoid duplicate reporting - alreadySet := signer.Signer.SetBeingReportedFlag(outboundHash) - if alreadySet { - logger.Info(). - Msgf("reportToOutboundTracker: outboundHash %s for chain %d nonce %d is being reported", outboundHash, chainID, nonce) - return - } - - // report to outbound tracker with goroutine - go func() { - defer func() { - signer.Signer.ClearBeingReportedFlag(outboundHash) - }() - - // try monitoring tx inclusion status for 10 minutes - var err error - report := false - isPending := false - blockNumber := uint64(0) - tStart := time.Now() - for { - // give up after 10 minutes of monitoring - time.Sleep(10 * time.Second) - - if time.Since(tStart) > evm.OutboundInclusionTimeout { - // if tx is still pending after timeout, report to outboundTracker anyway as we cannot monitor forever - if isPending { - report = true // probably will be included later - } - logger.Info(). - Msgf("reportToOutboundTracker: timeout waiting tx inclusion for chain %d nonce %d outboundHash %s report %v", chainID, nonce, outboundHash, report) - break - } - // try getting the tx - _, isPending, err = signer.client.TransactionByHash(ctx, ethcommon.HexToHash(outboundHash)) - if err != nil { - logger.Info(). - Err(err). - Msgf("reportToOutboundTracker: error getting tx for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - continue - } - // if tx is include in a block, try getting receipt - if !isPending { - report = true // included - receipt, err := signer.client.TransactionReceipt(ctx, ethcommon.HexToHash(outboundHash)) - if err != nil { - logger.Info(). - Err(err). - Msgf("reportToOutboundTracker: error getting receipt for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - } - if receipt != nil { - blockNumber = receipt.BlockNumber.Uint64() - } - break - } - // keep monitoring pending tx - logger.Info(). - Msgf("reportToOutboundTracker: tx has not been included yet for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - } - - // try adding to outbound tracker for 10 minutes - if report { - tStart := time.Now() - for { - // give up after 10 minutes of retrying - if time.Since(tStart) > evm.OutboundTrackerReportTimeout { - logger.Info(). - Msgf("reportToOutboundTracker: timeout adding outbound tracker for chain %d nonce %d outboundHash %s, please add manually", chainID, nonce, outboundHash) - break - } - // stop if the cctx is already finalized - cctx, err := zetacoreClient.GetCctxByNonce(ctx, chainID, nonce) - if err != nil { - logger.Err(err). - Msgf("reportToOutboundTracker: error getting cctx for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - } else if !crosschainkeeper.IsPending(cctx) { - logger.Info().Msgf("reportToOutboundTracker: cctx already finalized for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - break - } - // report to outbound tracker - zetaHash, err := zetacoreClient.AddOutboundTracker(ctx, chainID, nonce, outboundHash, nil, "", -1) - if err != nil { - logger.Err(err). - Msgf("reportToOutboundTracker: error adding to outbound tracker for chain %d nonce %d outboundHash %s", chainID, nonce, outboundHash) - } else if zetaHash != "" { - logger.Info().Msgf("reportToOutboundTracker: added outboundHash to core successful %s, chain %d nonce %d outboundHash %s block %d", - zetaHash, chainID, nonce, outboundHash, blockNumber) - } else { - // stop if the tracker contains the outboundHash - logger.Info().Msgf("reportToOutboundTracker: outbound tracker contains outboundHash %s for chain %d nonce %d", outboundHash, chainID, nonce) - break - } - // retry otherwise - time.Sleep(evm.ZetaBlockTime * 3) - } - } - }() -} - // getEVMRPC is a helper function to set up the client and signer, also initializes a mock client for unit tests func getEVMRPC(ctx context.Context, endpoint string) (interfaces.EVMRPCClient, ethtypes.Signer, error) { if endpoint == mocks.EVMRPCEnabled { diff --git a/zetaclient/chains/solana/signer/outbound_tracker_reporter.go b/zetaclient/chains/solana/signer/outbound_tracker_reporter.go index 6462060beb..9c325ae3f5 100644 --- a/zetaclient/chains/solana/signer/outbound_tracker_reporter.go +++ b/zetaclient/chains/solana/signer/outbound_tracker_reporter.go @@ -9,6 +9,7 @@ import ( "github.com/rs/zerolog" "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" + "github.com/zeta-chain/zetacore/zetaclient/logs" ) const ( @@ -27,11 +28,19 @@ func (signer *Signer) reportToOutboundTracker( txSig solana.Signature, logger zerolog.Logger, ) { + // prepare logger + logger = logger.With(). + Str(logs.FieldMethod, "reportToOutboundTracker"). + Int64(logs.FieldChain, chainID). + Uint64(logs.FieldNonce, nonce). + Str(logs.FieldTx, txSig.String()). + Logger() + // set being reported flag to avoid duplicate reporting alreadySet := signer.Signer.SetBeingReportedFlag(txSig.String()) if alreadySet { logger.Info(). - Msgf("reportToOutboundTracker: outbound %s for chain %d nonce %d is being reported", txSig, chainID, nonce) + Msgf("outbound %s for chain %d nonce %d is being reported", txSig, chainID, nonce) return } @@ -49,7 +58,7 @@ func (signer *Signer) reportToOutboundTracker( // give up if we know the tx is too old and already expired if time.Since(start) > SolanaTransactionTimeout { logger.Info(). - Msgf("reportToOutboundTracker: outbound %s expired for chain %d nonce %d", txSig, chainID, nonce) + Msgf("outbound %s expired for chain %d nonce %d", txSig, chainID, nonce) return } @@ -70,7 +79,7 @@ func (signer *Signer) reportToOutboundTracker( // a good/valid candidate of outbound tracker hash must come with a successful tx. logger.Warn(). Any("Err", tx.Meta.Err). - Msgf("reportToOutboundTracker: outbound %s failed for chain %d nonce %d", txSig, chainID, nonce) + Msgf("outbound %s failed for chain %d nonce %d", txSig, chainID, nonce) return } @@ -78,12 +87,12 @@ func (signer *Signer) reportToOutboundTracker( zetaHash, err := zetacoreClient.AddOutboundTracker(ctx, chainID, nonce, txSig.String(), nil, "", -1) if err != nil { logger.Err(err). - Msgf("reportToOutboundTracker: error adding outbound %s for chain %d nonce %d", txSig, chainID, nonce) + Msgf("error adding outbound %s for chain %d nonce %d", txSig, chainID, nonce) } else if zetaHash != "" { - logger.Info().Msgf("reportToOutboundTracker: added outbound %s for chain %d nonce %d; zeta txhash %s", txSig, chainID, nonce, zetaHash) + logger.Info().Msgf("added outbound %s for chain %d nonce %d; zeta txhash %s", txSig, chainID, nonce, zetaHash) } else { - // exit goroutine if the tracker already contains the hash (reported by other signer) - logger.Info().Msgf("reportToOutboundTracker: outbound %s already in tracker for chain %d nonce %d", txSig, chainID, nonce) + // exit goroutine until the tracker contains the hash (reported by either this or other signers) + logger.Info().Msgf("outbound %s now exists in tracker for chain %d nonce %d", txSig, chainID, nonce) return } } diff --git a/zetaclient/logs/fields.go b/zetaclient/logs/fields.go new file mode 100644 index 0000000000..6984c1a13d --- /dev/null +++ b/zetaclient/logs/fields.go @@ -0,0 +1,33 @@ +package logs + +const ( + // FieldModule is the field key for the module name in logs + FieldModule = "module" + + // FieldMethod is the field key for the method name in logs + FieldMethod = "method" + + // FieldChain is the field key for the chain ID in logs + FieldChain = "chain" + + // FieldNonce is the field key for the nonce in logs + FieldNonce = "nonce" + + // FieldTx is the field key for the transaction hash in logs + FieldTx = "tx" + + // FieldCctx is the field key for the cctx index in logs + FieldCctx = "cctx" + + // ModNameInbound is the module name for inbound logs + ModNameInbound = "inbound" + + // ModNameOutbound is the module name for outbound logs + ModNameOutbound = "outbound" + + // ModNameGasPrice is the module name for gas price logs + ModNameGasPrice = "gasprice" + + // ModNameHeaders is the module name for block headers logs + ModNameHeaders = "headers" +) diff --git a/zetaclient/orchestrator/orchestrator.go b/zetaclient/orchestrator/orchestrator.go index 8bff065099..39ed12bdec 100644 --- a/zetaclient/orchestrator/orchestrator.go +++ b/zetaclient/orchestrator/orchestrator.go @@ -15,12 +15,12 @@ import ( "github.com/samber/lo" "github.com/zeta-chain/zetacore/pkg/bg" + "github.com/zeta-chain/zetacore/pkg/constant" zetamath "github.com/zeta-chain/zetacore/pkg/math" "github.com/zeta-chain/zetacore/x/crosschain/types" observertypes "github.com/zeta-chain/zetacore/x/observer/types" "github.com/zeta-chain/zetacore/zetaclient/chains/base" btcobserver "github.com/zeta-chain/zetacore/zetaclient/chains/bitcoin/observer" - "github.com/zeta-chain/zetacore/zetaclient/chains/evm" "github.com/zeta-chain/zetacore/zetaclient/chains/interfaces" solanaobserver "github.com/zeta-chain/zetacore/zetaclient/chains/solana/observer" zctx "github.com/zeta-chain/zetacore/zetaclient/context" @@ -664,7 +664,7 @@ func (oc *Orchestrator) ScheduleCctxSolana( // and optionally (de)provisions respective observers and signers. func (oc *Orchestrator) runObserverSignerSync(ctx context.Context) error { // check every other zeta block - const cadence = 2 * evm.ZetaBlockTime + const cadence = 2 * constant.ZetaBlockTime ticker := time.NewTicker(cadence) defer ticker.Stop()