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.

Sign up for GitHub

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

Jump to bottom

refactor: revise validator log to output seen instead of exists #5507

Merged
merged 1 commit into from
May 18, 2023
Merged

refactor: revise validator log to output seen instead of exists #5507

merged 1 commit into from
May 18, 2023

Conversation

philknows
Copy link
Member

Motivation

Referencing feedback from a user on Discord: https://discord.com/channels/593655374469660673/593655641445367808/1108123487840763977

On the VC, due to the frequency of this log being output: Validator exists in beacon chain, there is a probable chance that the word exists can be easily misinterpreted with the word exits - which should be avoided for bad UX.

Description

An alternative syntax for this log output is Validator seen on beacon chain which will avoid any misinterpretation.

@philknows philknows requested a review from a team as a code owner May 17, 2023 23:57
@matthewkeil
Copy link
Member

You may need to update the title to a conventional commit

@philknows philknows changed the title Revise validator log to output seen instead of exists refactor: revise validator log to output seen instead of exists May 18, 2023
@github-actions
Copy link
Contributor

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: fd23539 Previous: c780a1d Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 864.55 us/op 556.38 us/op 1.55
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 44.678 us/op 49.548 us/op 0.90
BLS verify - blst-native 1.1833 ms/op 1.2148 ms/op 0.97
BLS verifyMultipleSignatures 3 - blst-native 2.3884 ms/op 2.4666 ms/op 0.97
BLS verifyMultipleSignatures 8 - blst-native 5.1276 ms/op 5.2934 ms/op 0.97
BLS verifyMultipleSignatures 32 - blst-native 18.546 ms/op 19.033 ms/op 0.97
BLS aggregatePubkeys 32 - blst-native 24.862 us/op 25.507 us/op 0.97
BLS aggregatePubkeys 128 - blst-native 96.915 us/op 99.673 us/op 0.97
getAttestationsForBlock 52.480 ms/op 57.613 ms/op 0.91
isKnown best case - 1 super set check 237.00 ns/op 258.00 ns/op 0.92
isKnown normal case - 2 super set checks 236.00 ns/op 249.00 ns/op 0.95
isKnown worse case - 16 super set checks 233.00 ns/op 250.00 ns/op 0.93
CheckpointStateCache - add get delete 4.9380 us/op 5.3060 us/op 0.93
validate gossip signedAggregateAndProof - struct 2.6854 ms/op 2.8108 ms/op 0.96
validate gossip attestation - struct 1.3176 ms/op 1.3347 ms/op 0.99
pickEth1Vote - no votes 1.2308 ms/op 1.4239 ms/op 0.86
pickEth1Vote - max votes 10.108 ms/op 11.264 ms/op 0.90
pickEth1Vote - Eth1Data hashTreeRoot value x2048 8.5742 ms/op 9.8970 ms/op 0.87
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 13.922 ms/op 16.711 ms/op 0.83
pickEth1Vote - Eth1Data fastSerialize value x2048 632.27 us/op 671.33 us/op 0.94
pickEth1Vote - Eth1Data fastSerialize tree x2048 7.7010 ms/op 7.0556 ms/op 1.09
bytes32 toHexString 469.00 ns/op 582.00 ns/op 0.81
bytes32 Buffer.toString(hex) 330.00 ns/op 356.00 ns/op 0.93
bytes32 Buffer.toString(hex) from Uint8Array 533.00 ns/op 623.00 ns/op 0.86
bytes32 Buffer.toString(hex) + 0x 334.00 ns/op 416.00 ns/op 0.80
Object access 1 prop 0.15900 ns/op 0.19700 ns/op 0.81
Map access 1 prop 0.15500 ns/op 0.16600 ns/op 0.93
Object get x1000 7.0160 ns/op 7.1840 ns/op 0.98
Map get x1000 0.54500 ns/op 0.63000 ns/op 0.87
Object set x1000 49.969 ns/op 56.996 ns/op 0.88
Map set x1000 42.746 ns/op 53.285 ns/op 0.80
Return object 10000 times 0.22950 ns/op 0.24390 ns/op 0.94
Throw Error 10000 times 4.1117 us/op 4.2183 us/op 0.97
fastMsgIdFn sha256 / 200 bytes 3.3530 us/op 3.4980 us/op 0.96
fastMsgIdFn h32 xxhash / 200 bytes 268.00 ns/op 303.00 ns/op 0.88
fastMsgIdFn h64 xxhash / 200 bytes 384.00 ns/op 451.00 ns/op 0.85
fastMsgIdFn sha256 / 1000 bytes 11.393 us/op 11.696 us/op 0.97
fastMsgIdFn h32 xxhash / 1000 bytes 403.00 ns/op 439.00 ns/op 0.92
fastMsgIdFn h64 xxhash / 1000 bytes 463.00 ns/op 530.00 ns/op 0.87
fastMsgIdFn sha256 / 10000 bytes 105.18 us/op 104.60 us/op 1.01
fastMsgIdFn h32 xxhash / 10000 bytes 1.9080 us/op 1.9880 us/op 0.96
fastMsgIdFn h64 xxhash / 10000 bytes 1.3500 us/op 1.4130 us/op 0.96
enrSubnets - fastDeserialize 64 bits 1.2660 us/op 1.3330 us/op 0.95
enrSubnets - ssz BitVector 64 bits 492.00 ns/op 502.00 ns/op 0.98
enrSubnets - fastDeserialize 4 bits 164.00 ns/op 170.00 ns/op 0.96
enrSubnets - ssz BitVector 4 bits 503.00 ns/op 512.00 ns/op 0.98
prioritizePeers score -10:0 att 32-0.1 sync 2-0 108.43 us/op 112.86 us/op 0.96
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 132.17 us/op 160.11 us/op 0.83
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 169.76 us/op 202.86 us/op 0.84
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 301.91 us/op 369.92 us/op 0.82
prioritizePeers score 0:0 att 64-1 sync 4-1 365.55 us/op 417.98 us/op 0.87
array of 16000 items push then shift 1.6366 us/op 1.7356 us/op 0.94
LinkedList of 16000 items push then shift 8.8330 ns/op 9.2110 ns/op 0.96
array of 16000 items push then pop 85.636 ns/op 103.39 ns/op 0.83
LinkedList of 16000 items push then pop 8.5980 ns/op 9.0290 ns/op 0.95
array of 24000 items push then shift 2.3764 us/op 2.3992 us/op 0.99
LinkedList of 24000 items push then shift 8.8840 ns/op 9.3740 ns/op 0.95
array of 24000 items push then pop 76.150 ns/op 92.334 ns/op 0.82
LinkedList of 24000 items push then pop 8.6980 ns/op 8.6710 ns/op 1.00
intersect bitArray bitLen 8 13.590 ns/op 13.512 ns/op 1.01
intersect array and set length 8 77.986 ns/op 99.595 ns/op 0.78
intersect bitArray bitLen 128 44.283 ns/op 45.832 ns/op 0.97
intersect array and set length 128 1.0579 us/op 1.3084 us/op 0.81
Buffer.concat 32 items 2.9190 us/op 3.2920 us/op 0.89
Uint8Array.set 32 items 2.6030 us/op 3.3000 us/op 0.79
pass gossip attestations to forkchoice per slot 2.8936 ms/op 3.1502 ms/op 0.92
computeDeltas 2.9375 ms/op 3.0797 ms/op 0.95
computeProposerBoostScoreFromBalances 1.8167 ms/op 1.8181 ms/op 1.00
altair processAttestation - 250000 vs - 7PWei normalcase 2.5958 ms/op 3.6983 ms/op 0.70
altair processAttestation - 250000 vs - 7PWei worstcase 3.5135 ms/op 4.8440 ms/op 0.73
altair processAttestation - setStatus - 1/6 committees join 144.17 us/op 163.80 us/op 0.88
altair processAttestation - setStatus - 1/3 committees join 280.85 us/op 296.72 us/op 0.95
altair processAttestation - setStatus - 1/2 committees join 377.93 us/op 415.48 us/op 0.91
altair processAttestation - setStatus - 2/3 committees join 468.65 us/op 535.45 us/op 0.88
altair processAttestation - setStatus - 4/5 committees join 639.32 us/op 670.18 us/op 0.95
altair processAttestation - setStatus - 100% committees join 759.06 us/op 782.31 us/op 0.97
altair processBlock - 250000 vs - 7PWei normalcase 16.970 ms/op 18.357 ms/op 0.92
altair processBlock - 250000 vs - 7PWei normalcase hashState 23.148 ms/op 27.927 ms/op 0.83
altair processBlock - 250000 vs - 7PWei worstcase 47.746 ms/op 56.376 ms/op 0.85
altair processBlock - 250000 vs - 7PWei worstcase hashState 73.390 ms/op 75.948 ms/op 0.97
phase0 processBlock - 250000 vs - 7PWei normalcase 2.2734 ms/op 2.9145 ms/op 0.78
phase0 processBlock - 250000 vs - 7PWei worstcase 30.131 ms/op 35.057 ms/op 0.86
altair processEth1Data - 250000 vs - 7PWei normalcase 484.24 us/op 731.25 us/op 0.66
vc - 250000 eb 1 eth1 1 we 0 wn 0 - smpl 15 8.4170 us/op 13.474 us/op 0.62
vc - 250000 eb 0.95 eth1 0.1 we 0.05 wn 0 - smpl 219 36.161 us/op 36.471 us/op 0.99
vc - 250000 eb 0.95 eth1 0.3 we 0.05 wn 0 - smpl 42 10.301 us/op 15.627 us/op 0.66
vc - 250000 eb 0.95 eth1 0.7 we 0.05 wn 0 - smpl 18 9.0720 us/op 12.859 us/op 0.71
vc - 250000 eb 0.1 eth1 0.1 we 0 wn 0 - smpl 1020 114.49 us/op 140.07 us/op 0.82
vc - 250000 eb 0.03 eth1 0.03 we 0 wn 0 - smpl 11777 661.76 us/op 962.94 us/op 0.69
vc - 250000 eb 0.01 eth1 0.01 we 0 wn 0 - smpl 16384 930.35 us/op 1.2511 ms/op 0.74
vc - 250000 eb 0 eth1 0 we 0 wn 0 - smpl 16384 906.26 us/op 1.1082 ms/op 0.82
vc - 250000 eb 0 eth1 0 we 0 wn 0 nocache - smpl 16384 2.6334 ms/op 3.2714 ms/op 0.80
vc - 250000 eb 0 eth1 1 we 0 wn 0 - smpl 16384 1.7071 ms/op 2.0879 ms/op 0.82
vc - 250000 eb 0 eth1 1 we 0 wn 0 nocache - smpl 16384 4.3388 ms/op 4.3458 ms/op 1.00
Tree 40 250000 create 346.04 ms/op 462.41 ms/op 0.75
Tree 40 250000 get(125000) 194.10 ns/op 211.63 ns/op 0.92
Tree 40 250000 set(125000) 1.0332 us/op 1.8550 us/op 0.56
Tree 40 250000 toArray() 20.715 ms/op 28.063 ms/op 0.74
Tree 40 250000 iterate all - toArray() + loop 19.711 ms/op 29.886 ms/op 0.66
Tree 40 250000 iterate all - get(i) 72.733 ms/op 86.018 ms/op 0.85
MutableVector 250000 create 11.193 ms/op 15.298 ms/op 0.73
MutableVector 250000 get(125000) 6.4650 ns/op 9.7470 ns/op 0.66
MutableVector 250000 set(125000) 269.80 ns/op 769.79 ns/op 0.35
MutableVector 250000 toArray() 2.8840 ms/op 5.5828 ms/op 0.52
MutableVector 250000 iterate all - toArray() + loop 3.0147 ms/op 5.7919 ms/op 0.52
MutableVector 250000 iterate all - get(i) 1.5307 ms/op 1.6969 ms/op 0.90
Array 250000 create 2.7183 ms/op 4.2942 ms/op 0.63
Array 250000 clone - spread 1.1902 ms/op 1.9639 ms/op 0.61
Array 250000 get(125000) 0.58200 ns/op 1.5620 ns/op 0.37
Array 250000 set(125000) 0.60600 ns/op 1.8100 ns/op 0.33
Array 250000 iterate all - loop 83.341 us/op 128.97 us/op 0.65
effectiveBalanceIncrements clone Uint8Array 300000 23.299 us/op 69.737 us/op 0.33
effectiveBalanceIncrements clone MutableVector 300000 315.00 ns/op 447.00 ns/op 0.70
effectiveBalanceIncrements rw all Uint8Array 300000 168.63 us/op 185.38 us/op 0.91
effectiveBalanceIncrements rw all MutableVector 300000 79.712 ms/op 159.16 ms/op 0.50
phase0 afterProcessEpoch - 250000 vs - 7PWei 115.26 ms/op 126.54 ms/op 0.91
phase0 beforeProcessEpoch - 250000 vs - 7PWei 33.692 ms/op 53.005 ms/op 0.64
altair processEpoch - mainnet_e81889 332.42 ms/op 343.41 ms/op 0.97
mainnet_e81889 - altair beforeProcessEpoch 66.465 ms/op 73.945 ms/op 0.90
mainnet_e81889 - altair processJustificationAndFinalization 19.064 us/op 19.447 us/op 0.98
mainnet_e81889 - altair processInactivityUpdates 5.9368 ms/op 5.7474 ms/op 1.03
mainnet_e81889 - altair processRewardsAndPenalties 69.454 ms/op 67.812 ms/op 1.02
mainnet_e81889 - altair processRegistryUpdates 3.9380 us/op 2.5660 us/op 1.53
mainnet_e81889 - altair processSlashings 995.00 ns/op 804.00 ns/op 1.24
mainnet_e81889 - altair processEth1DataReset 627.00 ns/op 875.00 ns/op 0.72
mainnet_e81889 - altair processEffectiveBalanceUpdates 3.4382 ms/op 1.2686 ms/op 2.71
mainnet_e81889 - altair processSlashingsReset 6.3890 us/op 5.4700 us/op 1.17
mainnet_e81889 - altair processRandaoMixesReset 10.922 us/op 4.8680 us/op 2.24
mainnet_e81889 - altair processHistoricalRootsUpdate 1.7160 us/op 716.00 ns/op 2.40
mainnet_e81889 - altair processParticipationFlagUpdates 3.6290 us/op 2.6080 us/op 1.39
mainnet_e81889 - altair processSyncCommitteeUpdates 1000.0 ns/op 600.00 ns/op 1.67
mainnet_e81889 - altair afterProcessEpoch 137.17 ms/op 121.24 ms/op 1.13
phase0 processEpoch - mainnet_e58758 389.49 ms/op 346.40 ms/op 1.12
mainnet_e58758 - phase0 beforeProcessEpoch 138.24 ms/op 116.31 ms/op 1.19
mainnet_e58758 - phase0 processJustificationAndFinalization 14.826 us/op 18.402 us/op 0.81
mainnet_e58758 - phase0 processRewardsAndPenalties 64.486 ms/op 57.513 ms/op 1.12
mainnet_e58758 - phase0 processRegistryUpdates 8.9290 us/op 7.6370 us/op 1.17
mainnet_e58758 - phase0 processSlashings 442.00 ns/op 477.00 ns/op 0.93
mainnet_e58758 - phase0 processEth1DataReset 460.00 ns/op 492.00 ns/op 0.93
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 989.63 us/op 997.70 us/op 0.99
mainnet_e58758 - phase0 processSlashingsReset 3.2910 us/op 3.2310 us/op 1.02
mainnet_e58758 - phase0 processRandaoMixesReset 4.7060 us/op 4.9300 us/op 0.95
mainnet_e58758 - phase0 processHistoricalRootsUpdate 531.00 ns/op 573.00 ns/op 0.93
mainnet_e58758 - phase0 processParticipationRecordUpdates 4.3040 us/op 5.3720 us/op 0.80
mainnet_e58758 - phase0 afterProcessEpoch 99.291 ms/op 95.519 ms/op 1.04
phase0 processEffectiveBalanceUpdates - 250000 normalcase 1.2300 ms/op 1.2608 ms/op 0.98
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 1.5043 ms/op 1.4987 ms/op 1.00
altair processInactivityUpdates - 250000 normalcase 25.140 ms/op 22.310 ms/op 1.13
altair processInactivityUpdates - 250000 worstcase 25.787 ms/op 23.972 ms/op 1.08
phase0 processRegistryUpdates - 250000 normalcase 6.8070 us/op 8.1400 us/op 0.84
phase0 processRegistryUpdates - 250000 badcase_full_deposits 230.04 us/op 270.02 us/op 0.85
phase0 processRegistryUpdates - 250000 worstcase 0.5 123.94 ms/op 116.91 ms/op 1.06
altair processRewardsAndPenalties - 250000 normalcase 68.825 ms/op 54.488 ms/op 1.26
altair processRewardsAndPenalties - 250000 worstcase 70.309 ms/op 52.988 ms/op 1.33
phase0 getAttestationDeltas - 250000 normalcase 6.5509 ms/op 6.9665 ms/op 0.94
phase0 getAttestationDeltas - 250000 worstcase 6.4204 ms/op 6.6275 ms/op 0.97
phase0 processSlashings - 250000 worstcase 3.4412 ms/op 3.6018 ms/op 0.96
altair processSyncCommitteeUpdates - 250000 175.06 ms/op 179.17 ms/op 0.98
BeaconState.hashTreeRoot - No change 261.00 ns/op 268.00 ns/op 0.97
BeaconState.hashTreeRoot - 1 full validator 53.077 us/op 48.921 us/op 1.08
BeaconState.hashTreeRoot - 32 full validator 556.79 us/op 524.02 us/op 1.06
BeaconState.hashTreeRoot - 512 full validator 5.4038 ms/op 5.8576 ms/op 0.92
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 61.739 us/op 63.526 us/op 0.97
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 869.69 us/op 910.54 us/op 0.96
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 11.302 ms/op 11.744 ms/op 0.96
BeaconState.hashTreeRoot - 1 balances 49.201 us/op 51.385 us/op 0.96
BeaconState.hashTreeRoot - 32 balances 440.21 us/op 458.59 us/op 0.96
BeaconState.hashTreeRoot - 512 balances 4.3004 ms/op 4.5128 ms/op 0.95
BeaconState.hashTreeRoot - 250000 balances 78.856 ms/op 74.736 ms/op 1.06
aggregationBits - 2048 els - zipIndexesInBitList 15.638 us/op 17.095 us/op 0.91
regular array get 100000 times 31.762 us/op 32.641 us/op 0.97
wrappedArray get 100000 times 32.692 us/op 32.646 us/op 1.00
arrayWithProxy get 100000 times 15.589 ms/op 15.324 ms/op 1.02
ssz.Root.equals 541.00 ns/op 562.00 ns/op 0.96
byteArrayEquals 533.00 ns/op 568.00 ns/op 0.94
shuffle list - 16384 els 6.7682 ms/op 7.0018 ms/op 0.97
shuffle list - 250000 els 99.455 ms/op 104.28 ms/op 0.95
processSlot - 1 slots 9.0420 us/op 9.2400 us/op 0.98
processSlot - 32 slots 1.3411 ms/op 1.4198 ms/op 0.94
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 37.371 ms/op 32.937 ms/op 1.13
getCommitteeAssignments - req 1 vs - 250000 vc 2.8801 ms/op 3.0719 ms/op 0.94
getCommitteeAssignments - req 100 vs - 250000 vc 4.0129 ms/op 4.1440 ms/op 0.97
getCommitteeAssignments - req 1000 vs - 250000 vc 4.3195 ms/op 4.5687 ms/op 0.95
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 4.5000 ns/op 4.9400 ns/op 0.91
state getBlockRootAtSlot - 250000 vs - 7PWei 855.06 ns/op 672.96 ns/op 1.27
computeProposers - vc 250000 10.608 ms/op 11.135 ms/op 0.95
computeEpochShuffling - vc 250000 99.590 ms/op 108.38 ms/op 0.92
getNextSyncCommittee - vc 250000 175.37 ms/op 187.45 ms/op 0.94
computeSigningRoot for AttestationData 13.898 us/op 14.675 us/op 0.95
hash AttestationData serialized data then Buffer.toString(base64) 2.4236 us/op 2.5178 us/op 0.96
toHexString serialized data 1.0673 us/op 1.2464 us/op 0.86
Buffer.toString(base64) 312.86 ns/op 353.31 ns/op 0.89

