diff --git a/beacon_chain/consensus_object_pools/block_clearance.nim b/beacon_chain/consensus_object_pools/block_clearance.nim index d7e64a4de..bd4e385da 100644 --- a/beacon_chain/consensus_object_pools/block_clearance.nim +++ b/beacon_chain/consensus_object_pools/block_clearance.nim @@ -78,7 +78,8 @@ proc addResolvedBlock( dag: var ChainDAGRef, quarantine: var QuarantineRef, state: var StateData, trustedBlock: TrustedSignedBeaconBlock, parent: BlockRef, cache: var StateCache, - onBlockAdded: OnBlockAdded + onBlockAdded: OnBlockAdded, stateDataDur, sigVerifyDur, + stateVerifyDur: Duration ) = # TODO move quarantine processing out of here doAssert getStateField(state, slot) == trustedBlock.message.slot, @@ -108,7 +109,7 @@ proc addResolvedBlock( # Resolved blocks should be stored in database dag.putBlock(trustedBlock) - let putTick = Moment.now() + let putBlockTick = Moment.now() var foundHead: BlockRef for head in dag.heads.mitems(): @@ -127,8 +128,9 @@ proc addResolvedBlock( blck = shortLog(trustedBlock.message), blockRoot = shortLog(blockRoot), heads = dag.heads.len(), + stateDataDur, sigVerifyDur, stateVerifyDur, epochRefDur = epochRefTick - startTick, - putBlockDur = putTick - epochRefTick + putBlockDur = putBlockTick - epochRefTick state.blck = blockRef @@ -221,13 +223,14 @@ proc addRawBlockKnownParent( # The block is resolved, now it's time to validate it to ensure that the # blocks we add to the database are clean for the given state - + let startTick = Moment.now() # TODO if the block is from the future, we should not be resolving it (yet), # but maybe we should use it as a hint that our clock is wrong? var cache = StateCache() updateStateData( dag, dag.clearanceState, parent.atSlot(signedBlock.message.slot), true, cache) + let stateDataTick = Moment.now() # First batch verify crypto if skipBLSValidation notin dag.updateFlags: @@ -240,19 +243,23 @@ proc addRawBlockKnownParent( if not quarantine.batchVerify(sigs): return err((ValidationResult.Reject, Invalid)) + let sigVerifyTick = Moment.now() static: doAssert sizeof(SignedBeaconBlock) == sizeof(SigVerifiedSignedBeaconBlock) let (valRes, blockErr) = addRawBlockCheckStateTransition( dag, quarantine, signedBlock.asSigVerified(), cache) if valRes != ValidationResult.Accept: return err((valRes, blockErr)) - + let stateVerifyTick = Moment.now() # Careful, clearanceState.data has been updated but not blck - we need to # create the BlockRef first! addResolvedBlock( dag, quarantine, dag.clearanceState, signedBlock.asTrusted(), parent, cache, - onBlockAdded) + onBlockAdded, + stateDataDur = stateDataTick - startTick, + sigVerifyDur = sigVerifyTick - stateDataTick, + stateVerifyDur = stateVerifyTick - sigVerifyTick) return ok dag.clearanceState.blck diff --git a/beacon_chain/consensus_object_pools/blockchain_dag.nim b/beacon_chain/consensus_object_pools/blockchain_dag.nim index 23d3c1b60..0dc385c03 100644 --- a/beacon_chain/consensus_object_pools/blockchain_dag.nim +++ b/beacon_chain/consensus_object_pools/blockchain_dag.nim @@ -919,12 +919,10 @@ proc pruneBlocksDAG(dag: ChainDAGRef) = dag.heads.del(n) - let dagPruningDur = Moment.now() - startTick - debug "Pruned the blockchain DAG", currentCandidateHeads = dag.heads.len, prunedHeads = hlen - dag.heads.len, - dagPruningDur + dagPruneDur = Moment.now() - startTick func needStateCachesAndForkChoicePruning*(dag: ChainDAGRef): bool = dag.lastPrunePoint != dag.finalizedHead @@ -937,7 +935,7 @@ proc pruneStateCachesDAG*(dag: ChainDAGRef) = ## This updates the `dag.lastPrunePoint` variable doAssert dag.needStateCachesAndForkChoicePruning() - let startState = Moment.now() + let startTick = Moment.now() block: # Remove states, walking slot by slot # We remove all state checkpoints that come _before_ the current finalized # head, as we might frequently be asked to replay states from the @@ -955,10 +953,8 @@ proc pruneStateCachesDAG*(dag: ChainDAGRef) = if cur.slot.epoch mod 32 != 0 and cur.slot != dag.tail.slot: dag.delState(cur) cur = cur.parentOrSlot - let stopState = Moment.now() - let durState = stopState - startState + let statePruneTick = Moment.now() - let startEpochRef = Moment.now() block: # Clean up old EpochRef instances # After finalization, we can clear up the epoch cache and save memory - # it will be recomputed if needed @@ -966,14 +962,13 @@ proc pruneStateCachesDAG*(dag: ChainDAGRef) = if dag.epochRefs[i][1] != nil and dag.epochRefs[i][1].epoch < dag.finalizedHead.slot.epoch: dag.epochRefs[i] = (nil, nil) - let stopEpochRef = Moment.now() - let durEpochRef = stopEpochRef - startEpochRef + let epochRefPruneTick = Moment.now() dag.lastPrunePoint = dag.finalizedHead debug "Pruned the state checkpoints and DAG caches.", - statePruningDur = durState, - epochRefPruningDur = durEpochRef + statePruneDur = statePruneTick - startTick, + epochRefPruneDur = epochRefPruneTick - statePruneTick proc updateHead*( dag: ChainDAGRef, diff --git a/beacon_chain/gossip_processing/block_processor.nim b/beacon_chain/gossip_processing/block_processor.nim index 82bc4c61b..a96da865d 100644 --- a/beacon_chain/gossip_processing/block_processor.nim +++ b/beacon_chain/gossip_processing/block_processor.nim @@ -185,7 +185,7 @@ proc processBlock(self: var BlockProcessor, entry: BlockEntry) = let startTick = Moment.now() res = self.storeBlock(entry.blck, wallSlot) - storeTick = Moment.now() + storeBlockTick = Moment.now() if res.isOk(): # Eagerly update head in case the new block gets selected @@ -194,8 +194,8 @@ proc processBlock(self: var BlockProcessor, entry: BlockEntry) = let updateHeadTick = Moment.now() queueDur = startTick - entry.queueTick - storeBlockDur = storeTick - startTick - updateHeadDur = updateHeadTick - storeTick + storeBlockDur = storeBlockTick - startTick + updateHeadDur = updateHeadTick - storeBlockTick beacon_store_block_duration_seconds.observe(storeBlockDur.toFloatSeconds())