From 99be105427c00312588c4c08f4bb4807ac0fd274 Mon Sep 17 00:00:00 2001
From: Jerry <jerrycgh@gmail.com>
Date: Wed, 15 Jan 2025 14:39:44 -0800
Subject: [PATCH] Make block execution timer more accurate

Block execution contains the time it takes to fetch state sync data from heimdall, which sometimes returns data with long latency (> 1s). When the latency is significant, the chain execution time will be affected and become inaccurate. This PR isolate the time of heimdall requests from block execution.
---
 consensus/bor/bor.go  | 3 +++
 core/blockchain.go    | 6 ++++--
 core/state/statedb.go | 3 +++
 3 files changed, 10 insertions(+), 2 deletions(-)

diff --git a/consensus/bor/bor.go b/consensus/bor/bor.go
index 3bf38f6ac0..829a5f67c4 100644
--- a/consensus/bor/bor.go
+++ b/consensus/bor/bor.go
@@ -832,6 +832,7 @@ func (c *Bor) Finalize(chain consensus.ChainHeaderReader, header *types.Header,
 	}
 
 	if IsSprintStart(headerNumber, c.config.CalculateSprint(headerNumber)) {
+		start := time.Now()
 		ctx := context.Background()
 		cx := statefull.ChainContext{Chain: chain, Bor: c}
 		// check and commit span
@@ -848,6 +849,8 @@ func (c *Bor) Finalize(chain consensus.ChainHeaderReader, header *types.Header,
 				return
 			}
 		}
+
+		state.BorConsensusTime = time.Since(start)
 	}
 
 	if err = c.changeContractCodeIfNeeded(headerNumber, state); err != nil {
diff --git a/core/blockchain.go b/core/blockchain.go
index 6c849f8e82..3d8a9a4853 100644
--- a/core/blockchain.go
+++ b/core/blockchain.go
@@ -82,6 +82,8 @@ var (
 	snapshotStorageReadTimer = metrics.NewRegisteredResettingTimer("chain/snapshot/storage/reads", nil)
 	snapshotCommitTimer      = metrics.NewRegisteredResettingTimer("chain/snapshot/commits", nil)
 
+	borConsensusTime = metrics.NewRegisteredTimer("chain/bor/consensus", nil)
+
 	blockImportTimer  = metrics.NewRegisteredMeter("chain/imports", nil)
 	triedbCommitTimer = metrics.NewRegisteredTimer("chain/triedb/commits", nil)
 
@@ -2355,7 +2357,7 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool) (int, error)
 			bc.stateSyncFeed.Send(StateSyncEvent{Data: data})
 		}
 		// BOR
-		ptime := time.Since(pstart) - vtime
+		ptime := time.Since(pstart) - vtime - statedb.BorConsensusTime
 
 		proctime := time.Since(start) // processing + validation
 
@@ -2374,7 +2376,7 @@ func (bc *BlockChain) insertChain(chain types.Blocks, setHead bool) (int, error)
 		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
-
+		borConsensusTime.Update(statedb.BorConsensusTime)               // The time spent on bor consensus (span + state sync)
 		// Write the block to the chain and get the status.
 		var (
 			wstart = time.Now()
diff --git a/core/state/statedb.go b/core/state/statedb.go
index f1cf27795d..709658f813 100644
--- a/core/state/statedb.go
+++ b/core/state/statedb.go
@@ -174,6 +174,9 @@ type StateDB struct {
 	SnapshotCommits      time.Duration
 	TrieDBCommits        time.Duration
 
+	// Bor metrics
+	BorConsensusTime time.Duration
+
 	AccountUpdated int
 	StorageUpdated atomic.Int64
 	AccountDeleted int