From fb2843779fc2b6390187edce611789a322508c7e Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Wed, 29 May 2024 12:00:41 -0400 Subject: [PATCH 1/8] feat: adds v1 tracing --- internal/ethapi/api.go | 4 ++++ miner/worker.go | 12 ++++++++++-- 2 files changed, 14 insertions(+), 2 deletions(-) diff --git a/internal/ethapi/api.go b/internal/ethapi/api.go index c022bd4ac0e8..1efbb3fb432d 100644 --- a/internal/ethapi/api.go +++ b/internal/ethapi/api.go @@ -1530,6 +1530,10 @@ func AccessList(ctx context.Context, b Backend, blockNrOrHash rpc.BlockNumberOrH vmenv := b.GetEVM(ctx, msg, statedb, header, &config, nil) res, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.GasLimit)) if err != nil { + log.Error("Failed to apply message", "txHash", args.toTransaction().Hash(), "error", err) + } else { + log.Info("Successfully applied message", "txHash", args.toTransaction().Hash()) + } return nil, 0, nil, fmt.Errorf("failed to apply transaction: %v err: %v", args.toTransaction().Hash(), err) } if tracer.Equal(prevTracer) { diff --git a/miner/worker.go b/miner/worker.go index 201db9ea8b68..40e5f3519668 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -750,6 +750,9 @@ func (w *worker) updateSnapshot(env *environment) { w.snapshotState = env.state.Copy() } +// This function commits a transaction to the EVM. +// If the transaction type is BlobTxType, it calls the commitBlobTransaction function. +// Otherwise, it applies the transaction and updates the EVM state. func (w *worker) commitTransaction(env *environment, tx *types.Transaction) ([]*types.Log, error) { if tx.Type() == types.BlobTxType { return w.commitBlobTransaction(env, tx) @@ -762,7 +765,6 @@ func (w *worker) commitTransaction(env *environment, tx *types.Transaction) ([]* env.receipts = append(env.receipts, receipt) return receipt.Logs, nil } - func (w *worker) commitBlobTransaction(env *environment, tx *types.Transaction) ([]*types.Log, error) { sc := tx.BlobTxSidecar() if sc == nil { @@ -793,14 +795,20 @@ func (w *worker) applyTransaction(env *environment, tx *types.Transaction) (*typ snap = env.state.Snapshot() gp = env.gasPool.Gas() ) + log.Info("Applying transaction", "tx_hash", tx.Hash(), "coinbase", env.coinbase, "gas_available", gp) receipt, err := core.ApplyTransaction(w.chainConfig, w.chain, &env.coinbase, env.gasPool, env.state, env.header, tx, &env.header.GasUsed, *w.chain.GetVMConfig()) if err != nil { + log.Error("Transaction application failed", "tx_hash", tx.Hash(), "error", err) env.state.RevertToSnapshot(snap) env.gasPool.SetGas(gp) + } else { + log.Info("Transaction applied successfully", "tx_hash", tx.Hash(), "gas_used", env.header.GasUsed) } return receipt, err } +// This function commits transactions by processing them in order of price and nonce. +// It handles transaction execution, gas and tip calculations, and interruption handling. func (w *worker) commitTransactions(env *environment, txs *transactionsByPriceAndNonce, interrupt *atomic.Int32, minTip *big.Int) error { gasLimit := env.header.GasLimit if env.gasPool == nil { @@ -827,7 +835,7 @@ func (w *worker) commitTransactions(env *environment, txs *transactionsByPriceAn } // If we don't have enough space for the next transaction, skip the account. if env.gasPool.Gas() < ltx.Gas { - log.Trace("Not enough gas left for transaction", "hash", ltx.Hash, "left", env.gasPool.Gas(), "needed", ltx.Gas) + log.Info("Not enough gas left for transaction", "hash", ltx.Hash, "left", env.gasPool.Gas(), "needed", ltx.Gas) txs.Pop() continue } From 725ebaf547f487971754d67b979a5fd2c3ab12a0 Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Wed, 29 May 2024 12:10:26 -0400 Subject: [PATCH 2/8] feat: adds more logs --- miner/worker.go | 16 +++++++++++++++- 1 file changed, 15 insertions(+), 1 deletion(-) diff --git a/miner/worker.go b/miner/worker.go index 40e5f3519668..65baa9ff54ce 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -1008,6 +1008,7 @@ func (w *worker) prepareWork(genParams *generateParams) (*environment, error) { // be customized with the plugin in the future. func (w *worker) fillTransactions(interrupt *atomic.Int32, env *environment) error { pending := w.eth.TxPool().Pending(true) + log.Info("Pending transactions retrieved in fillTransactions", "count", len(pending)) // Split the pending transactions into locals and remotes. localTxs, remoteTxs := make(map[common.Address][]*txpool.LazyTransaction), pending @@ -1040,8 +1041,10 @@ func (w *worker) fillTransactions(interrupt *atomic.Int32, env *environment) err // generateWork generates a sealing block based on the given parameters. func (w *worker) generateWork(params *generateParams) *newPayloadResult { + log.Info("Starting to generate work for sealing block", "params", params) work, err := w.prepareWork(params) if err != nil { + log.Error("Failed to prepare work for sealing", "error", err) return &newPayloadResult{err: err} } defer work.discard() @@ -1050,18 +1053,29 @@ func (w *worker) generateWork(params *generateParams) *newPayloadResult { interrupt := new(atomic.Int32) timer := time.AfterFunc(w.newpayloadTimeout, func() { interrupt.Store(commitInterruptTimeout) + log.Info("Transaction processing interrupted due to timeout", "timeout", w.newpayloadTimeout) }) defer timer.Stop() err := w.fillTransactions(interrupt, work) if errors.Is(err, errBlockInterruptedByTimeout) { - log.Warn("Block building is interrupted", "allowance", common.PrettyDuration(w.newpayloadTimeout)) + log.Warn("Block building is interrupted by timeout", "allowance", common.PrettyDuration(w.newpayloadTimeout)) + } else if err != nil { + log.Error("Error while filling transactions into block", "error", err) + } else { + log.Info("Transactions successfully filled into block") } + } else { + log.Info("No transactions to process as per parameters") } + + log.Info("Finalizing and assembling block") block, err := w.engine.FinalizeAndAssemble(w.chain, work.header, work.state, work.txs, nil, work.receipts, params.withdrawals) if err != nil { + log.Error("Failed to finalize and assemble block", "error", err) return &newPayloadResult{err: err} } + log.Info("Block successfully finalized and assembled", "blockHash", block.Hash()) return &newPayloadResult{ block: block, fees: totalFees(block, work.receipts), From 3d61c1daf48f231f6ab572a217a75404d4c71c55 Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Wed, 29 May 2024 15:02:43 -0400 Subject: [PATCH 3/8] nit fix --- internal/ethapi/api.go | 4 ---- 1 file changed, 4 deletions(-) diff --git a/internal/ethapi/api.go b/internal/ethapi/api.go index 1efbb3fb432d..c022bd4ac0e8 100644 --- a/internal/ethapi/api.go +++ b/internal/ethapi/api.go @@ -1530,10 +1530,6 @@ func AccessList(ctx context.Context, b Backend, blockNrOrHash rpc.BlockNumberOrH vmenv := b.GetEVM(ctx, msg, statedb, header, &config, nil) res, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.GasLimit)) if err != nil { - log.Error("Failed to apply message", "txHash", args.toTransaction().Hash(), "error", err) - } else { - log.Info("Successfully applied message", "txHash", args.toTransaction().Hash()) - } return nil, 0, nil, fmt.Errorf("failed to apply transaction: %v err: %v", args.toTransaction().Hash(), err) } if tracer.Equal(prevTracer) { From 37546359638baa9dd5062e93528d81b2e3df02a5 Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Thu, 30 May 2024 14:21:46 -0400 Subject: [PATCH 4/8] feat: adds log at txpool --- eth/api_backend.go | 3 +++ 1 file changed, 3 insertions(+) diff --git a/eth/api_backend.go b/eth/api_backend.go index 0edcce5c8789..b0625eec2472 100644 --- a/eth/api_backend.go +++ b/eth/api_backend.go @@ -37,6 +37,7 @@ import ( "github.com/ethereum/go-ethereum/eth/tracers" "github.com/ethereum/go-ethereum/ethdb" "github.com/ethereum/go-ethereum/event" + "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/miner" "github.com/ethereum/go-ethereum/params" "github.com/ethereum/go-ethereum/rpc" @@ -287,7 +288,9 @@ func (b *EthAPIBackend) SubscribeLogsEvent(ch chan<- []*types.Log) event.Subscri return b.eth.BlockChain().SubscribeLogsEvent(ch) } +// SendTx sends a signed transaction to the transaction pool. func (b *EthAPIBackend) SendTx(ctx context.Context, signedTx *types.Transaction) error { + log.Info("Sending transaction", "tx_hash", signedTx.Hash().Hex()) return b.eth.txPool.Add([]*types.Transaction{signedTx}, true, false)[0] } From f97680c0cb17895e289927813826f9332e6e13cf Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Thu, 30 May 2024 17:45:29 -0400 Subject: [PATCH 5/8] feat: adds more tracing --- consensus/clique/clique.go | 3 +++ eth/api_backend.go | 2 +- miner/worker.go | 12 ++++++++++-- 3 files changed, 14 insertions(+), 3 deletions(-) diff --git a/consensus/clique/clique.go b/consensus/clique/clique.go index ecf5be129ccf..47ac815e8590 100644 --- a/consensus/clique/clique.go +++ b/consensus/clique/clique.go @@ -636,6 +636,9 @@ func (c *Clique) Seal(chain consensus.ChainHeaderReader, block *types.Block, res if c.config.PeriodMs == 0 && len(block.Transactions()) == 0 { return errors.New("sealing paused while waiting for transactions") } + for _, tx := range block.Transactions() { + log.Info("Processing transaction at consensus layer", "tx_hash", tx.Hash().Hex()) + } // Don't hold the signer fields for the entire sealing procedure c.lock.RLock() signer, signFn := c.signer, c.signFn diff --git a/eth/api_backend.go b/eth/api_backend.go index b0625eec2472..35da87c74653 100644 --- a/eth/api_backend.go +++ b/eth/api_backend.go @@ -290,7 +290,7 @@ func (b *EthAPIBackend) SubscribeLogsEvent(ch chan<- []*types.Log) event.Subscri // SendTx sends a signed transaction to the transaction pool. func (b *EthAPIBackend) SendTx(ctx context.Context, signedTx *types.Transaction) error { - log.Info("Sending transaction", "tx_hash", signedTx.Hash().Hex()) + log.Info("transaction entering mempool", "tx_hash", signedTx.Hash().Hex()) return b.eth.txPool.Add([]*types.Transaction{signedTx}, true, false)[0] } diff --git a/miner/worker.go b/miner/worker.go index 65baa9ff54ce..563d52a2ff11 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -545,10 +545,12 @@ func (w *worker) mainLoop() { if !w.isRunning() && w.current != nil { // If block is already full, abort if gp := w.current.gasPool; gp != nil && gp.Gas() < params.TxGas { + log.Info("Gas pool is full, skipping transaction", "gas", gp.Gas()) continue } txs := make(map[common.Address][]*txpool.LazyTransaction, len(ev.Txs)) for _, tx := range ev.Txs { + log.Info("Adding transaction to pending block", "tx_hash", tx.Hash().Hex()) acc, _ := types.Sender(w.current.signer, tx) txs[acc] = append(txs[acc], &txpool.LazyTransaction{ Pool: w.eth.TxPool(), // We don't know where this came from, yolo resolve from everywhere @@ -795,7 +797,7 @@ func (w *worker) applyTransaction(env *environment, tx *types.Transaction) (*typ snap = env.state.Snapshot() gp = env.gasPool.Gas() ) - log.Info("Applying transaction", "tx_hash", tx.Hash(), "coinbase", env.coinbase, "gas_available", gp) + log.Info("executing transaction on node", "tx_hash", tx.Hash(), "coinbase", env.coinbase, "gas_available", gp) receipt, err := core.ApplyTransaction(w.chainConfig, w.chain, &env.coinbase, env.gasPool, env.state, env.header, tx, &env.header.GasUsed, *w.chain.GetVMConfig()) if err != nil { log.Error("Transaction application failed", "tx_hash", tx.Hash(), "error", err) @@ -1009,7 +1011,13 @@ func (w *worker) prepareWork(genParams *generateParams) (*environment, error) { func (w *worker) fillTransactions(interrupt *atomic.Int32, env *environment) error { pending := w.eth.TxPool().Pending(true) log.Info("Pending transactions retrieved in fillTransactions", "count", len(pending)) - + for _, batch := range pending { + for _, tx := range batch { + if tx != nil { + log.Info("filltransactions pulling out of mempool", "tx_hash", tx.Hash.String()) + } + } + } // Split the pending transactions into locals and remotes. localTxs, remoteTxs := make(map[common.Address][]*txpool.LazyTransaction), pending for _, account := range w.eth.TxPool().Locals() { From ad34c3cd552c9bed7a4284457b5c52619b5a3afc Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Fri, 31 May 2024 19:12:08 -0400 Subject: [PATCH 6/8] feat: adds more logs --- core/txpool/legacypool/legacypool.go | 1 + 1 file changed, 1 insertion(+) diff --git a/core/txpool/legacypool/legacypool.go b/core/txpool/legacypool/legacypool.go index 624dafc60d03..9914daafd9b2 100644 --- a/core/txpool/legacypool/legacypool.go +++ b/core/txpool/legacypool/legacypool.go @@ -968,6 +968,7 @@ func (pool *LegacyPool) Add(txs []*types.Transaction, local, sync bool) []error for i, tx := range txs { // If the transaction is known, pre-set the error slot if pool.all.Get(tx.Hash()) != nil { + log.Error("Transaction already known", "tx_hash", tx.Hash()) errs[i] = txpool.ErrAlreadyKnown knownTxMeter.Mark(1) continue From 3720c1a77d258daf592c1714abb30999a539460d Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Fri, 31 May 2024 19:14:16 -0400 Subject: [PATCH 7/8] feat: remove redundant loop --- miner/worker.go | 9 +-------- 1 file changed, 1 insertion(+), 8 deletions(-) diff --git a/miner/worker.go b/miner/worker.go index 563d52a2ff11..12d7010f92bf 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -797,7 +797,7 @@ func (w *worker) applyTransaction(env *environment, tx *types.Transaction) (*typ snap = env.state.Snapshot() gp = env.gasPool.Gas() ) - log.Info("executing transaction on node", "tx_hash", tx.Hash(), "coinbase", env.coinbase, "gas_available", gp) + log.Info("executing transaction on node", "tx_hash", tx.Hash(), "gas_available", gp) receipt, err := core.ApplyTransaction(w.chainConfig, w.chain, &env.coinbase, env.gasPool, env.state, env.header, tx, &env.header.GasUsed, *w.chain.GetVMConfig()) if err != nil { log.Error("Transaction application failed", "tx_hash", tx.Hash(), "error", err) @@ -1011,13 +1011,6 @@ func (w *worker) prepareWork(genParams *generateParams) (*environment, error) { func (w *worker) fillTransactions(interrupt *atomic.Int32, env *environment) error { pending := w.eth.TxPool().Pending(true) log.Info("Pending transactions retrieved in fillTransactions", "count", len(pending)) - for _, batch := range pending { - for _, tx := range batch { - if tx != nil { - log.Info("filltransactions pulling out of mempool", "tx_hash", tx.Hash.String()) - } - } - } // Split the pending transactions into locals and remotes. localTxs, remoteTxs := make(map[common.Address][]*txpool.LazyTransaction), pending for _, account := range w.eth.TxPool().Locals() { From 5e1af63053848c08ec931a8a232c7d43012631c4 Mon Sep 17 00:00:00 2001 From: Kartik Chopra Date: Fri, 31 May 2024 19:15:01 -0400 Subject: [PATCH 8/8] feat: removes loop of txns from concensus --- consensus/clique/clique.go | 3 --- 1 file changed, 3 deletions(-) diff --git a/consensus/clique/clique.go b/consensus/clique/clique.go index 47ac815e8590..ecf5be129ccf 100644 --- a/consensus/clique/clique.go +++ b/consensus/clique/clique.go @@ -636,9 +636,6 @@ func (c *Clique) Seal(chain consensus.ChainHeaderReader, block *types.Block, res if c.config.PeriodMs == 0 && len(block.Transactions()) == 0 { return errors.New("sealing paused while waiting for transactions") } - for _, tx := range block.Transactions() { - log.Info("Processing transaction at consensus layer", "tx_hash", tx.Hash().Hex()) - } // Don't hold the signer fields for the entire sealing procedure c.lock.RLock() signer, signFn := c.signer, c.signFn