by benchmarkbot/action

@dapplion dapplion merged commit 724281e into unstable May 18, 2023
@dapplion dapplion deleted the philknows/fix-log-existing branch May 18, 2023 13:22
@nflaig
Copy link
Member

nflaig commented May 22, 2023 •
edited
Loading

Just a thought, this log seems a bit verbose as it is printed out per validator. If this is done on startup it might make sense to keep it simple (Validator index=461468, pubkey=0x8042...10a0 feeRecipient=0x0000) or maybe as suggested in #5161 (comment).

The current implementation also does not work correctly as mentioned in #5161 (comment) and #5239 (comment).

I think the validator statuses should be printed out each epoch based on clock (data from cache) and not based on fetching getStateValidators while discovery/lifecycle logs should printed as soon as status of a validator changes.

Might have to rework this a bit when adding fee recipient and also think about logs for life cycle changes which could be useful for operators

This PR addresses some issues but it requires refactoring

@philknows
Copy link
Member Author

Definitely. I'm all for changes that achieve the same messaging in the most efficient way possible. Did we agree upon including status for the validator lifecycle in #5192? If yes, that should be included as well on initialization.

As suggested in #5161 (comment), it would make sense to just do this once on startup to print:

Validator index=461468, pubkey=0x8042...10a0 feeRecipient=0x0000 status=pending | active | exited | withdrawn

The only time I would foresee this message coming up again is upon re-initialization of the VC or if one of the running validators has a status change.

@nflaig
Copy link
Member

nflaig commented May 23, 2023

Did we agree upon including status for the validator lifecycle in #5192?

Not sure if that was discussed but printing the status on initialization sounds good to me, just need to define how status changes and newly discovered validators should be handled.

@philknows
Copy link
Member Author

just need to define how status changes and newly discovered validators should be handled.

We should probably continue discussing this on PR #5239 itself if it's being refactored to include this or directly on the #5192 issue.

@philknows philknows mentioned this pull request May 24, 2023
Open
@wemeetagain
Copy link
Member

🎉 This PR is included in v1.9.0 🎉

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@matthewkeil matthewkeil matthewkeil approved these changes

@dapplion dapplion dapplion approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
5 participants
@philknows @matthewkeil @nflaig @wemeetagain @dapplion