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

test: move mocha to vitest for beacon-node change #6028

Merged
merged 24 commits into from
Oct 13, 2023
Merged

Conversation

nazarhussain
Copy link
Contributor

@nazarhussain nazarhussain commented Oct 9, 2023

Motivation

Improve the developer productivity by reducing the time spent on the CI jobs reiterations, by making the tests run produce more stable results.

Description

We observed over the months that our tests runs are not stable. Specially the E2E tests were really fragile. This introduces a friction and delay in the development cycle. We endup considering the E2E tests not required for the CI, which is same as not having any e2e tests at all. Reducing the trust level on the code changes we introduce.

Based on every day understanding of debugging those tests I realized that something is not right with our tests runner. One clear identification is that we explicitly set force exit for mocha. All tests should exit naturally, if we don't set this exit option, tests does not exit even on local development machines.

I also observed one other indicator that mocha is not serving well. Below code is throwing error in the tests, but the tests are passing just fine.

signedBlobSidecars.forEach(async (signedBlobSidecar) => {
await validateGossipBlobSidecar(chain.config, chain, signedBlobSidecar, signedBlobSidecar.message.index);
});
});

There are few other nits and bits that suggests that mocha test runner is not performing well. So based on assumption I tried other runner and found a lot of errors right away, some were logical issues, some were mocks and few runtime errors, all those issues were buried by mocha specially when code is running in the worker thread. Some of those issues are mentioned in the PR comments. By moving to other test runner, identified of those issues and for future we don't encounter the same problem I suggest to migrate to another test runner completely which makes our tests more stable.

This PR will introduce migration to other test runner.

  1. Analyzed two options Jest and Vitest
  2. As of latest version of Jest 29.7 the Jest support for ESM modules are still experimental while the Vitest is all build on EMS and support it natively.
  3. The typescript support for the Jest is prune to errors. There are many issues reported for it. While for Vitest we don't even need to configure it for Typescirpt, it's configuration files can even be in TS.
  4. Based on above two reasons, as we are heavily based on ESM modules an always use the Typescript I prefer to use the Vitest.

The migration can be divided into steps:

  1. We can migrate to other tests runner step by step.
  2. This PR will introduce the migration for unit and e2e tests for the beacon-node package
  3. We can migrate other packages separately in independant PRs.
  4. For most of the expectation assertions migration we can use jest-codemods tool. Used that in this current PR as well.
  5. The remaining manual fixes remains rewriting mock codes.

Here are some key points for migration;

  1. Use npx jest-codemods to automatically migrate all assertions.
  2. The mocha syntax for this.timeout can be moved as third parameter for describe or it.
  3. sinon.createStubbedInstance can be migrated with vi.mock and vi.mocked methods.

Steps to test or reproduce

Run all tests.

@nazarhussain nazarhussain self-assigned this Oct 9, 2023
@github-actions
Copy link
Contributor

github-actions bot commented Oct 9, 2023

Performance Report

✔️ no performance regression detected

