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

Add debug level logs and sync test to sim tests #4673

Merged
merged 13 commits into from
Oct 28, 2022
Merged

Add debug level logs and sync test to sim tests #4673

merged 13 commits into from
Oct 28, 2022

Conversation

nazarhussain
Copy link
Contributor

@nazarhussain nazarhussain commented Oct 19, 2022 •
edited
Loading

Motivation

Add a new node to sim test network and test the syncing from genesis.

Covered following points:

  • Log std to file, disable log to file. Enable DEBUG=* for Lodestar
  • Once nodes reach untilEpoch, keep the chain running and spawn extra nodes to test syncing
    • Start 1 node from genesis and range sync to head
    • Start 1 node with checkpoint sync and sync to head
  • Disable the file logging for lodestar by explicitly setting it to none

Partially Resolves #4275

Steps to test or reproduce

Run sim tests.

@nazarhussain nazarhussain marked this pull request as ready for review October 19, 2022 23:39
@nazarhussain nazarhussain requested a review from a team as a code owner October 19, 2022 23:39
@github-actions
Copy link
Contributor

github-actions bot commented Oct 19, 2022 •
edited
Loading

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: aafbccb Previous: b06453a Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 1.7545 ms/op 2.4275 ms/op 0.72
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 71.119 us/op 93.987 us/op 0.76
BLS verify - blst-native 1.8542 ms/op 2.4577 ms/op 0.75
BLS verifyMultipleSignatures 3 - blst-native 3.7997 ms/op 4.8288 ms/op 0.79
BLS verifyMultipleSignatures 8 - blst-native 8.1827 ms/op 10.255 ms/op 0.80
BLS verifyMultipleSignatures 32 - blst-native 29.655 ms/op 37.078 ms/op 0.80
BLS aggregatePubkeys 32 - blst-native 39.226 us/op 50.040 us/op 0.78
BLS aggregatePubkeys 128 - blst-native 153.56 us/op 198.38 us/op 0.77
getAttestationsForBlock 81.583 ms/op 110.13 ms/op 0.74
isKnown best case - 1 super set check 430.00 ns/op 582.00 ns/op 0.74
isKnown normal case - 2 super set checks 418.00 ns/op 555.00 ns/op 0.75
isKnown worse case - 16 super set checks 419.00 ns/op 520.00 ns/op 0.81
CheckpointStateCache - add get delete 8.2580 us/op 11.126 us/op 0.74
validate gossip signedAggregateAndProof - struct 4.2650 ms/op 5.5632 ms/op 0.77
validate gossip attestation - struct 2.0281 ms/op 2.6877 ms/op 0.75
pickEth1Vote - no votes 2.1123 ms/op 2.9226 ms/op 0.72
pickEth1Vote - max votes 18.028 ms/op 25.962 ms/op 0.69
pickEth1Vote - Eth1Data hashTreeRoot value x2048 10.623 ms/op 14.441 ms/op 0.74
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 18.915 ms/op 26.113 ms/op 0.72
pickEth1Vote - Eth1Data fastSerialize value x2048 1.4814 ms/op 1.9464 ms/op 0.76
pickEth1Vote - Eth1Data fastSerialize tree x2048 12.946 ms/op 18.252 ms/op 0.71
bytes32 toHexString 1.1140 us/op 1.3380 us/op 0.83
bytes32 Buffer.toString(hex) 707.00 ns/op 907.00 ns/op 0.78
bytes32 Buffer.toString(hex) from Uint8Array 1.0130 us/op 1.1600 us/op 0.87
bytes32 Buffer.toString(hex) + 0x 722.00 ns/op 933.00 ns/op 0.77
Object access 1 prop 0.37700 ns/op 0.47500 ns/op 0.79
Map access 1 prop 0.29200 ns/op 0.37100 ns/op 0.79
Object get x1000 18.329 ns/op 22.203 ns/op 0.83
Map get x1000 0.97800 ns/op 1.4290 ns/op 0.68
Object set x1000 110.34 ns/op 150.60 ns/op 0.73
Map set x1000 65.921 ns/op 88.120 ns/op 0.75
Return object 10000 times 0.38160 ns/op 0.44000 ns/op 0.87
Throw Error 10000 times 6.1038 us/op 7.1565 us/op 0.85
fastMsgIdFn sha256 / 200 bytes 4.2000 us/op 5.1890 us/op 0.81
fastMsgIdFn h32 xxhash / 200 bytes 507.00 ns/op 681.00 ns/op 0.74
fastMsgIdFn h64 xxhash / 200 bytes 632.00 ns/op 974.00 ns/op 0.65
fastMsgIdFn sha256 / 1000 bytes 13.047 us/op 15.723 us/op 0.83
fastMsgIdFn h32 xxhash / 1000 bytes 642.00 ns/op 851.00 ns/op 0.75
fastMsgIdFn h64 xxhash / 1000 bytes 713.00 ns/op 977.00 ns/op 0.73
fastMsgIdFn sha256 / 10000 bytes 112.47 us/op 136.26 us/op 0.83
fastMsgIdFn h32 xxhash / 10000 bytes 2.4140 us/op 2.8410 us/op 0.85
fastMsgIdFn h64 xxhash / 10000 bytes 1.7330 us/op 2.1170 us/op 0.82
enrSubnets - fastDeserialize 64 bits 2.5120 us/op 3.3260 us/op 0.76
enrSubnets - ssz BitVector 64 bits 716.00 ns/op 989.00 ns/op 0.72
enrSubnets - fastDeserialize 4 bits 364.00 ns/op 475.00 ns/op 0.77
enrSubnets - ssz BitVector 4 bits 710.00 ns/op 941.00 ns/op 0.75
prioritizePeers score -10:0 att 32-0.1 sync 2-0 89.020 us/op 111.58 us/op 0.80
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 132.04 us/op 161.47 us/op 0.82
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 207.79 us/op 272.66 us/op 0.76
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 388.03 us/op 466.77 us/op 0.83
prioritizePeers score 0:0 att 64-1 sync 4-1 462.07 us/op 554.52 us/op 0.83
RateTracker 1000000 limit, 1 obj count per request 188.82 ns/op 241.72 ns/op 0.78
RateTracker 1000000 limit, 2 obj count per request 143.06 ns/op 186.77 ns/op 0.77
RateTracker 1000000 limit, 4 obj count per request 119.99 ns/op 161.05 ns/op 0.75
RateTracker 1000000 limit, 8 obj count per request 113.39 ns/op 141.93 ns/op 0.80
RateTracker with prune 4.0890 us/op 5.1950 us/op 0.79
array of 16000 items push then shift 3.1825 us/op 3.8136 us/op 0.83
LinkedList of 16000 items push then shift 16.815 ns/op 19.735 ns/op 0.85
array of 16000 items push then pop 229.64 ns/op 284.91 ns/op 0.81
LinkedList of 16000 items push then pop 16.444 ns/op 19.770 ns/op 0.83
array of 24000 items push then shift 4.5574 us/op 5.4443 us/op 0.84
LinkedList of 24000 items push then shift 19.639 ns/op 22.635 ns/op 0.87
array of 24000 items push then pop 206.92 ns/op 264.33 ns/op 0.78
LinkedList of 24000 items push then pop 17.632 ns/op 25.478 ns/op 0.69
intersect bitArray bitLen 8 11.718 ns/op 13.815 ns/op 0.85
intersect array and set length 8 157.67 ns/op 194.60 ns/op 0.81
intersect bitArray bitLen 128 72.087 ns/op 85.702 ns/op 0.84
intersect array and set length 128 2.1395 us/op 2.6988 us/op 0.79
Buffer.concat 32 items 2.1670 ns/op 2.3250 ns/op 0.93
pass gossip attestations to forkchoice per slot 6.6238 ms/op 4.8198 ms/op 1.37
computeDeltas 6.3679 ms/op 7.4809 ms/op 0.85
computeProposerBoostScoreFromBalances 907.28 us/op 1.1285 ms/op 0.80
altair processAttestation - 250000 vs - 7PWei normalcase 3.4116 ms/op 4.5964 ms/op 0.74
altair processAttestation - 250000 vs - 7PWei worstcase 5.3927 ms/op 7.4647 ms/op 0.72
altair processAttestation - setStatus - 1/6 committees join 208.48 us/op 255.93 us/op 0.81
altair processAttestation - setStatus - 1/3 committees join 396.92 us/op 516.80 us/op 0.77
altair processAttestation - setStatus - 1/2 committees join 553.77 us/op 721.31 us/op 0.77
altair processAttestation - setStatus - 2/3 committees join 723.54 us/op 900.42 us/op 0.80
altair processAttestation - setStatus - 4/5 committees join 996.11 us/op 1.3494 ms/op 0.74
altair processAttestation - setStatus - 100% committees join 1.1672 ms/op 1.5611 ms/op 0.75
altair processBlock - 250000 vs - 7PWei normalcase 26.250 ms/op 35.343 ms/op 0.74
altair processBlock - 250000 vs - 7PWei normalcase hashState 39.134 ms/op 45.611 ms/op 0.86
altair processBlock - 250000 vs - 7PWei worstcase 81.074 ms/op 97.735 ms/op 0.83
altair processBlock - 250000 vs - 7PWei worstcase hashState 108.24 ms/op 121.45 ms/op 0.89
phase0 processBlock - 250000 vs - 7PWei normalcase 3.2833 ms/op 4.3656 ms/op 0.75
phase0 processBlock - 250000 vs - 7PWei worstcase 44.903 ms/op 58.359 ms/op 0.77
altair processEth1Data - 250000 vs - 7PWei normalcase 767.78 us/op 1.1314 ms/op 0.68
Tree 40 250000 create 765.08 ms/op 1.0011 s/op 0.76
Tree 40 250000 get(125000) 281.85 ns/op 344.95 ns/op 0.82
Tree 40 250000 set(125000) 2.3110 us/op 3.0565 us/op 0.76
Tree 40 250000 toArray() 30.975 ms/op 37.054 ms/op 0.84
Tree 40 250000 iterate all - toArray() + loop 30.648 ms/op 37.593 ms/op 0.82
Tree 40 250000 iterate all - get(i) 107.41 ms/op 131.81 ms/op 0.81
MutableVector 250000 create 16.558 ms/op 20.267 ms/op 0.82
MutableVector 250000 get(125000) 13.060 ns/op 18.373 ns/op 0.71
MutableVector 250000 set(125000) 689.78 ns/op 748.00 ns/op 0.92
MutableVector 250000 toArray() 7.2372 ms/op 8.7401 ms/op 0.83
MutableVector 250000 iterate all - toArray() + loop 7.4754 ms/op 9.6790 ms/op 0.77
MutableVector 250000 iterate all - get(i) 3.2809 ms/op 4.2751 ms/op 0.77
Array 250000 create 6.7245 ms/op 8.8624 ms/op 0.76
Array 250000 clone - spread 3.8678 ms/op 5.3035 ms/op 0.73
Array 250000 get(125000) 1.5740 ns/op 2.0870 ns/op 0.75
Array 250000 set(125000) 1.6060 ns/op 2.0100 ns/op 0.80
Array 250000 iterate all - loop 167.85 us/op 204.69 us/op 0.82
effectiveBalanceIncrements clone Uint8Array 300000 81.651 us/op 113.68 us/op 0.72
effectiveBalanceIncrements clone MutableVector 300000 1.2210 us/op 1.4510 us/op 0.84
effectiveBalanceIncrements rw all Uint8Array 300000 252.50 us/op 303.56 us/op 0.83
effectiveBalanceIncrements rw all MutableVector 300000 208.75 ms/op 248.71 ms/op 0.84
phase0 afterProcessEpoch - 250000 vs - 7PWei 184.33 ms/op 231.39 ms/op 0.80
phase0 beforeProcessEpoch - 250000 vs - 7PWei 67.786 ms/op 124.63 ms/op 0.54
altair processEpoch - mainnet_e81889 573.09 ms/op 704.41 ms/op 0.81
mainnet_e81889 - altair beforeProcessEpoch 156.10 ms/op 205.97 ms/op 0.76
mainnet_e81889 - altair processJustificationAndFinalization 24.259 us/op 42.829 us/op 0.57
mainnet_e81889 - altair processInactivityUpdates 10.702 ms/op 13.373 ms/op 0.80
mainnet_e81889 - altair processRewardsAndPenalties 89.749 ms/op 112.44 ms/op 0.80
mainnet_e81889 - altair processRegistryUpdates 3.5980 us/op 8.0140 us/op 0.45
mainnet_e81889 - altair processSlashings 868.00 ns/op 2.5200 us/op 0.34
mainnet_e81889 - altair processEth1DataReset 1.1030 us/op 2.2000 us/op 0.50
mainnet_e81889 - altair processEffectiveBalanceUpdates 2.4182 ms/op 3.1840 ms/op 0.76
mainnet_e81889 - altair processSlashingsReset 6.9380 us/op 12.259 us/op 0.57
mainnet_e81889 - altair processRandaoMixesReset 5.4010 us/op 13.270 us/op 0.41
mainnet_e81889 - altair processHistoricalRootsUpdate 957.00 ns/op 2.0200 us/op 0.47
mainnet_e81889 - altair processParticipationFlagUpdates 3.9630 us/op 8.2720 us/op 0.48
mainnet_e81889 - altair processSyncCommitteeUpdates 735.00 ns/op 1.5570 us/op 0.47
mainnet_e81889 - altair afterProcessEpoch 193.22 ms/op 236.83 ms/op 0.82
phase0 processEpoch - mainnet_e58758 518.73 ms/op 634.65 ms/op 0.82
mainnet_e58758 - phase0 beforeProcessEpoch 223.34 ms/op 274.10 ms/op 0.81
mainnet_e58758 - phase0 processJustificationAndFinalization 20.832 us/op 39.345 us/op 0.53
mainnet_e58758 - phase0 processRewardsAndPenalties 81.416 ms/op 144.20 ms/op 0.56
mainnet_e58758 - phase0 processRegistryUpdates 9.6650 us/op 19.216 us/op 0.50
mainnet_e58758 - phase0 processSlashings 766.00 ns/op 1.8860 us/op 0.41
mainnet_e58758 - phase0 processEth1DataReset 817.00 ns/op 1.7250 us/op 0.47
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.8591 ms/op 2.4309 ms/op 0.76
mainnet_e58758 - phase0 processSlashingsReset 4.6770 us/op 10.496 us/op 0.45
mainnet_e58758 - phase0 processRandaoMixesReset 6.0310 us/op 12.852 us/op 0.47
mainnet_e58758 - phase0 processHistoricalRootsUpdate 904.00 ns/op 2.2450 us/op 0.40
mainnet_e58758 - phase0 processParticipationRecordUpdates 5.6200 us/op 13.013 us/op 0.43
mainnet_e58758 - phase0 afterProcessEpoch 160.16 ms/op 207.63 ms/op 0.77
phase0 processEffectiveBalanceUpdates - 250000 normalcase 2.5389 ms/op 3.3662 ms/op 0.75
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 3.5098 ms/op 4.5237 ms/op 0.78
altair processInactivityUpdates - 250000 normalcase 39.326 ms/op 49.889 ms/op 0.79
altair processInactivityUpdates - 250000 worstcase 39.700 ms/op 49.819 ms/op 0.80
phase0 processRegistryUpdates - 250000 normalcase 9.9050 us/op 14.813 us/op 0.67
phase0 processRegistryUpdates - 250000 badcase_full_deposits 406.26 us/op 538.28 us/op 0.75
phase0 processRegistryUpdates - 250000 worstcase 0.5 208.99 ms/op 286.08 ms/op 0.73
altair processRewardsAndPenalties - 250000 normalcase 81.548 ms/op 154.26 ms/op 0.53
altair processRewardsAndPenalties - 250000 worstcase 126.29 ms/op 99.713 ms/op 1.27
phase0 getAttestationDeltas - 250000 normalcase 12.314 ms/op 16.890 ms/op 0.73
phase0 getAttestationDeltas - 250000 worstcase 12.385 ms/op 16.324 ms/op 0.76
phase0 processSlashings - 250000 worstcase 5.3567 ms/op 6.6817 ms/op 0.80
altair processSyncCommitteeUpdates - 250000 276.83 ms/op 364.54 ms/op 0.76
BeaconState.hashTreeRoot - No change 487.00 ns/op 572.00 ns/op 0.85
BeaconState.hashTreeRoot - 1 full validator 62.287 us/op 73.485 us/op 0.85
BeaconState.hashTreeRoot - 32 full validator 543.67 us/op 801.00 us/op 0.68
BeaconState.hashTreeRoot - 512 full validator 5.8782 ms/op 8.3066 ms/op 0.71
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 75.490 us/op 99.686 us/op 0.76
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 1.1291 ms/op 1.5012 ms/op 0.75
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 15.002 ms/op 19.328 ms/op 0.78
BeaconState.hashTreeRoot - 1 balances 59.548 us/op 79.644 us/op 0.75
BeaconState.hashTreeRoot - 32 balances 633.10 us/op 855.58 us/op 0.74
BeaconState.hashTreeRoot - 512 balances 5.5389 ms/op 7.0649 ms/op 0.78
BeaconState.hashTreeRoot - 250000 balances 88.700 ms/op 115.39 ms/op 0.77
aggregationBits - 2048 els - zipIndexesInBitList 30.700 us/op 40.732 us/op 0.75
regular array get 100000 times 67.377 us/op 83.839 us/op 0.80
wrappedArray get 100000 times 67.394 us/op 80.950 us/op 0.83
arrayWithProxy get 100000 times 28.861 ms/op 40.563 ms/op 0.71
ssz.Root.equals 445.00 ns/op 608.00 ns/op 0.73
byteArrayEquals 451.00 ns/op 590.00 ns/op 0.76
shuffle list - 16384 els 11.016 ms/op 13.864 ms/op 0.79
shuffle list - 250000 els 162.83 ms/op 231.46 ms/op 0.70
processSlot - 1 slots 11.586 us/op 16.609 us/op 0.70
processSlot - 32 slots 1.6921 ms/op 2.2352 ms/op 0.76
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 403.30 us/op 434.60 us/op 0.93
getCommitteeAssignments - req 1 vs - 250000 vc 5.3397 ms/op 6.5753 ms/op 0.81
getCommitteeAssignments - req 100 vs - 250000 vc 7.3157 ms/op 9.9857 ms/op 0.73
getCommitteeAssignments - req 1000 vs - 250000 vc 7.7475 ms/op 10.451 ms/op 0.74
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 10.470 ns/op 12.900 ns/op 0.81
state getBlockRootAtSlot - 250000 vs - 7PWei 1.0252 us/op 1.5457 us/op 0.66
computeProposers - vc 250000 16.272 ms/op 22.336 ms/op 0.73
computeEpochShuffling - vc 250000 165.36 ms/op 232.78 ms/op 0.71
getNextSyncCommittee - vc 250000 267.73 ms/op 362.82 ms/op 0.74

