mirror of
https://github.com/ethereum/go-ethereum.git
synced 2026-07-23 13:16:42 +00:00
core, cmd, eth: log detailed statistics for slow block
This commit is contained in:
parent
ccacbd1e37
commit
445496de0c
11 changed files with 242 additions and 66 deletions
|
|
@ -96,6 +96,7 @@ if one is set. Otherwise it prints the genesis from the datadir.`,
|
||||||
utils.CacheNoPrefetchFlag,
|
utils.CacheNoPrefetchFlag,
|
||||||
utils.CachePreimagesFlag,
|
utils.CachePreimagesFlag,
|
||||||
utils.NoCompactionFlag,
|
utils.NoCompactionFlag,
|
||||||
|
utils.LogSlowBlockFlag,
|
||||||
utils.MetricsEnabledFlag,
|
utils.MetricsEnabledFlag,
|
||||||
utils.MetricsEnabledExpensiveFlag,
|
utils.MetricsEnabledExpensiveFlag,
|
||||||
utils.MetricsHTTPFlag,
|
utils.MetricsHTTPFlag,
|
||||||
|
|
|
||||||
|
|
@ -156,6 +156,7 @@ var (
|
||||||
utils.BeaconGenesisTimeFlag,
|
utils.BeaconGenesisTimeFlag,
|
||||||
utils.BeaconCheckpointFlag,
|
utils.BeaconCheckpointFlag,
|
||||||
utils.BeaconCheckpointFileFlag,
|
utils.BeaconCheckpointFileFlag,
|
||||||
|
utils.LogSlowBlockFlag,
|
||||||
}, utils.NetworkFlags, utils.DatabaseFlags)
|
}, utils.NetworkFlags, utils.DatabaseFlags)
|
||||||
|
|
||||||
rpcFlags = []cli.Flag{
|
rpcFlags = []cli.Flag{
|
||||||
|
|
|
||||||
|
|
@ -667,6 +667,11 @@ var (
|
||||||
Usage: "Disables db compaction after import",
|
Usage: "Disables db compaction after import",
|
||||||
Category: flags.LoggingCategory,
|
Category: flags.LoggingCategory,
|
||||||
}
|
}
|
||||||
|
LogSlowBlockFlag = &cli.Uint64Flag{
|
||||||
|
Name: "debug.logslowblock",
|
||||||
|
Usage: "The block execution speed threshold (Mgas/s) below which detailed statistics are logged",
|
||||||
|
Category: flags.LoggingCategory,
|
||||||
|
}
|
||||||
|
|
||||||
// MISC settings
|
// MISC settings
|
||||||
SyncTargetFlag = &cli.StringFlag{
|
SyncTargetFlag = &cli.StringFlag{
|
||||||
|
|
@ -1710,6 +1715,9 @@ func SetEthConfig(ctx *cli.Context, stack *node.Node, cfg *ethconfig.Config) {
|
||||||
if ctx.IsSet(LogNoHistoryFlag.Name) {
|
if ctx.IsSet(LogNoHistoryFlag.Name) {
|
||||||
cfg.LogNoHistory = true
|
cfg.LogNoHistory = true
|
||||||
}
|
}
|
||||||
|
if ctx.IsSet(LogSlowBlockFlag.Name) {
|
||||||
|
cfg.SlowBlockThreshold = ctx.Uint64(LogSlowBlockFlag.Name)
|
||||||
|
}
|
||||||
if ctx.IsSet(LogExportCheckpointsFlag.Name) {
|
if ctx.IsSet(LogExportCheckpointsFlag.Name) {
|
||||||
cfg.LogExportCheckpoints = ctx.String(LogExportCheckpointsFlag.Name)
|
cfg.LogExportCheckpoints = ctx.String(LogExportCheckpointsFlag.Name)
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -111,6 +111,11 @@ var (
|
||||||
errChainStopped = errors.New("blockchain is stopped")
|
errChainStopped = errors.New("blockchain is stopped")
|
||||||
errInvalidOldChain = errors.New("invalid old chain")
|
errInvalidOldChain = errors.New("invalid old chain")
|
||||||
errInvalidNewChain = errors.New("invalid new chain")
|
errInvalidNewChain = errors.New("invalid new chain")
|
||||||
|
|
||||||
|
// slowBlockProcessThreshold defines the threshold (10 Mgas per second) for
|
||||||
|
// considering a block execution as slow. Detailed performance metrics will be
|
||||||
|
// printed if debug mode is enabled.
|
||||||
|
slowBlockProcessThreshold = float64(10)
|
||||||
)
|
)
|
||||||
|
|
||||||
var (
|
var (
|
||||||
|
|
@ -198,6 +203,10 @@ type BlockChainConfig struct {
|
||||||
|
|
||||||
// StateSizeTracking indicates whether the state size tracking is enabled.
|
// StateSizeTracking indicates whether the state size tracking is enabled.
|
||||||
StateSizeTracking bool
|
StateSizeTracking bool
|
||||||
|
|
||||||
|
// SlowBlockThreshold is the block execution speed threshold (Mgas/s)
|
||||||
|
// below which detailed statistics are logged.
|
||||||
|
SlowBlockThreshold uint64
|
||||||
}
|
}
|
||||||
|
|
||||||
// DefaultConfig returns the default config.
|
// DefaultConfig returns the default config.
|
||||||
|
|
@ -338,6 +347,7 @@ type BlockChain struct {
|
||||||
stateSizer *state.SizeTracker // State size tracking
|
stateSizer *state.SizeTracker // State size tracking
|
||||||
|
|
||||||
lastForkReadyAlert time.Time // Last time there was a fork readiness print out
|
lastForkReadyAlert time.Time // Last time there was a fork readiness print out
|
||||||
|
slowBlockThreshold uint64 // Block execution speed threshold (Mgas/s) below which detailed statistics are logged
|
||||||
}
|
}
|
||||||
|
|
||||||
// NewBlockChain returns a fully initialised block chain using information
|
// NewBlockChain returns a fully initialised block chain using information
|
||||||
|
|
@ -372,19 +382,20 @@ func NewBlockChain(db ethdb.Database, genesis *Genesis, engine consensus.Engine,
|
||||||
log.Info("")
|
log.Info("")
|
||||||
|
|
||||||
bc := &BlockChain{
|
bc := &BlockChain{
|
||||||
chainConfig: chainConfig,
|
chainConfig: chainConfig,
|
||||||
cfg: cfg,
|
cfg: cfg,
|
||||||
db: db,
|
db: db,
|
||||||
triedb: triedb,
|
triedb: triedb,
|
||||||
triegc: prque.New[int64, common.Hash](nil),
|
triegc: prque.New[int64, common.Hash](nil),
|
||||||
chainmu: syncx.NewClosableMutex(),
|
chainmu: syncx.NewClosableMutex(),
|
||||||
bodyCache: lru.NewCache[common.Hash, *types.Body](bodyCacheLimit),
|
bodyCache: lru.NewCache[common.Hash, *types.Body](bodyCacheLimit),
|
||||||
bodyRLPCache: lru.NewCache[common.Hash, rlp.RawValue](bodyCacheLimit),
|
bodyRLPCache: lru.NewCache[common.Hash, rlp.RawValue](bodyCacheLimit),
|
||||||
receiptsCache: lru.NewCache[common.Hash, []*types.Receipt](receiptsCacheLimit),
|
receiptsCache: lru.NewCache[common.Hash, []*types.Receipt](receiptsCacheLimit),
|
||||||
blockCache: lru.NewCache[common.Hash, *types.Block](blockCacheLimit),
|
blockCache: lru.NewCache[common.Hash, *types.Block](blockCacheLimit),
|
||||||
txLookupCache: lru.NewCache[common.Hash, txLookup](txLookupCacheLimit),
|
txLookupCache: lru.NewCache[common.Hash, txLookup](txLookupCacheLimit),
|
||||||
engine: engine,
|
engine: engine,
|
||||||
logger: cfg.VmConfig.Tracer,
|
logger: cfg.VmConfig.Tracer,
|
||||||
|
slowBlockThreshold: cfg.SlowBlockThreshold,
|
||||||
}
|
}
|
||||||
bc.hc, err = NewHeaderChain(db, chainConfig, engine, bc.insertStopped)
|
bc.hc, err = NewHeaderChain(db, chainConfig, engine, bc.insertStopped)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
|
|
@ -1847,7 +1858,7 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool, makeWitness
|
||||||
// still need re-execution to generate snapshots that are missing
|
// still need re-execution to generate snapshots that are missing
|
||||||
case err != nil && !errors.Is(err, ErrKnownBlock):
|
case err != nil && !errors.Is(err, ErrKnownBlock):
|
||||||
stats.ignored += len(it.chain)
|
stats.ignored += len(it.chain)
|
||||||
bc.reportBlock(block, nil, err)
|
bc.reportBadBlock(block, nil, err)
|
||||||
return nil, it.index, err
|
return nil, it.index, err
|
||||||
}
|
}
|
||||||
// Track the singleton witness from this chain insertion (if any)
|
// Track the singleton witness from this chain insertion (if any)
|
||||||
|
|
@ -1915,6 +1926,9 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool, makeWitness
|
||||||
if err != nil {
|
if err != nil {
|
||||||
return nil, it.index, err
|
return nil, it.index, err
|
||||||
}
|
}
|
||||||
|
res.stats.reportMetrics()
|
||||||
|
res.stats.logSlow(block, bc.slowBlockThreshold)
|
||||||
|
|
||||||
// Report the import stats before returning the various results
|
// Report the import stats before returning the various results
|
||||||
stats.processed++
|
stats.processed++
|
||||||
stats.usedGas += res.usedGas
|
stats.usedGas += res.usedGas
|
||||||
|
|
@ -1975,15 +1989,20 @@ type blockProcessingResult struct {
|
||||||
procTime time.Duration
|
procTime time.Duration
|
||||||
status WriteStatus
|
status WriteStatus
|
||||||
witness *stateless.Witness
|
witness *stateless.Witness
|
||||||
|
stats *ExecuteStats
|
||||||
}
|
}
|
||||||
|
|
||||||
func (bpr *blockProcessingResult) Witness() *stateless.Witness {
|
func (bpr *blockProcessingResult) Witness() *stateless.Witness {
|
||||||
return bpr.witness
|
return bpr.witness
|
||||||
}
|
}
|
||||||
|
|
||||||
|
func (bpr *blockProcessingResult) Stats() *ExecuteStats {
|
||||||
|
return bpr.stats
|
||||||
|
}
|
||||||
|
|
||||||
// ProcessBlock executes and validates the given block. If there was no error
|
// ProcessBlock executes and validates the given block. If there was no error
|
||||||
// it writes the block and associated state to database.
|
// it writes the block and associated state to database.
|
||||||
func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, setHead bool, makeWitness bool) (_ *blockProcessingResult, blockEndErr error) {
|
func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, setHead bool, makeWitness bool) (result *blockProcessingResult, blockEndErr error) {
|
||||||
var (
|
var (
|
||||||
err error
|
err error
|
||||||
startTime = time.Now()
|
startTime = time.Now()
|
||||||
|
|
@ -2017,16 +2036,22 @@ func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, s
|
||||||
}
|
}
|
||||||
// Upload the statistics of reader at the end
|
// Upload the statistics of reader at the end
|
||||||
defer func() {
|
defer func() {
|
||||||
stats := prefetch.GetStats()
|
pStat := prefetch.GetStats()
|
||||||
accountCacheHitPrefetchMeter.Mark(stats.AccountHit)
|
accountCacheHitPrefetchMeter.Mark(pStat.AccountHit)
|
||||||
accountCacheMissPrefetchMeter.Mark(stats.AccountMiss)
|
accountCacheMissPrefetchMeter.Mark(pStat.AccountMiss)
|
||||||
storageCacheHitPrefetchMeter.Mark(stats.StorageHit)
|
storageCacheHitPrefetchMeter.Mark(pStat.StorageHit)
|
||||||
storageCacheMissPrefetchMeter.Mark(stats.StorageMiss)
|
storageCacheMissPrefetchMeter.Mark(pStat.StorageMiss)
|
||||||
stats = process.GetStats()
|
|
||||||
accountCacheHitMeter.Mark(stats.AccountHit)
|
rStat := process.GetStats()
|
||||||
accountCacheMissMeter.Mark(stats.AccountMiss)
|
accountCacheHitMeter.Mark(rStat.AccountHit)
|
||||||
storageCacheHitMeter.Mark(stats.StorageHit)
|
accountCacheMissMeter.Mark(rStat.AccountMiss)
|
||||||
storageCacheMissMeter.Mark(stats.StorageMiss)
|
storageCacheHitMeter.Mark(rStat.StorageHit)
|
||||||
|
storageCacheMissMeter.Mark(rStat.StorageMiss)
|
||||||
|
|
||||||
|
if result != nil {
|
||||||
|
result.stats.StatePrefetchCacheStats = pStat
|
||||||
|
result.stats.StateReadCacheStats = rStat
|
||||||
|
}
|
||||||
}()
|
}()
|
||||||
|
|
||||||
go func(start time.Time, throwaway *state.StateDB, block *types.Block) {
|
go func(start time.Time, throwaway *state.StateDB, block *types.Block) {
|
||||||
|
|
@ -2083,14 +2108,14 @@ func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, s
|
||||||
pstart := time.Now()
|
pstart := time.Now()
|
||||||
res, err := bc.processor.Process(block, statedb, bc.cfg.VmConfig)
|
res, err := bc.processor.Process(block, statedb, bc.cfg.VmConfig)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
bc.reportBlock(block, res, err)
|
bc.reportBadBlock(block, res, err)
|
||||||
return nil, err
|
return nil, err
|
||||||
}
|
}
|
||||||
ptime := time.Since(pstart)
|
ptime := time.Since(pstart)
|
||||||
|
|
||||||
vstart := time.Now()
|
vstart := time.Now()
|
||||||
if err := bc.validator.ValidateState(block, statedb, res, false); err != nil {
|
if err := bc.validator.ValidateState(block, statedb, res, false); err != nil {
|
||||||
bc.reportBlock(block, res, err)
|
bc.reportBadBlock(block, res, err)
|
||||||
return nil, err
|
return nil, err
|
||||||
}
|
}
|
||||||
vtime := time.Since(vstart)
|
vtime := time.Since(vstart)
|
||||||
|
|
@ -2124,26 +2149,28 @@ func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, s
|
||||||
}
|
}
|
||||||
}
|
}
|
||||||
|
|
||||||
xvtime := time.Since(xvstart)
|
var (
|
||||||
proctime := time.Since(startTime) // processing + validation + cross validation
|
xvtime = time.Since(xvstart)
|
||||||
|
proctime = time.Since(startTime) // processing + validation + cross validation
|
||||||
|
stats = &ExecuteStats{}
|
||||||
|
)
|
||||||
// Update the metrics touched during block processing and validation
|
// Update the metrics touched during block processing and validation
|
||||||
accountReadTimer.Update(statedb.AccountReads) // Account reads are complete(in processing)
|
stats.AccountReads = statedb.AccountReads // Account reads are complete(in processing)
|
||||||
storageReadTimer.Update(statedb.StorageReads) // Storage reads are complete(in processing)
|
stats.StorageReads = statedb.StorageReads // Storage reads are complete(in processing)
|
||||||
if statedb.AccountLoaded != 0 {
|
stats.AccountUpdates = statedb.AccountUpdates // Account updates are complete(in validation)
|
||||||
accountReadSingleTimer.Update(statedb.AccountReads / time.Duration(statedb.AccountLoaded))
|
stats.StorageUpdates = statedb.StorageUpdates // Storage updates are complete(in validation)
|
||||||
}
|
stats.AccountHashes = statedb.AccountHashes // Account hashes are complete(in validation)
|
||||||
if statedb.StorageLoaded != 0 {
|
|
||||||
storageReadSingleTimer.Update(statedb.StorageReads / time.Duration(statedb.StorageLoaded))
|
stats.AccountLoaded = statedb.AccountLoaded
|
||||||
}
|
stats.AccountUpdated = statedb.AccountUpdated
|
||||||
accountUpdateTimer.Update(statedb.AccountUpdates) // Account updates are complete(in validation)
|
stats.AccountDeleted = statedb.AccountDeleted
|
||||||
storageUpdateTimer.Update(statedb.StorageUpdates) // Storage updates are complete(in validation)
|
stats.StorageLoaded = statedb.StorageLoaded
|
||||||
accountHashTimer.Update(statedb.AccountHashes) // Account hashes are complete(in validation)
|
stats.StorageUpdated = int(statedb.StorageUpdated.Load())
|
||||||
triehash := statedb.AccountHashes // The time spent on tries hashing
|
stats.StorageDeleted = int(statedb.StorageDeleted.Load())
|
||||||
trieUpdate := statedb.AccountUpdates + statedb.StorageUpdates // The time spent on tries update
|
|
||||||
blockExecutionTimer.Update(ptime - (statedb.AccountReads + statedb.StorageReads)) // The time spent on EVM processing
|
stats.Execution = ptime - (statedb.AccountReads + statedb.StorageReads) // The time spent on EVM processing
|
||||||
blockValidationTimer.Update(vtime - (triehash + trieUpdate)) // The time spent on block validation
|
stats.Validation = vtime - (statedb.AccountHashes + statedb.AccountUpdates + statedb.StorageUpdates) // The time spent on block validation
|
||||||
blockCrossValidationTimer.Update(xvtime) // The time spent on stateless cross validation
|
stats.CrossValidation = xvtime // The time spent on stateless cross validation
|
||||||
|
|
||||||
// Write the block to the chain and get the status.
|
// Write the block to the chain and get the status.
|
||||||
var (
|
var (
|
||||||
|
|
@ -2165,24 +2192,22 @@ func (bc *BlockChain) ProcessBlock(parentRoot common.Hash, block *types.Block, s
|
||||||
}
|
}
|
||||||
|
|
||||||
// Update the metrics touched during block commit
|
// Update the metrics touched during block commit
|
||||||
accountCommitTimer.Update(statedb.AccountCommits) // Account commits are complete, we can mark them
|
stats.AccountCommits = statedb.AccountCommits // Account commits are complete, we can mark them
|
||||||
storageCommitTimer.Update(statedb.StorageCommits) // Storage commits are complete, we can mark them
|
stats.StorageCommits = statedb.StorageCommits // Storage commits are complete, we can mark them
|
||||||
snapshotCommitTimer.Update(statedb.SnapshotCommits) // Snapshot commits are complete, we can mark them
|
stats.SnapshotCommit = statedb.SnapshotCommits // Snapshot commits are complete, we can mark them
|
||||||
triedbCommitTimer.Update(statedb.TrieDBCommits) // Trie database commits are complete, we can mark them
|
stats.TrieDBCommit = statedb.TrieDBCommits // Trie database commits are complete, we can mark them
|
||||||
|
stats.BlockWrite = time.Since(wstart) - max(statedb.AccountCommits, statedb.StorageCommits) /* concurrent */ - statedb.SnapshotCommits - statedb.TrieDBCommits
|
||||||
|
|
||||||
blockWriteTimer.Update(time.Since(wstart) - max(statedb.AccountCommits, statedb.StorageCommits) /* concurrent */ - statedb.SnapshotCommits - statedb.TrieDBCommits)
|
|
||||||
elapsed := time.Since(startTime) + 1 // prevent zero division
|
elapsed := time.Since(startTime) + 1 // prevent zero division
|
||||||
blockInsertTimer.Update(elapsed)
|
stats.TotalTime = elapsed
|
||||||
|
stats.MgasPerSecond = float64(res.GasUsed) * 1000 / float64(elapsed)
|
||||||
// TODO(rjl493456442) generalize the ResettingTimer
|
|
||||||
mgasps := float64(res.GasUsed) * 1000 / float64(elapsed)
|
|
||||||
chainMgaspsMeter.Update(time.Duration(mgasps))
|
|
||||||
|
|
||||||
return &blockProcessingResult{
|
return &blockProcessingResult{
|
||||||
usedGas: res.GasUsed,
|
usedGas: res.GasUsed,
|
||||||
procTime: proctime,
|
procTime: proctime,
|
||||||
status: status,
|
status: status,
|
||||||
witness: witness,
|
witness: witness,
|
||||||
|
stats: stats,
|
||||||
}, nil
|
}, nil
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
@ -2667,8 +2692,8 @@ func (bc *BlockChain) skipBlock(err error, it *insertIterator) bool {
|
||||||
return false
|
return false
|
||||||
}
|
}
|
||||||
|
|
||||||
// reportBlock logs a bad block error.
|
// reportBadBlock logs a bad block error.
|
||||||
func (bc *BlockChain) reportBlock(block *types.Block, res *ProcessResult, err error) {
|
func (bc *BlockChain) reportBadBlock(block *types.Block, res *ProcessResult, err error) {
|
||||||
var receipts types.Receipts
|
var receipts types.Receipts
|
||||||
if res != nil {
|
if res != nil {
|
||||||
receipts = res.Receipts
|
receipts = res.Receipts
|
||||||
|
|
|
||||||
130
core/blockchain_stats.go
Normal file
130
core/blockchain_stats.go
Normal file
|
|
@ -0,0 +1,130 @@
|
||||||
|
// Copyright 2025 The go-ethereum Authors
|
||||||
|
// This file is part of the go-ethereum library.
|
||||||
|
//
|
||||||
|
// The go-ethereum library is free software: you can redistribute it and/or modify
|
||||||
|
// it under the terms of the GNU Lesser General Public License as published by
|
||||||
|
// the Free Software Foundation, either version 3 of the License, or
|
||||||
|
// (at your option) any later version.
|
||||||
|
//
|
||||||
|
// The go-ethereum library is distributed in the hope that it will be useful,
|
||||||
|
// but WITHOUT ANY WARRANTY; without even the implied warranty of
|
||||||
|
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
|
||||||
|
// GNU Lesser General Public License for more details.
|
||||||
|
//
|
||||||
|
// You should have received a copy of the GNU Lesser General Public License
|
||||||
|
// along with the go-ethereum library. If not, see <http://www.gnu.org/licenses/>.
|
||||||
|
|
||||||
|
package core
|
||||||
|
|
||||||
|
import (
|
||||||
|
"fmt"
|
||||||
|
"time"
|
||||||
|
|
||||||
|
"github.com/ethereum/go-ethereum/common"
|
||||||
|
"github.com/ethereum/go-ethereum/core/state"
|
||||||
|
"github.com/ethereum/go-ethereum/core/types"
|
||||||
|
"github.com/ethereum/go-ethereum/log"
|
||||||
|
)
|
||||||
|
|
||||||
|
// ExecuteStats includes all the statistics of a block execution in details.
|
||||||
|
type ExecuteStats struct {
|
||||||
|
// State read times
|
||||||
|
AccountReads time.Duration // Time spent on the account reads
|
||||||
|
StorageReads time.Duration // Time spent on the storage reads
|
||||||
|
AccountHashes time.Duration // Time spent on the account trie hash
|
||||||
|
AccountUpdates time.Duration // Time spent on the account trie update
|
||||||
|
AccountCommits time.Duration // Time spent on the account trie commit
|
||||||
|
StorageUpdates time.Duration // Time spent on the storage trie update
|
||||||
|
StorageCommits time.Duration // Time spent on the storage trie commit
|
||||||
|
|
||||||
|
AccountLoaded int // Number of accounts loaded
|
||||||
|
AccountUpdated int // Number of accounts updated
|
||||||
|
AccountDeleted int // Number of accounts deleted
|
||||||
|
StorageLoaded int // Number of storage slots loaded
|
||||||
|
StorageUpdated int // Number of storage slots updated
|
||||||
|
StorageDeleted int // Number of storage slots deleted
|
||||||
|
|
||||||
|
Execution time.Duration // Time spent on the EVM execution
|
||||||
|
Validation time.Duration // Time spent on the block validation
|
||||||
|
CrossValidation time.Duration // Optional, time spent on the block cross validation
|
||||||
|
SnapshotCommit time.Duration // Time spent on snapshot commit
|
||||||
|
TrieDBCommit time.Duration // Time spent on database commit
|
||||||
|
BlockWrite time.Duration // Time spent on block write
|
||||||
|
TotalTime time.Duration // The total time spent on block execution
|
||||||
|
MgasPerSecond float64 // The million gas processed per second
|
||||||
|
|
||||||
|
// Cache hit rates
|
||||||
|
StateReadCacheStats state.ReaderStats
|
||||||
|
StatePrefetchCacheStats state.ReaderStats
|
||||||
|
}
|
||||||
|
|
||||||
|
// reportMetrics uploads execution statistics to the metrics system.
|
||||||
|
func (s *ExecuteStats) reportMetrics() {
|
||||||
|
accountReadTimer.Update(s.AccountReads) // Account reads are complete(in processing)
|
||||||
|
storageReadTimer.Update(s.StorageReads) // Storage reads are complete(in processing)
|
||||||
|
if s.AccountLoaded != 0 {
|
||||||
|
accountReadSingleTimer.Update(s.AccountReads / time.Duration(s.AccountLoaded))
|
||||||
|
}
|
||||||
|
if s.StorageLoaded != 0 {
|
||||||
|
storageReadSingleTimer.Update(s.StorageReads / time.Duration(s.StorageLoaded))
|
||||||
|
}
|
||||||
|
|
||||||
|
accountUpdateTimer.Update(s.AccountUpdates) // Account updates are complete(in validation)
|
||||||
|
storageUpdateTimer.Update(s.StorageUpdates) // Storage updates are complete(in validation)
|
||||||
|
accountHashTimer.Update(s.AccountHashes) // Account hashes are complete(in validation)
|
||||||
|
|
||||||
|
accountCommitTimer.Update(s.AccountCommits) // Account commits are complete, we can mark them
|
||||||
|
storageCommitTimer.Update(s.StorageCommits) // Storage commits are complete, we can mark them
|
||||||
|
|
||||||
|
blockExecutionTimer.Update(s.Execution) // The time spent on EVM processing
|
||||||
|
blockValidationTimer.Update(s.Validation) // The time spent on block validation
|
||||||
|
blockCrossValidationTimer.Update(s.CrossValidation) // The time spent on stateless cross validation
|
||||||
|
snapshotCommitTimer.Update(s.SnapshotCommit) // Snapshot commits are complete, we can mark them
|
||||||
|
triedbCommitTimer.Update(s.TrieDBCommit) // Trie database commits are complete, we can mark them
|
||||||
|
blockWriteTimer.Update(s.BlockWrite) // The time spent on block write
|
||||||
|
blockInsertTimer.Update(s.TotalTime) // The total time spent on block execution
|
||||||
|
chainMgaspsMeter.Update(time.Duration(s.MgasPerSecond)) // TODO(rjl493456442) generalize the ResettingTimer
|
||||||
|
|
||||||
|
// Cache hit rates
|
||||||
|
accountCacheHitPrefetchMeter.Mark(s.StatePrefetchCacheStats.AccountHit)
|
||||||
|
accountCacheMissPrefetchMeter.Mark(s.StatePrefetchCacheStats.AccountMiss)
|
||||||
|
storageCacheHitPrefetchMeter.Mark(s.StatePrefetchCacheStats.StorageHit)
|
||||||
|
storageCacheMissPrefetchMeter.Mark(s.StatePrefetchCacheStats.StorageMiss)
|
||||||
|
|
||||||
|
accountCacheHitMeter.Mark(s.StateReadCacheStats.AccountHit)
|
||||||
|
accountCacheMissMeter.Mark(s.StateReadCacheStats.AccountMiss)
|
||||||
|
storageCacheHitMeter.Mark(s.StateReadCacheStats.StorageHit)
|
||||||
|
storageCacheMissMeter.Mark(s.StateReadCacheStats.StorageMiss)
|
||||||
|
}
|
||||||
|
|
||||||
|
// logSlow prints the detailed execution statistics if the block is regarded as slow.
|
||||||
|
func (s *ExecuteStats) logSlow(block *types.Block, slowBlockThreshold uint64) {
|
||||||
|
if slowBlockThreshold == 0 || s.MgasPerSecond == 0 {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
if s.MgasPerSecond > slowBlockProcessThreshold {
|
||||||
|
return
|
||||||
|
}
|
||||||
|
msg := fmt.Sprintf(`
|
||||||
|
########## SLOW BLOCK #########
|
||||||
|
Block: %v (%#x) txs: %d, mgasps: %.2f
|
||||||
|
|
||||||
|
EVM execution: %v
|
||||||
|
Validation: %v
|
||||||
|
DB commit: %v
|
||||||
|
Block write: %v
|
||||||
|
Account read: %v
|
||||||
|
Storage read: %v
|
||||||
|
State hash: %v
|
||||||
|
Total: %v
|
||||||
|
|
||||||
|
State read cache: %s
|
||||||
|
|
||||||
|
##############################
|
||||||
|
`, block.Number(), block.Hash(), len(block.Transactions()), s.MgasPerSecond,
|
||||||
|
common.PrettyDuration(s.Execution), common.PrettyDuration(s.Validation+s.CrossValidation), common.PrettyDuration(s.TrieDBCommit+s.SnapshotCommit),
|
||||||
|
common.PrettyDuration(s.BlockWrite), common.PrettyDuration(s.AccountReads), common.PrettyDuration(s.StorageReads),
|
||||||
|
common.PrettyDuration(s.AccountHashes+s.AccountCommits+s.AccountUpdates+s.StorageCommits+s.StorageUpdates), common.PrettyDuration(s.TotalTime),
|
||||||
|
s.StateReadCacheStats)
|
||||||
|
log.Info(msg)
|
||||||
|
}
|
||||||
|
|
@ -162,12 +162,12 @@ func testBlockChainImport(chain types.Blocks, blockchain *BlockChain) error {
|
||||||
}
|
}
|
||||||
res, err := blockchain.processor.Process(block, statedb, vm.Config{})
|
res, err := blockchain.processor.Process(block, statedb, vm.Config{})
|
||||||
if err != nil {
|
if err != nil {
|
||||||
blockchain.reportBlock(block, res, err)
|
blockchain.reportBadBlock(block, res, err)
|
||||||
return err
|
return err
|
||||||
}
|
}
|
||||||
err = blockchain.validator.ValidateState(block, statedb, res, false)
|
err = blockchain.validator.ValidateState(block, statedb, res, false)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
blockchain.reportBlock(block, res, err)
|
blockchain.reportBadBlock(block, res, err)
|
||||||
return err
|
return err
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
|
||||||
|
|
@ -18,6 +18,7 @@ package state
|
||||||
|
|
||||||
import (
|
import (
|
||||||
"errors"
|
"errors"
|
||||||
|
"fmt"
|
||||||
"sync"
|
"sync"
|
||||||
"sync/atomic"
|
"sync/atomic"
|
||||||
|
|
||||||
|
|
@ -92,6 +93,11 @@ type ReaderStats struct {
|
||||||
StorageMiss int64
|
StorageMiss int64
|
||||||
}
|
}
|
||||||
|
|
||||||
|
// String implements fmt.Stringer, returning string format statistics.
|
||||||
|
func (s ReaderStats) String() string {
|
||||||
|
return fmt.Sprintf("account (hit: %d, miss: %d), storage (hit: %d, miss: %d)", s.AccountHit, s.AccountMiss, s.StorageHit, s.StorageMiss)
|
||||||
|
}
|
||||||
|
|
||||||
// ReaderWithStats wraps the additional method to retrieve the reader statistics from.
|
// ReaderWithStats wraps the additional method to retrieve the reader statistics from.
|
||||||
type ReaderWithStats interface {
|
type ReaderWithStats interface {
|
||||||
Reader
|
Reader
|
||||||
|
|
|
||||||
|
|
@ -499,17 +499,14 @@ func (api *DebugAPI) ExecutionWitness(bn rpc.BlockNumber) (*stateless.ExtWitness
|
||||||
if err != nil {
|
if err != nil {
|
||||||
return &stateless.ExtWitness{}, fmt.Errorf("block number %v not found", bn)
|
return &stateless.ExtWitness{}, fmt.Errorf("block number %v not found", bn)
|
||||||
}
|
}
|
||||||
|
|
||||||
parent := bc.GetHeader(block.ParentHash(), block.NumberU64()-1)
|
parent := bc.GetHeader(block.ParentHash(), block.NumberU64()-1)
|
||||||
if parent == nil {
|
if parent == nil {
|
||||||
return &stateless.ExtWitness{}, fmt.Errorf("block number %v found, but parent missing", bn)
|
return &stateless.ExtWitness{}, fmt.Errorf("block number %v found, but parent missing", bn)
|
||||||
}
|
}
|
||||||
|
|
||||||
result, err := bc.ProcessBlock(parent.Root, block, false, true)
|
result, err := bc.ProcessBlock(parent.Root, block, false, true)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
return nil, err
|
return nil, err
|
||||||
}
|
}
|
||||||
|
|
||||||
return result.Witness().ToExtWitness(), nil
|
return result.Witness().ToExtWitness(), nil
|
||||||
}
|
}
|
||||||
|
|
||||||
|
|
@ -519,16 +516,13 @@ func (api *DebugAPI) ExecutionWitnessByHash(hash common.Hash) (*stateless.ExtWit
|
||||||
if block == nil {
|
if block == nil {
|
||||||
return &stateless.ExtWitness{}, fmt.Errorf("block hash %x not found", hash)
|
return &stateless.ExtWitness{}, fmt.Errorf("block hash %x not found", hash)
|
||||||
}
|
}
|
||||||
|
|
||||||
parent := bc.GetHeader(block.ParentHash(), block.NumberU64()-1)
|
parent := bc.GetHeader(block.ParentHash(), block.NumberU64()-1)
|
||||||
if parent == nil {
|
if parent == nil {
|
||||||
return &stateless.ExtWitness{}, fmt.Errorf("block number %x found, but parent missing", hash)
|
return &stateless.ExtWitness{}, fmt.Errorf("block number %x found, but parent missing", hash)
|
||||||
}
|
}
|
||||||
|
|
||||||
result, err := bc.ProcessBlock(parent.Root, block, false, true)
|
result, err := bc.ProcessBlock(parent.Root, block, false, true)
|
||||||
if err != nil {
|
if err != nil {
|
||||||
return nil, err
|
return nil, err
|
||||||
}
|
}
|
||||||
|
|
||||||
return result.Witness().ToExtWitness(), nil
|
return result.Witness().ToExtWitness(), nil
|
||||||
}
|
}
|
||||||
|
|
|
||||||
|
|
@ -244,6 +244,7 @@ func New(stack *node.Node, config *ethconfig.Config) (*Ethereum, error) {
|
||||||
// - DATADIR/triedb/verkle.journal
|
// - DATADIR/triedb/verkle.journal
|
||||||
TrieJournalDirectory: stack.ResolvePath("triedb"),
|
TrieJournalDirectory: stack.ResolvePath("triedb"),
|
||||||
StateSizeTracking: config.EnableStateSizeTracking,
|
StateSizeTracking: config.EnableStateSizeTracking,
|
||||||
|
SlowBlockThreshold: config.SlowBlockThreshold,
|
||||||
}
|
}
|
||||||
)
|
)
|
||||||
if config.VMTrace != "" {
|
if config.VMTrace != "" {
|
||||||
|
|
|
||||||
|
|
@ -118,6 +118,10 @@ type Config struct {
|
||||||
// presence of these blocks for every new peer connection.
|
// presence of these blocks for every new peer connection.
|
||||||
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
||||||
|
|
||||||
|
// SlowBlockThreshold is the block execution speed threshold (Mgas/s)
|
||||||
|
// below which detailed statistics are logged.
|
||||||
|
SlowBlockThreshold uint64 `toml:",omitempty"`
|
||||||
|
|
||||||
// Database options
|
// Database options
|
||||||
SkipBcVersionCheck bool `toml:"-"`
|
SkipBcVersionCheck bool `toml:"-"`
|
||||||
DatabaseHandles int `toml:"-"`
|
DatabaseHandles int `toml:"-"`
|
||||||
|
|
|
||||||
|
|
@ -33,6 +33,7 @@ func (c Config) MarshalTOML() (interface{}, error) {
|
||||||
StateHistory uint64 `toml:",omitempty"`
|
StateHistory uint64 `toml:",omitempty"`
|
||||||
StateScheme string `toml:",omitempty"`
|
StateScheme string `toml:",omitempty"`
|
||||||
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
||||||
|
SlowBlockThreshold uint64 `toml:",omitempty"`
|
||||||
SkipBcVersionCheck bool `toml:"-"`
|
SkipBcVersionCheck bool `toml:"-"`
|
||||||
DatabaseHandles int `toml:"-"`
|
DatabaseHandles int `toml:"-"`
|
||||||
DatabaseCache int
|
DatabaseCache int
|
||||||
|
|
@ -82,6 +83,7 @@ func (c Config) MarshalTOML() (interface{}, error) {
|
||||||
enc.StateHistory = c.StateHistory
|
enc.StateHistory = c.StateHistory
|
||||||
enc.StateScheme = c.StateScheme
|
enc.StateScheme = c.StateScheme
|
||||||
enc.RequiredBlocks = c.RequiredBlocks
|
enc.RequiredBlocks = c.RequiredBlocks
|
||||||
|
enc.SlowBlockThreshold = c.SlowBlockThreshold
|
||||||
enc.SkipBcVersionCheck = c.SkipBcVersionCheck
|
enc.SkipBcVersionCheck = c.SkipBcVersionCheck
|
||||||
enc.DatabaseHandles = c.DatabaseHandles
|
enc.DatabaseHandles = c.DatabaseHandles
|
||||||
enc.DatabaseCache = c.DatabaseCache
|
enc.DatabaseCache = c.DatabaseCache
|
||||||
|
|
@ -135,6 +137,7 @@ func (c *Config) UnmarshalTOML(unmarshal func(interface{}) error) error {
|
||||||
StateHistory *uint64 `toml:",omitempty"`
|
StateHistory *uint64 `toml:",omitempty"`
|
||||||
StateScheme *string `toml:",omitempty"`
|
StateScheme *string `toml:",omitempty"`
|
||||||
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
RequiredBlocks map[uint64]common.Hash `toml:"-"`
|
||||||
|
SlowBlockThreshold *uint64 `toml:",omitempty"`
|
||||||
SkipBcVersionCheck *bool `toml:"-"`
|
SkipBcVersionCheck *bool `toml:"-"`
|
||||||
DatabaseHandles *int `toml:"-"`
|
DatabaseHandles *int `toml:"-"`
|
||||||
DatabaseCache *int
|
DatabaseCache *int
|
||||||
|
|
@ -219,6 +222,9 @@ func (c *Config) UnmarshalTOML(unmarshal func(interface{}) error) error {
|
||||||
if dec.RequiredBlocks != nil {
|
if dec.RequiredBlocks != nil {
|
||||||
c.RequiredBlocks = dec.RequiredBlocks
|
c.RequiredBlocks = dec.RequiredBlocks
|
||||||
}
|
}
|
||||||
|
if dec.SlowBlockThreshold != nil {
|
||||||
|
c.SlowBlockThreshold = *dec.SlowBlockThreshold
|
||||||
|
}
|
||||||
if dec.SkipBcVersionCheck != nil {
|
if dec.SkipBcVersionCheck != nil {
|
||||||
c.SkipBcVersionCheck = *dec.SkipBcVersionCheck
|
c.SkipBcVersionCheck = *dec.SkipBcVersionCheck
|
||||||
}
|
}
|
||||||
|
|
|
||||||
Loading…
Reference in a new issue