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

chore: reorder block production log statements #6601

Merged
merged 4 commits into from
Mar 27, 2024
Merged

Conversation

jeluard
Copy link
Contributor

@jeluard jeluard commented Mar 27, 2024

Motivation

Make sure logs are not discarded

Description

Logs can be discarded by an exception thrown beforehand. Reorder logic so that it doesn't happen.

@jeluard jeluard requested a review from a team as a code owner March 27, 2024 10:39
Copy link

codecov bot commented Mar 27, 2024

Codecov Report

Merging #6601 (59bbc3f) into unstable (971871e) will increase coverage by 0.00%.
Report is 1 commits behind head on unstable.
The diff coverage is n/a.

Additional details and impacted files
@@            Coverage Diff            @@
##           unstable    #6601   +/-   ##
=========================================
  Coverage     61.49%   61.49%           
=========================================
  Files           556      556           
  Lines         58895    58903    +8     
  Branches       1856     1857    +1     
=========================================
+ Hits          36216    36222    +6     
- Misses        22638    22640    +2     
  Partials         41       41           

Copy link
Member

@nflaig nflaig left a comment

Choose a reason for hiding this comment

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

This seems to be a regression introduced in #6241, we should make sure to log the error somewhere.

Also noticed that the thrown error might be confusing for users that do not have builder enabled as it states both block failed to produce which is incorrect in that case

throw Error("Builder and engine both failed to produce the block");

Maybe should differentiate errors based on isEnabled booleans for a cleaner UX

@nflaig
Copy link
Member

nflaig commented Mar 27, 2024

cc @g11tech @nazarhussain

Copy link
Contributor

