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

fix: move and fix execution engine state update checks for online state #5862

Merged
merged 2 commits into from
Aug 8, 2023

Conversation

g11tech
Copy link
Contributor

@g11tech g11tech commented Aug 8, 2023

Noticed that PR - fix: offline error message when node is shutting down #5797 was updating execution state from SYNCED to ONLINE since the checks for the same were not located at correct place which caused excessive logging: here is an example log:

ph 0/2 0.022[Node-A/execution] info: Execution client became online oldState=SYNCED, newState=ONLINE
EL 5743: INFO [08-07|18:59:44.030] Imported new potential chain segment     number=2 hash=fd4af3..63ebe2 blocks=1 txs=0 mgas=0.000 elapsed="190.628µs" mgasps=0.000 dirty=698.00B
Eph 0/2 0.031[Node-A/execution] info: Execution client is synced oldState=ONLINE, newState=SYNCED

This PR fixes the same

@g11tech g11tech requested a review from a team as a code owner August 8, 2023 08:32
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.

Do we really want to print out the enum values in all caps? oldState=SYNCED, newState=ONLINE

newState is already part of the message and oldState should be logged previously. There are also not that much changes of state where this would be helpful, most of the time it is from syncing to synced.

@nazarhussain
Copy link
Contributor

@g11tech That change will make the tests fail, will fix those and update the PR.

@nazarhussain
Copy link
Contributor

@nflaig The message is more descriptive, and having extra information and context does not harm, rather useful for log parsing for someone.

@github-actions
Copy link
Contributor

