Add more metrics on network latencies and import times

cl/monitor/metrics.go

@@ -24,6 +24,8 @@ var (
 	fullBlockProcessingTime        = metrics.GetOrCreateGauge("full_block_processing_time")
 	attestationBlockProcessingTime = metrics.GetOrCreateGauge("attestation_block_processing_time")
 	batchVerificationThroughput    = metrics.GetOrCreateGauge("aggregation_per_signature")
+	blobVerificationTime           = metrics.GetOrCreateGauge("blob_verification_time")
+	executionTime                  = metrics.GetOrCreateGauge("execution_time")
 
 	// Epoch processing metrics
 	epochProcessingTime                     = metrics.GetOrCreateGauge("epoch_processing_time")
@@ -45,6 +47,7 @@ var (
 	aggregateQuality75Per           = metrics.GetOrCreateGauge("aggregate_quality_75")
 	aggregateQualityMin             = metrics.GetOrCreateGauge("aggregate_quality_min")
 	aggregateQualityMax             = metrics.GetOrCreateGauge("aggregate_quality_max")
+	blockImportingLatency           = metrics.GetOrCreateGauge("block_importing_latency")
 
 	// Beacon chain metrics
 	committeeSize         = metrics.GetOrCreateGauge("committee_size")
@@ -219,3 +222,15 @@ func ObserveFrozenBlocks(count int) {
 func ObserveFrozenBlobs(count int) {
 	frozenBlobs.Set(float64(count))
 }
+
+func ObserveBlockImportingLatency(latency time.Time) {
+	blockImportingLatency.Set(microToMilli(time.Since(latency).Microseconds()))
+}
+
+func ObserveBlobVerificationTime(startTime time.Time) {
+	blobVerificationTime.Set(microToMilli(time.Since(startTime).Microseconds()))
+}
+
+func ObserveExecutionTime(startTime time.Time) {
+	executionTime.Set(microToMilli(time.Since(startTime).Microseconds()))
+}

cl/phase1/forkchoice/on_block.go

@@ -38,6 +38,7 @@ import (
 	"github.com/erigontech/erigon/cl/phase1/forkchoice/fork_graph"
 	"github.com/erigontech/erigon/cl/transition/impl/eth2/statechange"
 	"github.com/erigontech/erigon/cl/utils"
+	"github.com/erigontech/erigon/cl/utils/eth_clock"
 	"github.com/erigontech/erigon/core/types"
 	"github.com/erigontech/erigon/eth/ethutils"
 )
@@ -68,6 +69,15 @@ func verifyKzgCommitmentsAgainstTransactions(cfg *clparams.BeaconChainConfig, bl
 	return ethutils.ValidateBlobs(block.BlobGasUsed, cfg.MaxBlobGasPerBlock, cfg.MaxBlobsPerBlock, expectedBlobHashes, &transactions)
 }
 
+func collectOnBlockLatencyToUnixTime(ethClock eth_clock.EthereumClock, slot uint64) {
+	currSlot := ethClock.GetCurrentSlot()
+	if slot != currSlot {
+		return
+	}
+	initialSlotTime := ethClock.GetSlotTime(slot)
+	monitor.ObserveBlockImportingLatency(initialSlotTime)
+}
+
 func (f *ForkChoiceStore) OnBlock(ctx context.Context, block *cltypes.SignedBeaconBlock, newPayload, fullValidation, checkDataAvaiability bool) error {
 	f.mu.Lock()
 	defer f.mu.Unlock()
@@ -108,6 +118,9 @@ func (f *ForkChoiceStore) OnBlock(ctx context.Context, block *cltypes.SignedBeac
 			}
 			return fmt.Errorf("OnBlock: data is not available for block %x: %v", libcommon.Hash(blockRoot), err)
 		}
+		if f.highestSeen.Load() < block.Block.Slot {
+			collectOnBlockLatencyToUnixTime(f.ethClock, block.Block.Slot)
+		}
 	}
 
 	startEngine := time.Now()
@@ -117,6 +130,7 @@ func (f *ForkChoiceStore) OnBlock(ctx context.Context, block *cltypes.SignedBeac
 				return fmt.Errorf("OnBlock: failed to process kzg commitments: %v", err)
 			}
 		}
+		timeStartExec := time.Now()
 		payloadStatus, err := f.engine.NewPayload(ctx, block.Block.Body.ExecutionPayload, &block.Block.ParentRoot, versionedHashes)
 		switch payloadStatus {
 		case execution_client.PayloadStatusNotValidated:
@@ -144,6 +158,7 @@ func (f *ForkChoiceStore) OnBlock(ctx context.Context, block *cltypes.SignedBeac
 		if err != nil {
 			return fmt.Errorf("newPayload failed: %v", err)
 		}
+		monitor.ObserveExecutionTime(timeStartExec)
 	}
 	log.Trace("OnBlock: engine", "elapsed", time.Since(startEngine))
 	startStateProcess := time.Now()

cl/phase1/network/services/blob_sidecar_service.go

@@ -33,6 +33,7 @@ import (
 	"github.com/erigontech/erigon/cl/clparams"
 	"github.com/erigontech/erigon/cl/cltypes"
 	"github.com/erigontech/erigon/cl/fork"
+	"github.com/erigontech/erigon/cl/monitor"
 	"github.com/erigontech/erigon/cl/phase1/core/state"
 	"github.com/erigontech/erigon/cl/phase1/forkchoice"
 	"github.com/erigontech/erigon/cl/utils"
@@ -142,6 +143,7 @@ func (b *blobSidecarService) verifyAndStoreBlobSidecar(headState *state.CachingB
 		return ErrCommitmentsInclusionProofFailed
 	}
 
+	start := time.Now()
 	if err := kzgCtx.VerifyBlobKZGProof(gokzg4844.Blob(msg.Blob), gokzg4844.KZGCommitment(msg.KzgCommitment), gokzg4844.KZGProof(msg.KzgProof)); err != nil {
 		return fmt.Errorf("blob KZG proof verification failed: %v", err)
 	}
@@ -150,6 +152,7 @@ func (b *blobSidecarService) verifyAndStoreBlobSidecar(headState *state.CachingB
 			return err
 		}
 	}
+	monitor.ObserveBlobVerificationTime(start)
 	// operation is not thread safe from here.
 	return b.forkchoiceStore.AddPreverifiedBlobSidecar(msg)
 }