by benchmarkbot/action

@dapplion dapplion marked this pull request as draft October 21, 2022 13:22
@nazarhussain nazarhussain marked this pull request as ready for review October 21, 2022 15:51
@nazarhussain nazarhussain force-pushed the nh/4275-sim-tests-sync branch from 1b3517b to f50e7de Compare October 21, 2022 16:01
@dapplion dapplion marked this pull request as draft October 21, 2022 16:44
@nazarhussain nazarhussain marked this pull request as ready for review October 25, 2022 12:36
dapplion
dapplion reviewed Oct 27, 2022
View reviewed changes
packages/cli/test/simulation/simulation.test.ts

describe(`simulation test - ${testIdStr}`, function () {
this.timeout("5m");
this.timeout("10m");
Copy link
Contributor

@dapplion dapplion Oct 27, 2022 •
edited
Loading

Choose a reason for hiding this comment

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

Can you add an issue to compute this timeout dynamically in a number that makes sense given the test requirements? i.e. expected duration time + 10%

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Added it as task to the main issue.

dapplion
dapplion previously requested changes Oct 27, 2022
View reviewed changes
Copy link
Contributor

@dapplion dapplion left a comment

Choose a reason for hiding this comment

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

Some minor comments, otherwise good to merge

@nazarhussain nazarhussain mentioned this pull request Oct 28, 2022
Closed
20 tasks
@nazarhussain nazarhussain requested a review from dapplion October 28, 2022 08:03
@nazarhussain nazarhussain merged commit 8c42768 into unstable Oct 28, 2022
@nazarhussain nazarhussain deleted the nh/4275-sim-tests-sync branch October 28, 2022 14:19
@nazarhussain nazarhussain mentioned this pull request Nov 1, 2022
Merged
3 tasks
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@wemeetagain wemeetagain wemeetagain approved these changes

@dapplion dapplion Awaiting requested review from dapplion

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

Successfully merging this pull request may close these issues.

Sim tests overhaul
3 participants
@nazarhussain @wemeetagain @dapplion