Full benchmark results
Benchmark suite Current: 590262a Previous: ab2dfdd Ratio
getPubkeys - index2pubkey - req 1000 vs - 250000 vc 841.73 us/op 987.93 us/op 0.85
getPubkeys - validatorsArr - req 1000 vs - 250000 vc 67.696 us/op 95.386 us/op 0.71
BLS verify - blst-native 1.1578 ms/op 1.3420 ms/op 0.86
BLS verifyMultipleSignatures 3 - blst-native 2.3937 ms/op 2.7894 ms/op 0.86
BLS verifyMultipleSignatures 8 - blst-native 5.3037 ms/op 6.1616 ms/op 0.86
BLS verifyMultipleSignatures 32 - blst-native 19.639 ms/op 22.500 ms/op 0.87
BLS verifyMultipleSignatures 64 - blst-native 38.749 ms/op 44.296 ms/op 0.87
BLS verifyMultipleSignatures 128 - blst-native 76.077 ms/op 87.759 ms/op 0.87
BLS deserializing 10000 signatures 789.72 ms/op 906.59 ms/op 0.87
BLS deserializing 100000 signatures 7.9713 s/op 9.2602 s/op 0.86
BLS verifyMultipleSignatures - same message - 3 - blst-native 1.1792 ms/op 1.4203 ms/op 0.83
BLS verifyMultipleSignatures - same message - 8 - blst-native 1.2790 ms/op 1.5956 ms/op 0.80
BLS verifyMultipleSignatures - same message - 32 - blst-native 2.0256 ms/op 2.6411 ms/op 0.77
BLS verifyMultipleSignatures - same message - 64 - blst-native 3.0011 ms/op 3.8014 ms/op 0.79
BLS verifyMultipleSignatures - same message - 128 - blst-native 5.6968 ms/op 5.7757 ms/op 0.99
BLS aggregatePubkeys 32 - blst-native 23.611 us/op 26.681 us/op 0.88
BLS aggregatePubkeys 128 - blst-native 92.534 us/op 103.39 us/op 0.90
getAttestationsForBlock 30.323 ms/op 48.004 ms/op 0.63
isKnown best case - 1 super set check 338.00 ns/op 371.00 ns/op 0.91
isKnown normal case - 2 super set checks 342.00 ns/op 406.00 ns/op 0.84
isKnown worse case - 16 super set checks 344.00 ns/op 370.00 ns/op 0.93
CheckpointStateCache - add get delete 4.2530 us/op 6.0730 us/op 0.70
validate api signedAggregateAndProof - struct 2.3972 ms/op 2.8839 ms/op 0.83
validate gossip signedAggregateAndProof - struct 2.3872 ms/op 2.8846 ms/op 0.83
validate gossip attestation - vc 640000 1.1415 ms/op 1.4365 ms/op 0.79
batch validate gossip attestation - vc 640000 - chunk 32 146.65 us/op 169.00 us/op 0.87
batch validate gossip attestation - vc 640000 - chunk 64 126.57 us/op 151.26 us/op 0.84
batch validate gossip attestation - vc 640000 - chunk 128 114.32 us/op 141.24 us/op 0.81
batch validate gossip attestation - vc 640000 - chunk 256 110.20 us/op 137.34 us/op 0.80
pickEth1Vote - no votes 906.97 us/op 1.2939 ms/op 0.70
pickEth1Vote - max votes 6.9679 ms/op 9.8033 ms/op 0.71
pickEth1Vote - Eth1Data hashTreeRoot value x2048 13.486 ms/op 16.571 ms/op 0.81
pickEth1Vote - Eth1Data hashTreeRoot tree x2048 20.843 ms/op 29.696 ms/op 0.70
pickEth1Vote - Eth1Data fastSerialize value x2048 467.92 us/op 671.79 us/op 0.70
pickEth1Vote - Eth1Data fastSerialize tree x2048 4.4694 ms/op 8.1891 ms/op 0.55
bytes32 toHexString 432.00 ns/op 528.00 ns/op 0.82
bytes32 Buffer.toString(hex) 302.00 ns/op 295.00 ns/op 1.02
bytes32 Buffer.toString(hex) from Uint8Array 410.00 ns/op 478.00 ns/op 0.86
bytes32 Buffer.toString(hex) + 0x 294.00 ns/op 307.00 ns/op 0.96
Object access 1 prop 0.18800 ns/op 0.18200 ns/op 1.03
Map access 1 prop 0.18200 ns/op 0.15700 ns/op 1.16
Object get x1000 5.5970 ns/op 7.9140 ns/op 0.71
Map get x1000 0.50200 ns/op 0.57400 ns/op 0.87
Object set x1000 26.701 ns/op 55.398 ns/op 0.48
Map set x1000 16.593 ns/op 43.380 ns/op 0.38
Return object 10000 times 0.22620 ns/op 0.24520 ns/op 0.92
Throw Error 10000 times 2.7620 us/op 3.9477 us/op 0.70
fastMsgIdFn sha256 / 200 bytes 2.0530 us/op 3.3800 us/op 0.61
fastMsgIdFn h32 xxhash / 200 bytes 322.00 ns/op 311.00 ns/op 1.04
fastMsgIdFn h64 xxhash / 200 bytes 361.00 ns/op 362.00 ns/op 1.00
fastMsgIdFn sha256 / 1000 bytes 6.3010 us/op 11.658 us/op 0.54
fastMsgIdFn h32 xxhash / 1000 bytes 447.00 ns/op 434.00 ns/op 1.03
fastMsgIdFn h64 xxhash / 1000 bytes 433.00 ns/op 432.00 ns/op 1.00
fastMsgIdFn sha256 / 10000 bytes 53.457 us/op 105.72 us/op 0.51
fastMsgIdFn h32 xxhash / 10000 bytes 2.0120 us/op 1.9960 us/op 1.01
fastMsgIdFn h64 xxhash / 10000 bytes 1.3010 us/op 1.3510 us/op 0.96
send data - 1000 256B messages 14.082 ms/op 20.365 ms/op 0.69
send data - 1000 512B messages 16.690 ms/op 27.499 ms/op 0.61
send data - 1000 1024B messages 22.427 ms/op 42.199 ms/op 0.53
send data - 1000 1200B messages 17.420 ms/op 33.115 ms/op 0.53
send data - 1000 2048B messages 23.499 ms/op 35.555 ms/op 0.66
send data - 1000 4096B messages 19.896 ms/op 30.562 ms/op 0.65
send data - 1000 16384B messages 54.814 ms/op 79.960 ms/op 0.69
send data - 1000 65536B messages 228.23 ms/op 266.29 ms/op 0.86
enrSubnets - fastDeserialize 64 bits 894.00 ns/op 1.4450 us/op 0.62
enrSubnets - ssz BitVector 64 bits 422.00 ns/op 466.00 ns/op 0.91
enrSubnets - fastDeserialize 4 bits 195.00 ns/op 190.00 ns/op 1.03
enrSubnets - ssz BitVector 4 bits 408.00 ns/op 478.00 ns/op 0.85
prioritizePeers score -10:0 att 32-0.1 sync 2-0 65.121 us/op 114.72 us/op 0.57
prioritizePeers score 0:0 att 32-0.25 sync 2-0.25 81.642 us/op 129.08 us/op 0.63
prioritizePeers score 0:0 att 32-0.5 sync 2-0.5 101.47 us/op 175.58 us/op 0.58
prioritizePeers score 0:0 att 64-0.75 sync 4-0.75 179.44 us/op 317.82 us/op 0.56
prioritizePeers score 0:0 att 64-1 sync 4-1 202.63 us/op 364.62 us/op 0.56
array of 16000 items push then shift 1.2861 us/op 1.6793 us/op 0.77
LinkedList of 16000 items push then shift 5.9440 ns/op 9.1990 ns/op 0.65
array of 16000 items push then pop 68.045 ns/op 82.903 ns/op 0.82
LinkedList of 16000 items push then pop 5.8530 ns/op 9.0230 ns/op 0.65
array of 24000 items push then shift 1.8606 us/op 2.5780 us/op 0.72
LinkedList of 24000 items push then shift 6.6760 ns/op 9.4450 ns/op 0.71
array of 24000 items push then pop 116.67 ns/op 141.16 ns/op 0.83
LinkedList of 24000 items push then pop 5.8500 ns/op 9.6180 ns/op 0.61
intersect bitArray bitLen 8 5.4530 ns/op 7.2070 ns/op 0.76
intersect array and set length 8 41.342 ns/op 59.427 ns/op 0.70
intersect bitArray bitLen 128 25.779 ns/op 33.211 ns/op 0.78
intersect array and set length 128 577.60 ns/op 894.52 ns/op 0.65
bitArray.getTrueBitIndexes() bitLen 128 1.1830 us/op 2.0220 us/op 0.59
bitArray.getTrueBitIndexes() bitLen 248 1.8800 us/op 3.1110 us/op 0.60
bitArray.getTrueBitIndexes() bitLen 512 3.5310 us/op 5.9650 us/op 0.59
Buffer.concat 32 items 846.00 ns/op 1.1580 us/op 0.73
Uint8Array.set 32 items 2.1470 us/op 2.2120 us/op 0.97
Set add up to 64 items then delete first 1.6188 us/op 4.7722 us/op 0.34
OrderedSet add up to 64 items then delete first 2.4815 us/op 6.3031 us/op 0.39
Set add up to 64 items then delete last 1.8473 us/op 5.1700 us/op 0.36
OrderedSet add up to 64 items then delete last 3.0719 us/op 6.4552 us/op 0.48
Set add up to 64 items then delete middle 1.9534 us/op 5.0620 us/op 0.39
OrderedSet add up to 64 items then delete middle 4.2912 us/op 7.8505 us/op 0.55
Set add up to 128 items then delete first 3.7148 us/op 10.303 us/op 0.36
OrderedSet add up to 128 items then delete first 5.5144 us/op 13.733 us/op 0.40
Set add up to 128 items then delete last 3.7444 us/op 10.204 us/op 0.37
OrderedSet add up to 128 items then delete last 5.8645 us/op 13.091 us/op 0.45
Set add up to 128 items then delete middle 3.7066 us/op 10.138 us/op 0.37
OrderedSet add up to 128 items then delete middle 10.663 us/op 18.883 us/op 0.56
Set add up to 256 items then delete first 7.2995 us/op 20.838 us/op 0.35
OrderedSet add up to 256 items then delete first 11.783 us/op 28.235 us/op 0.42
Set add up to 256 items then delete last 7.2543 us/op 20.164 us/op 0.36
OrderedSet add up to 256 items then delete last 11.375 us/op 25.922 us/op 0.44
Set add up to 256 items then delete middle 7.2672 us/op 20.132 us/op 0.36
OrderedSet add up to 256 items then delete middle 30.478 us/op 50.147 us/op 0.61
transfer serialized Status (84 B) 1.4280 us/op 1.8430 us/op 0.77
copy serialized Status (84 B) 1.2780 us/op 1.7150 us/op 0.75
transfer serialized SignedVoluntaryExit (112 B) 1.4830 us/op 2.1540 us/op 0.69
copy serialized SignedVoluntaryExit (112 B) 1.3420 us/op 1.6800 us/op 0.80
transfer serialized ProposerSlashing (416 B) 1.5780 us/op 2.2330 us/op 0.71
copy serialized ProposerSlashing (416 B) 1.4880 us/op 2.1460 us/op 0.69
transfer serialized Attestation (485 B) 1.5980 us/op 2.1910 us/op 0.73
copy serialized Attestation (485 B) 1.4640 us/op 2.0840 us/op 0.70
transfer serialized AttesterSlashing (33232 B) 1.7380 us/op 2.2720 us/op 0.76
copy serialized AttesterSlashing (33232 B) 3.3260 us/op 6.5960 us/op 0.50
transfer serialized Small SignedBeaconBlock (128000 B) 1.7070 us/op 2.6280 us/op 0.65
copy serialized Small SignedBeaconBlock (128000 B) 7.5010 us/op 20.445 us/op 0.37
transfer serialized Avg SignedBeaconBlock (200000 B) 1.6960 us/op 3.7080 us/op 0.46
copy serialized Avg SignedBeaconBlock (200000 B) 10.932 us/op 24.433 us/op 0.45
transfer serialized BlobsSidecar (524380 B) 2.1460 us/op 3.6740 us/op 0.58
copy serialized BlobsSidecar (524380 B) 75.074 us/op 102.43 us/op 0.73
transfer serialized Big SignedBeaconBlock (1000000 B) 2.6660 us/op 3.7030 us/op 0.72
copy serialized Big SignedBeaconBlock (1000000 B) 138.87 us/op 160.94 us/op 0.86
pass gossip attestations to forkchoice per slot 2.6288 ms/op 3.9436 ms/op 0.67
forkChoice updateHead vc 100000 bc 64 eq 0 503.91 us/op 742.09 us/op 0.68
forkChoice updateHead vc 600000 bc 64 eq 0 2.7472 ms/op 5.1767 ms/op 0.53
forkChoice updateHead vc 1000000 bc 64 eq 0 4.4124 ms/op 7.5309 ms/op 0.59
forkChoice updateHead vc 600000 bc 320 eq 0 2.8427 ms/op 4.3670 ms/op 0.65
forkChoice updateHead vc 600000 bc 1200 eq 0 2.6761 ms/op 4.3849 ms/op 0.61
forkChoice updateHead vc 600000 bc 7200 eq 0 3.2754 ms/op 5.3121 ms/op 0.62
forkChoice updateHead vc 600000 bc 64 eq 1000 10.135 ms/op 11.376 ms/op 0.89
forkChoice updateHead vc 600000 bc 64 eq 10000 9.8710 ms/op 12.267 ms/op 0.80
forkChoice updateHead vc 600000 bc 64 eq 300000 11.831 ms/op 17.757 ms/op 0.67
computeDeltas 500000 validators 300 proto nodes 2.9431 ms/op 6.4941 ms/op 0.45
computeDeltas 500000 validators 1200 proto nodes 2.8531 ms/op 6.3697 ms/op 0.45
computeDeltas 500000 validators 7200 proto nodes 2.8321 ms/op 6.4348 ms/op 0.44
computeDeltas 750000 validators 300 proto nodes 4.3719 ms/op 9.9209 ms/op 0.44
computeDeltas 750000 validators 1200 proto nodes 4.4245 ms/op 9.7974 ms/op 0.45
computeDeltas 750000 validators 7200 proto nodes 4.4188 ms/op 9.9987 ms/op 0.44
computeDeltas 1400000 validators 300 proto nodes 8.4813 ms/op 18.558 ms/op 0.46
computeDeltas 1400000 validators 1200 proto nodes 8.4487 ms/op 18.141 ms/op 0.47
computeDeltas 1400000 validators 7200 proto nodes 8.3635 ms/op 18.857 ms/op 0.44
computeDeltas 2100000 validators 300 proto nodes 12.765 ms/op 27.729 ms/op 0.46
computeDeltas 2100000 validators 1200 proto nodes 12.898 ms/op 28.033 ms/op 0.46
computeDeltas 2100000 validators 7200 proto nodes 13.132 ms/op 28.062 ms/op 0.47
computeProposerBoostScoreFromBalances 500000 validators 2.8229 ms/op 3.4198 ms/op 0.83
computeProposerBoostScoreFromBalances 750000 validators 2.8032 ms/op 3.3902 ms/op 0.83
computeProposerBoostScoreFromBalances 1400000 validators 2.7866 ms/op 3.3490 ms/op 0.83
computeProposerBoostScoreFromBalances 2100000 validators 2.7765 ms/op 3.3425 ms/op 0.83
altair processAttestation - 250000 vs - 7PWei normalcase 2.1330 ms/op 3.3380 ms/op 0.64
altair processAttestation - 250000 vs - 7PWei worstcase 2.8310 ms/op 4.1173 ms/op 0.69
altair processAttestation - setStatus - 1/6 committees join 74.322 us/op 185.20 us/op 0.40
altair processAttestation - setStatus - 1/3 committees join 161.34 us/op 359.86 us/op 0.45
altair processAttestation - setStatus - 1/2 committees join 231.25 us/op 483.16 us/op 0.48
altair processAttestation - setStatus - 2/3 committees join 282.35 us/op 606.82 us/op 0.47
altair processAttestation - setStatus - 4/5 committees join 416.47 us/op 858.74 us/op 0.48
altair processAttestation - setStatus - 100% committees join 500.94 us/op 994.40 us/op 0.50
altair processBlock - 250000 vs - 7PWei normalcase 7.2834 ms/op 10.383 ms/op 0.70
altair processBlock - 250000 vs - 7PWei normalcase hashState 25.238 ms/op 35.450 ms/op 0.71
altair processBlock - 250000 vs - 7PWei worstcase 35.255 ms/op 43.653 ms/op 0.81
altair processBlock - 250000 vs - 7PWei worstcase hashState 76.296 ms/op 99.073 ms/op 0.77
phase0 processBlock - 250000 vs - 7PWei normalcase 2.3310 ms/op 3.0790 ms/op 0.76
phase0 processBlock - 250000 vs - 7PWei worstcase 27.201 ms/op 35.825 ms/op 0.76
altair processEth1Data - 250000 vs - 7PWei normalcase 382.60 us/op 654.41 us/op 0.58
getExpectedWithdrawals 250000 eb:1,eth1:1,we:0,wn:0,smpl:15 13.624 us/op 19.137 us/op 0.71
getExpectedWithdrawals 250000 eb:0.95,eth1:0.1,we:0.05,wn:0,smpl:219 43.080 us/op 80.750 us/op 0.53
getExpectedWithdrawals 250000 eb:0.95,eth1:0.3,we:0.05,wn:0,smpl:42 14.861 us/op 17.057 us/op 0.87
getExpectedWithdrawals 250000 eb:0.95,eth1:0.7,we:0.05,wn:0,smpl:18 13.096 us/op 18.328 us/op 0.71
getExpectedWithdrawals 250000 eb:0.1,eth1:0.1,we:0,wn:0,smpl:1020 147.21 us/op 214.71 us/op 0.69
getExpectedWithdrawals 250000 eb:0.03,eth1:0.03,we:0,wn:0,smpl:11777 1.0453 ms/op 1.4752 ms/op 0.71
getExpectedWithdrawals 250000 eb:0.01,eth1:0.01,we:0,wn:0,smpl:16384 891.18 us/op 1.9266 ms/op 0.46
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,smpl:16384 1.2874 ms/op 1.9056 ms/op 0.68
getExpectedWithdrawals 250000 eb:0,eth1:0,we:0,wn:0,nocache,smpl:16384 2.7695 ms/op 4.1094 ms/op 0.67
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,smpl:16384 1.3203 ms/op 3.0750 ms/op 0.43
getExpectedWithdrawals 250000 eb:0,eth1:1,we:0,wn:0,nocache,smpl:16384 3.7358 ms/op 6.5917 ms/op 0.57
Tree 40 250000 create 234.18 ms/op 445.59 ms/op 0.53
Tree 40 250000 get(125000) 105.58 ns/op 212.68 ns/op 0.50
Tree 40 250000 set(125000) 682.32 ns/op 956.91 ns/op 0.71
Tree 40 250000 toArray() 12.615 ms/op 22.666 ms/op 0.56
Tree 40 250000 iterate all - toArray() + loop 16.862 ms/op 23.155 ms/op 0.73
Tree 40 250000 iterate all - get(i) 53.110 ms/op 74.146 ms/op 0.72
MutableVector 250000 create 8.9701 ms/op 15.658 ms/op 0.57
MutableVector 250000 get(125000) 5.8280 ns/op 6.7590 ns/op 0.86
MutableVector 250000 set(125000) 186.71 ns/op 282.53 ns/op 0.66
MutableVector 250000 toArray() 2.2742 ms/op 4.0537 ms/op 0.56
MutableVector 250000 iterate all - toArray() + loop 2.2022 ms/op 4.1739 ms/op 0.53
MutableVector 250000 iterate all - get(i) 1.3910 ms/op 1.5824 ms/op 0.88
Array 250000 create 2.2896 ms/op 3.8564 ms/op 0.59
Array 250000 clone - spread 950.51 us/op 1.2679 ms/op 0.75
Array 250000 get(125000) 0.56100 ns/op 0.63500 ns/op 0.88
Array 250000 set(125000) 0.63500 ns/op 0.71900 ns/op 0.88
Array 250000 iterate all - loop 79.676 us/op 86.816 us/op 0.92
effectiveBalanceIncrements clone Uint8Array 300000 13.598 us/op 41.306 us/op 0.33
effectiveBalanceIncrements clone MutableVector 300000 342.00 ns/op 364.00 ns/op 0.94
effectiveBalanceIncrements rw all Uint8Array 300000 173.89 us/op 182.03 us/op 0.96
effectiveBalanceIncrements rw all MutableVector 300000 66.242 ms/op 94.171 ms/op 0.70
phase0 afterProcessEpoch - 250000 vs - 7PWei 81.288 ms/op 121.19 ms/op 0.67
phase0 beforeProcessEpoch - 250000 vs - 7PWei 37.463 ms/op 42.092 ms/op 0.89
altair processEpoch - mainnet_e81889 364.84 ms/op 523.00 ms/op 0.70
mainnet_e81889 - altair beforeProcessEpoch 56.020 ms/op 71.623 ms/op 0.78
mainnet_e81889 - altair processJustificationAndFinalization 9.9070 us/op 26.092 us/op 0.38
mainnet_e81889 - altair processInactivityUpdates 6.2799 ms/op 8.8804 ms/op 0.71
mainnet_e81889 - altair processRewardsAndPenalties 60.671 ms/op 84.173 ms/op 0.72
mainnet_e81889 - altair processRegistryUpdates 1.7750 us/op 7.8490 us/op 0.23
mainnet_e81889 - altair processSlashings 596.00 ns/op 1.0960 us/op 0.54
mainnet_e81889 - altair processEth1DataReset 626.00 ns/op 1.2960 us/op 0.48
mainnet_e81889 - altair processEffectiveBalanceUpdates 1.6046 ms/op 2.2429 ms/op 0.72
mainnet_e81889 - altair processSlashingsReset 3.4120 us/op 6.3040 us/op 0.54
mainnet_e81889 - altair processRandaoMixesReset 4.9910 us/op 6.8180 us/op 0.73
mainnet_e81889 - altair processHistoricalRootsUpdate 1.0930 us/op 1.5460 us/op 0.71
mainnet_e81889 - altair processParticipationFlagUpdates 2.5520 us/op 4.8620 us/op 0.52
mainnet_e81889 - altair processSyncCommitteeUpdates 611.00 ns/op 2.0040 us/op 0.30
mainnet_e81889 - altair afterProcessEpoch 84.708 ms/op 151.34 ms/op 0.56
capella processEpoch - mainnet_e217614 1.2945 s/op 1.6139 s/op 0.80
mainnet_e217614 - capella beforeProcessEpoch 187.87 ms/op 242.07 ms/op 0.78
mainnet_e217614 - capella processJustificationAndFinalization 9.6140 us/op 13.274 us/op 0.72
mainnet_e217614 - capella processInactivityUpdates 13.013 ms/op 18.837 ms/op 0.69
mainnet_e217614 - capella processRewardsAndPenalties 273.45 ms/op 296.87 ms/op 0.92
mainnet_e217614 - capella processRegistryUpdates 7.1980 us/op 23.655 us/op 0.30
mainnet_e217614 - capella processSlashings 508.00 ns/op 612.00 ns/op 0.83
mainnet_e217614 - capella processEth1DataReset 519.00 ns/op 499.00 ns/op 1.04
mainnet_e217614 - capella processEffectiveBalanceUpdates 2.9415 ms/op 4.2030 ms/op 0.70
mainnet_e217614 - capella processSlashingsReset 1.8760 us/op 2.3710 us/op 0.79
mainnet_e217614 - capella processRandaoMixesReset 3.0950 us/op 4.4040 us/op 0.70
mainnet_e217614 - capella processHistoricalRootsUpdate 474.00 ns/op 649.00 ns/op 0.73
mainnet_e217614 - capella processParticipationFlagUpdates 1.4970 us/op 1.6620 us/op 0.90
mainnet_e217614 - capella afterProcessEpoch 203.41 ms/op 315.39 ms/op 0.64
phase0 processEpoch - mainnet_e58758 377.58 ms/op 466.02 ms/op 0.81
mainnet_e58758 - phase0 beforeProcessEpoch 107.54 ms/op 118.88 ms/op 0.90
mainnet_e58758 - phase0 processJustificationAndFinalization 11.544 us/op 17.547 us/op 0.66
mainnet_e58758 - phase0 processRewardsAndPenalties 58.380 ms/op 61.185 ms/op 0.95
mainnet_e58758 - phase0 processRegistryUpdates 6.4420 us/op 12.663 us/op 0.51
mainnet_e58758 - phase0 processSlashings 544.00 ns/op 568.00 ns/op 0.96
mainnet_e58758 - phase0 processEth1DataReset 509.00 ns/op 694.00 ns/op 0.73
mainnet_e58758 - phase0 processEffectiveBalanceUpdates 1.2270 ms/op 1.2805 ms/op 0.96
mainnet_e58758 - phase0 processSlashingsReset 1.6740 us/op 3.0030 us/op 0.56
mainnet_e58758 - phase0 processRandaoMixesReset 2.5350 us/op 5.4020 us/op 0.47
mainnet_e58758 - phase0 processHistoricalRootsUpdate 464.00 ns/op 772.00 ns/op 0.60
mainnet_e58758 - phase0 processParticipationRecordUpdates 3.3100 us/op 7.3770 us/op 0.45
mainnet_e58758 - phase0 afterProcessEpoch 64.922 ms/op 121.82 ms/op 0.53
phase0 processEffectiveBalanceUpdates - 250000 normalcase 878.50 us/op 2.0647 ms/op 0.43
phase0 processEffectiveBalanceUpdates - 250000 worstcase 0.5 1.1096 ms/op 2.8866 ms/op 0.38
altair processInactivityUpdates - 250000 normalcase 17.435 ms/op 35.211 ms/op 0.50
altair processInactivityUpdates - 250000 worstcase 16.061 ms/op 34.243 ms/op 0.47
phase0 processRegistryUpdates - 250000 normalcase 6.5070 us/op 17.025 us/op 0.38
phase0 processRegistryUpdates - 250000 badcase_full_deposits 316.95 us/op 539.45 us/op 0.59
phase0 processRegistryUpdates - 250000 worstcase 0.5 112.18 ms/op 165.06 ms/op 0.68
altair processRewardsAndPenalties - 250000 normalcase 59.574 ms/op 98.206 ms/op 0.61
altair processRewardsAndPenalties - 250000 worstcase 59.755 ms/op 91.918 ms/op 0.65
phase0 getAttestationDeltas - 250000 normalcase 5.1768 ms/op 11.711 ms/op 0.44
phase0 getAttestationDeltas - 250000 worstcase 5.0374 ms/op 11.672 ms/op 0.43
phase0 processSlashings - 250000 worstcase 1.5024 ms/op 2.9317 ms/op 0.51
altair processSyncCommitteeUpdates - 250000 102.74 ms/op 175.53 ms/op 0.59
BeaconState.hashTreeRoot - No change 297.00 ns/op 340.00 ns/op 0.87
BeaconState.hashTreeRoot - 1 full validator 154.24 us/op 138.71 us/op 1.11
BeaconState.hashTreeRoot - 32 full validator 1.1484 ms/op 1.6655 ms/op 0.69
BeaconState.hashTreeRoot - 512 full validator 12.622 ms/op 18.785 ms/op 0.67
BeaconState.hashTreeRoot - 1 validator.effectiveBalance 164.46 us/op 182.66 us/op 0.90
BeaconState.hashTreeRoot - 32 validator.effectiveBalance 1.6845 ms/op 2.5622 ms/op 0.66
BeaconState.hashTreeRoot - 512 validator.effectiveBalance 21.423 ms/op 34.859 ms/op 0.61
BeaconState.hashTreeRoot - 1 balances 132.92 us/op 161.67 us/op 0.82
BeaconState.hashTreeRoot - 32 balances 1.0565 ms/op 1.6462 ms/op 0.64
BeaconState.hashTreeRoot - 512 balances 10.790 ms/op 14.732 ms/op 0.73
BeaconState.hashTreeRoot - 250000 balances 182.76 ms/op 291.19 ms/op 0.63
aggregationBits - 2048 els - zipIndexesInBitList 9.5850 us/op 27.377 us/op 0.35
regular array get 100000 times 31.519 us/op 37.476 us/op 0.84
wrappedArray get 100000 times 31.027 us/op 37.135 us/op 0.84
arrayWithProxy get 100000 times 10.123 ms/op 17.287 ms/op 0.59
ssz.Root.equals 249.00 ns/op 292.00 ns/op 0.85
byteArrayEquals 244.00 ns/op 285.00 ns/op 0.86
shuffle list - 16384 els 4.5534 ms/op 8.0908 ms/op 0.56
shuffle list - 250000 els 66.587 ms/op 111.68 ms/op 0.60
processSlot - 1 slots 12.071 us/op 20.582 us/op 0.59
processSlot - 32 slots 1.9825 ms/op 4.5939 ms/op 0.43
getEffectiveBalanceIncrementsZeroInactive - 250000 vs - 7PWei 42.364 ms/op 60.463 ms/op 0.70
getCommitteeAssignments - req 1 vs - 250000 vc 2.2403 ms/op 2.5945 ms/op 0.86
getCommitteeAssignments - req 100 vs - 250000 vc 3.3717 ms/op 3.8373 ms/op 0.88
getCommitteeAssignments - req 1000 vs - 250000 vc 3.6380 ms/op 4.1709 ms/op 0.87
RootCache.getBlockRootAtSlot - 250000 vs - 7PWei 4.6200 ns/op 5.0500 ns/op 0.91
state getBlockRootAtSlot - 250000 vs - 7PWei 818.08 ns/op 647.33 ns/op 1.26
computeProposers - vc 250000 5.5689 ms/op 9.3264 ms/op 0.60
computeEpochShuffling - vc 250000 68.129 ms/op 107.65 ms/op 0.63
getNextSyncCommittee - vc 250000 113.09 ms/op 161.49 ms/op 0.70
computeSigningRoot for AttestationData 29.182 us/op 30.605 us/op 0.95
hash AttestationData serialized data then Buffer.toString(base64) 1.2273 us/op 2.3845 us/op 0.51
toHexString serialized data 806.83 ns/op 1.0937 us/op 0.74
Buffer.toString(base64) 138.64 ns/op 220.33 ns/op 0.63

