feat(metrics):migrate metrics from develop branch (#910)

migrate metrics from develop

Co-authored-by: HAOYUatHZ <37070449+HAOYUatHZ@users.noreply.github.com>

core/block_validator.go

@@ -20,6 +20,7 @@ import (
 	"errors"
 	"fmt"
 	"sync"
+	"time"
 
 	"github.com/scroll-tech/go-ethereum/consensus"
 	"github.com/scroll-tech/go-ethereum/core/rawdb"
@@ -27,11 +28,20 @@ import (
 	"github.com/scroll-tech/go-ethereum/core/types"
 	"github.com/scroll-tech/go-ethereum/ethdb"
 	"github.com/scroll-tech/go-ethereum/log"
+	"github.com/scroll-tech/go-ethereum/metrics"
 	"github.com/scroll-tech/go-ethereum/params"
 	"github.com/scroll-tech/go-ethereum/rollup/circuitcapacitychecker"
 	"github.com/scroll-tech/go-ethereum/trie"
 )
 
+var (
+	validateL1MessagesTimer     = metrics.NewRegisteredTimer("validator/l1msg", nil)
+	validateRowConsumptionTimer = metrics.NewRegisteredTimer("validator/rowconsumption", nil)
+	validateTraceTimer          = metrics.NewRegisteredTimer("validator/trace", nil)
+	validateLockTimer           = metrics.NewRegisteredTimer("validator/lock", nil)
+	validateCccTimer            = metrics.NewRegisteredTimer("validator/ccc", nil)
+)
+
 // BlockValidator is responsible for validating block headers, uncles and
 // processed state.
 //
@@ -182,6 +192,10 @@ func (v *BlockValidator) ValidateBody(block *types.Block) error {
 // - L1 messages follow the QueueIndex order.
 // - The L1 messages included in the block match the node's view of the L1 ledger.
 func (v *BlockValidator) ValidateL1Messages(block *types.Block) error {
+	defer func(t0 time.Time) {
+		validateL1MessagesTimer.Update(time.Since(t0))
+	}(time.Now())
+
 	// skip DB read if the block contains no L1 messages
 	if !block.ContainsL1Messages() {
 		return nil
@@ -334,6 +348,10 @@ func (v *BlockValidator) createTraceEnvAndGetBlockTrace(block *types.Block) (*ty
 }
 
 func (v *BlockValidator) validateCircuitRowConsumption(block *types.Block) (*types.RowConsumption, error) {
+	defer func(t0 time.Time) {
+		validateRowConsumptionTimer.Update(time.Since(t0))
+	}(time.Now())
+
 	log.Trace(
 		"Validator apply ccc for block",
 		"id", v.circuitCapacityChecker.ID,
@@ -342,17 +360,23 @@ func (v *BlockValidator) validateCircuitRowConsumption(block *types.Block) (*typ
 		"len(txs)", block.Transactions().Len(),
 	)
 
+	traceStartTime := time.Now()
 	traces, err := v.createTraceEnvAndGetBlockTrace(block)
 	if err != nil {
 		return nil, err
 	}
+	validateTraceTimer.Update(time.Since(traceStartTime))
 
+	lockStartTime := time.Now()
 	v.cMu.Lock()
 	defer v.cMu.Unlock()
+	validateLockTimer.Update(time.Since(lockStartTime))
 
+	cccStartTime := time.Now()
 	v.circuitCapacityChecker.Reset()
 	log.Trace("Validator reset ccc", "id", v.circuitCapacityChecker.ID)
 	rc, err := v.circuitCapacityChecker.ApplyBlock(traces)
+	validateCccTimer.Update(time.Since(cccStartTime))
 
 	log.Trace(
 		"Validator apply ccc for block result",

core/blockchain.go

@@ -59,6 +59,9 @@ var (
 	headFastBlockGauge      = metrics.NewRegisteredGauge("chain/head/receipt", nil)
 	headFinalizedBlockGauge = metrics.NewRegisteredGauge("chain/head/finalized", nil)
 	headSafeBlockGauge      = metrics.NewRegisteredGauge("chain/head/safe", nil)
+	headTimeGapGauge        = metrics.NewRegisteredGauge("chain/head/timegap", nil)
+
+	l2BaseFeeGauge = metrics.NewRegisteredGauge("chain/fees/l2basefee", nil)
 
 	chainInfoGauge = metrics.NewRegisteredGaugeInfo("chain/info", nil)
 
@@ -1434,6 +1437,19 @@ func (bc *BlockChain) writeKnownBlock(block *types.Block) error {
 // writeBlockWithState writes block, metadata and corresponding state data to the
 // database.
 func (bc *BlockChain) writeBlockWithState(block *types.Block, receipts []*types.Receipt, state *state.StateDB) error {
+	// Note latest seen L2 base fee
+	if block.BaseFee() != nil {
+		l2BaseFeeGauge.Update(block.BaseFee().Int64())
+	} else {
+		l2BaseFeeGauge.Update(0)
+	}
+
+	parent := bc.GetHeaderByHash(block.ParentHash())
+	// block.Time is guaranteed to be larger than parent.Time,
+	// and the time gap should fit into int64.
+	gap := int64(block.Time() - parent.Time)
+	headTimeGapGauge.Update(gap)
+
 	// Calculate the total difficulty of the block
 	ptd := bc.GetTd(block.ParentHash(), block.NumberU64()-1)
 	if ptd == nil {

core/state_processor.go

@@ -20,6 +20,7 @@ import (
 	"errors"
 	"fmt"
 	"math/big"
+	"time"
 
 	"github.com/scroll-tech/go-ethereum/common"
 	"github.com/scroll-tech/go-ethereum/consensus"
@@ -28,10 +29,20 @@ import (
 	"github.com/scroll-tech/go-ethereum/core/types"
 	"github.com/scroll-tech/go-ethereum/core/vm"
 	"github.com/scroll-tech/go-ethereum/crypto"
+	"github.com/scroll-tech/go-ethereum/metrics"
 	"github.com/scroll-tech/go-ethereum/params"
 	"github.com/scroll-tech/go-ethereum/rollup/fees"
 )
 
+var (
+	processorBlockTransactionGauge = metrics.NewRegisteredGauge("processor/block/transactions", nil)
+	processBlockTimer              = metrics.NewRegisteredTimer("processor/block/process", nil)
+	finalizeBlockTimer             = metrics.NewRegisteredTimer("processor/block/finalize", nil)
+	applyTransactionTimer          = metrics.NewRegisteredTimer("processor/tx/apply", nil)
+	applyMessageTimer              = metrics.NewRegisteredTimer("processor/tx/msg/apply", nil)
+	updateStatedbTimer             = metrics.NewRegisteredTimer("processor/tx/statedb/update", nil)
+)
+
 // StateProcessor is a basic Processor, which takes care of transitioning
 // state from one point to another.
 //
@@ -59,6 +70,10 @@ func NewStateProcessor(config *params.ChainConfig, bc *BlockChain, engine consen
 // returns the amount of gas that was used in the process. If any of the
 // transactions failed to execute due to insufficient gas it will return an error.
 func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg vm.Config) (types.Receipts, []*types.Log, uint64, error) {
+	defer func(t0 time.Time) {
+		processBlockTimer.Update(time.Since(t0))
+	}(time.Now())
+
 	var (
 		receipts    types.Receipts
 		usedGas     = new(uint64)
@@ -84,6 +99,7 @@ func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg
 	if beaconRoot := block.BeaconRoot(); beaconRoot != nil {
 		ProcessBeaconBlockRoot(*beaconRoot, vmenv, statedb)
 	}
+	processorBlockTransactionGauge.Update(int64(block.Transactions().Len()))
 	// Iterate over and process the individual transactions
 	for i, tx := range block.Transactions() {
 		msg, err := TransactionToMessage(tx, signer, header.BaseFee)
@@ -104,12 +120,18 @@ func (p *StateProcessor) Process(block *types.Block, statedb *state.StateDB, cfg
 		return nil, nil, 0, errors.New("withdrawals before shanghai")
 	}
 	// Finalize the block, applying any consensus engine specific extras (e.g. block rewards)
+	finalizeBlockStartTime := time.Now()
 	p.engine.Finalize(p.bc, header, statedb, block.Transactions(), block.Uncles(), withdrawals)
+	finalizeBlockTimer.Update(time.Since(finalizeBlockStartTime))
 
 	return receipts, allLogs, *usedGas, nil
 }
 
 func applyTransaction(msg *Message, config *params.ChainConfig, gp *GasPool, statedb *state.StateDB, blockNumber *big.Int, blockHash common.Hash, tx *types.Transaction, usedGas *uint64, evm *vm.EVM) (*types.Receipt, error) {
+	defer func(t0 time.Time) {
+		applyTransactionTimer.Update(time.Since(t0))
+	}(time.Now())
+
 	// Create a new context to be used in the EVM environment.
 	txContext := NewEVMTxContext(msg)
 	evm.Reset(txContext, statedb)
@@ -120,18 +142,22 @@ func applyTransaction(msg *Message, config *params.ChainConfig, gp *GasPool, sta
 	}
 
 	// Apply the transaction to the current state (included in the env).
+	applyMessageStartTime := time.Now()
 	result, err := ApplyMessage(evm, msg, gp, l1DataFee)
+	applyMessageTimer.Update(time.Since(applyMessageStartTime))
 	if err != nil {
 		return nil, err
 	}
 
 	// Update the state with pending changes.
 	var root []byte
+	updateStatedbStartTime := time.Now()
 	if config.IsByzantium(blockNumber) {
 		statedb.Finalise(true)
 	} else {
 		root = statedb.IntermediateRoot(config.IsEIP158(blockNumber)).Bytes()
 	}
+	updateStatedbTimer.Update(time.Since(updateStatedbStartTime))
 	*usedGas += result.UsedGas
 
 	// Create a new receipt for the transaction, storing the intermediate root and gas used

core/state_transition.go

@@ -21,15 +21,22 @@ import (
 	"fmt"
 	"math"
 	"math/big"
+	"time"
 
 	"github.com/scroll-tech/go-ethereum/common"
 	cmath "github.com/scroll-tech/go-ethereum/common/math"
 	"github.com/scroll-tech/go-ethereum/core/types"
 	"github.com/scroll-tech/go-ethereum/core/vm"
 	"github.com/scroll-tech/go-ethereum/log"
+	"github.com/scroll-tech/go-ethereum/metrics"
 	"github.com/scroll-tech/go-ethereum/params"
 )
 
+var (
+	stateTransitionEvmCallExecutionTimer = metrics.NewRegisteredTimer("state/transition/call_execution", nil)
+	stateTransitionApplyMessageTimer     = metrics.NewRegisteredTimer("state/transition/apply_message", nil)
+)
+
 // ExecutionResult includes all output after executing given evm
 // message no matter the execution itself is successful or not.
 type ExecutionResult struct {
@@ -196,6 +203,10 @@ func TransactionToMessage(tx *types.Transaction, s types.Signer, baseFee *big.In
 // indicates a core error meaning that the message would always fail for that particular
 // state and would never be accepted within a block.
 func ApplyMessage(evm *vm.EVM, msg *Message, gp *GasPool, l1DataFee *big.Int) (*ExecutionResult, error) {
+	defer func(t time.Time) {
+		stateTransitionApplyMessageTimer.Update(time.Since(t))
+	}(time.Now())
+
 	return NewStateTransition(evm, msg, gp, l1DataFee).TransitionDb()
 }
 
@@ -463,7 +474,9 @@ func (st *StateTransition) TransitionDb() (*ExecutionResult, error) {
 	} else {
 		// Increment the nonce for the next transaction
 		st.state.SetNonce(msg.From, st.state.GetNonce(sender.Address())+1)
+		evmCallStart := time.Now()
 		ret, st.gasRemaining, vmerr = st.evm.Call(sender, st.to(), msg.Data, st.gasRemaining, msg.Value)
+		stateTransitionEvmCallExecutionTimer.Update(time.Since(evmCallStart))
 	}
 
 	// no refunds for l1 messages

rollup/sync_service/sync_service.go

@@ -11,6 +11,7 @@ import (
 	"github.com/scroll-tech/go-ethereum/ethdb"
 	"github.com/scroll-tech/go-ethereum/event"
 	"github.com/scroll-tech/go-ethereum/log"
+	"github.com/scroll-tech/go-ethereum/metrics"
 	"github.com/scroll-tech/go-ethereum/node"
 	"github.com/scroll-tech/go-ethereum/params"
 )
@@ -35,6 +36,10 @@ const (
 	DbWriteThresholdBlocks = 1000
 )
 
+var (
+	l1MessageTotalCounter = metrics.NewRegisteredCounter("rollup/l1/message", nil)
+)
+
 // SyncService collects all L1 messages and stores them in a local database.
 type SyncService struct {
 	ctx                  context.Context
@@ -172,6 +177,7 @@ func (s *SyncService) fetchMessages() {
 		numBlocksPendingDbWrite = 0
 
 		if numMessagesPendingDbWrite > 0 {
+			l1MessageTotalCounter.Inc(int64(numMessagesPendingDbWrite))
 			s.msgCountFeed.Send(core.NewL1MsgsEvent{Count: numMessagesPendingDbWrite})
 			numMessagesPendingDbWrite = 0
 		}

rollup/tracing/tracing.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"runtime"
 	"sync"
+	"time"
 
 	"github.com/scroll-tech/go-ethereum/common"
 	"github.com/scroll-tech/go-ethereum/common/hexutil"
@@ -21,12 +22,22 @@ import (
 	"github.com/scroll-tech/go-ethereum/eth/tracers/native"
 	"github.com/scroll-tech/go-ethereum/ethdb"
 	"github.com/scroll-tech/go-ethereum/log"
+	"github.com/scroll-tech/go-ethereum/metrics"
 	"github.com/scroll-tech/go-ethereum/params"
 	"github.com/scroll-tech/go-ethereum/rollup/fees"
 	"github.com/scroll-tech/go-ethereum/rollup/rcfg"
 	"github.com/scroll-tech/go-ethereum/rollup/withdrawtrie"
 )
 
+var (
+	getTxResultTimer             = metrics.NewRegisteredTimer("rollup/tracing/get_tx_result", nil)
+	getTxResultApplyMessageTimer = metrics.NewRegisteredTimer("rollup/tracing/get_tx_result/apply_message", nil)
+	getTxResultZkTrieBuildTimer  = metrics.NewRegisteredTimer("rollup/tracing/get_tx_result/zk_trie_build", nil)
+	getTxResultTracerResultTimer = metrics.NewRegisteredTimer("rollup/tracing/get_tx_result/tracer_result", nil)
+	feedTxToTracerTimer          = metrics.NewRegisteredTimer("rollup/tracing/feed_tx_to_tracer", nil)
+	fillBlockTraceTimer          = metrics.NewRegisteredTimer("rollup/tracing/fill_block_trace", nil)
+)
+
 // TracerWrapper implements ScrollTracerWrapper interface
 type TracerWrapper struct{}
 
@@ -191,7 +202,11 @@ func (env *TraceEnv) GetBlockTrace(block *types.Block) (*types.BlockTrace, error
 	for th := 0; th < threads; th++ {
 		pend.Add(1)
 		go func() {
-			defer pend.Done()
+			defer func(t time.Time) {
+				pend.Done()
+				getTxResultTimer.Update(time.Since(t))
+			}(time.Now())
+
 			// Fetch and execute the next transaction trace tasks
 			for task := range jobs {
 				if err := env.getTxResult(task.statedb, task.index, block); err != nil {
@@ -213,27 +228,29 @@ func (env *TraceEnv) GetBlockTrace(block *types.Block) (*types.BlockTrace, error
 
 	// Feed the transactions into the tracers and return
 	var failed error
-	for i, tx := range txs {
-		// Send the trace task over for execution
-		jobs <- &txTraceTask{statedb: env.state.Copy(), index: i}
+	common.WithTimer(feedTxToTracerTimer, func() {
+		for i, tx := range txs {
+			// Send the trace task over for execution
+			jobs <- &txTraceTask{statedb: env.state.Copy(), index: i}
 
-		// Generate the next state snapshot fast without tracing
-		msg, _ := core.TransactionToMessage(tx, env.signer, block.BaseFee())
-		env.state.SetTxContext(tx.Hash(), i)
-		vmenv := vm.NewEVM(env.blockCtx, core.NewEVMTxContext(msg), env.state, env.chainConfig, vm.Config{})
-		l1DataFee, err := fees.CalculateL1DataFee(tx, env.state, env.chainConfig, block.Number())
-		if err != nil {
-			failed = err
-			break
+			// Generate the next state snapshot fast without tracing
+			msg, _ := core.TransactionToMessage(tx, env.signer, block.BaseFee())
+			env.state.SetTxContext(tx.Hash(), i)
+			vmenv := vm.NewEVM(env.blockCtx, core.NewEVMTxContext(msg), env.state, env.chainConfig, vm.Config{})
+			l1DataFee, err := fees.CalculateL1DataFee(tx, env.state, env.chainConfig, block.Number())
+			if err != nil {
+				failed = err
+				break
+			}
+			if _, err = core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.GasLimit), l1DataFee); err != nil {
+				failed = err
+				break
+			}
+			if env.finaliseStateAfterApply {
+				env.state.Finalise(vmenv.ChainConfig().IsEIP158(block.Number()))
+			}
 		}
-		if _, err = core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.GasLimit), l1DataFee); err != nil {
-			failed = err
-			break
-		}
-		if env.finaliseStateAfterApply {
-			env.state.Finalise(vmenv.ChainConfig().IsEIP158(block.Number()))
-		}
-	}
+	})
 	close(jobs)
 	pend.Wait()
 
@@ -301,6 +318,7 @@ func (env *TraceEnv) getTxResult(state *state.StateDB, index int, block *types.B
 		}
 	}
 
+	applyMessageStart := time.Now()
 	structLogger := logger.NewStructLogger(env.logConfig)
 	tracerContext := tracers.Context{
 		BlockHash: block.Hash(),
@@ -331,8 +349,10 @@ func (env *TraceEnv) getTxResult(state *state.StateDB, index int, block *types.B
 	}
 	result, err := core.ApplyMessage(vmenv, msg, new(core.GasPool).AddGas(msg.GasLimit), l1DataFee)
 	if err != nil {
+		getTxResultApplyMessageTimer.UpdateSince(applyMessageStart)
 		return err
 	}
+	getTxResultApplyMessageTimer.UpdateSince(applyMessageStart)
 	// If the result contains a revert reason, return it.
 	returnVal := result.Return()
 	if len(result.Revert()) > 0 {
@@ -407,6 +427,7 @@ func (env *TraceEnv) getTxResult(state *state.StateDB, index int, block *types.B
 		env.pMu.Unlock()
 	}
 
+	zkTrieBuildStart := time.Now()
 	proofStorages := structLogger.UpdatedStorages()
 	for addr, keys := range proofStorages {
 		if _, existed := txStorageTrace.StorageProofs[addr.String()]; !existed {
@@ -476,11 +497,14 @@ func (env *TraceEnv) getTxResult(state *state.StateDB, index int, block *types.B
 			env.sMu.Unlock()
 		}
 	}
+	getTxResultZkTrieBuildTimer.UpdateSince(zkTrieBuildStart)
 
+	tracerResultTimer := time.Now()
 	callTrace, err := callTracer.GetResult()
 	if err != nil {
 		return fmt.Errorf("failed to get callTracer result: %w", err)
 	}
+	getTxResultTracerResultTimer.UpdateSince(tracerResultTimer)
 
 	env.ExecutionResults[index] = &types.ExecutionResult{
 		From:           sender,
@@ -501,6 +525,10 @@ func (env *TraceEnv) getTxResult(state *state.StateDB, index int, block *types.B
 
 // fillBlockTrace content after all the txs are finished running.
 func (env *TraceEnv) fillBlockTrace(block *types.Block) (*types.BlockTrace, error) {
+	defer func(t time.Time) {
+		fillBlockTraceTimer.Update(time.Since(t))
+	}(time.Now())
+
 	statedb := env.state
 
 	txs := make([]*types.TransactionData, block.Transactions().Len())