Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

feat: track timings of various stages of block import #6439

Merged
merged 2 commits into from Feb 17, 2024

Conversation

g11tech
Copy link
Contributor

@g11tech g11tech commented Feb 16, 2024

to track correctly various stages of block import to figure out why we have verify latency for e.g. and to uncover any possible optimizations
also

  • fixes recvToVal times for block and blob
  • use same variables for log
  • some better encapsulation of metrics (adds new metrics and rename metric variables but doesn't rename previous existing actual metrics lables so current dashboad will not be affected)

dashboard for new values coming up in followup PR

@g11tech g11tech requested a review from a team as a code owner February 16, 2024 12:31
@@ -133,19 +133,28 @@ function getDefaultHandlers(modules: ValidatorFnsModules, options: GossipHandler
const blockInputMeta =
config.getForkSeq(signedBlock.message.slot) >= ForkSeq.deneb ? blockInputRes.blockInputMeta : {};

metrics?.gossipBlock.receivedToGossipValidate.observe(recvToVal);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this previously was incorrect because it was observing the latency not the actual rec to validation time, fixed below


const {blockInput, blockInputMeta} = chain.seenGossipBlockInput.getGossipBlockInput(config, {
type: GossipedInputType.blob,
blobSidecar,
blobBytes,
});

metrics?.gossipBlob.receivedToGossipValidate.observe(recvToVal);
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this previously was incorrect because it was observing the latency not the actual rec to validation time, fixed below

Copy link

codecov bot commented Feb 16, 2024

Codecov Report

Merging #6439 (0fc61b0) into unstable (d01c542) will decrease coverage by 0.07%.
Report is 7 commits behind head on unstable.
The diff coverage is 0.00%.

Additional details and impacted files
@@             Coverage Diff              @@
##           unstable    #6439      +/-   ##
============================================
- Coverage     61.70%   61.64%   -0.07%     
============================================
  Files           553      553              
  Lines         57858    57918      +60     
  Branches       1829     1829              
============================================
  Hits          35702    35702              
- Misses        22119    22179      +60     
  Partials         37       37              

Copy link
Contributor

github-actions bot commented Feb 16, 2024

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: b4590e9 Previous: 4c09412 Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 978.32 us/op 758.58 us/op 1.29
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 132.99 us/op 80.883 us/op 1.64
BLS verify - blst-native 1.4026 ms/op 1.2779 ms/op 1.10
BLS verifyMultipleSignatures 3 - blst-native 2.9367 ms/op 2.6825 ms/op 1.09
BLS verifyMultipleSignatures 8 - blst-native 6.4201 ms/op 5.8957 ms/op 1.09
BLS verifyMultipleSignatures 32 - blst-native 23.588 ms/op 21.528 ms/op 1.10
BLS verifyMultipleSignatures 64 - blst-native 48.073 ms/op 42.414 ms/op 1.13
BLS verifyMultipleSignatures 128 - blst-native 92.354 ms/op 84.136 ms/op 1.10
BLS deserializing 10000 signatures 1.0193 s/op 899.65 ms/op 1.13
BLS deserializing 100000 signatures 8.7072 s/op 9.1503 s/op 0.95
BLS verifyMultipleSignatures - same message - 3 - blst-native 1.3133 ms/op 1.2990 ms/op 1.01
BLS verifyMultipleSignatures - same message - 8 - blst-native 1.4899 ms/op 1.6119 ms/op 0.92
BLS verifyMultipleSignatures - same message - 32 - blst-native 2.2929 ms/op 2.9967 ms/op 0.77
BLS verifyMultipleSignatures - same message - 64 - blst-native 3.3843 ms/op 3.3270 ms/op 1.02
BLS verifyMultipleSignatures - same message - 128 - blst-native 5.5134 ms/op 7.6611 ms/op 0.72
BLS aggregatePubkeys 32 - blst-native 25.228 us/op 26.189 us/op 0.96
BLS aggregatePubkeys 128 - blst-native 98.953 us/op 97.623 us/op 1.01
notSeenSlots=1 numMissedVotes=1 numBadVotes=10 62.570 ms/op 50.043 ms/op 1.25
notSeenSlots=1 numMissedVotes=0 numBadVotes=4 53.619 ms/op 51.693 ms/op 1.04
notSeenSlots=2 numMissedVotes=1 numBadVotes=10 44.867 ms/op 30.283 ms/op 1.48
getSlashingsAndExits - default max 196.92 us/op 167.73 us/op 1.17
getSlashingsAndExits - 2k 379.60 us/op 445.11 us/op 0.85
proposeBlockBody type=full, size=empty 5.1992 ms/op 4.9593 ms/op 1.05
isKnown best case - 1 super set check 286.00 ns/op 283.00 ns/op 1.01
isKnown normal case - 2 super set checks 292.00 ns/op 275.00 ns/op 1.06
isKnown worse case - 16 super set checks 282.00 ns/op 273.00 ns/op 1.03
CheckpointStateCache - add get delete 4.8360 us/op 4.8180 us/op 1.00
validate api signedAggregateAndProof - struct 2.6902 ms/op 2.6807 ms/op 1.00
validate gossip signedAggregateAndProof - struct 2.6870 ms/op 2.6600 ms/op 1.01
validate gossip attestation - vc 640000 1.3101 ms/op 1.3034 ms/op 1.01
batch validate gossip attestation - vc 640000 - chunk 32 156.29 us/op 158.50 us/op 0.99
batch validate gossip attestation - vc 640000 - chunk 64 138.12 us/op 139.78 us/op 0.99
batch validate gossip attestation - vc 640000 - chunk 128 133.26 us/op 130.70 us/op 1.02
batch validate gossip attestation - vc 640000 - chunk 256 127.75 us/op 129.17 us/op 0.99
pickEth1Vote - no votes 1.1120 ms/op 1.1292 ms/op 0.98
pickEth1Vote - max votes 10.317 ms/op 10.533 ms/op 0.98
pickEth1Vote - Eth1Data hashTreeRoot value x2048 22.731 ms/op 19.564 ms/op 1.16
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 35.850 ms/op 29.634 ms/op 1.21
pickEth1Vote - Eth1Data fastSerialize value x2048 603.02 us/op 578.39 us/op 1.04
pickEth1Vote - Eth1Data fastSerialize tree x2048 7.8485 ms/op 6.3119 ms/op 1.24
bytes32 toHexString 482.00 ns/op 458.00 ns/op 1.05
bytes32 Buffer.toString(hex) 286.00 ns/op 276.00 ns/op 1.04
bytes32 Buffer.toString(hex) from Uint8Array 414.00 ns/op 400.00 ns/op 1.03
bytes32 Buffer.toString(hex) + 0x 287.00 ns/op 275.00 ns/op 1.04
Object access 1 prop 0.15900 ns/op 0.15000 ns/op 1.06
Map access 1 prop 0.14500 ns/op 0.14600 ns/op 0.99
Object get x1000 7.0870 ns/op 6.7210 ns/op 1.05
Map get x1000 0.73200 ns/op 0.70400 ns/op 1.04
Object set x1000 48.609 ns/op 47.043 ns/op 1.03
Map set x1000 38.264 ns/op 37.439 ns/op 1.02
Return object 10000 times 0.23200 ns/op 0.22790 ns/op 1.02
Throw Error 10000 times 3.7931 us/op 3.7186 us/op 1.02
fastMsgIdFn sha256 / 200 bytes 3.2090 us/op 3.1350 us/op 1.02
fastMsgIdFn h32 xxhash / 200 bytes 262.00 ns/op 255.00 ns/op 1.03
fastMsgIdFn h64 xxhash / 200 bytes 334.00 ns/op 323.00 ns/op 1.03
fastMsgIdFn sha256 / 1000 bytes 11.228 us/op 10.838 us/op 1.04
fastMsgIdFn h32 xxhash / 1000 bytes 381.00 ns/op 382.00 ns/op 1.00
fastMsgIdFn h64 xxhash / 1000 bytes 403.00 ns/op 388.00 ns/op 1.04
fastMsgIdFn sha256 / 10000 bytes 101.81 us/op 99.091 us/op 1.03
fastMsgIdFn h32 xxhash / 10000 bytes 1.8700 us/op 1.8070 us/op 1.03
fastMsgIdFn h64 xxhash / 10000 bytes 1.2870 us/op 1.2430 us/op 1.04
send data - 1000 256B messages 17.326 ms/op 18.298 ms/op 0.95
send data - 1000 512B messages 24.503 ms/op 23.011 ms/op 1.06
send data - 1000 1024B messages 39.487 ms/op 40.000 ms/op 0.99
send data - 1000 1200B messages 40.373 ms/op 37.753 ms/op 1.07
send data - 1000 2048B messages 51.013 ms/op 48.673 ms/op 1.05
send data - 1000 4096B messages 45.495 ms/op 43.321 ms/op 1.05
send data - 1000 16384B messages 127.30 ms/op 110.61 ms/op 1.15
send data - 1000 65536B messages 460.70 ms/op 453.08 ms/op 1.02
enrSubnets - fastDeserialize 64 bits 1.2660 us/op 1.2610 us/op 1.00
enrSubnets - ssz BitVector 64 bits 432.00 ns/op 400.00 ns/op 1.08
enrSubnets - fastDeserialize 4 bits 170.00 ns/op 160.00 ns/op 1.06
enrSubnets - ssz BitVector 4 bits 423.00 ns/op 400.00 ns/op 1.06
prioritizePeers score -10:0 att 32-0.1 sync 2-0 103.64 us/op 101.01 us/op 1.03
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 123.28 us/op 123.16 us/op 1.00
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 158.49 us/op 173.62 us/op 0.91
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 283.21 us/op 277.43 us/op 1.02
prioritizePeers score 0:0 att 64-1 sync 4-1 325.56 us/op 331.97 us/op 0.98
array of 16000 items push then shift 1.5814 us/op 1.5413 us/op 1.03
LinkedList of 16000 items push then shift 8.6990 ns/op 8.4690 ns/op 1.03
array of 16000 items push then pop 80.186 ns/op 81.385 ns/op 0.99
LinkedList of 16000 items push then pop 8.4510 ns/op 8.2100 ns/op 1.03
array of 24000 items push then shift 2.5943 us/op 2.2620 us/op 1.15
LinkedList of 24000 items push then shift 9.2510 ns/op 8.4170 ns/op 1.10
array of 24000 items push then pop 103.62 ns/op 88.507 ns/op 1.17
LinkedList of 24000 items push then pop 9.1960 ns/op 8.3130 ns/op 1.11
intersect bitArray bitLen 8 5.7540 ns/op 5.5880 ns/op 1.03
intersect array and set length 8 62.522 ns/op 60.742 ns/op 1.03
intersect bitArray bitLen 128 35.561 ns/op 34.641 ns/op 1.03
intersect array and set length 128 852.42 ns/op 831.58 ns/op 1.03
bitArray.getTrueBitIndexes() bitLen 128 1.4570 us/op 1.4320 us/op 1.02
bitArray.getTrueBitIndexes() bitLen 248 2.4300 us/op 2.4370 us/op 1.00
bitArray.getTrueBitIndexes() bitLen 512 4.7670 us/op 4.7060 us/op 1.01
Buffer.concat 32 items 927.00 ns/op 957.00 ns/op 0.97
Uint8Array.set 32 items 1.5850 us/op 1.8920 us/op 0.84
Set add up to 64 items then delete first 4.3195 us/op 4.1652 us/op 1.04
OrderedSet add up to 64 items then delete first 5.4317 us/op 5.2420 us/op 1.04
Set add up to 64 items then delete last 4.7059 us/op 4.4326 us/op 1.06
OrderedSet add up to 64 items then delete last 5.7973 us/op 5.6005 us/op 1.04
Set add up to 64 items then delete middle 4.6270 us/op 4.4954 us/op 1.03
OrderedSet add up to 64 items then delete middle 7.0692 us/op 6.7746 us/op 1.04
Set add up to 128 items then delete first 9.2450 us/op 8.9120 us/op 1.04
OrderedSet add up to 128 items then delete first 12.070 us/op 11.832 us/op 1.02
Set add up to 128 items then delete last 9.0181 us/op 8.7914 us/op 1.03
OrderedSet add up to 128 items then delete last 11.472 us/op 11.031 us/op 1.04
Set add up to 128 items then delete middle 9.0001 us/op 8.7948 us/op 1.02
OrderedSet add up to 128 items then delete middle 16.703 us/op 16.251 us/op 1.03
Set add up to 256 items then delete first 18.499 us/op 18.193 us/op 1.02
OrderedSet add up to 256 items then delete first 24.853 us/op 24.363 us/op 1.02
Set add up to 256 items then delete last 17.968 us/op 17.575 us/op 1.02
OrderedSet add up to 256 items then delete last 23.127 us/op 22.289 us/op 1.04
Set add up to 256 items then delete middle 17.976 us/op 17.481 us/op 1.03
OrderedSet add up to 256 items then delete middle 44.784 us/op 43.410 us/op 1.03
transfer serialized Status (84 B) 1.7010 us/op 1.5750 us/op 1.08
copy serialized Status (84 B) 1.3450 us/op 1.2110 us/op 1.11
transfer serialized SignedVoluntaryExit (112 B) 1.8850 us/op 1.6900 us/op 1.12
copy serialized SignedVoluntaryExit (112 B) 1.4470 us/op 1.3810 us/op 1.05
transfer serialized ProposerSlashing (416 B) 2.5180 us/op 2.1800 us/op 1.16
copy serialized ProposerSlashing (416 B) 2.3130 us/op 1.7400 us/op 1.33
transfer serialized Attestation (485 B) 2.5440 us/op 2.1290 us/op 1.19
copy serialized Attestation (485 B) 2.4600 us/op 1.9660 us/op 1.25
transfer serialized AttesterSlashing (33232 B) 2.8000 us/op 2.4020 us/op 1.17
copy serialized AttesterSlashing (33232 B) 5.3820 us/op 5.5660 us/op 0.97
transfer serialized Small SignedBeaconBlock (128000 B) 2.8850 us/op 2.6400 us/op 1.09
copy serialized Small SignedBeaconBlock (128000 B) 14.393 us/op 14.485 us/op 0.99
transfer serialized Avg SignedBeaconBlock (200000 B) 2.9070 us/op 2.8360 us/op 1.03
copy serialized Avg SignedBeaconBlock (200000 B) 20.749 us/op 20.732 us/op 1.00
transfer serialized BlobsSidecar (524380 B) 2.7610 us/op 2.8340 us/op 0.97
copy serialized BlobsSidecar (524380 B) 185.36 us/op 122.61 us/op 1.51
transfer serialized Big SignedBeaconBlock (1000000 B) 3.0560 us/op 3.0850 us/op 0.99
copy serialized Big SignedBeaconBlock (1000000 B) 177.70 us/op 369.90 us/op 0.48
pass gossip attestations to forkchoice per slot 3.8566 ms/op 3.7880 ms/op 1.02
forkChoice updateHead vc 100000 bc 64 eq 0 678.83 us/op 678.29 us/op 1.00
forkChoice updateHead vc 600000 bc 64 eq 0 4.5629 ms/op 4.1032 ms/op 1.11
forkChoice updateHead vc 1000000 bc 64 eq 0 6.8566 ms/op 6.9472 ms/op 0.99
forkChoice updateHead vc 600000 bc 320 eq 0 4.2430 ms/op 4.1264 ms/op 1.03
forkChoice updateHead vc 600000 bc 1200 eq 0 4.4140 ms/op 4.2997 ms/op 1.03
forkChoice updateHead vc 600000 bc 7200 eq 0 5.3143 ms/op 5.3498 ms/op 0.99
forkChoice updateHead vc 600000 bc 64 eq 1000 11.143 ms/op 11.032 ms/op 1.01
forkChoice updateHead vc 600000 bc 64 eq 10000 11.924 ms/op 11.538 ms/op 1.03
forkChoice updateHead vc 600000 bc 64 eq 300000 15.668 ms/op 15.629 ms/op 1.00
computeDeltas 500000 validators 300 proto nodes 6.5566 ms/op 6.3708 ms/op 1.03
computeDeltas 500000 validators 1200 proto nodes 6.6386 ms/op 6.3169 ms/op 1.05
computeDeltas 500000 validators 7200 proto nodes 6.5120 ms/op 6.2523 ms/op 1.04
computeDeltas 750000 validators 300 proto nodes 10.025 ms/op 9.4090 ms/op 1.07
computeDeltas 750000 validators 1200 proto nodes 9.8440 ms/op 9.2567 ms/op 1.06
computeDeltas 750000 validators 7200 proto nodes 10.040 ms/op 9.4638 ms/op 1.06
computeDeltas 1400000 validators 300 proto nodes 18.724 ms/op 18.326 ms/op 1.02
computeDeltas 1400000 validators 1200 proto nodes 19.300 ms/op 18.503 ms/op 1.04
computeDeltas 1400000 validators 7200 proto nodes 19.682 ms/op 18.586 ms/op 1.06
computeDeltas 2100000 validators 300 proto nodes 27.877 ms/op 27.708 ms/op 1.01
computeDeltas 2100000 validators 1200 proto nodes 28.994 ms/op 28.043 ms/op 1.03
computeDeltas 2100000 validators 7200 proto nodes 28.937 ms/op 27.604 ms/op 1.05
altair processAttestation - 250000 vs - 7PWei normalcase 2.0705 ms/op 2.0667 ms/op 1.00
altair processAttestation - 250000 vs - 7PWei worstcase 3.1033 ms/op 3.0190 ms/op 1.03
altair processAttestation - setStatus - 1/6 committees join 148.70 us/op 176.40 us/op 0.84
altair processAttestation - setStatus - 1/3 committees join 265.03 us/op 343.57 us/op 0.77
altair processAttestation - setStatus - 1/2 committees join 355.12 us/op 453.83 us/op 0.78
altair processAttestation - setStatus - 2/3 committees join 444.18 us/op 569.99 us/op 0.78
altair processAttestation - setStatus - 4/5 committees join 632.19 us/op 774.16 us/op 0.82
altair processAttestation - setStatus - 100% committees join 750.66 us/op 884.01 us/op 0.85
altair processBlock - 250000 vs - 7PWei normalcase 11.151 ms/op 10.297 ms/op 1.08
altair processBlock - 250000 vs - 7PWei normalcase hashState 37.000 ms/op 39.057 ms/op 0.95
altair processBlock - 250000 vs - 7PWei worstcase 42.739 ms/op 37.331 ms/op 1.14
altair processBlock - 250000 vs - 7PWei worstcase hashState 105.90 ms/op 97.700 ms/op 1.08
phase0 processBlock - 250000 vs - 7PWei normalcase 4.2400 ms/op 2.4778 ms/op 1.71
phase0 processBlock - 250000 vs - 7PWei worstcase 30.346 ms/op 28.716 ms/op 1.06
altair processEth1Data - 250000 vs - 7PWei normalcase 496.37 us/op 514.57 us/op 0.96
getExpectedWithdrawals 250000 eb:1,eth1:1,we:0,wn:0,smpl:15 16.806 us/op 11.038 us/op 1.52
getExpectedWithdrawals 250000 eb:0.95,eth1:0.1,we:0.05,wn:0,smpl:219 88.969 us/op 58.535 us/op 1.52
getExpectedWithdrawals 250000 eb:0.95,eth1:0.3,we:0.05,wn:0,smpl:42 30.260 us/op 16.230 us/op 1.86
getExpectedWithdrawals 250000 eb:0.95,eth1:0.7,we:0.05,wn:0,smpl:18 18.872 us/op 7.2850 us/op 2.59
getExpectedWithdrawals 250000 eb:0.1,eth1:0.1,we:0,wn:0,smpl:1020 276.70 us/op 126.21 us/op 2.19
getExpectedWithdrawals 250000 eb:0.03,eth1:0.03,we:0,wn:0,smpl:11777 2.7177 ms/op 1.4408 ms/op 1.89
getExpectedWithdrawals 250000 eb:0.01,eth1:0.01,we:0,wn:0,smpl:16384 1.4426 ms/op 1.5513 ms/op 0.93
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,smpl:16384 2.2331 ms/op 1.5892 ms/op 1.41
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,nocache,smpl:16384 3.5801 ms/op 3.4554 ms/op 1.04
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,smpl:16384 2.2246 ms/op 2.2994 ms/op 0.97
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,nocache,smpl:16384 5.0159 ms/op 5.1577 ms/op 0.97
Tree 40 250000 create 338.34 ms/op 344.83 ms/op 0.98
Tree 40 250000 get(125000) 196.96 ns/op 196.61 ns/op 1.00
Tree 40 250000 set(125000) 926.22 ns/op 965.95 ns/op 0.96
Tree 40 250000 toArray() 17.520 ms/op 18.288 ms/op 0.96
Tree 40 250000 iterate all - toArray() + loop 17.971 ms/op 18.326 ms/op 0.98
Tree 40 250000 iterate all - get(i) 64.674 ms/op 64.586 ms/op 1.00
MutableVector 250000 create 18.347 ms/op 14.482 ms/op 1.27
MutableVector 250000 get(125000) 6.4630 ns/op 8.4990 ns/op 0.76
MutableVector 250000 set(125000) 251.60 ns/op 252.44 ns/op 1.00
MutableVector 250000 toArray() 3.7090 ms/op 3.2858 ms/op 1.13
MutableVector 250000 iterate all - toArray() + loop 3.7324 ms/op 3.3241 ms/op 1.12
MutableVector 250000 iterate all - get(i) 1.5494 ms/op 1.5703 ms/op 0.99
Array 250000 create 2.9454 ms/op 2.8107 ms/op 1.05
Array 250000 clone - spread 1.2544 ms/op 1.2439 ms/op 1.01
Array 250000 get(125000) 1.0290 ns/op 1.0450 ns/op 0.98
Array 250000 set(125000) 4.0570 ns/op 4.0420 ns/op 1.00
Array 250000 iterate all - loop 161.13 us/op 161.53 us/op 1.00
effectiveBalanceIncrements clone Uint8Array 300000 26.303 us/op 28.316 us/op 0.93
effectiveBalanceIncrements clone MutableVector 300000 366.00 ns/op 389.00 ns/op 0.94
effectiveBalanceIncrements rw all Uint8Array 300000 195.13 us/op 194.88 us/op 1.00
effectiveBalanceIncrements rw all MutableVector 300000 82.052 ms/op 79.824 ms/op 1.03
phase0 afterProcessEpoch - 250000 vs - 7PWei 109.24 ms/op 109.48 ms/op 1.00
phase0 beforeProcessEpoch - 250000 vs - 7PWei 59.617 ms/op 52.100 ms/op 1.14
altair processEpoch - mainnet_e81889 536.11 ms/op 525.57 ms/op 1.02
mainnet_e81889 - altair beforeProcessEpoch 85.920 ms/op 81.849 ms/op 1.05
mainnet_e81889 - altair processJustificationAndFinalization 21.983 us/op 14.241 us/op 1.54
mainnet_e81889 - altair processInactivityUpdates 5.6496 ms/op 5.8015 ms/op 0.97
mainnet_e81889 - altair processRewardsAndPenalties 66.061 ms/op 60.408 ms/op 1.09
mainnet_e81889 - altair processRegistryUpdates 4.0070 us/op 2.5150 us/op 1.59
mainnet_e81889 - altair processSlashings 1.0070 us/op 483.00 ns/op 2.08
mainnet_e81889 - altair processEth1DataReset 855.00 ns/op 475.00 ns/op 1.80
mainnet_e81889 - altair processEffectiveBalanceUpdates 2.6553 ms/op 1.3729 ms/op 1.93
mainnet_e81889 - altair processSlashingsReset 6.0160 us/op 3.5830 us/op 1.68
mainnet_e81889 - altair processRandaoMixesReset 6.5500 us/op 3.6750 us/op 1.78
mainnet_e81889 - altair processHistoricalRootsUpdate 717.00 ns/op 691.00 ns/op 1.04
mainnet_e81889 - altair processParticipationFlagUpdates 3.0110 us/op 1.3470 us/op 2.24
mainnet_e81889 - altair processSyncCommitteeUpdates 854.00 ns/op 554.00 ns/op 1.54
mainnet_e81889 - altair afterProcessEpoch 116.43 ms/op 114.48 ms/op 1.02
capella processEpoch - mainnet_e217614 2.4182 s/op 2.0328 s/op 1.19
mainnet_e217614 - capella beforeProcessEpoch 503.59 ms/op 467.31 ms/op 1.08
mainnet_e217614 - capella processJustificationAndFinalization 19.434 us/op 14.422 us/op 1.35
mainnet_e217614 - capella processInactivityUpdates 19.573 ms/op 18.994 ms/op 1.03
mainnet_e217614 - capella processRewardsAndPenalties 444.54 ms/op 396.83 ms/op 1.12
mainnet_e217614 - capella processRegistryUpdates 27.177 us/op 17.614 us/op 1.54
mainnet_e217614 - capella processSlashings 906.00 ns/op 557.00 ns/op 1.63
mainnet_e217614 - capella processEth1DataReset 677.00 ns/op 398.00 ns/op 1.70
mainnet_e217614 - capella processEffectiveBalanceUpdates 4.8030 ms/op 4.8092 ms/op 1.00
mainnet_e217614 - capella processSlashingsReset 4.6620 us/op 2.7200 us/op 1.71
mainnet_e217614 - capella processRandaoMixesReset 7.5580 us/op 3.8470 us/op 1.96
mainnet_e217614 - capella processHistoricalRootsUpdate 825.00 ns/op 693.00 ns/op 1.19
mainnet_e217614 - capella processParticipationFlagUpdates 2.4330 us/op 1.8140 us/op 1.34
mainnet_e217614 - capella afterProcessEpoch 308.11 ms/op 286.93 ms/op 1.07
phase0 processEpoch - mainnet_e58758 502.78 ms/op 440.96 ms/op 1.14
mainnet_e58758 - phase0 beforeProcessEpoch 159.45 ms/op 141.97 ms/op 1.12
mainnet_e58758 - phase0 processJustificationAndFinalization 23.840 us/op 14.631 us/op 1.63
mainnet_e58758 - phase0 processRewardsAndPenalties 66.585 ms/op 33.950 ms/op 1.96
mainnet_e58758 - phase0 processRegistryUpdates 14.763 us/op 9.9970 us/op 1.48
mainnet_e58758 - phase0 processSlashings 668.00 ns/op 562.00 ns/op 1.19
mainnet_e58758 - phase0 processEth1DataReset 617.00 ns/op 421.00 ns/op 1.47
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.3921 ms/op 1.0840 ms/op 1.28
mainnet_e58758 - phase0 processSlashingsReset 3.2490 us/op 2.7340 us/op 1.19
mainnet_e58758 - phase0 processRandaoMixesReset 7.1330 us/op 3.8510 us/op 1.85
mainnet_e58758 - phase0 processHistoricalRootsUpdate 836.00 ns/op 390.00 ns/op 2.14
mainnet_e58758 - phase0 processParticipationRecordUpdates 6.1940 us/op 3.5480 us/op 1.75
mainnet_e58758 - phase0 afterProcessEpoch 99.682 ms/op 92.432 ms/op 1.08
phase0 processEffectiveBalanceUpdates - 250000 normalcase 1.4144 ms/op 1.3691 ms/op 1.03
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 2.1132 ms/op 1.4567 ms/op 1.45
altair processInactivityUpdates - 250000 normalcase 39.202 ms/op 22.192 ms/op 1.77
altair processInactivityUpdates - 250000 worstcase 36.147 ms/op 25.906 ms/op 1.40
phase0 processRegistryUpdates - 250000 normalcase 10.262 us/op 8.5710 us/op 1.20
phase0 processRegistryUpdates - 250000 badcase_full_deposits 579.05 us/op 360.49 us/op 1.61
phase0 processRegistryUpdates - 250000 worstcase 0.5 150.09 ms/op 127.84 ms/op 1.17
altair processRewardsAndPenalties - 250000 normalcase 72.040 ms/op 57.485 ms/op 1.25
altair processRewardsAndPenalties - 250000 worstcase 68.543 ms/op 41.190 ms/op 1.66
phase0 getAttestationDeltas - 250000 normalcase 11.707 ms/op 8.1104 ms/op 1.44
phase0 getAttestationDeltas - 250000 worstcase 11.020 ms/op 8.1239 ms/op 1.36
phase0 processSlashings - 250000 worstcase 111.68 us/op 80.305 us/op 1.39
altair processSyncCommitteeUpdates - 250000 174.19 ms/op 150.37 ms/op 1.16
BeaconState.hashTreeRoot - No change 733.00 ns/op 358.00 ns/op 2.05
BeaconState.hashTreeRoot - 1 full validator 146.68 us/op 170.77 us/op 0.86
BeaconState.hashTreeRoot - 32 full validator 1.4897 ms/op 1.7126 ms/op 0.87
BeaconState.hashTreeRoot - 512 full validator 20.059 ms/op 18.126 ms/op 1.11
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 184.68 us/op 184.95 us/op 1.00
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 2.4039 ms/op 2.5474 ms/op 0.94
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 31.245 ms/op 33.913 ms/op 0.92
BeaconState.hashTreeRoot - 1 balances 134.98 us/op 137.26 us/op 0.98
BeaconState.hashTreeRoot - 32 balances 1.2303 ms/op 1.3192 ms/op 0.93
BeaconState.hashTreeRoot - 512 balances 14.507 ms/op 11.434 ms/op 1.27
BeaconState.hashTreeRoot - 250000 balances 265.41 ms/op 210.52 ms/op 1.26
aggregationBits - 2048 els - zipIndexesInBitList 22.290 us/op 16.362 us/op 1.36
byteArrayEquals 32 80.639 ns/op 72.806 ns/op 1.11
Buffer.compare 32 59.870 ns/op 53.679 ns/op 1.12
byteArrayEquals 1024 2.2005 us/op 1.9821 us/op 1.11
Buffer.compare 1024 77.425 ns/op 68.056 ns/op 1.14
byteArrayEquals 16384 34.842 us/op 31.553 us/op 1.10
Buffer.compare 16384 285.13 ns/op 246.88 ns/op 1.15
byteArrayEquals 123687377 266.72 ms/op 238.34 ms/op 1.12
Buffer.compare 123687377 7.9647 ms/op 6.0197 ms/op 1.32
byteArrayEquals 32 - diff last byte 78.367 ns/op 69.983 ns/op 1.12
Buffer.compare 32 - diff last byte 61.298 ns/op 54.082 ns/op 1.13
byteArrayEquals 1024 - diff last byte 2.2392 us/op 1.9785 us/op 1.13
Buffer.compare 1024 - diff last byte 76.934 ns/op 68.680 ns/op 1.12
byteArrayEquals 16384 - diff last byte 35.673 us/op 31.570 us/op 1.13
Buffer.compare 16384 - diff last byte 297.08 ns/op 268.82 ns/op 1.11
byteArrayEquals 123687377 - diff last byte 257.58 ms/op 238.73 ms/op 1.08
Buffer.compare 123687377 - diff last byte 6.9588 ms/op 6.0973 ms/op 1.14
byteArrayEquals 32 - random bytes 5.4450 ns/op 5.2890 ns/op 1.03
Buffer.compare 32 - random bytes 65.861 ns/op 59.244 ns/op 1.11
byteArrayEquals 1024 - random bytes 5.4120 ns/op 5.0680 ns/op 1.07
Buffer.compare 1024 - random bytes 64.902 ns/op 59.005 ns/op 1.10
byteArrayEquals 16384 - random bytes 5.4070 ns/op 5.0600 ns/op 1.07
Buffer.compare 16384 - random bytes 65.578 ns/op 58.662 ns/op 1.12
byteArrayEquals 123687377 - random bytes 8.7900 ns/op 8.2600 ns/op 1.06
Buffer.compare 123687377 - random bytes 67.760 ns/op 62.150 ns/op 1.09
regular array get 100000 times 45.358 us/op 43.224 us/op 1.05
wrappedArray get 100000 times 45.891 us/op 43.153 us/op 1.06
arrayWithProxy get 100000 times 14.412 ms/op 14.691 ms/op 0.98
ssz.Root.equals 55.427 ns/op 53.106 ns/op 1.04
byteArrayEquals 57.099 ns/op 51.466 ns/op 1.11
Buffer.compare 11.656 ns/op 10.481 ns/op 1.11
shuffle list - 16384 els 7.2036 ms/op 6.8000 ms/op 1.06
shuffle list - 250000 els 107.28 ms/op 98.720 ms/op 1.09
processSlot - 1 slots 20.590 us/op 17.220 us/op 1.20
processSlot - 32 slots 3.3973 ms/op 3.3644 ms/op 1.01
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 63.619 ms/op 57.143 ms/op 1.11
getCommitteeAssignments - req 1 vs - 250000 vc 2.6326 ms/op 2.4721 ms/op 1.06
getCommitteeAssignments - req 100 vs - 250000 vc 3.8974 ms/op 3.6749 ms/op 1.06
getCommitteeAssignments - req 1000 vs - 250000 vc 4.2861 ms/op 4.0122 ms/op 1.07
findModifiedValidators - 10000 modified validators 538.32 ms/op 514.46 ms/op 1.05
findModifiedValidators - 1000 modified validators 439.67 ms/op 413.38 ms/op 1.06
findModifiedValidators - 100 modified validators 437.94 ms/op 399.15 ms/op 1.10
findModifiedValidators - 10 modified validators 431.89 ms/op 407.17 ms/op 1.06
findModifiedValidators - 1 modified validators 433.86 ms/op 401.50 ms/op 1.08
findModifiedValidators - no difference 420.42 ms/op 389.68 ms/op 1.08
compare ViewDUs 4.9005 s/op 4.2357 s/op 1.16
compare each validator Uint8Array 1.9260 s/op 1.6233 s/op 1.19
compare ViewDU to Uint8Array 1.1603 s/op 1.0785 s/op 1.08
migrate state 1000000 validators, 24 modified, 0 new 777.71 ms/op 806.04 ms/op 0.96
migrate state 1000000 validators, 1700 modified, 1000 new 1.0674 s/op 1.0848 s/op 0.98
migrate state 1000000 validators, 3400 modified, 2000 new 1.3189 s/op 1.3513 s/op 0.98
migrate state 1500000 validators, 24 modified, 0 new 788.56 ms/op 779.14 ms/op 1.01
migrate state 1500000 validators, 1700 modified, 1000 new 1.0889 s/op 1.1275 s/op 0.97
migrate state 1500000 validators, 3400 modified, 2000 new 1.4167 s/op 1.4276 s/op 0.99
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 4.7200 ns/op 4.3900 ns/op 1.08
state getBlockRootAtSlot - 250000 vs - 7PWei 792.19 ns/op 642.35 ns/op 1.23
computeProposers - vc 250000 9.3760 ms/op 9.2524 ms/op 1.01
computeEpochShuffling - vc 250000 104.92 ms/op 103.48 ms/op 1.01
getNextSyncCommittee - vc 250000 158.63 ms/op 153.97 ms/op 1.03
computeSigningRoot for AttestationData 28.893 us/op 26.717 us/op 1.08
hash AttestationData serialized data then Buffer.toString(base64) 2.3214 us/op 2.3823 us/op 0.97
toHexString serialized data 1.0738 us/op 1.1756 us/op 0.91
Buffer.toString(base64) 218.10 ns/op 254.52 ns/op 0.86

by benchmarkbot/action

@wemeetagain wemeetagain changed the title feat: minutely track timings of various stages of block import feat: track timings of various stages of block import Feb 17, 2024
@wemeetagain wemeetagain merged commit c7c9941 into unstable Feb 17, 2024
19 of 21 checks passed
@wemeetagain wemeetagain deleted the import-timings branch February 17, 2024 17:59
@wemeetagain
Copy link
Member

🎉 This PR is included in v1.16.0 🎉

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

None yet

3 participants