forks/go-ethereum
1
0
Fork 1
mirror of https://github.com/ethereum/go-ethereum.git synced 2026-07-24 13:46:43 +00:00
Code Issues Projects Releases Packages Wiki Activity Actions 1

feat(txpool): more txn tracing logs (#1167)

Browse source 
* feat(txpool): increase level of txn tracing logs

* simplify

* tweak logs

* chore: auto version bump [bot]
This commit is contained in:
colin 2025-04-09 20:43:13 +08:00 committed by GitHub
parent ad017f50ec
commit 8a150b44ff
No known key found for this signature in database
GPG key ID: B5690EEEBB952194
2 changed files with 52 additions and 25 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

75
core/tx_pool.go
View file

@ -106,7 +106,7 @@ var (
evictionInterval = time.Minute // Time interval to check for evictable transactions
statsReportInterval = 8 * time.Second // Time interval to report transaction pool stats
dumpReorgTxHashThreshold = 100 // Number of transaction hashse to dump when runReorg
dumpReorgTxHashThreshold = 100 // Number of transaction hashes to dump when runReorg
)
var (
@ -467,7 +467,7 @@ func (pool *TxPool) loop() {
if time.Since(pool.beats[addr]) > pool.config.Lifetime {
list := pool.queue[addr].Flatten()
for _, tx := range list {
log.Trace("Evicting queued transaction due to timeout", "account", addr.Hex(), "hash", tx.Hash().Hex(), "lifetime sec", time.Since(pool.beats[addr]).Seconds(), "lifetime limit sec", pool.config.Lifetime.Seconds())
log.Debug("Evicting queued transaction due to timeout", "account", addr.Hex(), "hash", tx.Hash().Hex(), "lifetime sec", time.Since(pool.beats[addr]).Seconds(), "lifetime limit sec", pool.config.Lifetime.Seconds())
pool.removeTx(tx.Hash(), true)
}
queuedEvictionMeter.Mark(int64(len(list)))
@ -483,7 +483,7 @@ func (pool *TxPool) loop() {
if time.Since(pool.beats[addr]) > pool.config.Lifetime {
list := pool.pending[addr].Flatten()
for _, tx := range list {
log.Trace("Evicting pending transaction due to timeout", "account", addr.Hex(), "hash", tx.Hash().Hex(), "lifetime sec", time.Since(pool.beats[addr]).Seconds(), "lifetime limit sec", pool.config.Lifetime.Seconds())
log.Debug("Evicting pending transaction due to timeout", "account", addr.Hex(), "hash", tx.Hash().Hex(), "lifetime sec", time.Since(pool.beats[addr]).Seconds(), "lifetime limit sec", pool.config.Lifetime.Seconds())
pool.removeTx(tx.Hash(), true)
}
pendingEvictionMeter.Mark(int64(len(list)))
@ -546,6 +546,7 @@ func (pool *TxPool) SetGasPrice(price *big.Int) {
// pool.priced is sorted by GasFeeCap, so we have to iterate through pool.all instead
drop := pool.all.RemotesBelowTip(price)
for _, tx := range drop {
log.Debug("Removing transaction below price limit", "hash", tx.Hash().Hex(), "price", tx.GasFeeCap().String(), "limit", price.String())
pool.removeTx(tx.Hash(), false)
}
pool.priced.Removed(len(drop))
@ -852,13 +853,13 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
// If the transaction is already known, discard it
hash := tx.Hash()
if pool.all.Get(hash) != nil {
log.Trace("Discarding already known transaction", "hash", hash.Hex())
log.Debug("Discarding already known transaction when adding the transaction", "hash", hash.Hex())
knownTxMeter.Mark(1)
return false, ErrAlreadyKnown
}
if pool.IsMiner() && rawdb.IsSkippedTransaction(pool.chain.Database(), hash) {
log.Trace("Discarding already known skipped transaction", "hash", hash.Hex())
log.Debug("Discarding already known skipped transaction when adding the transaction", "hash", hash.Hex())
knownSkippedTxMeter.Mark(1)
return false, ErrAlreadyKnown
}
@ -869,7 +870,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
// If the transaction fails basic validation, discard it
if err := pool.validateTx(tx, isLocal); err != nil {
log.Trace("Discarding invalid transaction", "hash", hash.Hex(), "err", err)
log.Debug("Discarding invalid transaction when adding the transaction", "hash", hash.Hex(), "err", err)
invalidTxMeter.Mark(1)
return false, err
}
@ -877,7 +878,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
if uint64(pool.all.Slots()+numSlots(tx)) > pool.config.GlobalSlots+pool.config.GlobalQueue {
// If the new transaction is underpriced, don't accept it
if !isLocal && pool.priced.Underpriced(tx) {
log.Trace("Discarding underpriced transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
log.Debug("Discarding underpriced transaction when transaction pool is full", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
underpricedTxMeter.Mark(1)
return false, ErrUnderpriced
}
@ -897,7 +898,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
// Special case, we still can't make the room for the new remote one.
if !isLocal && !success {
log.Trace("Discarding overflown transaction", "hash", hash.Hex())
log.Debug("Discarding overflown transaction when transaction pool is full", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
overflowedTxMeter.Mark(1)
return false, ErrTxPoolOverflow
}
@ -905,7 +906,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
pool.changesSinceReorg += len(drop)
// Kick out the underpriced remote transactions.
for _, tx := range drop {
log.Trace("Discarding freshly underpriced transaction", "hash", tx.Hash(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
log.Debug("Discarding underpriced transaction when transaction pool is full", "hash", tx.Hash().Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
underpricedTxMeter.Mark(1)
pool.removeTx(tx.Hash(), false)
}
@ -916,11 +917,13 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
// Nonce already pending, check if required price bump is met
inserted, old := list.Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
if !inserted {
log.Debug("Discarding underpriced pending transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
pendingDiscardMeter.Mark(1)
return false, ErrReplaceUnderpriced
}
// New transaction is better, replace old one
if old != nil {
log.Debug("Replacing pending transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
pool.all.Remove(old.Hash())
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
pool.priced.Removed(1)
@ -930,7 +933,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
pool.priced.Put(tx, isLocal)
pool.journalTx(from, tx)
pool.queueTxEvent(tx)
log.Trace("Pooled new executable transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To())
log.Debug("Pooled new executable transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
// Successful promotion, bump the heartbeat
pool.beats[from] = time.Now()
@ -952,7 +955,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
}
pool.journalTx(from, tx)
log.Trace("Pooled new future transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To())
log.Debug("Pooled new future transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
return replaced, nil
}
@ -969,11 +972,13 @@ func (pool *TxPool) enqueueTx(hash common.Hash, tx *types.Transaction, local boo
inserted, old := pool.queue[from].Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
if !inserted {
// An older transaction was better, discard this
log.Debug("Discarding underpriced queued transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
queuedDiscardMeter.Mark(1)
return false, ErrReplaceUnderpriced
}
// Discard any previous transaction and mark this
if old != nil {
log.Debug("Replacing queued transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
pool.all.Remove(old.Hash())
pool.priced.Removed(1)
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
@ -1023,6 +1028,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
// Account pending list is full
if uint64(list.Len()) >= pool.config.AccountPendingLimit {
log.Debug("Discarding pending transaction when account pending limit is reached", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
pool.priced.Removed(1)
@ -1033,6 +1039,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
inserted, old := list.Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
if !inserted {
// An older transaction was better, discard this
log.Debug("Discarding underpriced pending transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
pool.priced.Removed(1)
@ -1041,6 +1048,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
}
// Otherwise discard any previous transaction and mark this
if old != nil {
log.Debug("Replacing pending transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
pool.all.Remove(old.Hash())
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
pool.priced.Removed(1)
@ -1049,7 +1057,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
// Nothing was replaced, bump the pending counter
pendingGauge.Inc(1)
}
log.Trace("Transaction promoted from future queue to pending", "hash", hash.Hex(), "from", addr.Hex(), "to", tx.To())
log.Debug("Transaction promoted from future queue to pending", "hash", hash.Hex(), "from", addr.Hex(), "to", tx.To())
// Set the potentially new pending nonce and notify any subsystems of the new tx
pool.pendingNonces.set(addr, tx.Nonce()+1)
@ -1222,7 +1230,7 @@ func (pool *TxPool) removeTx(hash common.Hash, outofbound bool) {
return
}
log.Trace("Removing transaction from pool", "hash", hash.Hex())
log.Debug("Removing transaction from pool", "hash", hash.Hex())
addr, _ := types.Sender(pool.signer, tx) // already validated during insertion
@ -1452,10 +1460,10 @@ func (pool *TxPool) runReorg(done chan struct{}, reset *txpoolResetRequest, dirt
}
pool.txFeed.Send(NewTxsEvent{txs})
log.Debug("runReorg", "len(txs)", len(txs))
log.Trace("runReorg", "len(txs)", len(txs))
if len(txs) > dumpReorgTxHashThreshold {
for _, txs := range txs {
log.Debug("dumping runReorg tx hashes", "txHash", txs.Hash().Hex())
log.Trace("dumping runReorg tx hashes", "txHash", txs.Hash().Hex())
}
}
}
@ -1524,6 +1532,15 @@ func (pool *TxPool) reset(oldHead, newHead *types.Header) {
}
}
reinject = types.TxDifference(discarded, included)
for _, tx := range discarded {
log.Debug("TXPOOL_REORG: TX removed from old chain", "hash", tx.Hash().Hex())
}
for _, tx := range included {
log.Debug("TXPOOL_REORG: TX added in the chain", "hash", tx.Hash().Hex())
}
}
}
}
@ -1541,7 +1558,9 @@ func (pool *TxPool) reset(oldHead, newHead *types.Header) {
pool.currentMaxGas = newHead.GasLimit
// Inject any transactions discarded due to reorgs
log.Debug("Reinjecting stale transactions", "count", len(reinject))
if len(reinject) > 0 {
log.Debug("Reinjecting stale transactions", "count", len(reinject))
}
senderCacher.recover(pool.signer, reinject)
pool.addTxsLocked(reinject, false)
@ -1577,6 +1596,9 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
hash := tx.Hash()
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
// This is a special case where the transaction was already included in a block,
// thus no need to mark it as removed, setting a trace log level to avoid confusion.
log.Trace("Removed queued transaction with low nonce", "hash", hash.Hex())
}
log.Trace("Removed old queued transactions", "count", len(forwards))
@ -1587,6 +1609,7 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
hash := tx.Hash()
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
log.Debug("Removed unpayable queued transaction", "hash", hash.Hex())
}
log.Trace("Removed unpayable queued transactions", "count", len(drops))
queuedNofundsMeter.Mark(int64(len(drops)))
@ -1610,7 +1633,7 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
hash := tx.Hash()
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
log.Trace("Removed cap-exceeding queued transaction", "hash", hash.Hex())
log.Debug("Removed cap-exceeding queued transaction", "hash", hash.Hex())
}
queuedRateLimitMeter.Mark(int64(len(caps)))
}
@ -1668,7 +1691,7 @@ func (pool *TxPool) truncatePending() {
// Update the account nonce to the dropped transaction
// note: this will set pending nonce to the min nonce from the discarded txs
pool.pendingNonces.setIfLower(addr, tx.Nonce())
log.Trace("Removed pending transaction to comply with hard limit", "hash", hash.Hex())
log.Debug("Removed pending transaction to comply with hard limit", "hash", hash.Hex())
}
pool.priced.Removed(len(caps))
pendingGauge.Dec(int64(len(caps)))
@ -1721,7 +1744,7 @@ func (pool *TxPool) truncatePending() {
// Update the account nonce to the dropped transaction
pool.pendingNonces.setIfLower(offenders[i], tx.Nonce())
log.Trace("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
log.Debug("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
}
pool.priced.Removed(len(caps))
pendingGauge.Dec(int64(len(caps)))
@ -1749,7 +1772,7 @@ func (pool *TxPool) truncatePending() {
// Update the account nonce to the dropped transaction
pool.pendingNonces.setIfLower(addr, tx.Nonce())
log.Trace("Removed fairness-exceeding pending transaction", "hash", hash)
log.Debug("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
}
pool.priced.Removed(len(caps))
pendingGauge.Dec(int64(len(caps)))
@ -1792,6 +1815,7 @@ func (pool *TxPool) truncateQueue() {
// Drop all transactions if they are less than the overflow
if size := uint64(list.Len()); size <= drop {
for _, tx := range list.Flatten() {
log.Debug("Removed fairness-exceeding queued transaction", "hash", tx.Hash().Hex())
pool.removeTx(tx.Hash(), true)
}
drop -= size
@ -1801,6 +1825,7 @@ func (pool *TxPool) truncateQueue() {
// Otherwise drop only last few transactions
txs := list.Flatten()
for i := len(txs) - 1; i >= 0 && drop > 0; i-- {
log.Debug("Removed fairness-exceeding queued transaction", "hash", txs[i].Hash().Hex())
pool.removeTx(txs[i].Hash(), true)
drop--
queuedRateLimitMeter.Mark(1)
@ -1826,22 +1851,24 @@ func (pool *TxPool) demoteUnexecutables() {
hash := tx.Hash()
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
log.Trace("Removed old pending transaction", "hash", hash.Hex())
// This is a special case where the transaction was already included in a block,
// thus no need to mark it as removed, setting a trace log level to avoid confusion.
log.Trace("Removed pending transaction with low nonce", "hash", hash.Hex())
}
// Drop all transactions that are too costly (low balance or out of gas), and queue any invalids back for later
costLimit := pool.currentState.GetBalance(addr)
drops, invalids := list.FilterF(costLimit, pool.currentMaxGas, pool.executableTxFilter(costLimit))
for _, tx := range drops {
hash := tx.Hash()
log.Trace("Removed unpayable pending transaction", "hash", hash.Hex())
pool.all.Remove(hash)
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
log.Debug("Removed unpayable pending transaction", "hash", hash.Hex())
}
pendingNofundsMeter.Mark(int64(len(drops)))
for _, tx := range invalids {
hash := tx.Hash()
log.Trace("Demoting pending transaction", "hash", hash.Hex())
log.Debug("Demoting pending transaction", "hash", hash.Hex())
// Internal shuffle shouldn't touch the lookup set.
pool.enqueueTx(hash, tx, false, false)
@ -1855,7 +1882,7 @@ func (pool *TxPool) demoteUnexecutables() {
gapped := list.Cap(0)
for _, tx := range gapped {
hash := tx.Hash()
log.Error("Demoting invalidated transaction", "hash", hash)
log.Error("Demoting invalidated transaction", "hash", hash.Hex())
// Internal shuffle shouldn't touch the lookup set.
pool.enqueueTx(hash, tx, false, false)

2
params/version.go
View file

@ -24,7 +24,7 @@ import (
const (
VersionMajor = 5 // Major version component of the current release
VersionMinor = 8 // Minor version component of the current release
VersionPatch = 36 // Patch version component of the current release
VersionPatch = 37 // Patch version component of the current release
VersionMeta = "mainnet" // Version metadata to append to the version string
)