by benchmarkbot/action

@dapplion
Copy link
Contributor

dapplion commented Oct 9, 2023

You should not propose such a substantial change with the sole argument

Make the test more stable.

You must proof:

  • are the tests unstable now?
  • why?
  • why is it mocha's fault?
  • what is this test rummer doing exactly that addresses the proven techincal issues above?
  • can you measure stability in a quantifiable way such that A/B testing master against this branch should substantial improvement?

@nazarhussain
Copy link
Contributor Author

You should not propose such a substantial change with the sole argument

Make the test more stable.

You must proof:

  • are the tests unstable now?
  • why?
  • why is it mocha's fault?
  • what is this test rummer doing exactly that addresses the proven techincal issues above?
  • can you measure stability in a quantifiable way such that A/B testing master against this branch should substantial improvement?

There is a lot of discussion and analysis shared with @wemeetagain and had long collaborative sessions with @matthewkeil to influence towards that mocha is not performing well. I started this based on assumption but during the process found a lot instances where code was clearly not performing as expected but mocha was hiding the error. Will be able to highlight this in the code.

This PR is still draft when we reached to stability level, the details for the questions you asked will be added in description.

@nazarhussain
Copy link
Contributor Author

Some straight forward errors that popup after moving the test runner, which never been shown while running in mocha.

  Object {
-   "code": "REQUEST_ERROR_TTFB_TIMEOUT",
+   "code": "REQUEST_ERROR_DIAL_ERROR",
+   "error": "Muxer already closed",
  }

