Skip to content

Commit 9d67639

Browse files
author
colinlyguo
committed
feat(txpool): increase level of txn tracing logs
1 parent d482b2f commit 9d67639

File tree

3 files changed

+50
-25
lines changed

3 files changed

+50
-25
lines changed

core/tx_pool.go

Lines changed: 47 additions & 23 deletions
Original file line numberDiff line numberDiff line change
@@ -106,7 +106,7 @@ var (
106106
evictionInterval = time.Minute // Time interval to check for evictable transactions
107107
statsReportInterval = 8 * time.Second // Time interval to report transaction pool stats
108108

109-
dumpReorgTxHashThreshold = 100 // Number of transaction hashse to dump when runReorg
109+
dumpReorgTxHashThreshold = 100 // Number of transaction hashes to dump when runReorg
110110
)
111111

112112
var (
@@ -467,7 +467,7 @@ func (pool *TxPool) loop() {
467467
if time.Since(pool.beats[addr]) > pool.config.Lifetime {
468468
list := pool.queue[addr].Flatten()
469469
for _, tx := range list {
470-
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())
470+
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())
471471
pool.removeTx(tx.Hash(), true)
472472
}
473473
queuedEvictionMeter.Mark(int64(len(list)))
@@ -483,7 +483,7 @@ func (pool *TxPool) loop() {
483483
if time.Since(pool.beats[addr]) > pool.config.Lifetime {
484484
list := pool.pending[addr].Flatten()
485485
for _, tx := range list {
486-
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())
486+
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())
487487
pool.removeTx(tx.Hash(), true)
488488
}
489489
pendingEvictionMeter.Mark(int64(len(list)))
@@ -546,6 +546,7 @@ func (pool *TxPool) SetGasPrice(price *big.Int) {
546546
// pool.priced is sorted by GasFeeCap, so we have to iterate through pool.all instead
547547
drop := pool.all.RemotesBelowTip(price)
548548
for _, tx := range drop {
549+
log.Debug("Removing transaction below price limit", "hash", tx.Hash().Hex(), "price", tx.GasFeeCap().String(), "limit", price.String())
549550
pool.removeTx(tx.Hash(), false)
550551
}
551552
pool.priced.Removed(len(drop))
@@ -852,13 +853,13 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
852853
// If the transaction is already known, discard it
853854
hash := tx.Hash()
854855
if pool.all.Get(hash) != nil {
855-
log.Trace("Discarding already known transaction", "hash", hash.Hex())
856+
log.Debug("Discarding already known transaction when adding the transaction", "hash", hash.Hex())
856857
knownTxMeter.Mark(1)
857858
return false, ErrAlreadyKnown
858859
}
859860

860861
if pool.IsMiner() && rawdb.IsSkippedTransaction(pool.chain.Database(), hash) {
861-
log.Trace("Discarding already known skipped transaction", "hash", hash.Hex())
862+
log.Debug("Discarding already known skipped transaction when adding the transaction", "hash", hash.Hex())
862863
knownSkippedTxMeter.Mark(1)
863864
return false, ErrAlreadyKnown
864865
}
@@ -869,15 +870,15 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
869870

870871
// If the transaction fails basic validation, discard it
871872
if err := pool.validateTx(tx, isLocal); err != nil {
872-
log.Trace("Discarding invalid transaction", "hash", hash.Hex(), "err", err)
873+
log.Debug("Discarding invalid transaction when adding the transaction", "hash", hash.Hex(), "err", err)
873874
invalidTxMeter.Mark(1)
874875
return false, err
875876
}
876877
// If the transaction pool is full, discard underpriced transactions
877878
if uint64(pool.all.Slots()+numSlots(tx)) > pool.config.GlobalSlots+pool.config.GlobalQueue {
878879
// If the new transaction is underpriced, don't accept it
879880
if !isLocal && pool.priced.Underpriced(tx) {
880-
log.Trace("Discarding underpriced transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
881+
log.Debug("Discarding underpriced transaction when transaction pool is full", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
881882
underpricedTxMeter.Mark(1)
882883
return false, ErrUnderpriced
883884
}
@@ -897,15 +898,15 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
897898

898899
// Special case, we still can't make the room for the new remote one.
899900
if !isLocal && !success {
900-
log.Trace("Discarding overflown transaction", "hash", hash.Hex())
901+
log.Debug("Discarding overflown transaction when transaction pool is full", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
901902
overflowedTxMeter.Mark(1)
902903
return false, ErrTxPoolOverflow
903904
}
904905
// Bump the counter of rejections-since-reorg
905906
pool.changesSinceReorg += len(drop)
906907
// Kick out the underpriced remote transactions.
907908
for _, tx := range drop {
908-
log.Trace("Discarding freshly underpriced transaction", "hash", tx.Hash(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
909+
log.Debug("Discarding underpriced transaction when transaction pool is full", "hash", tx.Hash().Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
909910
underpricedTxMeter.Mark(1)
910911
pool.removeTx(tx.Hash(), false)
911912
}
@@ -916,11 +917,13 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
916917
// Nonce already pending, check if required price bump is met
917918
inserted, old := list.Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
918919
if !inserted {
920+
log.Debug("Discarding underpriced pending transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
919921
pendingDiscardMeter.Mark(1)
920922
return false, ErrReplaceUnderpriced
921923
}
922924
// New transaction is better, replace old one
923925
if old != nil {
926+
log.Debug("Replacing pending transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
924927
pool.all.Remove(old.Hash())
925928
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
926929
pool.priced.Removed(1)
@@ -930,7 +933,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
930933
pool.priced.Put(tx, isLocal)
931934
pool.journalTx(from, tx)
932935
pool.queueTxEvent(tx)
933-
log.Trace("Pooled new executable transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To())
936+
log.Debug("Pooled new executable transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
934937

935938
// Successful promotion, bump the heartbeat
936939
pool.beats[from] = time.Now()
@@ -952,7 +955,7 @@ func (pool *TxPool) add(tx *types.Transaction, local bool) (replaced bool, err e
952955
}
953956
pool.journalTx(from, tx)
954957

955-
log.Trace("Pooled new future transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To())
958+
log.Debug("Pooled new future transaction", "hash", hash.Hex(), "from", from.Hex(), "to", tx.To(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
956959
return replaced, nil
957960
}
958961

@@ -969,11 +972,13 @@ func (pool *TxPool) enqueueTx(hash common.Hash, tx *types.Transaction, local boo
969972
inserted, old := pool.queue[from].Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
970973
if !inserted {
971974
// An older transaction was better, discard this
975+
log.Debug("Discarding underpriced queued transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
972976
queuedDiscardMeter.Mark(1)
973977
return false, ErrReplaceUnderpriced
974978
}
975979
// Discard any previous transaction and mark this
976980
if old != nil {
981+
log.Debug("Replacing queued transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
977982
pool.all.Remove(old.Hash())
978983
pool.priced.Removed(1)
979984
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
@@ -1023,6 +1028,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
10231028

10241029
// Account pending list is full
10251030
if uint64(list.Len()) >= pool.config.AccountPendingLimit {
1031+
log.Debug("Discarding pending transaction when account pending limit is reached", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
10261032
pool.all.Remove(hash)
10271033
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
10281034
pool.priced.Removed(1)
@@ -1033,6 +1039,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
10331039
inserted, old := list.Add(tx, pool.currentState, pool.config.PriceBump, pool.chainconfig, pool.currentHead)
10341040
if !inserted {
10351041
// An older transaction was better, discard this
1042+
log.Debug("Discarding underpriced pending transaction", "hash", hash.Hex(), "gasTipCap", tx.GasTipCap(), "gasFeeCap", tx.GasFeeCap())
10361043
pool.all.Remove(hash)
10371044
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
10381045
pool.priced.Removed(1)
@@ -1041,6 +1048,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
10411048
}
10421049
// Otherwise discard any previous transaction and mark this
10431050
if old != nil {
1051+
log.Debug("Replacing pending transaction", "hash", tx.Hash().Hex(), "old", old.Hash().Hex())
10441052
pool.all.Remove(old.Hash())
10451053
pool.calculateTxsLifecycle(types.Transactions{old}, time.Now())
10461054
pool.priced.Removed(1)
@@ -1049,7 +1057,7 @@ func (pool *TxPool) promoteTx(addr common.Address, hash common.Hash, tx *types.T
10491057
// Nothing was replaced, bump the pending counter
10501058
pendingGauge.Inc(1)
10511059
}
1052-
log.Trace("Transaction promoted from future queue to pending", "hash", hash.Hex(), "from", addr.Hex(), "to", tx.To())
1060+
log.Debug("Transaction promoted from future queue to pending", "hash", hash.Hex(), "from", addr.Hex(), "to", tx.To())
10531061
// Set the potentially new pending nonce and notify any subsystems of the new tx
10541062
pool.pendingNonces.set(addr, tx.Nonce()+1)
10551063

@@ -1222,7 +1230,7 @@ func (pool *TxPool) removeTx(hash common.Hash, outofbound bool) {
12221230
return
12231231
}
12241232

1225-
log.Trace("Removing transaction from pool", "hash", hash.Hex())
1233+
log.Debug("Removing transaction from pool", "hash", hash.Hex())
12261234

12271235
addr, _ := types.Sender(pool.signer, tx) // already validated during insertion
12281236

@@ -1452,10 +1460,10 @@ func (pool *TxPool) runReorg(done chan struct{}, reset *txpoolResetRequest, dirt
14521460
}
14531461
pool.txFeed.Send(NewTxsEvent{txs})
14541462

1455-
log.Debug("runReorg", "len(txs)", len(txs))
1463+
log.Trace("runReorg", "len(txs)", len(txs))
14561464
if len(txs) > dumpReorgTxHashThreshold {
14571465
for _, txs := range txs {
1458-
log.Debug("dumping runReorg tx hashes", "txHash", txs.Hash().Hex())
1466+
log.Trace("dumping runReorg tx hashes", "txHash", txs.Hash().Hex())
14591467
}
14601468
}
14611469
}
@@ -1524,6 +1532,18 @@ func (pool *TxPool) reset(oldHead, newHead *types.Header) {
15241532
}
15251533
}
15261534
reinject = types.TxDifference(discarded, included)
1535+
1536+
if len(discarded) > 0 {
1537+
for _, tx := range discarded {
1538+
log.Debug("TXPOOL_REORG: TX removed from old chain", "hash", tx.Hash().Hex())
1539+
}
1540+
}
1541+
1542+
if len(included) > 0 {
1543+
for _, tx := range included {
1544+
log.Debug("TXPOOL_REORG: TX added in the chain", "hash", tx.Hash().Hex())
1545+
}
1546+
}
15271547
}
15281548
}
15291549
}
@@ -1577,6 +1597,7 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
15771597
hash := tx.Hash()
15781598
pool.all.Remove(hash)
15791599
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
1600+
log.Debug("Removed queued transaction with low nonce", "hash", hash.Hex())
15801601
}
15811602
log.Trace("Removed old queued transactions", "count", len(forwards))
15821603

@@ -1587,6 +1608,7 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
15871608
hash := tx.Hash()
15881609
pool.all.Remove(hash)
15891610
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
1611+
log.Debug("Removed unpayable queued transaction", "hash", hash.Hex())
15901612
}
15911613
log.Trace("Removed unpayable queued transactions", "count", len(drops))
15921614
queuedNofundsMeter.Mark(int64(len(drops)))
@@ -1610,7 +1632,7 @@ func (pool *TxPool) promoteExecutables(accounts []common.Address) []*types.Trans
16101632
hash := tx.Hash()
16111633
pool.all.Remove(hash)
16121634
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
1613-
log.Trace("Removed cap-exceeding queued transaction", "hash", hash.Hex())
1635+
log.Debug("Removed cap-exceeding queued transaction", "hash", hash.Hex())
16141636
}
16151637
queuedRateLimitMeter.Mark(int64(len(caps)))
16161638
}
@@ -1668,7 +1690,7 @@ func (pool *TxPool) truncatePending() {
16681690
// Update the account nonce to the dropped transaction
16691691
// note: this will set pending nonce to the min nonce from the discarded txs
16701692
pool.pendingNonces.setIfLower(addr, tx.Nonce())
1671-
log.Trace("Removed pending transaction to comply with hard limit", "hash", hash.Hex())
1693+
log.Debug("Removed pending transaction to comply with hard limit", "hash", hash.Hex())
16721694
}
16731695
pool.priced.Removed(len(caps))
16741696
pendingGauge.Dec(int64(len(caps)))
@@ -1721,7 +1743,7 @@ func (pool *TxPool) truncatePending() {
17211743

17221744
// Update the account nonce to the dropped transaction
17231745
pool.pendingNonces.setIfLower(offenders[i], tx.Nonce())
1724-
log.Trace("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
1746+
log.Debug("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
17251747
}
17261748
pool.priced.Removed(len(caps))
17271749
pendingGauge.Dec(int64(len(caps)))
@@ -1749,7 +1771,7 @@ func (pool *TxPool) truncatePending() {
17491771

17501772
// Update the account nonce to the dropped transaction
17511773
pool.pendingNonces.setIfLower(addr, tx.Nonce())
1752-
log.Trace("Removed fairness-exceeding pending transaction", "hash", hash)
1774+
log.Debug("Removed fairness-exceeding pending transaction", "hash", hash.Hex())
17531775
}
17541776
pool.priced.Removed(len(caps))
17551777
pendingGauge.Dec(int64(len(caps)))
@@ -1792,6 +1814,7 @@ func (pool *TxPool) truncateQueue() {
17921814
// Drop all transactions if they are less than the overflow
17931815
if size := uint64(list.Len()); size <= drop {
17941816
for _, tx := range list.Flatten() {
1817+
log.Debug("Removed fairness-exceeding queued transaction", "hash", tx.Hash().Hex())
17951818
pool.removeTx(tx.Hash(), true)
17961819
}
17971820
drop -= size
@@ -1801,6 +1824,7 @@ func (pool *TxPool) truncateQueue() {
18011824
// Otherwise drop only last few transactions
18021825
txs := list.Flatten()
18031826
for i := len(txs) - 1; i >= 0 && drop > 0; i-- {
1827+
log.Debug("Removed fairness-exceeding queued transaction", "hash", txs[i].Hash().Hex())
18041828
pool.removeTx(txs[i].Hash(), true)
18051829
drop--
18061830
queuedRateLimitMeter.Mark(1)
@@ -1826,22 +1850,22 @@ func (pool *TxPool) demoteUnexecutables() {
18261850
hash := tx.Hash()
18271851
pool.all.Remove(hash)
18281852
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
1829-
log.Trace("Removed old pending transaction", "hash", hash.Hex())
1853+
log.Debug("Removed pending transaction with low nonce", "hash", hash.Hex())
18301854
}
18311855
// Drop all transactions that are too costly (low balance or out of gas), and queue any invalids back for later
18321856
costLimit := pool.currentState.GetBalance(addr)
18331857
drops, invalids := list.FilterF(costLimit, pool.currentMaxGas, pool.executableTxFilter(costLimit))
18341858
for _, tx := range drops {
18351859
hash := tx.Hash()
1836-
log.Trace("Removed unpayable pending transaction", "hash", hash.Hex())
18371860
pool.all.Remove(hash)
18381861
pool.calculateTxsLifecycle(types.Transactions{tx}, time.Now())
1862+
log.Debug("Removed unpayable pending transaction", "hash", hash.Hex())
18391863
}
18401864
pendingNofundsMeter.Mark(int64(len(drops)))
18411865

18421866
for _, tx := range invalids {
18431867
hash := tx.Hash()
1844-
log.Trace("Demoting pending transaction", "hash", hash.Hex())
1868+
log.Debug("Demoting pending transaction", "hash", hash.Hex())
18451869

18461870
// Internal shuffle shouldn't touch the lookup set.
18471871
pool.enqueueTx(hash, tx, false, false)
@@ -1855,7 +1879,7 @@ func (pool *TxPool) demoteUnexecutables() {
18551879
gapped := list.Cap(0)
18561880
for _, tx := range gapped {
18571881
hash := tx.Hash()
1858-
log.Error("Demoting invalidated transaction", "hash", hash)
1882+
log.Error("Demoting invalidated transaction", "hash", hash.Hex())
18591883

18601884
// Internal shuffle shouldn't touch the lookup set.
18611885
pool.enqueueTx(hash, tx, false, false)

eth/api.go

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,6 +29,8 @@ import (
2929
"strings"
3030
"time"
3131

32+
"github.com/syndtr/goleveldb/leveldb"
33+
3234
"github.com/scroll-tech/go-ethereum/common"
3335
"github.com/scroll-tech/go-ethereum/common/hexutil"
3436
"github.com/scroll-tech/go-ethereum/core"
@@ -44,7 +46,6 @@ import (
4446
"github.com/scroll-tech/go-ethereum/rollup/rcfg"
4547
"github.com/scroll-tech/go-ethereum/rpc"
4648
"github.com/scroll-tech/go-ethereum/trie"
47-
"github.com/syndtr/goleveldb/leveldb"
4849
)
4950

5051
// PublicEthereumAPI provides an API to access Ethereum full node-related

params/version.go

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@ import (
2424
const (
2525
VersionMajor = 5 // Major version component of the current release
2626
VersionMinor = 8 // Minor version component of the current release
27-
VersionPatch = 35 // Patch version component of the current release
27+
VersionPatch = 36 // Patch version component of the current release
2828
VersionMeta = "mainnet" // Version metadata to append to the version string
2929
)
3030

0 commit comments

Comments
 (0)