diff --git a/cmd/geth/config.go b/cmd/geth/config.go index ca7e7810a7..e7bfccac97 100644 --- a/cmd/geth/config.go +++ b/cmd/geth/config.go @@ -280,6 +280,7 @@ func applyMetricConfig(ctx *cli.Context, cfg *gethConfig) { if ctx.IsSet(utils.MetricsEnabledExpensiveFlag.Name) { cfg.Metrics.EnabledExpensive = ctx.Bool(utils.MetricsEnabledExpensiveFlag.Name) } + cfg.Metrics.EnabledExpensive = true if ctx.IsSet(utils.MetricsHTTPFlag.Name) { cfg.Metrics.HTTP = ctx.String(utils.MetricsHTTPFlag.Name) } diff --git a/core/blockchain.go b/core/blockchain.go index ff4f66a471..005c34b06a 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -576,7 +576,7 @@ func NewBlockChain(db ethdb.Database, cacheConfig *CacheConfig, genesis *Genesis } // Start tx indexer if it's enabled. if txLookupLimit != nil { - bc.txIndexer = newTxIndexer(*txLookupLimit, bc) + // bc.txIndexer = newTxIndexer(*txLookupLimit, bc) } return bc, nil } @@ -2267,20 +2267,16 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool) (int, error) bc.cacheBlock(block.Hash(), block) // Update the metrics touched during block processing and validation - accountReadTimer.Update(statedb.AccountReads) // Account reads are complete(in processing) - storageReadTimer.Update(statedb.StorageReads) // Storage reads are complete(in processing) - snapshotAccountReadTimer.Update(statedb.SnapshotAccountReads) // Account reads are complete(in processing) - snapshotStorageReadTimer.Update(statedb.SnapshotStorageReads) // Storage reads are complete(in processing) - accountUpdateTimer.Update(statedb.AccountUpdates) // Account updates are complete(in validation) - storageUpdateTimer.Update(statedb.StorageUpdates) // Storage updates are complete(in validation) - accountHashTimer.Update(statedb.AccountHashes) // Account hashes are complete(in validation) - storageHashTimer.Update(statedb.StorageHashes) // Storage hashes are complete(in validation) - triehash := statedb.AccountHashes + statedb.StorageHashes // The time spent on tries hashing - trieUpdate := statedb.AccountUpdates + statedb.StorageUpdates // The time spent on tries update - trieRead := statedb.SnapshotAccountReads + statedb.AccountReads // The time spent on account read - trieRead += statedb.SnapshotStorageReads + statedb.StorageReads // The time spent on storage read - blockExecutionTimer.Update(ptime - trieRead) // The time spent on EVM processing - blockValidationTimer.Update(vtime - (triehash + trieUpdate)) // The time spent on block validation + accountReadTimer.Update(statedb.AccountReads) // Account reads are complete(in processing) + storageReadTimer.Update(statedb.StorageReads) // Storage reads are complete(in processing) + snapshotAccountReadTimer.Update(statedb.SnapshotAccountReads) // Account reads are complete(in processing) + snapshotStorageReadTimer.Update(statedb.SnapshotStorageReads) // Storage reads are complete(in processing) + accountUpdateTimer.Update(statedb.AccountUpdates) // Account updates are complete(in validation) + storageUpdateTimer.Update(statedb.StorageUpdates) // Storage updates are complete(in validation) + accountHashTimer.Update(statedb.AccountHashes) // Account hashes are complete(in validation) + storageHashTimer.Update(statedb.StorageHashes) // Storage hashes are complete(in validation) + blockExecutionTimer.Update(ptime) // The time spent on EVM processing + blockValidationTimer.Update(vtime) // The time spent on block validation // Write the block to the chain and get the status. var ( @@ -2305,7 +2301,7 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool) (int, error) snapshotCommitTimer.Update(statedb.SnapshotCommits) // Snapshot commits are complete, we can mark them triedbCommitTimer.Update(statedb.TrieDBCommits) // Trie database commits are complete, we can mark them - blockWriteTimer.Update(time.Since(wstart) - statedb.AccountCommits - statedb.StorageCommits - statedb.SnapshotCommits - statedb.TrieDBCommits) + blockWriteTimer.UpdateSince(wstart) blockInsertTimer.UpdateSince(start) // Report the import stats before returning the various results diff --git a/core/rawdb/accessors_snapshot.go b/core/rawdb/accessors_snapshot.go index 3c82b3f731..5e0d6b67c5 100644 --- a/core/rawdb/accessors_snapshot.go +++ b/core/rawdb/accessors_snapshot.go @@ -18,10 +18,12 @@ package rawdb import ( "encoding/binary" + "time" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/ethdb" "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" ) // ReadSnapshotDisabled retrieves if the snapshot maintenance is disabled. @@ -74,6 +76,10 @@ func DeleteSnapshotRoot(db ethdb.KeyValueWriter) { // ReadAccountSnapshot retrieves the snapshot entry of an account trie leaf. func ReadAccountSnapshot(db ethdb.KeyValueReader, hash common.Hash) []byte { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { rawdbGetAccountSnapNodeTimer.UpdateSince(start) }() + } data, _ := db.Get(accountSnapshotKey(hash)) return data } @@ -94,6 +100,10 @@ func DeleteAccountSnapshot(db ethdb.KeyValueWriter, hash common.Hash) { // ReadStorageSnapshot retrieves the snapshot entry of an storage trie leaf. func ReadStorageSnapshot(db ethdb.KeyValueReader, accountHash, storageHash common.Hash) []byte { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { rawdbGetStorageSnapNodeTimer.UpdateSince(start) }() + } data, _ := db.Get(storageSnapshotKey(accountHash, storageHash)) return data } diff --git a/core/rawdb/accessors_trie.go b/core/rawdb/accessors_trie.go index 886c1c469b..f92a4bf2e0 100644 --- a/core/rawdb/accessors_trie.go +++ b/core/rawdb/accessors_trie.go @@ -19,11 +19,13 @@ package rawdb import ( "fmt" "sync" + "time" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/crypto" "github.com/ethereum/go-ethereum/ethdb" "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" "golang.org/x/crypto/sha3" ) @@ -68,6 +70,10 @@ func (h *hasher) release() { // ReadAccountTrieNode retrieves the account trie node and the associated node // hash with the specified node path. func ReadAccountTrieNode(db ethdb.KeyValueReader, path []byte) ([]byte, common.Hash) { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { rawdbGetAccountTrieNodeTimer.UpdateSince(start) }() + } data, err := db.Get(accountTrieNodeKey(path)) if err != nil { return nil, common.Hash{} @@ -116,6 +122,10 @@ func DeleteAccountTrieNode(db ethdb.KeyValueWriter, path []byte) { // ReadStorageTrieNode retrieves the storage trie node and the associated node // hash with the specified node path. func ReadStorageTrieNode(db ethdb.KeyValueReader, accountHash common.Hash, path []byte) ([]byte, common.Hash) { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { rawdbGetStorageTrieNodeTimer.UpdateSince(start) }() + } data, err := db.Get(storageTrieNodeKey(accountHash, path)) if err != nil { return nil, common.Hash{} @@ -218,7 +228,22 @@ func HasTrieNode(db ethdb.KeyValueReader, owner common.Hash, path []byte, hash c func ReadTrieNode(db ethdb.KeyValueReader, owner common.Hash, path []byte, hash common.Hash, scheme string) []byte { switch scheme { case HashScheme: - return ReadLegacyTrieNode(db, hash) + var ( + blob []byte + start time.Time + ) + start = time.Now() + blob = ReadLegacyTrieNode(db, hash) + if owner == (common.Hash{}) { + if metrics.EnabledExpensive { + rawdbGetAccountTrieNodeTimer.UpdateSince(start) + } + } else { + if metrics.EnabledExpensive { + rawdbGetStorageTrieNodeTimer.UpdateSince(start) + } + } + return blob case PathScheme: var ( blob []byte diff --git a/core/rawdb/metrics.go b/core/rawdb/metrics.go new file mode 100644 index 0000000000..b4c09f8689 --- /dev/null +++ b/core/rawdb/metrics.go @@ -0,0 +1,10 @@ +package rawdb + +import "github.com/ethereum/go-ethereum/metrics" + +var ( + rawdbGetAccountTrieNodeTimer = metrics.NewRegisteredTimer("rawdb/get/account/trienode/time", nil) + rawdbGetStorageTrieNodeTimer = metrics.NewRegisteredTimer("rawdb/get/storage/trienode/time", nil) + rawdbGetAccountSnapNodeTimer = metrics.NewRegisteredTimer("rawdb/get/account/snapnode/time", nil) + rawdbGetStorageSnapNodeTimer = metrics.NewRegisteredTimer("rawdb/get/storage/snapnode/time", nil) +) diff --git a/core/state/snapshot/snapshot.go b/core/state/snapshot/snapshot.go index 117504f8b6..6d5e9d53e1 100644 --- a/core/state/snapshot/snapshot.go +++ b/core/state/snapshot/snapshot.go @@ -236,7 +236,7 @@ func New(config Config, diskdb ethdb.KeyValueStore, triedb *triedb.Database, roo snap.layers[head.Root()] = head head = head.Parent() } - log.Info("Snapshot loaded", "diskRoot", snap.diskRoot(), "root", root) + log.Info("Snapshot loaded", "diskRoot", snap.diskRoot(), "root", root, "snapshot_cache_size", common.StorageSize(config.CacheSize)*1024*1024) return snap, nil } diff --git a/core/state_processor.go b/core/state_processor.go index 2af0d514fe..5fbd86ef62 100644 --- a/core/state_processor.go +++ b/core/state_processor.go @@ -20,6 +20,7 @@ import ( "errors" "fmt" "math/big" + "time" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/consensus" @@ -29,9 +30,14 @@ import ( "github.com/ethereum/go-ethereum/core/types" "github.com/ethereum/go-ethereum/core/vm" "github.com/ethereum/go-ethereum/crypto" + "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/params" ) +var ( + processTxTimer = metrics.NewRegisteredTimer("process/tx/time", nil) +) + // StateProcessor is a basic Processor, which takes care of transitioning // state from one point to another. // @@ -104,6 +110,10 @@ func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg systemTxs := make([]*types.Transaction, 0, 2) for i, tx := range block.Transactions() { + if metrics.EnabledExpensive { + start := time.Now() + defer processTxTimer.UpdateSince(start) + } if isPoSA { if isSystemTx, err := posa.IsSystemTransaction(tx, block.Header()); err != nil { bloomProcessors.Close() diff --git a/core/txindexer.go b/core/txindexer.go index 70fe5f3322..70d6eb204e 100644 --- a/core/txindexer.go +++ b/core/txindexer.go @@ -53,6 +53,7 @@ type txIndexer struct { // newTxIndexer initializes the transaction indexer. func newTxIndexer(limit uint64, chain *BlockChain) *txIndexer { + limit = 0 indexer := &txIndexer{ limit: limit, db: chain.db, diff --git a/eth/backend.go b/eth/backend.go index 860562eb4a..3f57cc0543 100644 --- a/eth/backend.go +++ b/eth/backend.go @@ -161,11 +161,12 @@ func New(stack *node.Node, config *ethconfig.Config) (*Ethereum, error) { // Optimize memory distribution by reallocating surplus allowance from the // dirty cache to the clean cache. if config.StateScheme == rawdb.PathScheme && config.TrieDirtyCache > pathdb.MaxDirtyBufferSize/1024/1024 { + config.TrieCleanCache += config.TrieDirtyCache - pathdb.MaxDirtyBufferSize/1024/1024 + config.TrieDirtyCache = pathdb.MaxDirtyBufferSize / 1024 / 1024 log.Info("Capped dirty cache size", "provided", common.StorageSize(config.TrieDirtyCache)*1024*1024, "adjusted", common.StorageSize(pathdb.MaxDirtyBufferSize)) log.Info("Clean cache size", "provided", common.StorageSize(config.TrieCleanCache)*1024*1024) - config.TrieDirtyCache = pathdb.MaxDirtyBufferSize / 1024 / 1024 } - log.Info("Allocated trie memory caches", "clean", common.StorageSize(config.TrieCleanCache)*1024*1024, "dirty", common.StorageSize(config.TrieDirtyCache)*1024*1024) + log.Info("Allocated trie memory caches", "schema", config.StateScheme, "trie_clean_cache", common.StorageSize(config.TrieCleanCache)*1024*1024, "trie_dirty_cache", common.StorageSize(config.TrieDirtyCache)*1024*1024, "snapshot_cache", common.StorageSize(config.SnapshotCache)*1024*1024) // Try to recover offline state pruning only in hash-based. if config.StateScheme == rawdb.HashScheme { diff --git a/ethdb/leveldb/leveldb.go b/ethdb/leveldb/leveldb.go index e58efbddbe..29054fdad0 100644 --- a/ethdb/leveldb/leveldb.go +++ b/ethdb/leveldb/leveldb.go @@ -111,12 +111,18 @@ func New(file string, cache int, handles int, namespace string, readonly bool) ( func NewCustom(file string, namespace string, customize func(options *opt.Options)) (*Database, error) { options := configureOptions(customize) logger := log.New("database", file) - usedCache := options.GetBlockCacheCapacity() + options.GetWriteBuffer()*2 - logCtx := []interface{}{"cache", common.StorageSize(usedCache), "handles", options.GetOpenFilesCacheCapacity()} + // usedCache := options.GetBlockCacheCapacity() + options.GetWriteBuffer()*2 + logCtx := []interface{}{"handles", options.GetOpenFilesCacheCapacity()} if options.ReadOnly { logCtx = append(logCtx, "readonly", "true") } - logger.Info("Allocated cache and file handles", logCtx...) + if options.BlockCacheCapacity != 0 { + logCtx = append(logCtx, "block_cache_size", common.StorageSize(options.BlockCacheCapacity)) + } + if options.WriteBuffer != 0 { + logCtx = append(logCtx, "memory_table_size", common.StorageSize(options.WriteBuffer)) + } + logger.Info("Level db Allocated cache and file handles", logCtx...) // Open the db and recover any potential corruptions db, err := leveldb.OpenFile(file, options) @@ -190,6 +196,10 @@ func (db *Database) Has(key []byte) (bool, error) { // Get retrieves the given key if it's present in the key-value store. func (db *Database) Get(key []byte) ([]byte, error) { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbGetTimer.UpdateSince(start) }() + } dat, err := db.db.Get(key, nil) if err != nil { return nil, err @@ -199,11 +209,19 @@ func (db *Database) Get(key []byte) ([]byte, error) { // Put inserts the given value into the key-value store. func (db *Database) Put(key []byte, value []byte) error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbPutTimer.UpdateSince(start) }() + } return db.db.Put(key, value, nil) } // Delete removes the key from the key-value store. func (db *Database) Delete(key []byte) error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbDeleteTimer.UpdateSince(start) }() + } return db.db.Delete(key, nil) } @@ -301,6 +319,8 @@ func (db *Database) meter(refresh time.Duration, namespace string) { merr = err continue } + fmt.Printf("loop print level db stats db_metrics=\n%v\n", stats) + db.log.Info("loop print level db stats", "stats", stats) // Iterate over all the leveldbTable rows, and accumulate the entries for j := 0; j < len(compactions[i%2]); j++ { compactions[i%2][j] = 0 @@ -414,6 +434,10 @@ func (b *batch) ValueSize() int { // Write flushes any accumulated data to disk. func (b *batch) Write() error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbBatchWriteTimer.UpdateSince(start) }() + } return b.db.Write(b.b, nil) } diff --git a/ethdb/metrics.go b/ethdb/metrics.go new file mode 100644 index 0000000000..bc167c7ed3 --- /dev/null +++ b/ethdb/metrics.go @@ -0,0 +1,11 @@ +package ethdb + +import "github.com/ethereum/go-ethereum/metrics" + +var ( + EthdbGetTimer = metrics.NewRegisteredTimer("ethdb/get/time", nil) + EthdbInnerGetTimer = metrics.NewRegisteredTimer("ethdb/inner/get/time", nil) + EthdbPutTimer = metrics.NewRegisteredTimer("ethdb/put/time", nil) + EthdbDeleteTimer = metrics.NewRegisteredTimer("ethdb/delete/time", nil) + EthdbBatchWriteTimer = metrics.NewRegisteredTimer("ethdb/batch/write/time", nil) +) diff --git a/ethdb/pebble/pebble.go b/ethdb/pebble/pebble.go index aa339bf2d6..8c6495a7cb 100644 --- a/ethdb/pebble/pebble.go +++ b/ethdb/pebble/pebble.go @@ -183,8 +183,8 @@ func New(file string, cache int, handles int, namespace string, readonly bool, e memTableSize = maxMemTableSize - 1 } - logger.Info("Allocated cache and file handles", "cache", common.StorageSize(cache*1024*1024), - "handles", handles, "memory table", common.StorageSize(memTableSize)) + logger.Info("Pebble db Allocated cache and file handles", "handles", handles, "block_cache_size", common.StorageSize(cache*1024*1024), + "memory_table_size", common.StorageSize(memTableSize)) db := &Database{ fn: file, @@ -309,23 +309,69 @@ func (d *Database) Has(key []byte) (bool, error) { // Get retrieves the given key if it's present in the key-value store. func (d *Database) Get(key []byte) ([]byte, error) { + var ( + step1Start time.Time + step1End time.Time + step2Start time.Time + step2End time.Time + step3Start time.Time + step3End time.Time + step4Start time.Time + step4End time.Time + keyLen int + valueLen int + ) + if metrics.EnabledExpensive { + start := time.Now() + defer func() { + ethdb.EthdbGetTimer.UpdateSince(start) + if time.Now().Sub(start) > 100*time.Millisecond { + d.log.Error("perf pebble read", + "key", key, + "key_len", keyLen, + "value_len", valueLen, + "step1", common.PrettyDuration(step1End.Sub(step1Start)), + "step2", common.PrettyDuration(step2End.Sub(step2Start)), + "step3", common.PrettyDuration(step3End.Sub(step3Start)), + "step4", common.PrettyDuration(step4End.Sub(step4Start))) + } + }() + } + keyLen = len(key) + step1Start = time.Now() d.quitLock.RLock() + step1End = time.Now() defer d.quitLock.RUnlock() if d.closed { return nil, pebble.ErrClosed } + step2Start = time.Now() + innerStart := time.Now() dat, closer, err := d.db.Get(key) + valueLen = len(dat) + ethdb.EthdbInnerGetTimer.UpdateSince(innerStart) + step2End = time.Now() + if err != nil { return nil, err } + step3Start = time.Now() ret := make([]byte, len(dat)) copy(ret, dat) + step3End = time.Now() + + step4Start = time.Now() closer.Close() + step4End = time.Now() return ret, nil } // Put inserts the given value into the key-value store. func (d *Database) Put(key []byte, value []byte) error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbPutTimer.UpdateSince(start) }() + } d.quitLock.RLock() defer d.quitLock.RUnlock() if d.closed { @@ -336,6 +382,10 @@ func (d *Database) Put(key []byte, value []byte) error { // Delete removes the key from the key-value store. func (d *Database) Delete(key []byte) error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbDeleteTimer.UpdateSince(start) }() + } d.quitLock.RLock() defer d.quitLock.RUnlock() if d.closed { @@ -494,6 +544,9 @@ func (d *Database) meter(refresh time.Duration, namespace string) { nonLevel0CompCount = int64(d.nonLevel0Comp.Load()) level0CompCount = int64(d.level0Comp.Load()) ) + fmt.Printf("loop print pebble db stats db_metrics=\n%v\n", stats) + d.log.Info("loop print pebble db stats", "comp_time", compTime, "write_delay_count", writeDelayCount, "write_delay_time", + writeDelayTime, "non_level0_comp_count", nonLevel0CompCount, "level0_comp_count", level0CompCount) writeDelayTimes[i%2] = writeDelayTime writeDelayCounts[i%2] = writeDelayCount compTimes[i%2] = compTime @@ -599,6 +652,10 @@ func (b *batch) ValueSize() int { // Write flushes any accumulated data to disk. func (b *batch) Write() error { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { ethdb.EthdbBatchWriteTimer.UpdateSince(start) }() + } b.db.quitLock.RLock() defer b.db.quitLock.RUnlock() if b.db.closed { diff --git a/metrics/config.go b/metrics/config.go index 2eb09fb48a..c91bf9de2a 100644 --- a/metrics/config.go +++ b/metrics/config.go @@ -37,8 +37,8 @@ type Config struct { // DefaultConfig is the default config for metrics used in go-ethereum. var DefaultConfig = Config{ - Enabled: false, - EnabledExpensive: false, + Enabled: true, + EnabledExpensive: true, HTTP: "127.0.0.1", Port: 6060, EnableInfluxDB: false, diff --git a/metrics/metrics.go b/metrics/metrics.go index fba6781b97..5d871f8df9 100644 --- a/metrics/metrics.go +++ b/metrics/metrics.go @@ -22,12 +22,12 @@ import ( // // This global kill-switch helps quantify the observer effect and makes // for less cluttered pprof profiles. -var Enabled = false +var Enabled = true // EnabledExpensive is a soft-flag meant for external packages to check if costly // metrics gathering is allowed or not. The goal is to separate standard metrics // for health monitoring and debug metrics that might impact runtime performance. -var EnabledExpensive = false +var EnabledExpensive = true // enablerFlags is the CLI flag names to use to enable metrics collections. var enablerFlags = []string{"metrics"} diff --git a/trie/trie.go b/trie/trie.go index a65bd596f5..321aaf4708 100644 --- a/trie/trie.go +++ b/trie/trie.go @@ -21,14 +21,22 @@ import ( "bytes" "errors" "fmt" + "time" "github.com/ethereum/go-ethereum/common" "github.com/ethereum/go-ethereum/core/types" "github.com/ethereum/go-ethereum/log" + "github.com/ethereum/go-ethereum/metrics" "github.com/ethereum/go-ethereum/trie/trienode" "github.com/ethereum/go-ethereum/triedb/database" ) +var ( + trieGetTimer = metrics.NewRegisteredTimer("trie/get/time", nil) + trieReaderGetTimer = metrics.NewRegisteredTimer("trie/reader/get/time", nil) + trieReaderTotalTimer = metrics.NewRegisteredTimer("trie/reader/total/time", nil) +) + // Trie is a Merkle Patricia Trie. Use New to create a trie that sits on // top of a database. Whenever trie performs a commit operation, the generated // nodes will be gathered and returned in a set. Once the trie is committed, @@ -146,6 +154,10 @@ func (t *Trie) Get(key []byte) ([]byte, error) { if t.committed { return nil, ErrCommitted } + if metrics.EnabledExpensive { + start := time.Now() + defer func() { trieGetTimer.UpdateSince(start) }() + } value, newroot, didResolve, err := t.get(t.root, keybytesToHex(key), 0) if err == nil && didResolve { t.root = newroot @@ -178,7 +190,11 @@ func (t *Trie) get(origNode node, key []byte, pos int) (value []byte, newnode no } return value, n, didResolve, err case hashNode: + start := time.Now() child, err := t.resolveAndTrack(n, key[:pos]) + if metrics.EnabledExpensive { + trieReaderGetTimer.UpdateSince(start) + } if err != nil { return nil, n, true, err } @@ -586,6 +602,10 @@ func (t *Trie) resolve(n node, prefix []byte) (node, error) { // node's original value. The rlp-encoded blob is preferred to be loaded from // database because it's easy to decode node while complex to encode node to blob. func (t *Trie) resolveAndTrack(n hashNode, prefix []byte) (node, error) { + if metrics.EnabledExpensive { + start := time.Now() + defer func() { trieReaderTotalTimer.UpdateSince(start) }() + } blob, err := t.reader.node(prefix, common.BytesToHash(n)) if err != nil { return nil, err