and

Serialized Error: { code: 'ERR_NOT_FOUND' }
This error originated in "test/e2e/network/gossipsub.test.ts" test file. It doesn't mean the error was thrown inside the file itself, but while it was running.

⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯ Unhandled Error ⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
Error: Unexpected message on Worker: {
  type: 'uncaughtError',
  error: {
    __error_marker: '$$error',
    message: 'Not Found',
    name: 'Error',
    stack: 'Error: Not Found\n' +
      '    at Module.notFoundError (file:///lodestar-review-2/node_modules/libp2p/node_modules/datastore-core/src/errors.ts:24:16)\n' +
      '    at MemoryDatastore.get (file:///lodestar-review-2/node_modules/libp2p/node_modules/datastore-core/src/memory.ts:26:20)\n' +
      '    at PersistentStore.load (file:///lodestar-review-2/node_modules/@libp2p/peer-store/src/store.ts:89:38)\n' +
      '    at PersistentPeerStore.get (file:///lodestar-review-2/node_modules/@libp2p/peer-store/src/index.ts:105:31)\n' +
      '    at Timeout._onTimeout (/lodestar-review-2/packages/beacon-node/src/network/peers/peerManager.ts:614:34)'
  }
}

@wemeetagain
Copy link
Member

I think the answer to most of the questions is that mocha has been swallowing errors and hanging tests.
We've mostly been unaware of all this until @nazarhussain did some digging on the e2e test hanging that has been happening and dropped into this rabbithole.
I'm assuming that this test runner is not doing as much magic as mocha, and it isn't hiding errors in the same way mocha was.

