From 40de959ba9e017636c654f58bceb86c35e06de48 Mon Sep 17 00:00:00 2001 From: gop Date: Mon, 9 Sep 2024 14:15:05 -0500 Subject: [PATCH] Setting the append, process, ph creation times into the header --- core/slice.go | 25 ++++++++++++++++++++++++- core/types/wo.go | 34 +++++++++++++++++++++++++++++++++- quaistats/quaistats.go | 20 ++++++++++++-------- 3 files changed, 69 insertions(+), 10 deletions(-) diff --git a/core/slice.go b/core/slice.go index f886f93541..601af1d44f 100644 --- a/core/slice.go +++ b/core/slice.go @@ -40,7 +40,7 @@ const ( c_pEtxRetryThreshold = 10 // Number of pEtxNotFound return on a dom block before asking for pEtx/Rollup from sub c_currentStateComputeWindow = 20 // Number of blocks around the current header the state generation is always done c_inboundEtxCacheSize = 10 // Number of inboundEtxs to keep in cache so that, we don't recompute it every time dom is processed - + c_appendTimeCacheSize = 1000 ) // Core will implement the following interface to enable dom-sub communication @@ -96,6 +96,8 @@ type Slice struct { bestPh *types.WorkObject bestPhMu sync.RWMutex + + appendTimeCache *lru.Cache[common.Hash, time.Duration] } func NewSlice(db ethdb.Database, config *Config, txConfig *TxPoolConfig, txLookupLimit *uint64, isLocalBlock func(block *types.WorkObject) bool, chainConfig *params.ChainConfig, slicesRunning []common.Location, currentExpansionNumber uint8, genesisBlock *types.WorkObject, engine consensus.Engine, cacheConfig *CacheConfig, vmConfig vm.Config, genesis *Genesis, logger *log.Logger) (*Slice, error) { @@ -132,6 +134,8 @@ func NewSlice(db ethdb.Database, config *Config, txConfig *TxPoolConfig, txLooku sl.inboundEtxsCache, _ = lru.New[common.Hash, types.Transactions](c_inboundEtxCacheSize) + sl.appendTimeCache, _ = lru.New[common.Hash, time.Duration](c_appendTimeCacheSize) + sl.subInterface = make([]CoreBackend, common.MaxWidth) if err := sl.init(); err != nil { @@ -371,6 +375,10 @@ func (sl *Slice) Append(header *types.WorkObject, domTerminus common.Hash, domOr "t10": time10, }).Info("Times during append") + // store the append time for the block + appendTime := time.Since(start) + sl.appendTimeCache.Add(block.Hash(), appendTime) + sl.logger.WithFields(log.Fields{ "t5_1": time5_1, "t5_2": time5_2, @@ -1045,6 +1053,7 @@ func (sl *Slice) MakeFullPendingHeader(primePendingHeader, regionPendingHeader, } func (sl *Slice) GeneratePendingHeader(block *types.WorkObject, fill bool, stopChan chan struct{}) (*types.WorkObject, error) { + start := time.Now() // set the current header to this block switch sl.NodeCtx() { case common.PRIME_CTX: @@ -1066,6 +1075,7 @@ func (sl *Slice) GeneratePendingHeader(block *types.WorkObject, fill bool, stopC return nil, err } } + stateProcessTime := time.Since(start) if sl.bestPh == nil { return nil, errors.New("best ph is nil") } @@ -1077,11 +1087,24 @@ func (sl *Slice) GeneratePendingHeader(block *types.WorkObject, fill bool, stopC if bestPhCopy != nil && bestPhCopy.ParentHash(sl.NodeCtx()) == block.Hash() { return bestPhCopy, nil } + + phStart := time.Now() pendingHeader, err := sl.miner.worker.GeneratePendingHeader(block, fill, stopChan) if err != nil { return nil, err } + pendingHeaderCreationTime := time.Since(phStart) + if sl.NodeCtx() == common.ZONE_CTX { + // Set the block processing times before sending the block in chain head + // feed + appendTime, exists := sl.appendTimeCache.Peek(block.Hash()) + if exists { + block.SetAppendTime(appendTime) + } + block.SetStateProcessTime(stateProcessTime) + block.SetPendingHeaderCreationTime(pendingHeaderCreationTime) + sl.hc.chainHeadFeed.Send(ChainHeadEvent{block}) } return pendingHeader, nil diff --git a/core/types/wo.go b/core/types/wo.go index 3df8eaffa9..9f9364964b 100644 --- a/core/types/wo.go +++ b/core/types/wo.go @@ -27,7 +27,9 @@ type WorkObject struct { tx *Transaction // caches - appendTime atomic.Value + appendTime atomic.Value + stateProcessTime atomic.Value + pendingHeaderCreationTime atomic.Value // These fields are used to track // inter-peer block relay. @@ -118,6 +120,14 @@ func (wo *WorkObject) SetAppendTime(appendTime time.Duration) { wo.appendTime.Store(appendTime) } +func (wo *WorkObject) SetStateProcessTime(stateProcessTimes time.Duration) { + wo.stateProcessTime.Store(stateProcessTimes) +} + +func (wo *WorkObject) SetPendingHeaderCreationTime(pendingHeaderCreationTime time.Duration) { + wo.pendingHeaderCreationTime.Store(pendingHeaderCreationTime) +} + //////////////////////////////////////////////////////////// /////////////////// Work Object Generic Getters /////////////// //////////////////////////////////////////////////////////// @@ -133,6 +143,28 @@ func (wo *WorkObject) GetAppendTime() time.Duration { return -1 } +// GetStateProcessTime returns the stateProcessTIme of the block +// The stateProcessTime is computed on the first call and cached thereafter. +func (wo *WorkObject) GetStateProcessTime() time.Duration { + if stateProcessTime := wo.stateProcessTime.Load(); stateProcessTime != nil { + if val, ok := stateProcessTime.(time.Duration); ok { + return val + } + } + return -1 +} + +// GetPendingHeaderCreationTime returns the pendingHeaderTime of the block +// The pendingHeaderTime is computed on the first call and cached thereafter. +func (wo *WorkObject) GetPendingHeaderCreationTime() time.Duration { + if pendingHeaderCreationTime := wo.appendTime.Load(); pendingHeaderCreationTime != nil { + if val, ok := pendingHeaderCreationTime.(time.Duration); ok { + return val + } + } + return -1 +} + // Size returns the true RLP encoded storage size of the block, either by encoding // and returning it, or returning a previsouly cached value. func (wo *WorkObject) Size() common.StorageSize { diff --git a/quaistats/quaistats.go b/quaistats/quaistats.go index a9ca9efc35..a6112a9564 100644 --- a/quaistats/quaistats.go +++ b/quaistats/quaistats.go @@ -1023,9 +1023,11 @@ type blockDetailStats struct { // Everyone sends every block type blockAppendTime struct { - AppendTime time.Duration `json:"appendTime"` - BlockNumber *big.Int `json:"number"` - Chain string `json:"chain"` + AppendTime time.Duration `json:"appendTime"` + StateProcessTime time.Duration `json:"stateProcessTime"` + PendingHeaderCreationTime time.Duration `json:"pendingHeaderCreationTime"` + BlockNumber *big.Int `json:"number"` + Chain string `json:"chain"` } type nodeStats struct { @@ -1292,14 +1294,16 @@ func (s *Service) assembleBlockAppendTimeStats(block *types.WorkObject) *blockAp return nil } appendTime := block.GetAppendTime() - - s.backend.Logger().WithField("appendTime", appendTime.Microseconds()).Info("Raw Block Append Time") + stateProcessTime := block.GetStateProcessTime() + pendingHeaderCreationTime := block.GetPendingHeaderCreationTime() // Assemble and return the block stats return &blockAppendTime{ - AppendTime: appendTime, - BlockNumber: block.Number(s.backend.NodeCtx()), - Chain: s.backend.NodeLocation().Name(), + AppendTime: appendTime, + StateProcessTime: stateProcessTime, + PendingHeaderCreationTime: pendingHeaderCreationTime, + BlockNumber: block.Number(s.backend.NodeCtx()), + Chain: s.backend.NodeLocation().Name(), } }