github-actions bot commented Mar 27, 2024

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: 9c0cede Previous: 4069b41 Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 486.34 us/op 595.58 us/op 0.82
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 85.187 us/op 100.82 us/op 0.84
BLS verify - blst-native 1.3356 ms/op 1.3611 ms/op 0.98
BLS verifyMultipleSignatures 3 - blst-native 2.7886 ms/op 2.8779 ms/op 0.97
BLS verifyMultipleSignatures 8 - blst-native 6.1253 ms/op 6.2604 ms/op 0.98
BLS verifyMultipleSignatures 32 - blst-native 22.960 ms/op 23.014 ms/op 1.00
BLS verifyMultipleSignatures 64 - blst-native 47.391 ms/op 45.136 ms/op 1.05
BLS verifyMultipleSignatures 128 - blst-native 88.627 ms/op 88.860 ms/op 1.00
BLS deserializing 10000 signatures 918.59 ms/op 932.35 ms/op 0.99
BLS deserializing 100000 signatures 9.6467 s/op 8.9499 s/op 1.08
BLS verifyMultipleSignatures - same message - 3 - blst-native 1.3957 ms/op 1.3644 ms/op 1.02
BLS verifyMultipleSignatures - same message - 8 - blst-native 1.5789 ms/op 1.4942 ms/op 1.06
BLS verifyMultipleSignatures - same message - 32 - blst-native 2.4280 ms/op 2.3866 ms/op 1.02
BLS verifyMultipleSignatures - same message - 64 - blst-native 3.4900 ms/op 3.4697 ms/op 1.01
BLS verifyMultipleSignatures - same message - 128 - blst-native 5.6756 ms/op 5.6234 ms/op 1.01
BLS aggregatePubkeys 32 - blst-native 26.072 us/op 25.651 us/op 1.02
BLS aggregatePubkeys 128 - blst-native 102.51 us/op 100.24 us/op 1.02
notSeenSlots=1 numMissedVotes=1 numBadVotes=10 77.046 ms/op 64.923 ms/op 1.19
notSeenSlots=1 numMissedVotes=0 numBadVotes=4 70.177 ms/op 65.535 ms/op 1.07
notSeenSlots=2 numMissedVotes=1 numBadVotes=10 52.373 ms/op 53.200 ms/op 0.98
getSlashingsAndExits - default max 255.21 us/op 254.51 us/op 1.00
getSlashingsAndExits - 2k 347.23 us/op 400.66 us/op 0.87
proposeBlockBody type=full, size=empty 6.3187 ms/op 6.5746 ms/op 0.96
isKnown best case - 1 super set check 314.00 ns/op 360.00 ns/op 0.87
isKnown normal case - 2 super set checks 322.00 ns/op 514.00 ns/op 0.63
isKnown worse case - 16 super set checks 306.00 ns/op 378.00 ns/op 0.81
CheckpointStateCache - add get delete 7.1290 us/op 6.5590 us/op 1.09
validate api signedAggregateAndProof - struct 2.6551 ms/op 2.8363 ms/op 0.94
validate gossip signedAggregateAndProof - struct 2.6594 ms/op 2.8283 ms/op 0.94
validate gossip attestation - vc 640000 1.3177 ms/op 1.4013 ms/op 0.94
batch validate gossip attestation - vc 640000 - chunk 32 154.74 us/op 172.07 us/op 0.90
batch validate gossip attestation - vc 640000 - chunk 64 138.09 us/op 155.49 us/op 0.89
batch validate gossip attestation - vc 640000 - chunk 128 133.07 us/op 158.55 us/op 0.84
batch validate gossip attestation - vc 640000 - chunk 256 126.76 us/op 152.73 us/op 0.83
pickEth1Vote - no votes 1.2674 ms/op 1.5070 ms/op 0.84
pickEth1Vote - max votes 10.591 ms/op 12.285 ms/op 0.86
pickEth1Vote - Eth1Data hashTreeRoot value x2048 17.726 ms/op 22.920 ms/op 0.77
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 22.190 ms/op 38.331 ms/op 0.58
pickEth1Vote - Eth1Data fastSerialize value x2048 602.59 us/op 930.00 us/op 0.65
pickEth1Vote - Eth1Data fastSerialize tree x2048 5.8784 ms/op 6.3223 ms/op 0.93
bytes32 toHexString 531.00 ns/op 967.00 ns/op 0.55
bytes32 Buffer.toString(hex) 288.00 ns/op 382.00 ns/op 0.75
bytes32 Buffer.toString(hex) from Uint8Array 434.00 ns/op 745.00 ns/op 0.58
bytes32 Buffer.toString(hex) + 0x 285.00 ns/op 433.00 ns/op 0.66
Object access 1 prop 0.16100 ns/op 0.29000 ns/op 0.56
Map access 1 prop 0.15900 ns/op 0.17400 ns/op 0.91
Object get x1000 8.3720 ns/op 12.448 ns/op 0.67
Map get x1000 0.78500 ns/op 1.0120 ns/op 0.78
Object set x1000 53.496 ns/op 100.20 ns/op 0.53
Map set x1000 43.039 ns/op 69.857 ns/op 0.62
Return object 10000 times 0.25270 ns/op 0.45820 ns/op 0.55
Throw Error 10000 times 4.0633 us/op 5.7074 us/op 0.71
fastMsgIdFn sha256 / 200 bytes 3.4480 us/op 4.0980 us/op 0.84
fastMsgIdFn h32 xxhash / 200 bytes 309.00 ns/op 427.00 ns/op 0.72
fastMsgIdFn h64 xxhash / 200 bytes 364.00 ns/op 460.00 ns/op 0.79
fastMsgIdFn sha256 / 1000 bytes 11.856 us/op 13.523 us/op 0.88
fastMsgIdFn h32 xxhash / 1000 bytes 417.00 ns/op 608.00 ns/op 0.69
fastMsgIdFn h64 xxhash / 1000 bytes 417.00 ns/op 547.00 ns/op 0.76
fastMsgIdFn sha256 / 10000 bytes 105.32 us/op 112.27 us/op 0.94
fastMsgIdFn h32 xxhash / 10000 bytes 1.9460 us/op 2.4780 us/op 0.79
fastMsgIdFn h64 xxhash / 10000 bytes 1.3210 us/op 1.5950 us/op 0.83
send data - 1000 256B messages 19.112 ms/op 32.621 ms/op 0.59
send data - 1000 512B messages 25.565 ms/op 34.054 ms/op 0.75
send data - 1000 1024B messages 42.490 ms/op 53.033 ms/op 0.80
send data - 1000 1200B messages 38.809 ms/op 43.851 ms/op 0.89
send data - 1000 2048B messages 51.957 ms/op 59.404 ms/op 0.87
send data - 1000 4096B messages 46.720 ms/op 51.481 ms/op 0.91
send data - 1000 16384B messages 119.09 ms/op 145.62 ms/op 0.82
send data - 1000 65536B messages 513.89 ms/op 564.94 ms/op 0.91
enrSubnets - fastDeserialize 64 bits 1.7880 us/op 2.2500 us/op 0.79
enrSubnets - ssz BitVector 64 bits 567.00 ns/op 647.00 ns/op 0.88
enrSubnets - fastDeserialize 4 bits 223.00 ns/op 294.00 ns/op 0.76
enrSubnets - ssz BitVector 4 bits 491.00 ns/op 606.00 ns/op 0.81
prioritizePeers score -10:0 att 32-0.1 sync 2-0 102.36 us/op 141.54 us/op 0.72
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 128.65 us/op 185.08 us/op 0.70
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 166.15 us/op 245.61 us/op 0.68
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 336.14 us/op 447.07 us/op 0.75
prioritizePeers score 0:0 att 64-1 sync 4-1 350.96 us/op 458.35 us/op 0.77
array of 16000 items push then shift 1.6713 us/op 2.3621 us/op 0.71
LinkedList of 16000 items push then shift 9.1580 ns/op 11.623 ns/op 0.79
array of 16000 items push then pop 99.136 ns/op 134.03 ns/op 0.74
LinkedList of 16000 items push then pop 9.1090 ns/op 14.437 ns/op 0.63
array of 24000 items push then shift 2.4568 us/op 3.2825 us/op 0.75
LinkedList of 24000 items push then shift 9.0490 ns/op 12.398 ns/op 0.73
array of 24000 items push then pop 127.70 ns/op 210.90 ns/op 0.61
LinkedList of 24000 items push then pop 8.9490 ns/op 12.326 ns/op 0.73
intersect bitArray bitLen 8 5.9550 ns/op 9.5540 ns/op 0.62
intersect array and set length 8 66.424 ns/op 114.50 ns/op 0.58
intersect bitArray bitLen 128 35.955 ns/op 58.211 ns/op 0.62
intersect array and set length 128 939.66 ns/op 1.5846 us/op 0.59
bitArray.getTrueBitIndexes() bitLen 128 1.6660 us/op 2.5320 us/op 0.66
bitArray.getTrueBitIndexes() bitLen 248 2.3970 us/op 3.7660 us/op 0.64
bitArray.getTrueBitIndexes() bitLen 512 5.1080 us/op 8.1770 us/op 0.62
Buffer.concat 32 items 983.00 ns/op 1.3620 us/op 0.72
Uint8Array.set 32 items 1.8630 us/op 2.8180 us/op 0.66
Set add up to 64 items then delete first 4.4685 us/op 5.5494 us/op 0.81
OrderedSet add up to 64 items then delete first 5.7103 us/op 7.7613 us/op 0.74
Set add up to 64 items then delete last 4.8067 us/op 6.3640 us/op 0.76
OrderedSet add up to 64 items then delete last 5.9322 us/op 7.6273 us/op 0.78
Set add up to 64 items then delete middle 4.6809 us/op 5.8351 us/op 0.80
OrderedSet add up to 64 items then delete middle 7.2117 us/op 9.7383 us/op 0.74
Set add up to 128 items then delete first 9.3390 us/op 12.882 us/op 0.72
OrderedSet add up to 128 items then delete first 12.633 us/op 16.577 us/op 0.76
Set add up to 128 items then delete last 10.588 us/op 12.517 us/op 0.85
OrderedSet add up to 128 items then delete last 13.844 us/op 16.118 us/op 0.86
Set add up to 128 items then delete middle 10.912 us/op 11.395 us/op 0.96
OrderedSet add up to 128 items then delete middle 21.114 us/op 25.328 us/op 0.83
Set add up to 256 items then delete first 22.821 us/op 24.890 us/op 0.92
OrderedSet add up to 256 items then delete first 31.347 us/op 38.629 us/op 0.81
Set add up to 256 items then delete last 21.512 us/op 23.840 us/op 0.90
OrderedSet add up to 256 items then delete last 25.921 us/op 33.382 us/op 0.78
Set add up to 256 items then delete middle 19.694 us/op 24.087 us/op 0.82
OrderedSet add up to 256 items then delete middle 47.245 us/op 65.570 us/op 0.72
transfer serialized Status (84 B) 1.7610 us/op 2.5510 us/op 0.69
copy serialized Status (84 B) 1.3350 us/op 1.8990 us/op 0.70
transfer serialized SignedVoluntaryExit (112 B) 2.1430 us/op 2.6330 us/op 0.81
copy serialized SignedVoluntaryExit (112 B) 1.4550 us/op 2.3960 us/op 0.61
transfer serialized ProposerSlashing (416 B) 2.2320 us/op 3.8460 us/op 0.58
copy serialized ProposerSlashing (416 B) 2.1820 us/op 2.9450 us/op 0.74
transfer serialized Attestation (485 B) 2.8190 us/op 3.8250 us/op 0.74
copy serialized Attestation (485 B) 2.2790 us/op 2.8960 us/op 0.79
transfer serialized AttesterSlashing (33232 B) 2.3380 us/op 3.7060 us/op 0.63
copy serialized AttesterSlashing (33232 B) 6.4710 us/op 11.669 us/op 0.55
transfer serialized Small SignedBeaconBlock (128000 B) 2.8490 us/op 6.0860 us/op 0.47
copy serialized Small SignedBeaconBlock (128000 B) 17.353 us/op 33.671 us/op 0.52
transfer serialized Avg SignedBeaconBlock (200000 B) 3.0470 us/op 6.6520 us/op 0.46
copy serialized Avg SignedBeaconBlock (200000 B) 21.321 us/op 48.742 us/op 0.44
transfer serialized BlobsSidecar (524380 B) 2.8470 us/op 7.1910 us/op 0.40
copy serialized BlobsSidecar (524380 B) 101.77 us/op 159.80 us/op 0.64
transfer serialized Big SignedBeaconBlock (1000000 B) 3.2240 us/op 7.7090 us/op 0.42
copy serialized Big SignedBeaconBlock (1000000 B) 143.01 us/op 289.61 us/op 0.49
pass gossip attestations to forkchoice per slot 3.9808 ms/op 6.1235 ms/op 0.65
forkChoice updateHead vc 100000 bc 64 eq 0 706.00 us/op 933.20 us/op 0.76
forkChoice updateHead vc 600000 bc 64 eq 0 4.7673 ms/op 6.0444 ms/op 0.79
forkChoice updateHead vc 1000000 bc 64 eq 0 7.4652 ms/op 12.470 ms/op 0.60
forkChoice updateHead vc 600000 bc 320 eq 0 4.2784 ms/op 6.5018 ms/op 0.66
forkChoice updateHead vc 600000 bc 1200 eq 0 4.3589 ms/op 6.0087 ms/op 0.73
forkChoice updateHead vc 600000 bc 7200 eq 0 5.3940 ms/op 7.5124 ms/op 0.72
forkChoice updateHead vc 600000 bc 64 eq 1000 11.477 ms/op 15.609 ms/op 0.74
forkChoice updateHead vc 600000 bc 64 eq 10000 12.573 ms/op 16.661 ms/op 0.75
forkChoice updateHead vc 600000 bc 64 eq 300000 16.545 ms/op 49.560 ms/op 0.33
computeDeltas 500000 validators 300 proto nodes 6.9033 ms/op 8.5410 ms/op 0.81
computeDeltas 500000 validators 1200 proto nodes 6.5211 ms/op 7.2364 ms/op 0.90
computeDeltas 500000 validators 7200 proto nodes 6.4220 ms/op 6.7769 ms/op 0.95
computeDeltas 750000 validators 300 proto nodes 10.025 ms/op 10.330 ms/op 0.97
computeDeltas 750000 validators 1200 proto nodes 10.149 ms/op 10.442 ms/op 0.97
computeDeltas 750000 validators 7200 proto nodes 10.160 ms/op 9.9527 ms/op 1.02
computeDeltas 1400000 validators 300 proto nodes 19.119 ms/op 18.709 ms/op 1.02
computeDeltas 1400000 validators 1200 proto nodes 20.841 ms/op 18.719 ms/op 1.11
computeDeltas 1400000 validators 7200 proto nodes 21.156 ms/op 18.897 ms/op 1.12
computeDeltas 2100000 validators 300 proto nodes 31.533 ms/op 28.760 ms/op 1.10
computeDeltas 2100000 validators 1200 proto nodes 30.437 ms/op 28.719 ms/op 1.06
computeDeltas 2100000 validators 7200 proto nodes 29.025 ms/op 29.202 ms/op 0.99
altair processAttestation - 250000 vs - 7PWei normalcase 2.3121 ms/op 2.8280 ms/op 0.82
altair processAttestation - 250000 vs - 7PWei worstcase 3.6394 ms/op 3.6674 ms/op 0.99
altair processAttestation - setStatus - 1/6 committees join 191.84 us/op 191.89 us/op 1.00
altair processAttestation - setStatus - 1/3 committees join 363.64 us/op 391.84 us/op 0.93
altair processAttestation - setStatus - 1/2 committees join 497.48 us/op 530.52 us/op 0.94
altair processAttestation - setStatus - 2/3 committees join 633.95 us/op 749.88 us/op 0.85
altair processAttestation - setStatus - 4/5 committees join 849.00 us/op 932.75 us/op 0.91
altair processAttestation - setStatus - 100% committees join 963.51 us/op 1.0687 ms/op 0.90
altair processBlock - 250000 vs - 7PWei normalcase 10.552 ms/op 12.106 ms/op 0.87
altair processBlock - 250000 vs - 7PWei normalcase hashState 33.697 ms/op 37.966 ms/op 0.89
altair processBlock - 250000 vs - 7PWei worstcase 41.928 ms/op 42.191 ms/op 0.99
altair processBlock - 250000 vs - 7PWei worstcase hashState 93.832 ms/op 103.73 ms/op 0.90
phase0 processBlock - 250000 vs - 7PWei normalcase 2.8499 ms/op 4.5307 ms/op 0.63
phase0 processBlock - 250000 vs - 7PWei worstcase 30.252 ms/op 34.271 ms/op 0.88
altair processEth1Data - 250000 vs - 7PWei normalcase 593.54 us/op 651.57 us/op 0.91
getExpectedWithdrawals 250000 eb:1,eth1:1,we:0,wn:0,smpl:15 12.530 us/op 23.567 us/op 0.53
getExpectedWithdrawals 250000 eb:0.95,eth1:0.1,we:0.05,wn:0,smpl:219 75.235 us/op 69.947 us/op 1.08
getExpectedWithdrawals 250000 eb:0.95,eth1:0.3,we:0.05,wn:0,smpl:42 12.051 us/op 33.795 us/op 0.36
getExpectedWithdrawals 250000 eb:0.95,eth1:0.7,we:0.05,wn:0,smpl:18 12.557 us/op 19.912 us/op 0.63
getExpectedWithdrawals 250000 eb:0.1,eth1:0.1,we:0,wn:0,smpl:1020 208.18 us/op 224.35 us/op 0.93
getExpectedWithdrawals 250000 eb:0.03,eth1:0.03,we:0,wn:0,smpl:11777 1.4409 ms/op 1.8258 ms/op 0.79
getExpectedWithdrawals 250000 eb:0.01,eth1:0.01,we:0,wn:0,smpl:16384 1.7145 ms/op 2.5657 ms/op 0.67
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,smpl:16384 1.5614 ms/op 2.0964 ms/op 0.74
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,nocache,smpl:16384 3.6935 ms/op 4.5084 ms/op 0.82
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,smpl:16384 2.3487 ms/op 2.9837 ms/op 0.79
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,nocache,smpl:16384 5.1044 ms/op 6.3424 ms/op 0.80
Tree 40 250000 create 368.37 ms/op 589.36 ms/op 0.63
Tree 40 250000 get(125000) 216.17 ns/op 213.97 ns/op 1.01
Tree 40 250000 set(125000) 1.2291 us/op 1.2081 us/op 1.02
Tree 40 250000 toArray() 22.929 ms/op 23.844 ms/op 0.96
Tree 40 250000 iterate all - toArray() + loop 22.733 ms/op 23.913 ms/op 0.95
Tree 40 250000 iterate all - get(i) 69.904 ms/op 76.642 ms/op 0.91
MutableVector 250000 create 13.274 ms/op 14.905 ms/op 0.89
MutableVector 250000 get(125000) 6.5270 ns/op 6.9500 ns/op 0.94
MutableVector 250000 set(125000) 276.74 ns/op 310.65 ns/op 0.89
MutableVector 250000 toArray() 3.7143 ms/op 4.0403 ms/op 0.92
MutableVector 250000 iterate all - toArray() + loop 3.7900 ms/op 4.4285 ms/op 0.86
MutableVector 250000 iterate all - get(i) 1.5633 ms/op 1.5969 ms/op 0.98
Array 250000 create 3.6162 ms/op 3.9236 ms/op 0.92
Array 250000 clone - spread 1.3247 ms/op 1.5270 ms/op 0.87
Array 250000 get(125000) 1.1530 ns/op 1.2850 ns/op 0.90
Array 250000 set(125000) 4.3590 ns/op 5.6670 ns/op 0.77
Array 250000 iterate all - loop 171.91 us/op 185.25 us/op 0.93
effectiveBalanceIncrements clone Uint8Array 300000 31.126 us/op 84.051 us/op 0.37
effectiveBalanceIncrements clone MutableVector 300000 394.00 ns/op 2.2150 us/op 0.18
effectiveBalanceIncrements rw all Uint8Array 300000 204.68 us/op 259.43 us/op 0.79
effectiveBalanceIncrements rw all MutableVector 300000 89.263 ms/op 307.35 ms/op 0.29
phase0 afterProcessEpoch - 250000 vs - 7PWei 116.58 ms/op 154.83 ms/op 0.75
phase0 beforeProcessEpoch - 250000 vs - 7PWei 51.700 ms/op 92.278 ms/op 0.56
altair processEpoch - mainnet_e81889 590.00 ms/op 839.71 ms/op 0.70
mainnet_e81889 - altair beforeProcessEpoch 119.80 ms/op 151.25 ms/op 0.79
mainnet_e81889 - altair processJustificationAndFinalization 28.736 us/op 30.824 us/op 0.93
mainnet_e81889 - altair processInactivityUpdates 9.0714 ms/op 13.122 ms/op 0.69
mainnet_e81889 - altair processRewardsAndPenalties 79.476 ms/op 90.783 ms/op 0.88
mainnet_e81889 - altair processRegistryUpdates 7.2840 us/op 7.6950 us/op 0.95
mainnet_e81889 - altair processSlashings 1.4680 us/op 2.5140 us/op 0.58
mainnet_e81889 - altair processEth1DataReset 1.5330 us/op 1.5760 us/op 0.97
mainnet_e81889 - altair processEffectiveBalanceUpdates 2.9863 ms/op 2.5010 ms/op 1.19
mainnet_e81889 - altair processSlashingsReset 11.984 us/op 11.056 us/op 1.08
mainnet_e81889 - altair processRandaoMixesReset 12.109 us/op 9.9410 us/op 1.22
mainnet_e81889 - altair processHistoricalRootsUpdate 3.1040 us/op 2.3530 us/op 1.32
mainnet_e81889 - altair processParticipationFlagUpdates 5.3910 us/op 5.8520 us/op 0.92
mainnet_e81889 - altair processSyncCommitteeUpdates 1.6340 us/op 1.6850 us/op 0.97
mainnet_e81889 - altair afterProcessEpoch 143.36 ms/op 153.61 ms/op 0.93
capella processEpoch - mainnet_e217614 3.8332 s/op 2.3947 s/op 1.60
mainnet_e217614 - capella beforeProcessEpoch 735.22 ms/op 518.38 ms/op 1.42
mainnet_e217614 - capella processJustificationAndFinalization 25.435 us/op 21.894 us/op 1.16
mainnet_e217614 - capella processInactivityUpdates 22.368 ms/op 20.589 ms/op 1.09
mainnet_e217614 - capella processRewardsAndPenalties 646.99 ms/op 608.47 ms/op 1.06
mainnet_e217614 - capella processRegistryUpdates 30.550 us/op 34.509 us/op 0.89
mainnet_e217614 - capella processSlashings 1.9390 us/op 1.2300 us/op 1.58
mainnet_e217614 - capella processEth1DataReset 787.00 ns/op 946.00 ns/op 0.83
mainnet_e217614 - capella processEffectiveBalanceUpdates 4.8590 ms/op 15.967 ms/op 0.30
mainnet_e217614 - capella processSlashingsReset 5.6010 us/op 5.5140 us/op 1.02
mainnet_e217614 - capella processRandaoMixesReset 8.8650 us/op 6.8470 us/op 1.29
mainnet_e217614 - capella processHistoricalRootsUpdate 1.0660 us/op 683.00 ns/op 1.56
mainnet_e217614 - capella processParticipationFlagUpdates 3.4330 us/op 2.5750 us/op 1.33
mainnet_e217614 - capella afterProcessEpoch 339.53 ms/op 323.01 ms/op 1.05
phase0 processEpoch - mainnet_e58758 504.67 ms/op 680.90 ms/op 0.74
mainnet_e58758 - phase0 beforeProcessEpoch 154.48 ms/op 183.88 ms/op 0.84
mainnet_e58758 - phase0 processJustificationAndFinalization 20.980 us/op 26.129 us/op 0.80
mainnet_e58758 - phase0 processRewardsAndPenalties 75.395 ms/op 77.499 ms/op 0.97
mainnet_e58758 - phase0 processRegistryUpdates 15.821 us/op 22.142 us/op 0.71
mainnet_e58758 - phase0 processSlashings 919.00 ns/op 947.00 ns/op 0.97
mainnet_e58758 - phase0 processEth1DataReset 730.00 ns/op 835.00 ns/op 0.87
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.1835 ms/op 1.4172 ms/op 0.84
mainnet_e58758 - phase0 processSlashingsReset 4.0120 us/op 4.9350 us/op 0.81
mainnet_e58758 - phase0 processRandaoMixesReset 6.6670 us/op 7.5830 us/op 0.88
mainnet_e58758 - phase0 processHistoricalRootsUpdate 798.00 ns/op 516.00 ns/op 1.55
mainnet_e58758 - phase0 processParticipationRecordUpdates 7.6540 us/op 4.5950 us/op 1.67
mainnet_e58758 - phase0 afterProcessEpoch 108.20 ms/op 118.27 ms/op 0.91
phase0 processEffectiveBalanceUpdates - 250000 normalcase 1.4946 ms/op 1.7755 ms/op 0.84
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 1.4965 ms/op 1.8335 ms/op 0.82
altair processInactivityUpdates - 250000 normalcase 27.882 ms/op 48.374 ms/op 0.58
altair processInactivityUpdates - 250000 worstcase 27.814 ms/op 41.614 ms/op 0.67
phase0 processRegistryUpdates - 250000 normalcase 14.272 us/op 16.259 us/op 0.88
phase0 processRegistryUpdates - 250000 badcase_full_deposits 515.26 us/op 546.07 us/op 0.94
phase0 processRegistryUpdates - 250000 worstcase 0.5 182.17 ms/op 194.98 ms/op 0.93
altair processRewardsAndPenalties - 250000 normalcase 74.026 ms/op 91.240 ms/op 0.81
altair processRewardsAndPenalties - 250000 worstcase 74.522 ms/op 91.473 ms/op 0.81
phase0 getAttestationDeltas - 250000 normalcase 12.440 ms/op 13.867 ms/op 0.90
phase0 getAttestationDeltas - 250000 worstcase 13.745 ms/op 12.544 ms/op 1.10
phase0 processSlashings - 250000 worstcase 112.14 us/op 148.80 us/op 0.75
altair processSyncCommitteeUpdates - 250000 184.92 ms/op 217.04 ms/op 0.85
BeaconState.hashTreeRoot - No change 733.00 ns/op 935.00 ns/op 0.78
BeaconState.hashTreeRoot - 1 full validator 170.59 us/op 173.15 us/op 0.99
BeaconState.hashTreeRoot - 32 full validator 1.8286 ms/op 1.4922 ms/op 1.23
BeaconState.hashTreeRoot - 512 full validator 17.167 ms/op 19.345 ms/op 0.89
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 178.17 us/op 208.19 us/op 0.86
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 2.6112 ms/op 2.5090 ms/op 1.04
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 34.601 ms/op 36.619 ms/op 0.94
BeaconState.hashTreeRoot - 1 balances 148.39 us/op 177.06 us/op 0.84
BeaconState.hashTreeRoot - 32 balances 1.2957 ms/op 1.4964 ms/op 0.87
BeaconState.hashTreeRoot - 512 balances 12.440 ms/op 18.319 ms/op 0.68
BeaconState.hashTreeRoot - 250000 balances 246.70 ms/op 333.20 ms/op 0.74
aggregationBits - 2048 els - zipIndexesInBitList 45.380 us/op 66.035 us/op 0.69
byteArrayEquals 32 78.871 ns/op 118.57 ns/op 0.67
Buffer.compare 32 57.324 ns/op 71.366 ns/op 0.80
byteArrayEquals 1024 2.1250 us/op 3.1718 us/op 0.67
Buffer.compare 1024 74.154 ns/op 86.357 ns/op 0.86
byteArrayEquals 16384 33.807 us/op 57.480 us/op 0.59
Buffer.compare 16384 267.61 ns/op 451.49 ns/op 0.59
byteArrayEquals 123687377 266.49 ms/op 276.12 ms/op 0.97
Buffer.compare 123687377 11.503 ms/op 8.9186 ms/op 1.29
byteArrayEquals 32 - diff last byte 78.938 ns/op 76.276 ns/op 1.03
Buffer.compare 32 - diff last byte 59.590 ns/op 59.446 ns/op 1.00
byteArrayEquals 1024 - diff last byte 2.1596 us/op 2.1114 us/op 1.02
Buffer.compare 1024 - diff last byte 75.080 ns/op 75.809 ns/op 0.99
byteArrayEquals 16384 - diff last byte 33.949 us/op 36.026 us/op 0.94
Buffer.compare 16384 - diff last byte 272.72 ns/op 292.75 ns/op 0.93
byteArrayEquals 123687377 - diff last byte 279.70 ms/op 261.59 ms/op 1.07
Buffer.compare 123687377 - diff last byte 11.860 ms/op 10.383 ms/op 1.14
byteArrayEquals 32 - random bytes 6.8920 ns/op 6.8310 ns/op 1.01
Buffer.compare 32 - random bytes 66.772 ns/op 64.637 ns/op 1.03
byteArrayEquals 1024 - random bytes 6.7800 ns/op 6.5400 ns/op 1.04
Buffer.compare 1024 - random bytes 66.372 ns/op 64.021 ns/op 1.04
byteArrayEquals 16384 - random bytes 7.0280 ns/op 6.5750 ns/op 1.07
Buffer.compare 16384 - random bytes 64.008 ns/op 63.229 ns/op 1.01
byteArrayEquals 123687377 - random bytes 10.960 ns/op 10.090 ns/op 1.09
Buffer.compare 123687377 - random bytes 82.990 ns/op 77.370 ns/op 1.07
regular array get 100000 times 52.724 us/op 47.902 us/op 1.10
wrappedArray get 100000 times 49.381 us/op 48.357 us/op 1.02
arrayWithProxy get 100000 times 14.834 ms/op 14.396 ms/op 1.03
ssz.Root.equals 59.041 ns/op 56.488 ns/op 1.05
byteArrayEquals 58.557 ns/op 55.909 ns/op 1.05
Buffer.compare 12.849 ns/op 12.882 ns/op 1.00
shuffle list - 16384 els 9.1446 ms/op 9.0397 ms/op 1.01
shuffle list - 250000 els 130.62 ms/op 132.96 ms/op 0.98
processSlot - 1 slots 20.182 us/op 20.444 us/op 0.99
processSlot - 32 slots 4.4077 ms/op 4.3608 ms/op 1.01
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 67.174 ms/op 67.265 ms/op 1.00
getCommitteeAssignments - req 1 vs - 250000 vc 2.7771 ms/op 2.7342 ms/op 1.02
getCommitteeAssignments - req 100 vs - 250000 vc 3.9961 ms/op 3.9302 ms/op 1.02
getCommitteeAssignments - req 1000 vs - 250000 vc 4.3190 ms/op 4.4388 ms/op 0.97
findModifiedValidators - 10000 modified validators 605.18 ms/op 647.63 ms/op 0.93
findModifiedValidators - 1000 modified validators 569.04 ms/op 542.70 ms/op 1.05
findModifiedValidators - 100 modified validators 520.72 ms/op 589.75 ms/op 0.88
findModifiedValidators - 10 modified validators 596.18 ms/op 586.86 ms/op 1.02
findModifiedValidators - 1 modified validators 642.87 ms/op 642.14 ms/op 1.00
findModifiedValidators - no difference 565.76 ms/op 848.15 ms/op 0.67
compare ViewDUs 5.9856 s/op 8.3758 s/op 0.71
compare each validator Uint8Array 2.1141 s/op 2.2215 s/op 0.95
compare ViewDU to Uint8Array 1.5318 s/op 1.5928 s/op 0.96
migrate state 1000000 validators, 24 modified, 0 new 949.21 ms/op 1.0976 s/op 0.86
migrate state 1000000 validators, 1700 modified, 1000 new 1.3373 s/op 1.6319 s/op 0.82
migrate state 1000000 validators, 3400 modified, 2000 new 1.6496 s/op 1.8198 s/op 0.91
migrate state 1500000 validators, 24 modified, 0 new 1.0597 s/op 1.0679 s/op 0.99
migrate state 1500000 validators, 1700 modified, 1000 new 1.3494 s/op 1.5284 s/op 0.88
migrate state 1500000 validators, 3400 modified, 2000 new 1.8505 s/op 1.8902 s/op 0.98
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 5.5500 ns/op 9.2600 ns/op 0.60
state getBlockRootAtSlot - 250000 vs - 7PWei 1.3160 us/op 1.3010 us/op 1.01
computeProposers - vc 250000 12.040 ms/op 14.011 ms/op 0.86
computeEpochShuffling - vc 250000 138.86 ms/op 164.37 ms/op 0.84
getNextSyncCommittee - vc 250000 196.29 ms/op 208.32 ms/op 0.94
computeSigningRoot for AttestationData 37.926 us/op 41.974 us/op 0.90
hash AttestationData serialized data then Buffer.toString(base64) 2.7964 us/op 3.2957 us/op 0.85
toHexString serialized data 1.9079 us/op 2.3628 us/op 0.81
Buffer.toString(base64) 285.69 ns/op 429.85 ns/op 0.66

by benchmarkbot/action

g11tech
g11tech previously approved these changes Mar 27, 2024
Copy link
Contributor

@g11tech g11tech left a comment

Choose a reason for hiding this comment

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

Ahh makes sense to log the reasons individually as well

@jeluard
Copy link
Contributor Author

jeluard commented Mar 27, 2024

@nflaig I addressed your comment

@jeluard jeluard requested a review from nflaig March 27, 2024 16:36
@nflaig nflaig changed the title chore: reorder log statements chore: reorder block production log statements Mar 27, 2024
Copy link
Member

@nflaig nflaig left a comment

Choose a reason for hiding this comment

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

LGTM

@jeluard jeluard merged commit 4b17640 into unstable Mar 27, 2024
19 of 21 checks passed
@jeluard jeluard deleted the jeluard/reorder-logs branch March 27, 2024 19:59
@wemeetagain
Copy link
Member

🎉 This PR is included in v1.18.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.

4 participants