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

Prevent MaxListenersExceededWarning observed in validator's abort controller #4512

Merged
merged 4 commits into from
Sep 8, 2022
Merged

Prevent MaxListenersExceededWarning observed in validator's abort controller #4512

merged 4 commits into from
Sep 8, 2022

Conversation

dadepo
Copy link
Contributor

@dadepo dadepo commented Sep 6, 2022

Motivation

See #3569 and # #4394 for bug report

Description

While running the validator client I noticed the following lines in the log:

Sep-06 11:51:38.076[]                 info: Genesis available
Sep-06 11:51:38.084[]                 info: Verified node and validator have same config
Sep-06 11:51:38.084[]                 info: Verified node and validator have same genesisValidatorRoot
Sep-06 11:51:38.133[]                 info: Discovered new validators count=3
(node:46338) MaxListenersExceededWarning: Possible EventTarget memory leak detected. 11 abort listeners added to [AbortSignal]. Use events.setMaxListeners() to increase limit
    at AbortSignal.[kNewListener] (node:internal/event_target:426:17)
    at AbortSignal.[kNewListener] (node:internal/abort_controller:173:24)
    at AbortSignal.addEventListener (node:internal/event_target:535:23)
    at file:///Users/dadepoaderemi/Documents/work/testing_remote_signer/lodestar/packages/utils/src/sleep.ts:26:24
    at new Promise (<anonymous>)
    at sleep (file:///Users/dadepoaderemi/Documents/work/testing_remote_signer/lodestar/packages/utils/src/sleep.ts:12:10)
    at Clock.runAtMostEvery (file:///Users/dadepoaderemi/Documents/work/testing_remote_signer/lodestar/packages/validator/src/util/clock.ts:101:15)
    at processTicksAndRejections (node:internal/process/task_queues:96:5)

This PR prevents this by setting the max event listener for the abort controller that trigger the log to infinity.

resolves #3569
resolves #4394

@github-actions
Copy link
Contributor

github-actions bot commented Sep 6, 2022 •
edited
Loading

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: c9b9f52 Previous: 91a5a06 Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 2.3427 ms/op 2.4283 ms/op 0.96
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 67.777 us/op 75.539 us/op 0.90
BLS verify - blst-native 2.1641 ms/op 1.8554 ms/op 1.17
BLS verifyMultipleSignatures 3 - blst-native 4.4700 ms/op 3.8102 ms/op 1.17
BLS verifyMultipleSignatures 8 - blst-native 9.6715 ms/op 8.1969 ms/op 1.18
BLS verifyMultipleSignatures 32 - blst-native 35.139 ms/op 29.703 ms/op 1.18
BLS aggregatePubkeys 32 - blst-native 46.489 us/op 39.393 us/op 1.18
BLS aggregatePubkeys 128 - blst-native 182.24 us/op 152.86 us/op 1.19
getAttestationsForBlock 152.33 ms/op 151.09 ms/op 1.01
isKnown best case - 1 super set check 474.00 ns/op 379.00 ns/op 1.25
isKnown normal case - 2 super set checks 469.00 ns/op 372.00 ns/op 1.26
isKnown worse case - 16 super set checks 479.00 ns/op 368.00 ns/op 1.30
CheckpointStateCache - add get delete 9.0440 us/op 8.0120 us/op 1.13
validate gossip signedAggregateAndProof - struct 5.0123 ms/op 3.7593 ms/op 1.33
validate gossip attestation - struct 2.3773 ms/op 1.7895 ms/op 1.33
pickEth1Vote - no votes 2.1179 ms/op 1.9817 ms/op 1.07
pickEth1Vote - max votes 19.595 ms/op 19.642 ms/op 1.00
pickEth1Vote - Eth1Data hashTreeRoot value x2048 13.272 ms/op 11.606 ms/op 1.14
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 21.862 ms/op 20.271 ms/op 1.08
pickEth1Vote - Eth1Data fastSerialize value x2048 1.5820 ms/op 1.3884 ms/op 1.14
pickEth1Vote - Eth1Data fastSerialize tree x2048 13.331 ms/op 11.845 ms/op 1.13
bytes32 toHexString 1.0510 us/op 937.00 ns/op 1.12
bytes32 Buffer.toString(hex) 774.00 ns/op 688.00 ns/op 1.13
bytes32 Buffer.toString(hex) from Uint8Array 1.0400 us/op 898.00 ns/op 1.16
bytes32 Buffer.toString(hex) + 0x 787.00 ns/op 691.00 ns/op 1.14
Object access 1 prop 0.40100 ns/op 0.34400 ns/op 1.17
Map access 1 prop 0.31200 ns/op 0.29900 ns/op 1.04
Object get x1000 11.915 ns/op 17.062 ns/op 0.70
Map get x1000 1.0970 ns/op 0.98800 ns/op 1.11
Object set x1000 79.152 ns/op 112.21 ns/op 0.71
Map set x1000 51.760 ns/op 69.292 ns/op 0.75
Return object 10000 times 0.44190 ns/op 0.36980 ns/op 1.19
Throw Error 10000 times 5.9029 us/op 5.8525 us/op 1.01
enrSubnets - fastDeserialize 64 bits 2.6320 us/op 2.5200 us/op 1.04
enrSubnets - ssz BitVector 64 bits 847.00 ns/op 698.00 ns/op 1.21
enrSubnets - fastDeserialize 4 bits 400.00 ns/op 365.00 ns/op 1.10
enrSubnets - ssz BitVector 4 bits 879.00 ns/op 710.00 ns/op 1.24
prioritizePeers score -10:0 att 32-0.1 sync 2-0 88.551 us/op 91.308 us/op 0.97
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 128.86 us/op 141.49 us/op 0.91
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 228.66 us/op 206.69 us/op 1.11
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 336.55 us/op 389.62 us/op 0.86
prioritizePeers score 0:0 att 64-1 sync 4-1 408.35 us/op 460.26 us/op 0.89
RateTracker 1000000 limit, 1 obj count per request 187.64 ns/op 190.79 ns/op 0.98
RateTracker 1000000 limit, 2 obj count per request 137.00 ns/op 147.01 ns/op 0.93
RateTracker 1000000 limit, 4 obj count per request 112.43 ns/op 120.18 ns/op 0.94
RateTracker 1000000 limit, 8 obj count per request 99.790 ns/op 109.98 ns/op 0.91
RateTracker with prune 3.9200 us/op 4.1180 us/op 0.95
array of 16000 items push then shift 51.579 us/op 3.1847 us/op 16.20
LinkedList of 16000 items push then shift 12.582 ns/op 17.580 ns/op 0.72
array of 16000 items push then pop 207.13 ns/op 233.50 ns/op 0.89
LinkedList of 16000 items push then pop 12.235 ns/op 14.854 ns/op 0.82
array of 24000 items push then shift 77.345 us/op 4.0148 us/op 19.26
LinkedList of 24000 items push then shift 13.047 ns/op 19.069 ns/op 0.68
array of 24000 items push then pop 197.70 ns/op 188.49 ns/op 1.05
LinkedList of 24000 items push then pop 12.392 ns/op 16.379 ns/op 0.76
intersect bitArray bitLen 8 10.746 ns/op 10.098 ns/op 1.06
intersect array and set length 8 138.70 ns/op 141.33 ns/op 0.98
intersect bitArray bitLen 128 57.958 ns/op 63.463 ns/op 0.91
intersect array and set length 128 1.8340 us/op 1.9281 us/op 0.95
Buffer.concat 32 items 2.0820 ns/op 1.6740 ns/op 1.24
pass gossip attestations to forkchoice per slot 2.9230 ms/op 2.8960 ms/op 1.01
computeDeltas 3.2527 ms/op 2.9197 ms/op 1.11
computeProposerBoostScoreFromBalances 807.57 us/op 804.77 us/op 1.00
altair processAttestation - 250000 vs - 7PWei normalcase 3.4878 ms/op 3.0915 ms/op 1.13
altair processAttestation - 250000 vs - 7PWei worstcase 5.3301 ms/op 4.8030 ms/op 1.11
altair processAttestation - setStatus - 1/6 committees join 181.92 us/op 191.90 us/op 0.95
altair processAttestation - setStatus - 1/3 committees join 354.82 us/op 409.01 us/op 0.87
altair processAttestation - setStatus - 1/2 committees join 505.18 us/op 513.26 us/op 0.98
altair processAttestation - setStatus - 2/3 committees join 663.52 us/op 660.84 us/op 1.00
altair processAttestation - setStatus - 4/5 committees join 926.17 us/op 928.33 us/op 1.00
altair processAttestation - setStatus - 100% committees join 1.1182 ms/op 1.2349 ms/op 0.91
altair processBlock - 250000 vs - 7PWei normalcase 25.648 ms/op 28.512 ms/op 0.90
altair processBlock - 250000 vs - 7PWei normalcase hashState 35.760 ms/op 43.749 ms/op 0.82
altair processBlock - 250000 vs - 7PWei worstcase 82.749 ms/op 68.806 ms/op 1.20
altair processBlock - 250000 vs - 7PWei worstcase hashState 119.63 ms/op 98.279 ms/op 1.22
phase0 processBlock - 250000 vs - 7PWei normalcase 3.3325 ms/op 3.2878 ms/op 1.01
phase0 processBlock - 250000 vs - 7PWei worstcase 51.342 ms/op 47.652 ms/op 1.08
altair processEth1Data - 250000 vs - 7PWei normalcase 811.65 us/op 723.93 us/op 1.12
Tree 40 250000 create 764.06 ms/op 760.88 ms/op 1.00
Tree 40 250000 get(125000) 238.14 ns/op 257.33 ns/op 0.93
Tree 40 250000 set(125000) 2.4779 us/op 2.3515 us/op 1.05
Tree 40 250000 toArray() 28.553 ms/op 29.413 ms/op 0.97
Tree 40 250000 iterate all - toArray() + loop 28.625 ms/op 29.509 ms/op 0.97
Tree 40 250000 iterate all - get(i) 113.92 ms/op 98.359 ms/op 1.16
MutableVector 250000 create 15.363 ms/op 23.734 ms/op 0.65
MutableVector 250000 get(125000) 10.644 ns/op 13.612 ns/op 0.78
MutableVector 250000 set(125000) 596.42 ns/op 478.34 ns/op 1.25
MutableVector 250000 toArray() 6.8205 ms/op 6.6508 ms/op 1.03
MutableVector 250000 iterate all - toArray() + loop 6.8494 ms/op 6.4308 ms/op 1.07
MutableVector 250000 iterate all - get(i) 2.5940 ms/op 3.0369 ms/op 0.85
Array 250000 create 6.7576 ms/op 6.2554 ms/op 1.08
Array 250000 clone - spread 3.5760 ms/op 2.5267 ms/op 1.42
Array 250000 get(125000) 1.6130 ns/op 1.0360 ns/op 1.56
Array 250000 set(125000) 1.5850 ns/op 1.0430 ns/op 1.52
Array 250000 iterate all - loop 154.60 us/op 148.02 us/op 1.04
effectiveBalanceIncrements clone Uint8Array 300000 154.81 us/op 59.158 us/op 2.62
effectiveBalanceIncrements clone MutableVector 300000 662.00 ns/op 719.00 ns/op 0.92
effectiveBalanceIncrements rw all Uint8Array 300000 247.61 us/op 222.66 us/op 1.11
effectiveBalanceIncrements rw all MutableVector 300000 138.92 ms/op 163.20 ms/op 0.85
phase0 afterProcessEpoch - 250000 vs - 7PWei 195.65 ms/op 159.89 ms/op 1.22
phase0 beforeProcessEpoch - 250000 vs - 7PWei 59.420 ms/op 74.089 ms/op 0.80
altair processEpoch - mainnet_e81889 548.29 ms/op 532.97 ms/op 1.03
mainnet_e81889 - altair beforeProcessEpoch 115.97 ms/op 169.07 ms/op 0.69
mainnet_e81889 - altair processJustificationAndFinalization 19.366 us/op 25.980 us/op 0.75
mainnet_e81889 - altair processInactivityUpdates 8.8094 ms/op 9.9964 ms/op 0.88
mainnet_e81889 - altair processRewardsAndPenalties 83.024 ms/op 86.141 ms/op 0.96
mainnet_e81889 - altair processRegistryUpdates 2.9210 us/op 4.8680 us/op 0.60
mainnet_e81889 - altair processSlashings 704.00 ns/op 1.0100 us/op 0.70
mainnet_e81889 - altair processEth1DataReset 580.00 ns/op 1.0140 us/op 0.57
mainnet_e81889 - altair processEffectiveBalanceUpdates 1.9220 ms/op 2.1081 ms/op 0.91
mainnet_e81889 - altair processSlashingsReset 4.7450 us/op 7.1230 us/op 0.67
mainnet_e81889 - altair processRandaoMixesReset 4.7840 us/op 9.1900 us/op 0.52
mainnet_e81889 - altair processHistoricalRootsUpdate 589.00 ns/op 1.4050 us/op 0.42
mainnet_e81889 - altair processParticipationFlagUpdates 2.5530 us/op 4.1250 us/op 0.62
mainnet_e81889 - altair processSyncCommitteeUpdates 1.6940 us/op 1.6060 us/op 1.05
mainnet_e81889 - altair afterProcessEpoch 218.52 ms/op 218.22 ms/op 1.00
phase0 processEpoch - mainnet_e58758 495.14 ms/op 579.15 ms/op 0.85
mainnet_e58758 - phase0 beforeProcessEpoch 182.13 ms/op 231.33 ms/op 0.79
mainnet_e58758 - phase0 processJustificationAndFinalization 18.874 us/op 32.001 us/op 0.59
mainnet_e58758 - phase0 processRewardsAndPenalties 73.303 ms/op 121.45 ms/op 0.60
mainnet_e58758 - phase0 processRegistryUpdates 9.1050 us/op 12.805 us/op 0.71
mainnet_e58758 - phase0 processSlashings 897.00 ns/op 1.0010 us/op 0.90
mainnet_e58758 - phase0 processEth1DataReset 626.00 ns/op 1.3660 us/op 0.46
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.6258 ms/op 2.2824 ms/op 0.71
mainnet_e58758 - phase0 processSlashingsReset 5.2280 us/op 8.0700 us/op 0.65
mainnet_e58758 - phase0 processRandaoMixesReset 4.7740 us/op 7.5800 us/op 0.63
mainnet_e58758 - phase0 processHistoricalRootsUpdate 585.00 ns/op 1.2880 us/op 0.45
mainnet_e58758 - phase0 processParticipationRecordUpdates 3.8220 us/op 7.1590 us/op 0.53
mainnet_e58758 - phase0 afterProcessEpoch 164.31 ms/op 155.59 ms/op 1.06
phase0 processEffectiveBalanceUpdates - 250000 normalcase 1.9480 ms/op 2.6932 ms/op 0.72
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 2.2677 ms/op 2.7772 ms/op 0.82
altair processInactivityUpdates - 250000 normalcase 36.998 ms/op 41.106 ms/op 0.90
altair processInactivityUpdates - 250000 worstcase 33.706 ms/op 51.346 ms/op 0.66
phase0 processRegistryUpdates - 250000 normalcase 6.7020 us/op 10.535 us/op 0.64
phase0 processRegistryUpdates - 250000 badcase_full_deposits 382.92 us/op 363.21 us/op 1.05
phase0 processRegistryUpdates - 250000 worstcase 0.5 203.85 ms/op 213.92 ms/op 0.95
altair processRewardsAndPenalties - 250000 normalcase 112.36 ms/op 111.53 ms/op 1.01
altair processRewardsAndPenalties - 250000 worstcase 78.792 ms/op 85.889 ms/op 0.92
phase0 getAttestationDeltas - 250000 normalcase 12.763 ms/op 12.191 ms/op 1.05
phase0 getAttestationDeltas - 250000 worstcase 13.266 ms/op 12.630 ms/op 1.05
phase0 processSlashings - 250000 worstcase 4.9961 ms/op 4.7091 ms/op 1.06
altair processSyncCommitteeUpdates - 250000 302.99 ms/op 263.91 ms/op 1.15
BeaconState.hashTreeRoot - No change 557.00 ns/op 412.00 ns/op 1.35
BeaconState.hashTreeRoot - 1 full validator 71.954 us/op 57.071 us/op 1.26
BeaconState.hashTreeRoot - 32 full validator 708.04 us/op 642.13 us/op 1.10
BeaconState.hashTreeRoot - 512 full validator 8.9642 ms/op 6.0297 ms/op 1.49
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 90.111 us/op 73.371 us/op 1.23
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 1.2836 ms/op 1.0951 ms/op 1.17
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 17.049 ms/op 16.822 ms/op 1.01
BeaconState.hashTreeRoot - 1 balances 68.056 us/op 55.174 us/op 1.23
BeaconState.hashTreeRoot - 32 balances 640.43 us/op 549.64 us/op 1.17
BeaconState.hashTreeRoot - 512 balances 6.2050 ms/op 6.5468 ms/op 0.95
BeaconState.hashTreeRoot - 250000 balances 94.789 ms/op 86.179 ms/op 1.10
aggregationBits - 2048 els - zipIndexesInBitList 31.388 us/op 36.947 us/op 0.85
regular array get 100000 times 60.559 us/op 59.520 us/op 1.02
wrappedArray get 100000 times 61.232 us/op 59.493 us/op 1.03
arrayWithProxy get 100000 times 28.459 ms/op 25.780 ms/op 1.10
ssz.Root.equals 538.00 ns/op 480.00 ns/op 1.12
byteArrayEquals 518.00 ns/op 476.00 ns/op 1.09
shuffle list - 16384 els 11.554 ms/op 9.7327 ms/op 1.19
shuffle list - 250000 els 165.82 ms/op 143.56 ms/op 1.16
processSlot - 1 slots 13.074 us/op 13.140 us/op 0.99
processSlot - 32 slots 1.9766 ms/op 1.7704 ms/op 1.12
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 406.17 us/op 390.84 us/op 1.04
getCommitteeAssignments - req 1 vs - 250000 vc 5.4737 ms/op 5.2691 ms/op 1.04
getCommitteeAssignments - req 100 vs - 250000 vc 7.9937 ms/op 7.3471 ms/op 1.09
getCommitteeAssignments - req 1000 vs - 250000 vc 8.5974 ms/op 8.1887 ms/op 1.05
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 8.1100 ns/op 10.210 ns/op 0.79
state getBlockRootAtSlot - 250000 vs - 7PWei 1.1348 us/op 1.0192 us/op 1.11
computeProposers - vc 250000 17.909 ms/op 14.500 ms/op 1.24
computeEpochShuffling - vc 250000 171.51 ms/op 169.09 ms/op 1.01
getNextSyncCommittee - vc 250000 301.89 ms/op 282.95 ms/op 1.07

by benchmarkbot/action

dapplion
dapplion reviewed Sep 6, 2022
View reviewed changes
packages/cli/src/cmds/validator/handler.ts Outdated
// This AbortController interrupts the sleep() calls when waiting for genesis
genesisReqController: new AbortController(),
// This AbortController interrupts the validators ops: clients call, clock etc
validatorOpsController: new AbortController(),
Copy link
Contributor

Choose a reason for hiding this comment

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

It looks like you could only need 1 AbortController, can you try that?

@dadepo dadepo marked this pull request as ready for review September 6, 2022 18:03
@dadepo dadepo requested a review from a team as a code owner September 6, 2022 18:03
@wemeetagain wemeetagain merged commit 172513f into unstable Sep 8, 2022
@wemeetagain wemeetagain deleted the dadepo/prevent-maxlistenersexceededwarning branch September 8, 2022 16:59
@dapplion
Copy link
Contributor

dapplion commented Sep 9, 2022

note this was merged before I had time to review

Having to pass an AbortController to the validator class is a very weird API. Consumers would be asking why? And the only justification is that we don't want to print a log. The tradeoff here doesn't make sense IMO. Is this really the only way to suppress such log in NodeJS? I think there must be a better solution.

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

@dapplion dapplion dapplion left review comments

@wemeetagain wemeetagain wemeetagain approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
3 participants
@dadepo @dapplion @wemeetagain