From 5a58f0ed8622b0e57ffd649bb1b9187bdb0009b2 Mon Sep 17 00:00:00 2001 From: Michael Gu Date: Wed, 3 Oct 2018 16:16:46 -0400 Subject: [PATCH] added print statements to tx_pool.go and worker.go to log the mining process --- core/tx_pool.go | 29 +++++++++++++++++++++++++++++ miner/worker.go | 27 +++++++++++++++++++++++++++ 2 files changed, 56 insertions(+) diff --git a/core/tx_pool.go b/core/tx_pool.go index f6da5da2a7..d3ee87bbd8 100644 --- a/core/tx_pool.go +++ b/core/tx_pool.go @@ -33,6 +33,10 @@ import ( "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/params" + + "github.com/jimlawless/whereami" + "github.com/natefinch/lumberjack" + l "log" ) const ( @@ -215,6 +219,14 @@ type TxPool struct { // NewTxPool creates a new transaction pool to gather, sort and filter inbound // transactions from the network. func NewTxPool(config TxPoolConfig, chainconfig *params.ChainConfig, chain blockChain) *TxPool { + l.SetOutput(&lumberjack.Logger{ + Filename: "../miner.log", + MaxSize: 500, + MaxBackups: 3, + MaxAge: 28, + Compress: true, + }) + // Sanitize the input to ensure no vulnerable gas prices are set config = (&config).sanitize() @@ -566,15 +578,19 @@ func (pool *TxPool) local() map[common.Address]types.Transactions { // validateTx checks whether a transaction is valid according to the consensus // rules and adheres to some heuristic limits of the local node (price and size). func (pool *TxPool) validateTx(tx *types.Transaction, local bool) error { + l.Printf("Pool beginning standard validation using local heuristics @ %s\n\n", whereami.WhereAmI()) + // Heuristic limit, reject transactions over 32KB to prevent DOS attacks if tx.Size() > 32*1024 { return ErrOversizedData } + l.Println("Txn passed size limit of 32KB\n") // Transactions can't be negative. This may never happen using RLP decoded // transactions but may occur if you create a transaction using the RPC. if tx.Value().Sign() < 0 { return ErrNegativeValue } + l.Println("Txn passed non-negative check\n") // Ensure the transaction doesn't exceed the current block limit gas. if pool.currentMaxGas < tx.Gas() { return ErrGasLimit @@ -584,20 +600,24 @@ func (pool *TxPool) validateTx(tx *types.Transaction, local bool) error { if err != nil { return ErrInvalidSender } + l.Println("Txn signed properly\n") // Drop non-local transactions under our own minimal accepted gas price local = local || pool.locals.contains(from) // account may be local even if the transaction arrived from the network if !local && pool.gasPrice.Cmp(tx.GasPrice()) > 0 { return ErrUnderpriced } + l.Printf("Txn gas price of %v is above our pool's acceptable gas price of %v\n\n", tx.GasPrice(), pool.gasPrice) // Ensure the transaction adheres to nonce ordering if pool.currentState.GetNonce(from) > tx.Nonce() { return ErrNonceTooLow } + l.Println("Txn correctly ordered by nonce\n") // Transactor should have enough funds to cover the costs // cost == V + GP * GL if pool.currentState.GetBalance(from).Cmp(tx.Cost()) < 0 { return ErrInsufficientFunds } + l.Printf("Sender has sufficient balance of %v to cover txn cost of %v\n\n", pool.currentState.GetBalance(from), tx.Cost()) intrGas, err := IntrinsicGas(tx.Data(), tx.To() == nil, pool.homestead) if err != nil { return err @@ -605,6 +625,7 @@ func (pool *TxPool) validateTx(tx *types.Transaction, local bool) error { if tx.Gas() < intrGas { return ErrIntrinsicGas } + l.Printf("Txn gas used (%v) is under max intrinsic gas threshold of %v\n\n", tx.Gas(), intrGas) return nil } @@ -624,11 +645,13 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (bool, error) { return false, fmt.Errorf("known transaction: %x", hash) } // If the transaction fails basic validation, discard it + l.Printf("Pool found incoming txn, queueing new txn with hash: %x @ %s\n\n", hash, whereami.WhereAmI()) if err := pool.validateTx(tx, local); err != nil { log.Trace("Discarding invalid transaction", "hash", hash, "err", err) invalidTxCounter.Inc(1) return false, err } + l.Printf("New txn passed all basic standard validation heuristics @ %s\n\n", whereami.WhereAmI()) // If the transaction pool is full, discard underpriced transactions if uint64(pool.all.Count()) >= pool.config.GlobalSlots+pool.config.GlobalQueue { // If the new transaction is underpriced, don't accept it @@ -937,12 +960,15 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) { continue // Just in case someone calls with a non existing account } // Drop all transactions that are deemed too old (low nonce) + l.Println("Pool dropping old queued txns\n") for _, tx := range list.Forward(pool.currentState.GetNonce(addr)) { hash := tx.Hash() log.Trace("Removed old queued transaction", "hash", hash) pool.all.Remove(hash) pool.priced.Removed() + l.Printf("Pool dropped old txn with hash: %x\n\n", hash) } + l.Println("Pool dropping unpayabe txns (low balance/no gas)\n") // Drop all transactions that are too costly (low balance or out of gas) drops, _ := list.Filter(pool.currentState.GetBalance(addr), pool.currentMaxGas) for _, tx := range drops { @@ -951,12 +977,15 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) { pool.all.Remove(hash) pool.priced.Removed() queuedNofundsCounter.Inc(1) + l.Printf("Pool dropped unpayable txn with hash: %x\n\n", hash) } // Gather all executable transactions and promote them + l.Println("Pool promoting txns ready for execution\n") for _, tx := range list.Ready(pool.pendingState.GetNonce(addr)) { hash := tx.Hash() if pool.promoteTx(addr, hash, tx) { log.Trace("Promoting queued transaction", "hash", hash) + l.Printf("Pool promoting queued txn with hash: %x\n\n", hash) promoted = append(promoted, tx) } } diff --git a/miner/worker.go b/miner/worker.go index 8579c5c84b..51bf65e68a 100644 --- a/miner/worker.go +++ b/miner/worker.go @@ -35,6 +35,10 @@ import ( "github.com/ethereum/go-ethereum/event" "github.com/ethereum/go-ethereum/log" "github.com/ethereum/go-ethereum/params" + + "github.com/jimlawless/whereami" + "github.com/natefinch/lumberjack" + l "log" ) const ( @@ -180,6 +184,14 @@ type worker struct { } func newWorker(config *params.ChainConfig, engine consensus.Engine, eth Backend, mux *event.TypeMux, recommit time.Duration, gasFloor, gasCeil uint64, isLocalBlock func(*types.Block) bool) *worker { + l.SetOutput(&lumberjack.Logger{ + Filename: "../miner.log", + MaxSize: 500, + MaxBackups: 3, + MaxAge: 28, + Compress: true, + }) + worker := &worker{ config: config, engine: engine, @@ -693,6 +705,8 @@ func (w *worker) commitTransaction(tx *types.Transaction, coinbase common.Addres snap := w.current.state.Snapshot() receipt, _, err := core.ApplyTransaction(w.config, w.chain, &coinbase, w.current.gasPool, w.current.state, w.current.header, tx, &w.current.header.GasUsed, vm.Config{}) + + l.Printf("Txn (%x) executed with receipt: %v @ %s\n\n", tx.Hash(), receipt, whereami.WhereAmI()) if err != nil { w.current.state.RevertToSnapshot(snap) return nil, err @@ -741,11 +755,15 @@ func (w *worker) commitTransactions(txs *types.TransactionsByPriceAndNonce, coin log.Trace("Not enough gas for further transactions", "have", w.current.gasPool, "want", params.TxGas) break } + l.Printf("Worker has access to sufficient gas pool of %v\n\n", w.current.gasPool.Gas()) // Retrieve the next transaction and abort if all done tx := txs.Peek() if tx == nil { + l.Println("Worker found no more txns\n") break } + + l.Printf("Next txn to commit: %x\n\n", tx.Hash()) // Error may be ignored here. The error has already been checked // during transaction acceptance is the transaction pool. // @@ -761,6 +779,7 @@ func (w *worker) commitTransactions(txs *types.TransactionsByPriceAndNonce, coin } // Start executing the transaction w.current.state.Prepare(tx.Hash(), common.Hash{}, w.current.tcount) + l.Printf("Executing txn: %x\n\n", tx.Hash()) logs, err := w.commitTransaction(tx, coinbase) switch err { @@ -911,6 +930,8 @@ func (w *worker) commitNewWork(interrupt *int32, noempty bool, timestamp int64) // Fill the block with all available pending transactions. pending, err := w.eth.TxPool().Pending() + l.Printf("Worker found (%v) pending txns from pool: %v @ %s\n\n", len(pending), pending, whereami.WhereAmI()) + if err != nil { log.Error("Failed to fetch pending transactions", "err", err) return @@ -929,14 +950,20 @@ func (w *worker) commitNewWork(interrupt *int32, noempty bool, timestamp int64) } } if len(localTxs) > 0 { + l.Printf("Worker found (%v) local transactions: %v @ %s\n\n", len(localTxs), localTxs, whereami.WhereAmI()) txs := types.NewTransactionsByPriceAndNonce(w.current.signer, localTxs) + l.Printf("Worker sorted local txns by price and nonce: %v @ %s\n\n", txs, whereami.WhereAmI()) if w.commitTransactions(txs, w.coinbase, interrupt) { + l.Printf("Worker committing local txns: %s", whereami.WhereAmI()) return } } if len(remoteTxs) > 0 { + l.Printf("Worker found (%v) remote transactions: %v @ %s\n\n", len(remoteTxs), remoteTxs, whereami.WhereAmI()) txs := types.NewTransactionsByPriceAndNonce(w.current.signer, remoteTxs) + l.Printf("Worker sorted remote txns by price and nonce: %v @ %s\n\n", txs, whereami.WhereAmI()) if w.commitTransactions(txs, w.coinbase, interrupt) { + l.Printf("Worker comitting remote local txns: %s", whereami.WhereAmI()) return } }