diff --git a/core/blockchain.go b/core/blockchain.go index 64345bc1a3..105650c2a0 100644 --- a/core/blockchain.go +++ b/core/blockchain.go @@ -1943,7 +1943,7 @@ func (bc *BlockChain) processBlock(parentRoot common.Hash, block *types.Block, s vmCfg.Tracer = nil bc.prefetcher.Prefetch(block, throwaway, vmCfg, &interrupt) - blockPrefetchExecuteTimer.Update(time.Since(start)) + blockPrefetchExecuteTimer.UpdateSince(start) if interrupt.Load() { blockPrefetchInterruptMeter.Mark(1) } @@ -2029,22 +2029,22 @@ func (bc *BlockChain) processBlock(parentRoot common.Hash, block *types.Block, s proctime := time.Since(startTime) // processing + validation + cross validation // 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) + accountReadTimer.Update(int64(statedb.AccountReads)) // Account reads are complete(in processing) + storageReadTimer.Update(int64(statedb.StorageReads)) // Storage reads are complete(in processing) if statedb.AccountLoaded != 0 { - accountReadSingleTimer.Update(statedb.AccountReads / time.Duration(statedb.AccountLoaded)) + accountReadSingleTimer.Update(int64(statedb.AccountReads) / int64(statedb.AccountLoaded)) } if statedb.StorageLoaded != 0 { - storageReadSingleTimer.Update(statedb.StorageReads / time.Duration(statedb.StorageLoaded)) + storageReadSingleTimer.Update(int64(statedb.StorageReads) / int64(statedb.StorageLoaded)) } - 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) - triehash := statedb.AccountHashes // The time spent on tries hashing - trieUpdate := statedb.AccountUpdates + statedb.StorageUpdates // The time spent on tries update - blockExecutionTimer.Update(ptime - (statedb.AccountReads + statedb.StorageReads)) // The time spent on EVM processing - blockValidationTimer.Update(vtime - (triehash + trieUpdate)) // The time spent on block validation - blockCrossValidationTimer.Update(xvtime) // The time spent on stateless cross validation + accountUpdateTimer.Update(int64(statedb.AccountUpdates)) // Account updates are complete(in validation) + storageUpdateTimer.Update(int64(statedb.StorageUpdates)) // Storage updates are complete(in validation) + accountHashTimer.Update(int64(statedb.AccountHashes)) // Account hashes are complete(in validation) + triehash := statedb.AccountHashes // The time spent on tries hashing + trieUpdate := statedb.AccountUpdates + statedb.StorageUpdates // The time spent on tries update + blockExecutionTimer.Update(int64(ptime - (statedb.AccountReads + statedb.StorageReads))) // The time spent on EVM processing + blockValidationTimer.Update(int64(vtime - (triehash + trieUpdate))) // The time spent on block validation + blockCrossValidationTimer.Update(int64(xvtime)) // The time spent on stateless cross validation // Write the block to the chain and get the status. var ( @@ -2061,12 +2061,12 @@ func (bc *BlockChain) processBlock(parentRoot common.Hash, block *types.Block, s return nil, err } // Update the metrics touched during block commit - accountCommitTimer.Update(statedb.AccountCommits) // Account commits are complete, we can mark them - storageCommitTimer.Update(statedb.StorageCommits) // Storage commits are complete, we can mark them - 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 + accountCommitTimer.Update(int64(statedb.AccountCommits)) // Account commits are complete, we can mark them + storageCommitTimer.Update(int64(statedb.StorageCommits)) // Storage commits are complete, we can mark them + snapshotCommitTimer.Update(int64(statedb.SnapshotCommits)) // Snapshot commits are complete, we can mark them + triedbCommitTimer.Update(int64(statedb.TrieDBCommits)) // Trie database commits are complete, we can mark them - blockWriteTimer.Update(time.Since(wstart) - max(statedb.AccountCommits, statedb.StorageCommits) /* concurrent */ - statedb.SnapshotCommits - statedb.TrieDBCommits) + blockWriteTimer.Update(int64(time.Since(wstart) - max(statedb.AccountCommits, statedb.StorageCommits) /* concurrent */ - statedb.SnapshotCommits - statedb.TrieDBCommits)) blockInsertTimer.UpdateSince(startTime) return &blockProcessingResult{ diff --git a/core/state/snapshot/difflayer.go b/core/state/snapshot/difflayer.go index 28957051d4..cea839b73f 100644 --- a/core/state/snapshot/difflayer.go +++ b/core/state/snapshot/difflayer.go @@ -164,7 +164,7 @@ func (dl *diffLayer) rebloom(origin *diskLayer) { defer dl.lock.Unlock() defer func(start time.Time) { - snapshotBloomIndexTimer.Update(time.Since(start)) + snapshotBloomIndexTimer.UpdateSince(start) }(time.Now()) // Inject the new origin that triggered the rebloom diff --git a/metrics/internal/sampledata.go b/metrics/internal/sampledata.go index de9b207b6d..101d31a617 100644 --- a/metrics/internal/sampledata.go +++ b/metrics/internal/sampledata.go @@ -53,12 +53,12 @@ func ExampleMetrics() metrics.Registry { registry.Register("test/meter", metrics.NewInactiveMeter()) { timer := metrics.NewRegisteredResettingTimer("test/resetting_timer", registry) - timer.Update(10 * time.Millisecond) - timer.Update(11 * time.Millisecond) - timer.Update(12 * time.Millisecond) - timer.Update(120 * time.Millisecond) - timer.Update(13 * time.Millisecond) - timer.Update(14 * time.Millisecond) + timer.Update(int64(10 * time.Millisecond)) + timer.Update(int64(11 * time.Millisecond)) + timer.Update(int64(12 * time.Millisecond)) + timer.Update(int64(120 * time.Millisecond)) + timer.Update(int64(13 * time.Millisecond)) + timer.Update(int64(14 * time.Millisecond)) } { timer := metrics.NewRegisteredTimer("test/timer", registry) diff --git a/metrics/resetting_timer.go b/metrics/resetting_timer.go index 66458bdb91..f21f68a612 100644 --- a/metrics/resetting_timer.go +++ b/metrics/resetting_timer.go @@ -53,27 +53,20 @@ func (t *ResettingTimer) Snapshot() *ResettingTimerSnapshot { return snapshot } -// Time records the duration of the execution of the given function. -func (t *ResettingTimer) Time(f func()) { - ts := time.Now() - f() - t.Update(time.Since(ts)) -} - // Update records the duration of an event. -func (t *ResettingTimer) Update(d time.Duration) { +func (t *ResettingTimer) Update(d int64) { if !metricsEnabled { return } t.mutex.Lock() defer t.mutex.Unlock() - t.values = append(t.values, int64(d)) - t.sum += int64(d) + t.values = append(t.values, d) + t.sum += d } // UpdateSince records the duration of an event that started at a time and ends now. func (t *ResettingTimer) UpdateSince(ts time.Time) { - t.Update(time.Since(ts)) + t.Update(int64(time.Since(ts))) } // ResettingTimerSnapshot is a point-in-time copy of another ResettingTimer. @@ -104,7 +97,6 @@ func (t *ResettingTimerSnapshot) Mean() float64 { if !t.calculated { t.calc(nil) } - return t.mean } @@ -134,4 +126,5 @@ func (t *ResettingTimerSnapshot) calc(percentiles []float64) { } t.min = t.values[0] t.max = t.values[len(t.values)-1] + t.calculated = true } diff --git a/metrics/resetting_timer_test.go b/metrics/resetting_timer_test.go index 4571fc8eb0..a41a5e65ca 100644 --- a/metrics/resetting_timer_test.go +++ b/metrics/resetting_timer_test.go @@ -2,7 +2,6 @@ package metrics import ( "testing" - "time" ) func TestResettingTimer(t *testing.T) { @@ -68,7 +67,7 @@ func TestResettingTimer(t *testing.T) { } for _, v := range tt.values { - timer.Update(time.Duration(v)) + timer.Update(v) } snap := timer.Snapshot() @@ -160,7 +159,7 @@ func TestResettingTimerWithFivePercentiles(t *testing.T) { } for _, v := range tt.values { - timer.Update(time.Duration(v)) + timer.Update(v) } snap := timer.Snapshot() diff --git a/triedb/hashdb/database.go b/triedb/hashdb/database.go index 38392aa519..e76659d060 100644 --- a/triedb/hashdb/database.go +++ b/triedb/hashdb/database.go @@ -266,7 +266,7 @@ func (db *Database) Dereference(root common.Hash) { db.gcsize += storage - db.dirtiesSize db.gctime += time.Since(start) - memcacheGCTimeTimer.Update(time.Since(start)) + memcacheGCTimeTimer.UpdateSince(start) memcacheGCBytesMeter.Mark(int64(storage - db.dirtiesSize)) memcacheGCNodesMeter.Mark(int64(nodes - len(db.dirties))) @@ -384,7 +384,7 @@ func (db *Database) Cap(limit common.StorageSize) error { db.flushsize += storage - db.dirtiesSize db.flushtime += time.Since(start) - memcacheFlushTimeTimer.Update(time.Since(start)) + memcacheFlushTimeTimer.UpdateSince(start) memcacheFlushBytesMeter.Mark(int64(storage - db.dirtiesSize)) memcacheFlushNodesMeter.Mark(int64(nodes - len(db.dirties))) @@ -428,7 +428,7 @@ func (db *Database) Commit(node common.Hash, report bool) error { batch.Reset() // Reset the storage counters and bumped metrics - memcacheCommitTimeTimer.Update(time.Since(start)) + memcacheCommitTimeTimer.UpdateSince(start) memcacheCommitBytesMeter.Mark(int64(storage - db.dirtiesSize)) memcacheCommitNodesMeter.Mark(int64(nodes - len(db.dirties)))