@matthewkeil
Copy link
Member

There was some very very weird behavior with how the after* hooks were behaving @dapplion. It was not respecting promises and there was some very funky async behavior when @nazarhussain and I were looking at it together

@nazarhussain
Copy link
Contributor Author

One other very simple case is below; This await is throwing error, but we never never see it with mocha. Try wrapping this await in try/catch and you will see the error for every test in the file.

I agree we should not be using forEach here but if we did the test runner should not hide the thrown error.

signedBlobSidecars.forEach(async (signedBlobSidecar) => {
await validateGossipBlobSidecar(chain.config, chain, signedBlobSidecar, signedBlobSidecar.message.index);
});
});

@dapplion
Copy link
Contributor

dapplion commented Oct 10, 2023

Thanks for the context, that's much more helpful.

Can you figure out a way to prevent the type of re-formatting example below?

from

describe("chain / lightclient", function () {
  // code at 2 indents

to

describe(
  "chain / lightclient",
  function () {
    // code at 4 indents

it adds a ton of diff making this PR very hard to review

@codecov
Copy link

codecov bot commented Oct 10, 2023

Codecov Report

❗ No coverage uploaded for pull request base (unstable@ab2dfdd). Click here to learn what that means.
The diff coverage is n/a.

❗ Current head 1f3d684 differs from pull request most recent head dc4b282. Consider uploading reports for the commit dc4b282 to get more accurate results

@@            Coverage Diff             @@
##             unstable   #6028   +/-   ##
==========================================
  Coverage            ?       0           
==========================================
  Files               ?       0           
  Lines               ?       0           
  Branches            ?       0           
==========================================
  Hits                ?       0           
  Misses              ?       0           
  Partials            ?       0           

@nazarhussain nazarhussain marked this pull request as ready for review October 10, 2023 12:32
@nazarhussain nazarhussain requested a review from a team as a code owner October 10, 2023 12:32
@nazarhussain
Copy link
Contributor Author

Codecov Report

Merging #6028 (75787da) into unstable (d25d57e) will not change coverage.
Report is 3 commits behind head on unstable.
The diff coverage is n/a.

❗ Current head 75787da differs from pull request most recent head 11ca6ef. Consider uploading reports for the commit 11ca6ef to get more accurate results

@@       Coverage Diff        @@
##   unstable   #6028   +/-   ##
================================
================================

Seems we had zero code coverage before, will be fixed this PR as well and for other packages as migrate.

https://app.codecov.io/gh/ChainSafe/lodestar/tree/unstable

image

@dapplion
Copy link
Contributor

dapplion commented Oct 10, 2023

You should not propose such a substantial change with the sole argument

Make the test more stable.

You must proof:

* [x]  are the tests unstable now?

* [ ]  why?

* [ ]  why is it mocha's fault?

* [ ]  what is this test rummer doing exactly that addresses the proven techincal issues above?

* [x]  can you measure stability in a quantifiable way such that A/B testing master against this branch should substantial improvement?

Thanks for the added details but I'm still missing specific concrete reasons for the points outlined here. I'm not questioning that another test runner is showing better results, but I believe it's very important to try to understand better the source of the problem. Otherwise we are playing blind games hoping that some other thing works.

@nflaig
Copy link
Member

nflaig commented Oct 10, 2023

We endup #6017 for the CI, which is same as not having any e2e tests at all. Reducing the trust level on the code changes we introduce.

We are not really skipping them right now, see rationale in the PR that added the workaround. Of course this is not ideal solution long term.

Based on every day understanding of debugging those tests I realized that something is not right with our tests runner. One clear identification is that we explicitly set force exit for mocha. All tests should exit naturally, if we don't set this exit option, tests does not exit even on local development machines.

I am not sure this is related to mocha, it seemed to happen since node v20 or around that time. There a bunch of issues around this topic recently, see Debugging hanging processes

@nazarhussain
Copy link
Contributor Author

Thanks for the added details but I'm still missing specific concrete reasons for the points outlined here. I'm not questioning that another test runner is showing better results, but I believe it's very important to try to understand better the source of the problem. Otherwise we are playing blind games hoping that some other thing works.

@dapplion

Why

The following two changes answers why our tests were unstable.

#6028 (comment)
#6028 (comment)

Why is it mocha's fault?

It's not mocha fault for those issues, but mocha was hiding these errors. And because we just see a test hanging without any error traces we were unable to identify and fix the bugs.

One other point is that having resource leaks is a common scenario in NodeJs ecosystem and all major tests runners support features to detect those natively. e.g. Jest have --detectopenhandles, Vitest have --reporter=hanging-process. Having support of such features natively to test runner helps us to detect and solve such issues on time.

What is this test rummer doing exactly that addresses the proven techincal issues above?

My understanding is that mocha was designed and developed before the Worker support in JS and they didn't cover all the scenarios and edge cases that can happen specially when SUT (System Under Test) execute in worker environment. The vitest on the other hand is developed with modern language and framework features in mind and they natively build their concurrency around the worker support so why it was able to catch up those errors properly. The further detail comparison of Vitest is available here.

@nazarhussain
Copy link
Contributor Author

nazarhussain commented Oct 11, 2023

@nflaig

We are not really skipping them right now, see rationale in the PR that added the workaround. Of course this is not ideal solution long term.

If a dev team build an impression that some tests are not stable, so not important to check if they fail. It's equivalent to not having such tests. Not often times people run tests locally and usually rely on CI to detect if something really is broken and required to look into.

I am not sure this is related to mocha, it seemed to happen since node v20 or around that time. There a bunch of issues around this topic recently, see Debugging hanging processes

I believe in case of Lodestar the observation is same even before Node v20. Secondly there can be issues introduced by runtime, but having a stable test runner which helps to detect those issues is more helpful. As I mentioned in earlier comment Jest and Vitest have this support natively so would be a good tool in our kit in case of runtime issues.

@nflaig
Copy link
Member

nflaig commented Oct 11, 2023

One other point is that having resource leaks is a common scenario in NodeJs ecosystem and all major tests runners support features to detect those natively. e.g. Jest have --detectopenhandles, Vitest have --reporter=hanging-process. Having support of such features natively to test runner helps us to detect and solve such issues on time.

That's a good point, mocha is very limited in that regard, you can't even trace max event listener warnings as far as I know.

I believe in case of Lodestar the observation is same even before Node v20. Secondly there can be issues introduced by runtime, but having a stable test runner which helps to detect those issues is more helpful. As I mentioned in earlier comment Jest and Vitest have this support natively so would be a good tool in our kit in case of runtime issues.

I trust in your judgement that vitest is a better and more stable test runner compared to mocha. Even if the exit issue is not directly related to mocha, just the fact that errors might be swallowed by mocha is enough of a selling point for me

@dapplion
Copy link
Contributor

@nazarhussain

The following two changes answers why our tests were unstable.

#6028 (comment)
#6028 (comment)

Those are fixes of our code, what I we should understand better is why mocha is not displaying those errors. And what other tests runners do different to actually show those errors.

As far as I understand the current position is:

  • Our e2e tests where observed to fail randomly and somewhat often
  • Nazar tried other test runners to see what happens
  • The result is that some tests that before did not fail, fail now. Plus tests (so far) appear to not fail randomly
  • We guess that it might have something to do with how mocha runner interferes with Workers, but we don't know the technical details, nor can point to a specific issue.

Also, ping on please addressing the formatting this issue raised before to reduce the diff

@nazarhussain
Copy link
Contributor Author

As far as I understand the current position is:

I would rathe list it like that:

  • Our e2e tests where observed to fail and hang randomly and somewhat often
  • Nazar tried to explore the reasoning which could end up hanging tests but because mocha does not have that support we were blind.
  • Then I used wtfnode and other tools that identified that some ports were open at the end of the tests.
  • Based on that information, created a reproducable script which identified an issue in libp2p and opened a PR to fix that.
  • After updating and verifying through that script that now there is no port, our tests were still hanging.
  • From outside monitoring tools like wtfnode were unable to detect why the tests are still hanging.
  • Because mocha does not have an exit hook, so had to create a wrapper around mocha which provide this support.
  • Integrating wtfnode with that exit hook, identified that there are some MessagePort left open when the tests hangs. Which code left that orphan object was not identified.
  • So far in whole process, not at any point was able to see any error identified by the mocha.
  • Even was able to identify a code block mentioned here which does not involve a worker thread and clearly throws an error but mocha didn't catch and reported that.
  • Out of curiosity migrated just that test case to other test runner and others were able to catch that error. So it was conclusive that there is something wrong going on with mocha runner.

So now comes to the point what could be wrong in the mocha, I am not fully sure but here is my assumption;

  1. It's the issue how mocha cli is initiated.
  2. If we pass any node-options then CLI does not execute the tests directly, rather it opens another child process to execute the tests.
  3. There is no error handler on that newly spawned child process, which could make the parent blind.
  4. Second assumption I have is use of pattern require.main === module which is used to run the CLI directly from terminal or from child processes. I believe this execution make the child process silent in case of any code run inside the worker.

The vitest on the other hand runs it's binary in the esm enabled process, so it does not need to spawn a child process.

Also, ping on please addressing the formatting this issue raised before to reduce the diff

Had disabled those prettier formatting on large block of codes, so it can be reviewed easily.

@nazarhussain
Copy link
Contributor Author

If someone want to explore the wrapper I created around mocha for debugging can look here.
https://github.com/ChainSafe/lodestar/tree/nh/mocha-exit-feature/scripts/mocha

@wemeetagain
Copy link
Member

wemeetagain commented Oct 11, 2023

I don't think we need to find the root cause of the mocha issues in order to switch test runners.
While it would be nice to contribute upstream, squash mocha bugs, dissect the internals of different test runners, at the end of the day its not really our job. We're trying to build a beacon node and ecosystem of related ethereum code.

We've had inconsistent and buggy results with mocha with reproduceable errors. We've seen those inconsistencies go away when using a different test runner. Thats good enough for me.
Lets just resolve this and get back to our problem domain.

Edit: I'm mostly just frustrated that our tests are so unreliable that we've had to basically ignore them.
I think there needs to be some balance between spending weeks getting to a root cause of a mocha bug and just shipping something that's better.

@dapplion
Copy link
Contributor

@nazarhussain thank you so much for the detailed breakdown of your investigation on the issue!

I don't think we need to find the root cause of the mocha issues in order to switch test runners.
While it would be nice to contribute upstream, squash mocha bugs, dissect the internals of different test runners, at the end of the day its not really our job. We're trying to build a beacon node and ecosystem of related ethereum code.

yeah definitely not, I'm ok with moving on. Just wanted to ensure this is a very well motivated decision.

dapplion
dapplion previously approved these changes Oct 12, 2023
Comment on lines -177 to +162
expect(chain.seenSyncCommitteeMessages.get(slot, subnet, validatorIndex)).to.be.equal(
toHexString(syncCommittee.beaconBlockRoot),
"should add message root to seenSyncCommitteeMessages"
expect(chain.seenSyncCommitteeMessages.get(slot, subnet, validatorIndex)).toBe(
toHexString(syncCommittee.beaconBlockRoot)
Copy link
Member

Choose a reason for hiding this comment

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

Aren't we losing information here if the assertion fails?

"should add message root to seenSyncCommitteeMessages"

This message seems helpful to me instead of just seeing value x does not equal value y

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes we are loosing some information here, that will require to some effort to get the tests in right order to get that information.

Comment on lines 176 to 183
"validator with doppelganger protection should be running"
);
expect(validator0WithoutDoppelganger[0].isRunning).to.be.equal(
true,
"validator without doppelganger protection should be running before first epoch"
);
Copy link
Member

Choose a reason for hiding this comment

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

The amount of information we lose here in terms of reading the test code and possible errors when assertions fails is not ideal

Copy link
Contributor Author

@nazarhussain nazarhussain Oct 12, 2023

Choose a reason for hiding this comment

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

I agree and reason is that we didn't had the tests in ideal position earlier.

These are the best practices;

  1. Have simple and straight forward expectations.
  2. All the information related to test should be capture from test description, so if that fails you know what's wrong.
  3. If test failure needs to have further explanation, that implies that test description need to be more informative.
  4. If a test need mixed or confused expectations, it needs to be divided into multiple test cases.
  5. If an assertion is complex then should be extracted as custom assertion so it have consistent messaging across the tests.

These practices can't be enforce if assertion libraries are flexible like chai. So why Jest, Vitest and similar libraries don't provide feature for custom messages.

Let's take an example.

We need to compare a is greater than b and if we do with nodejs assertion module, we will have.

assert(a > b); 

Such assertion is confusing unless provided more details as;

assert(a > b, "a is not greater than b"); 

The problem with this approach is that one developer may write a different assertion message and other may write different.

But if you use frameworks like Jest, Vitest they provide special assertions e.g.

expect(a). toBeGreaterThan(b); 

With this assertion it's very clear and will have consistent error messages across every project. For vitest it have expect.extend function to use such custom assertions that can be reused across the project.


Now take our example code.

 expect(validator0WithDoppelganger[0].isRunning).to.be.equal(
      true,
      "validator with doppelganger protection should be running"
    );

Having such assertion messages clearly sign of bad practice. It's a a clear an test case, not an assertion message. It should have been like this;

it("validator with doppelganger protection should be running", () => {
    expect(validator0WithDoppelganger[0].isRunning).to.be.true;
})

If that test was failed, you clearly knows what's wrong and you don't need custom assertions messages to explain.

Copy link
Member

Choose a reason for hiding this comment

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

The problem with this approach is that one developer may write a different assertion message and other may write different.

I don't mind different message as long as those are correct and informative. In my opinion the assertion itself only tells you what is expected but not why. Could split out each assertion into its own test case but would have to see how practical that is.

Definitely have to update the tests-style-guide as it specifically mentions assertion messages.

Copy link
Member

Choose a reason for hiding this comment

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

Should at least add previous messages as comments, as it was done in other places

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Yes we need to update that, never saw that earlier.

Copy link
Member

@nflaig nflaig Oct 12, 2023

Choose a reason for hiding this comment

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

Now take our example code.

Just to clarify this example, does it mean that what is currently in the assertion message should be moved up to it message and what is in the it message should be moved up to describe, and then possibly have nested describe blocks?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Logically yes.

packages/beacon-node/test/globalSetup.ts Show resolved Hide resolved
@@ -9,8 +9,6 @@ import {getDevBeaconNode} from "../../../../../utils/node/beacon.js";
import {BeaconNode} from "../../../../../../src/node/nodejs.js";

describe("beacon state api", function () {
this.timeout("30s");
Copy link
Member

Choose a reason for hiding this comment

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

What's the default timeout vitest has? Don't we need to increase the timeout of this test case?

Copy link
Contributor Author

@nazarhussain nazarhussain Oct 13, 2023

Choose a reason for hiding this comment

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

Default timeout for vitest is 5s. We didn't saw any failure due to this at least 7-8 last attempts. So I would not try to increase that timeout now.

Comment on lines 65 to 66
// "expect updateHead to be called"
expect(chainStub.recomputeForkChoiceHead).toHaveBeenCalled();
Copy link
Member

@nflaig nflaig Oct 13, 2023

Choose a reason for hiding this comment

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

I am not sure why there was "expect updateHead to be called" as assertion message, maybe the default message of .to.be.called was not great. But I'd say adding this as a comment here is just noise, the line below literally says the same thing.

Note: There are a bunch of places where this is the case, I'd suggest this is cleaned up as otherwise it would advocate for this kind of style of commenting which is just not a good practice.

const endpoint = `${baseUrl}${remoteServiceRoutes.pending}`;
service = new MonitoringService("beacon", {endpoint, collectSystemStats: false}, {register, logger});
it("should abort pending requests if monitoring service is closed", () =>
new Promise<void>((done, error) => {
Copy link
Member

Choose a reason for hiding this comment

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

don't we have to await this promise here? I'd assume otherwise this test case just finishes right away without waiting

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It's returning the promise, so eventually gonna be awaited for.

Copy link
Member

@nflaig nflaig Oct 13, 2023

Choose a reason for hiding this comment

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

This pattern feels kinda wrong to me but I guess can keep it 🤷

const endpoint = `${baseUrl}${remoteServiceRoutes.pending}`;
service = new MonitoringService("beacon", {endpoint, collectSystemStats: false}, {register, logger});
it("should abort pending requests if monitoring service is closed", () =>
new Promise<void>((done, error) => {
Copy link
Member

@nflaig nflaig Oct 13, 2023

Choose a reason for hiding this comment

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

This pattern feels kinda wrong to me but I guess can keep it 🤷

@nflaig
Copy link
Member

nflaig commented Oct 13, 2023

To be considered, should the contribution.md be updated here Debugging tests?

What's the equivalent we would use now to run a single test suite? --bail --grep are really good tools mocha provides for that.

@nazarhussain
Copy link
Contributor Author

What's the equivalent we would use now to run a single test suite? --bail --grep are really good tools mocha provides for that.

vitest --bail <pattern>

You can also set the minimum number tests to be failed, in cases when we know few certain tests would fail.

vitest --bail 3 <pattern>

@nazarhussain nazarhussain merged commit c06f4e5 into unstable Oct 13, 2023
15 checks passed
@nazarhussain nazarhussain deleted the nh/vitest branch October 13, 2023 13:13
@nflaig
Copy link
Member

nflaig commented Oct 14, 2023


Failed test runs on unstable

https://github.com/ChainSafe/lodestar/actions/runs/6517197158/job/17701469723#step:6:4037

@lodestar/beacon-node: ⎯⎯⎯⎯⎯⎯⎯ Failed Tests 1 ⎯⎯⎯⎯⎯⎯⎯
@lodestar/beacon-node:  FAIL  test/e2e/api/impl/lightclient/endpoint.test.ts > lightclient api > getOptimisticUpdate()
@lodestar/beacon-node:  Test Files  1 failed | 15 passed | 7 skipped (23)
@lodestar/beacon-node: AssertionError: expected 3 to be 4 // Object.is equality

https://github.com/ChainSafe/lodestar/actions/runs/6517197158/job/17701499293#step:6:1483

@lodestar/beacon-node: Segmentation fault (core dumped)
@lodestar/beacon-node: @lodestar/beacon-node: error Command failed with exit code 139.

The second one is likely unrelated but haven't seen assertion error before

@wemeetagain
Copy link
Member

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

5 participants