github-actions bot commented Aug 8, 2023

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: 1be0a65 Previous: df2f4d3 Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 535.71 us/op 466.47 us/op 1.15
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 84.213 us/op 79.543 us/op 1.06
BLS verify - blst-native 1.2279 ms/op 1.2305 ms/op 1.00
BLS verifyMultipleSignatures 3 - blst-native 2.5075 ms/op 2.5210 ms/op 0.99
BLS verifyMultipleSignatures 8 - blst-native 5.4078 ms/op 5.3880 ms/op 1.00
BLS verifyMultipleSignatures 32 - blst-native 19.513 ms/op 19.462 ms/op 1.00
BLS aggregatePubkeys 32 - blst-native 25.641 us/op 25.855 us/op 0.99
BLS aggregatePubkeys 128 - blst-native 100.99 us/op 101.37 us/op 1.00
getAttestationsForBlock 53.825 ms/op 59.687 ms/op 0.90
isKnown best case - 1 super set check 295.00 ns/op 331.00 ns/op 0.89
isKnown normal case - 2 super set checks 293.00 ns/op 287.00 ns/op 1.02
isKnown worse case - 16 super set checks 328.00 ns/op 275.00 ns/op 1.19
CheckpointStateCache - add get delete 5.3380 us/op 5.4020 us/op 0.99
validate api signedAggregateAndProof - struct 2.8078 ms/op 2.8512 ms/op 0.98
validate gossip signedAggregateAndProof - struct 2.8167 ms/op 2.8316 ms/op 0.99
validate api attestation - struct 1.3338 ms/op 1.3498 ms/op 0.99
validate gossip attestation - struct 1.3699 ms/op 1.3777 ms/op 0.99
pickEth1Vote - no votes 1.2529 ms/op 1.1786 ms/op 1.06
pickEth1Vote - max votes 10.073 ms/op 8.5222 ms/op 1.18
pickEth1Vote - Eth1Data hashTreeRoot value x2048 9.6454 ms/op 8.7800 ms/op 1.10
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 16.710 ms/op 16.678 ms/op 1.00
pickEth1Vote - Eth1Data fastSerialize value x2048 669.80 us/op 641.44 us/op 1.04
pickEth1Vote - Eth1Data fastSerialize tree x2048 5.2635 ms/op 4.2592 ms/op 1.24
bytes32 toHexString 545.00 ns/op 546.00 ns/op 1.00
bytes32 Buffer.toString(hex) 303.00 ns/op 293.00 ns/op 1.03
bytes32 Buffer.toString(hex) from Uint8Array 512.00 ns/op 443.00 ns/op 1.16
bytes32 Buffer.toString(hex) + 0x 311.00 ns/op 295.00 ns/op 1.05
Object access 1 prop 0.17800 ns/op 0.20300 ns/op 0.88
Map access 1 prop 0.14900 ns/op 0.15700 ns/op 0.95
Object get x1000 7.6610 ns/op 7.4790 ns/op 1.02
Map get x1000 0.67200 ns/op 0.73800 ns/op 0.91
Object set x1000 54.972 ns/op 59.976 ns/op 0.92
Map set x1000 40.543 ns/op 47.958 ns/op 0.85
Return object 10000 times 0.24620 ns/op 0.25390 ns/op 0.97
Throw Error 10000 times 3.8863 us/op 3.9072 us/op 0.99
fastMsgIdFn sha256 / 200 bytes 3.4290 us/op 3.4100 us/op 1.01
fastMsgIdFn h32 xxhash / 200 bytes 305.00 ns/op 358.00 ns/op 0.85
fastMsgIdFn h64 xxhash / 200 bytes 353.00 ns/op 370.00 ns/op 0.95
fastMsgIdFn sha256 / 1000 bytes 11.601 us/op 11.679 us/op 0.99
fastMsgIdFn h32 xxhash / 1000 bytes 441.00 ns/op 483.00 ns/op 0.91
fastMsgIdFn h64 xxhash / 1000 bytes 440.00 ns/op 457.00 ns/op 0.96
fastMsgIdFn sha256 / 10000 bytes 104.76 us/op 104.97 us/op 1.00
fastMsgIdFn h32 xxhash / 10000 bytes 1.9790 us/op 2.0060 us/op 0.99
fastMsgIdFn h64 xxhash / 10000 bytes 1.3540 us/op 1.3780 us/op 0.98
enrSubnets - fastDeserialize 64 bits 1.5080 us/op 1.3340 us/op 1.13
enrSubnets - ssz BitVector 64 bits 542.00 ns/op 433.00 ns/op 1.25
enrSubnets - fastDeserialize 4 bits 227.00 ns/op 216.00 ns/op 1.05
enrSubnets - ssz BitVector 4 bits 534.00 ns/op 505.00 ns/op 1.06
prioritizePeers score -10:0 att 32-0.1 sync 2-0 115.89 us/op 118.61 us/op 0.98
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 149.57 us/op 153.94 us/op 0.97
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 198.84 us/op 180.56 us/op 1.10
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 343.53 us/op 302.18 us/op 1.14
prioritizePeers score 0:0 att 64-1 sync 4-1 382.13 us/op 343.00 us/op 1.11
array of 16000 items push then shift 1.6187 us/op 1.6150 us/op 1.00
LinkedList of 16000 items push then shift 8.9720 ns/op 9.3680 ns/op 0.96
array of 16000 items push then pop 68.336 ns/op 63.764 ns/op 1.07
LinkedList of 16000 items push then pop 8.8910 ns/op 9.3810 ns/op 0.95
array of 24000 items push then shift 2.4615 us/op 2.5410 us/op 0.97
LinkedList of 24000 items push then shift 9.1220 ns/op 9.5560 ns/op 0.95
array of 24000 items push then pop 127.03 ns/op 122.87 ns/op 1.03
LinkedList of 24000 items push then pop 9.0700 ns/op 9.2720 ns/op 0.98
intersect bitArray bitLen 8 6.9650 ns/op 7.0230 ns/op 0.99
intersect array and set length 8 61.180 ns/op 65.254 ns/op 0.94
intersect bitArray bitLen 128 32.654 ns/op 32.569 ns/op 1.00
intersect array and set length 128 831.50 ns/op 932.08 ns/op 0.89
bitArray.getTrueBitIndexes() bitLen 128 1.6120 us/op 1.8460 us/op 0.87
bitArray.getTrueBitIndexes() bitLen 248 2.8910 us/op 2.9190 us/op 0.99
bitArray.getTrueBitIndexes() bitLen 512 5.4860 us/op 6.0590 us/op 0.91
Buffer.concat 32 items 1.0740 us/op 1.0290 us/op 1.04
Uint8Array.set 32 items 1.7630 us/op 1.9210 us/op 0.92
transfer serialized Status (84 B) 1.8790 us/op 1.8760 us/op 1.00
copy serialized Status (84 B) 1.5620 us/op 1.6930 us/op 0.92
transfer serialized SignedVoluntaryExit (112 B) 1.9890 us/op 1.9850 us/op 1.00
copy serialized SignedVoluntaryExit (112 B) 1.6820 us/op 1.7210 us/op 0.98
transfer serialized ProposerSlashing (416 B) 2.7230 us/op 2.3610 us/op 1.15
copy serialized ProposerSlashing (416 B) 2.8510 us/op 2.5980 us/op 1.10
transfer serialized Attestation (485 B) 2.9980 us/op 2.4400 us/op 1.23
copy serialized Attestation (485 B) 3.3990 us/op 2.3320 us/op 1.46
transfer serialized AttesterSlashing (33232 B) 3.3030 us/op 2.3000 us/op 1.44
copy serialized AttesterSlashing (33232 B) 6.9980 us/op 8.7180 us/op 0.80
transfer serialized Small SignedBeaconBlock (128000 B) 3.3680 us/op 2.6290 us/op 1.28
copy serialized Small SignedBeaconBlock (128000 B) 17.073 us/op 21.130 us/op 0.81
transfer serialized Avg SignedBeaconBlock (200000 B) 3.7710 us/op 2.9420 us/op 1.28
copy serialized Avg SignedBeaconBlock (200000 B) 24.711 us/op 34.244 us/op 0.72
transfer serialized BlobsSidecar (524380 B) 3.8730 us/op 3.2570 us/op 1.19
copy serialized BlobsSidecar (524380 B) 86.808 us/op 213.94 us/op 0.41
transfer serialized Big SignedBeaconBlock (1000000 B) 3.9050 us/op 3.5830 us/op 1.09
copy serialized Big SignedBeaconBlock (1000000 B) 150.25 us/op 192.40 us/op 0.78
pass gossip attestations to forkchoice per slot 2.1296 ms/op 2.2722 ms/op 0.94
forkChoice updateHead vc 100000 bc 64 eq 0 2.5739 ms/op 2.3039 ms/op 1.12
forkChoice updateHead vc 600000 bc 64 eq 0 13.826 ms/op 12.032 ms/op 1.15
forkChoice updateHead vc 1000000 bc 64 eq 0 18.982 ms/op 19.029 ms/op 1.00
forkChoice updateHead vc 600000 bc 320 eq 0 18.400 ms/op 18.117 ms/op 1.02
forkChoice updateHead vc 600000 bc 1200 eq 0 82.427 ms/op 88.122 ms/op 0.94
forkChoice updateHead vc 600000 bc 64 eq 1000 21.662 ms/op 19.272 ms/op 1.12
forkChoice updateHead vc 600000 bc 64 eq 10000 24.124 ms/op 21.880 ms/op 1.10
forkChoice updateHead vc 600000 bc 64 eq 300000 29.813 ms/op 29.680 ms/op 1.00
computeDeltas 3.4224 ms/op 3.0589 ms/op 1.12
computeProposerBoostScoreFromBalances 395.92 us/op 397.68 us/op 1.00
altair processAttestation - 250000 vs - 7PWei normalcase 2.3630 ms/op 2.4680 ms/op 0.96
altair processAttestation - 250000 vs - 7PWei worstcase 3.5593 ms/op 4.2850 ms/op 0.83
altair processAttestation - setStatus - 1/6 committees join 189.15 us/op 179.55 us/op 1.05
altair processAttestation - setStatus - 1/3 committees join 356.00 us/op 362.76 us/op 0.98
altair processAttestation - setStatus - 1/2 committees join 490.08 us/op 495.19 us/op 0.99
altair processAttestation - setStatus - 2/3 committees join 613.77 us/op 620.39 us/op 0.99
altair processAttestation - setStatus - 4/5 committees join 831.14 us/op 827.84 us/op 1.00
altair processAttestation - setStatus - 100% committees join 983.44 us/op 960.49 us/op 1.02
altair processBlock - 250000 vs - 7PWei normalcase 10.220 ms/op 10.030 ms/op 1.02
altair processBlock - 250000 vs - 7PWei normalcase hashState 17.433 ms/op 17.266 ms/op 1.01
altair processBlock - 250000 vs - 7PWei worstcase 39.799 ms/op 39.845 ms/op 1.00
altair processBlock - 250000 vs - 7PWei worstcase hashState 59.948 ms/op 61.466 ms/op 0.98
phase0 processBlock - 250000 vs - 7PWei normalcase 2.8407 ms/op 2.7770 ms/op 1.02
phase0 processBlock - 250000 vs - 7PWei worstcase 32.801 ms/op 32.938 ms/op 1.00
altair processEth1Data - 250000 vs - 7PWei normalcase 493.52 us/op 485.24 us/op 1.02
getExpectedWithdrawals 250000 eb:1,eth1:1,we:0,wn:0,smpl:15 14.208 us/op 15.877 us/op 0.89
getExpectedWithdrawals 250000 eb:0.95,eth1:0.1,we:0.05,wn:0,smpl:219 49.660 us/op 73.303 us/op 0.68
getExpectedWithdrawals 250000 eb:0.95,eth1:0.3,we:0.05,wn:0,smpl:42 13.460 us/op 25.459 us/op 0.53
getExpectedWithdrawals 250000 eb:0.95,eth1:0.7,we:0.05,wn:0,smpl:18 14.834 us/op 19.538 us/op 0.76
getExpectedWithdrawals 250000 eb:0.1,eth1:0.1,we:0,wn:0,smpl:1020 212.93 us/op 225.37 us/op 0.94
getExpectedWithdrawals 250000 eb:0.03,eth1:0.03,we:0,wn:0,smpl:11777 1.4260 ms/op 1.6392 ms/op 0.87
getExpectedWithdrawals 250000 eb:0.01,eth1:0.01,we:0,wn:0,smpl:16384 2.1166 ms/op 2.0294 ms/op 1.04
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,smpl:16384 2.3292 ms/op 2.4042 ms/op 0.97
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,nocache,smpl:16384 3.6950 ms/op 3.8353 ms/op 0.96
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,smpl:16384 2.8550 ms/op 3.0107 ms/op 0.95
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,nocache,smpl:16384 4.8509 ms/op 5.6430 ms/op 0.86
Tree 40 250000 create 335.56 ms/op 353.45 ms/op 0.95
Tree 40 250000 get(125000) 209.55 ns/op 220.19 ns/op 0.95
Tree 40 250000 set(125000) 1.0614 us/op 1.0960 us/op 0.97
Tree 40 250000 toArray() 22.134 ms/op 23.726 ms/op 0.93
Tree 40 250000 iterate all - toArray() + loop 20.206 ms/op 22.125 ms/op 0.91
Tree 40 250000 iterate all - get(i) 72.581 ms/op 73.258 ms/op 0.99
MutableVector 250000 create 14.560 ms/op 16.842 ms/op 0.86
MutableVector 250000 get(125000) 6.5790 ns/op 6.9740 ns/op 0.94
MutableVector 250000 set(125000) 257.46 ns/op 253.23 ns/op 1.02
MutableVector 250000 toArray() 3.4384 ms/op 3.6689 ms/op 0.94
MutableVector 250000 iterate all - toArray() + loop 3.5596 ms/op 3.5398 ms/op 1.01
MutableVector 250000 iterate all - get(i) 1.5514 ms/op 1.5576 ms/op 1.00
Array 250000 create 3.2504 ms/op 3.3589 ms/op 0.97
Array 250000 clone - spread 1.1241 ms/op 1.1112 ms/op 1.01
Array 250000 get(125000) 0.55800 ns/op 0.55700 ns/op 1.00
Array 250000 set(125000) 0.63500 ns/op 0.62700 ns/op 1.01
Array 250000 iterate all - loop 88.293 us/op 113.39 us/op 0.78
effectiveBalanceIncrements clone Uint8Array 300000 35.546 us/op 34.626 us/op 1.03
effectiveBalanceIncrements clone MutableVector 300000 336.00 ns/op 301.00 ns/op 1.12
effectiveBalanceIncrements rw all Uint8Array 300000 183.67 us/op 186.10 us/op 0.99
effectiveBalanceIncrements rw all MutableVector 300000 85.113 ms/op 100.86 ms/op 0.84
phase0 afterProcessEpoch - 250000 vs - 7PWei 118.67 ms/op 119.03 ms/op 1.00
phase0 beforeProcessEpoch - 250000 vs - 7PWei 42.468 ms/op 43.521 ms/op 0.98
altair processEpoch - mainnet_e81889 344.82 ms/op 345.15 ms/op 1.00
mainnet_e81889 - altair beforeProcessEpoch 51.884 ms/op 61.276 ms/op 0.85
mainnet_e81889 - altair processJustificationAndFinalization 16.424 us/op 15.032 us/op 1.09
mainnet_e81889 - altair processInactivityUpdates 6.4862 ms/op 6.3572 ms/op 1.02
mainnet_e81889 - altair processRewardsAndPenalties 58.321 ms/op 73.726 ms/op 0.79
mainnet_e81889 - altair processRegistryUpdates 4.2480 us/op 3.4360 us/op 1.24
mainnet_e81889 - altair processSlashings 743.00 ns/op 653.00 ns/op 1.14
mainnet_e81889 - altair processEth1DataReset 1.1980 us/op 620.00 ns/op 1.93
mainnet_e81889 - altair processEffectiveBalanceUpdates 1.5408 ms/op 1.4943 ms/op 1.03
mainnet_e81889 - altair processSlashingsReset 4.0900 us/op 4.2020 us/op 0.97
mainnet_e81889 - altair processRandaoMixesReset 4.9990 us/op 9.9630 us/op 0.50
mainnet_e81889 - altair processHistoricalRootsUpdate 810.00 ns/op 1.2900 us/op 0.63
mainnet_e81889 - altair processParticipationFlagUpdates 1.8450 us/op 4.6220 us/op 0.40
mainnet_e81889 - altair processSyncCommitteeUpdates 1.1590 us/op 1.6480 us/op 0.70
mainnet_e81889 - altair afterProcessEpoch 130.20 ms/op 146.47 ms/op 0.89
capella processEpoch - mainnet_e217614 1.1770 s/op 1.1972 s/op 0.98
mainnet_e217614 - capella beforeProcessEpoch 268.54 ms/op 307.46 ms/op 0.87
mainnet_e217614 - capella processJustificationAndFinalization 18.904 us/op 30.914 us/op 0.61
mainnet_e217614 - capella processInactivityUpdates 19.218 ms/op 24.088 ms/op 0.80
mainnet_e217614 - capella processRewardsAndPenalties 313.36 ms/op 343.46 ms/op 0.91
mainnet_e217614 - capella processRegistryUpdates 34.500 us/op 39.458 us/op 0.87
mainnet_e217614 - capella processSlashings 894.00 ns/op 1.1840 us/op 0.76
mainnet_e217614 - capella processEth1DataReset 1.0100 us/op 1.3220 us/op 0.76
mainnet_e217614 - capella processEffectiveBalanceUpdates 4.7754 ms/op 5.6330 ms/op 0.85
mainnet_e217614 - capella processSlashingsReset 3.2760 us/op 5.9260 us/op 0.55
mainnet_e217614 - capella processRandaoMixesReset 7.1900 us/op 8.5670 us/op 0.84
mainnet_e217614 - capella processHistoricalRootsUpdate 2.6270 us/op 1.1420 us/op 2.30
mainnet_e217614 - capella processParticipationFlagUpdates 2.3520 us/op 5.6230 us/op 0.42
mainnet_e217614 - capella afterProcessEpoch 315.25 ms/op 341.25 ms/op 0.92
phase0 processEpoch - mainnet_e58758 430.70 ms/op 419.70 ms/op 1.03
mainnet_e58758 - phase0 beforeProcessEpoch 156.81 ms/op 137.43 ms/op 1.14
mainnet_e58758 - phase0 processJustificationAndFinalization 18.995 us/op 22.996 us/op 0.83
mainnet_e58758 - phase0 processRewardsAndPenalties 70.702 ms/op 67.382 ms/op 1.05
mainnet_e58758 - phase0 processRegistryUpdates 15.762 us/op 21.025 us/op 0.75
mainnet_e58758 - phase0 processSlashings 715.00 ns/op 1.3090 us/op 0.55
mainnet_e58758 - phase0 processEth1DataReset 724.00 ns/op 1.1600 us/op 0.62
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.3531 ms/op 1.5035 ms/op 0.90
mainnet_e58758 - phase0 processSlashingsReset 4.3050 us/op 5.0830 us/op 0.85
mainnet_e58758 - phase0 processRandaoMixesReset 6.0160 us/op 7.9270 us/op 0.76
mainnet_e58758 - phase0 processHistoricalRootsUpdate 633.00 ns/op 1.0550 us/op 0.60
mainnet_e58758 - phase0 processParticipationRecordUpdates 5.7990 us/op 7.5120 us/op 0.77
mainnet_e58758 - phase0 afterProcessEpoch 107.89 ms/op 115.93 ms/op 0.93
phase0 processEffectiveBalanceUpdates - 250000 normalcase 1.6214 ms/op 1.5323 ms/op 1.06
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 1.6539 ms/op 2.6933 ms/op 0.61
altair processInactivityUpdates - 250000 normalcase 28.736 ms/op 31.744 ms/op 0.91
altair processInactivityUpdates - 250000 worstcase 26.357 ms/op 22.771 ms/op 1.16
phase0 processRegistryUpdates - 250000 normalcase 12.687 us/op 21.517 us/op 0.59
phase0 processRegistryUpdates - 250000 badcase_full_deposits 490.54 us/op 485.24 us/op 1.01
phase0 processRegistryUpdates - 250000 worstcase 0.5 141.13 ms/op 191.28 ms/op 0.74
altair processRewardsAndPenalties - 250000 normalcase 74.977 ms/op 99.554 ms/op 0.75
altair processRewardsAndPenalties - 250000 worstcase 72.718 ms/op 99.620 ms/op 0.73
phase0 getAttestationDeltas - 250000 normalcase 8.6532 ms/op 11.394 ms/op 0.76
phase0 getAttestationDeltas - 250000 worstcase 8.4092 ms/op 12.956 ms/op 0.65
phase0 processSlashings - 250000 worstcase 2.3398 ms/op 3.0759 ms/op 0.76
altair processSyncCommitteeUpdates - 250000 156.03 ms/op 173.76 ms/op 0.90
BeaconState.hashTreeRoot - No change 263.00 ns/op 335.00 ns/op 0.79
BeaconState.hashTreeRoot - 1 full validator 53.031 us/op 67.770 us/op 0.78
BeaconState.hashTreeRoot - 32 full validator 719.48 us/op 640.83 us/op 1.12
BeaconState.hashTreeRoot - 512 full validator 5.8803 ms/op 8.2450 ms/op 0.71
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 65.104 us/op 86.008 us/op 0.76
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 963.80 us/op 1.1742 ms/op 0.82
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 12.075 ms/op 14.746 ms/op 0.82
BeaconState.hashTreeRoot - 1 balances 54.443 us/op 63.892 us/op 0.85
BeaconState.hashTreeRoot - 32 balances 502.21 us/op 591.77 us/op 0.85
BeaconState.hashTreeRoot - 512 balances 4.8436 ms/op 5.9216 ms/op 0.82
BeaconState.hashTreeRoot - 250000 balances 82.005 ms/op 83.350 ms/op 0.98
aggregationBits - 2048 els - zipIndexesInBitList 15.328 us/op 20.858 us/op 0.73
regular array get 100000 times 45.554 us/op 47.486 us/op 0.96
wrappedArray get 100000 times 34.125 us/op 39.334 us/op 0.87
arrayWithProxy get 100000 times 14.884 ms/op 17.425 ms/op 0.85
ssz.Root.equals 211.00 ns/op 292.00 ns/op 0.72
byteArrayEquals 209.00 ns/op 275.00 ns/op 0.76
shuffle list - 16384 els 6.9923 ms/op 7.4460 ms/op 0.94
shuffle list - 250000 els 99.801 ms/op 109.53 ms/op 0.91
processSlot - 1 slots 8.9010 us/op 10.739 us/op 0.83
processSlot - 32 slots 1.4172 ms/op 1.5367 ms/op 0.92
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 54.679 ms/op 63.276 ms/op 0.86
getCommitteeAssignments - req 1 vs - 250000 vc 2.5019 ms/op 2.9057 ms/op 0.86
getCommitteeAssignments - req 100 vs - 250000 vc 3.7092 ms/op 4.2096 ms/op 0.88
getCommitteeAssignments - req 1000 vs - 250000 vc 4.0736 ms/op 4.5081 ms/op 0.90
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 4.6000 ns/op 5.5100 ns/op 0.83
state getBlockRootAtSlot - 250000 vs - 7PWei 782.69 ns/op 753.96 ns/op 1.04
computeProposers - vc 250000 9.0845 ms/op 10.251 ms/op 0.89
computeEpochShuffling - vc 250000 112.50 ms/op 111.04 ms/op 1.01
getNextSyncCommittee - vc 250000 149.00 ms/op 163.83 ms/op 0.91
computeSigningRoot for AttestationData 13.361 us/op 15.077 us/op 0.89
hash AttestationData serialized data then Buffer.toString(base64) 2.3631 us/op 2.5329 us/op 0.93
toHexString serialized data 1.0740 us/op 1.3940 us/op 0.77
Buffer.toString(base64) 231.30 ns/op 266.03 ns/op 0.87

by benchmarkbot/action

@nflaig
Copy link
Member

nflaig commented Aug 8, 2023

The message is more descriptive, and having extra information and context does not harm

@nazarhussain maybe just add previous state then? The log message already contains the newState hence it is duplicated information. Maybe not all caps would be preferable as well

One other note, on startup we print this

info: Execution client is synced oldState=ONLINE, newState=SYNCED

This is confusing to me, does this mean the EL was not synced before? I know it doesn't but will the user know?

Before it just sayed info: Execution client is synced which was fine since it was rather just the state without any indication of what the previous state might have been

@g11tech
Copy link
Contributor Author

g11tech commented Aug 8, 2023

i think the current logging is informative as well as easily understood , we always print out enum in caps i think so i guess that is fine as well

Copy link
Contributor Author

@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.

looks good to me, @nazarhussain you may approve the PR and merge (I as author can't do the same)

@g11tech g11tech enabled auto-merge (squash) August 8, 2023 09:17
@g11tech g11tech merged commit a8ad567 into unstable Aug 8, 2023
11 checks passed
@g11tech g11tech deleted the g11tech/fix-ee-state-log branch August 8, 2023 09:33
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.

3 participants