separate CL/EL timing in add block log (#5380)

the metric remains the same in order not to change overall meaning, but
in the logs we can do better - often, the EL is at the core of a
slowdown.
This commit is contained in:
Jacek Sieka 2023-09-04 19:23:29 +02:00 committed by GitHub
parent 6fab826487
commit bd513ca2ba
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
1 changed files with 11 additions and 4 deletions

View File

@ -522,6 +522,8 @@ proc storeBlock(
else: else:
discard discard
let newPayloadTick = Moment.now()
# TODO with v1.4.0, not sure this is still relevant # TODO with v1.4.0, not sure this is still relevant
# Establish blob viability before calling addHeadBlock to avoid # Establish blob viability before calling addHeadBlock to avoid
# writing the block in case of blob error. # writing the block in case of blob error.
@ -587,7 +589,7 @@ proc storeBlock(
for b in blobs: for b in blobs:
self.consensusManager.dag.db.putBlobSidecar(b[]) self.consensusManager.dag.db.putBlobSidecar(b[])
let storeBlockTick = Moment.now() let addHeadBlockTick = Moment.now()
# Eagerly update head: the incoming block "should" get selected. # Eagerly update head: the incoming block "should" get selected.
# #
@ -708,15 +710,20 @@ proc storeBlock(
let let
updateHeadTick = Moment.now() updateHeadTick = Moment.now()
queueDur = startTick - queueTick queueDur = startTick - queueTick
storeBlockDur = storeBlockTick - startTick newPayloadDur = newPayloadTick - startTick
updateHeadDur = updateHeadTick - storeBlockTick addHeadBlockDur = addHeadBlockTick - newPayloadTick
updateHeadDur = updateHeadTick - addHeadBlockTick
# "store block" is the full time it takes to process the block - in the log
# we split this into execution and consensus timings
storeBlockDur = newPayloadDur + addHeadBlockDur
beacon_store_block_duration_seconds.observe(storeBlockDur.toFloatSeconds()) beacon_store_block_duration_seconds.observe(storeBlockDur.toFloatSeconds())
debug "Block processed", debug "Block processed",
head = shortLog(dag.head), head = shortLog(dag.head),
blck = shortLog(blck.get()), blck = shortLog(blck.get()),
validationDur, queueDur, storeBlockDur, updateHeadDur validationDur, queueDur, newPayloadDur, addHeadBlockDur, updateHeadDur
for quarantined in self.consensusManager.quarantine[].pop(blck.get().root): for quarantined in self.consensusManager.quarantine[].pop(blck.get().root):
# Process the blocks that had the newly accepted block as parent # Process the blocks that had the newly accepted block as parent