/script/tests/doppelganger_protection.sh succeeded when it should have failed #2656
Description
Description
I renamed NODE_COUNT to BN_COUNT in /scripts/local_testnet/vars.env, but didn't do it in /scripts/tests/vars.env. The consequence was the test doppelganger_protection.sh success succeeded, but it should have failed. Luckily doppelganger_protection.sh failure did fail. Although, I believe, it should have failed for a different reason.
Version
Testing PR #2614 off unstable at this commit
Present Behaviour
What you can see below is that validator clients did not start and the Genesis state wasn't created as we don't Building genesis state... (this might take a while): nor do we see Created genesis state in /home/runner/.lighthouse/local-testnet/testnet. Instead we see BN_COUNT: unbound variable, the bug and the copy failed. But the script continued with Starting bootnode:
Submitting deposit for validator 79...
Specification generated at /home/runner/.lighthouse/local-testnet/testnet.
../local_testnet/setup.sh: line 45: BN_COUNT: unbound variable
Generating 80 validators concurrently... (this may take a while)
cp: cannot stat '/home/runner/.lighthouse/local-testnet/node_1': No such file or directory
Starting bootnode
And the test went on to "succeeded", but it should have failed because as validators never started and hence there were no attestations:
10m 2s
Run cd scripts/tests
cd scripts/tests
./doppelganger_protection.sh success
shell: /usr/bin/bash -e {0}
env:
RUSTFLAGS: -D warnings
PINNED_NIGHTLY: nightly-2021-06-09
Starting ganache
Setting up local testnet
Deposit contract address: "0x8c594691c0e592ffa21f153a16ae41db5befcaaa"
Submitting deposit for validator 0...
Submitting deposit for validator 1...
Submitting deposit for validator 2...
Submitting deposit for validator 3...
Submitting deposit for validator 4...
...
Submitting deposit for validator 75...
Submitting deposit for validator 76...
Submitting deposit for validator 77...
Submitting deposit for validator 78...
Submitting deposit for validator 79...
Specification generated at /home/runner/.lighthouse/local-testnet/testnet.
../local_testnet/setup.sh: line 45: BN_COUNT: unbound variable
Generating 80 validators concurrently... (this may take a while)
cp: cannot stat '/home/runner/.lighthouse/local-testnet/node_1': No such file or directory
Starting bootnode
Starting local beacon nodes
Starting local validator clients
Waiting an epoch before starting the next validator client
Starting the last validator client
Waiting three epochs...
Sep 30 03:20:10.186 INFO Lighthouse started version: Lighthouse/v1.5.2-028f7fa
Sep 30 03:20:10.186 INFO Configured for network name: custom (/home/runner/.lighthouse/local-testnet/testnet)
Sep 30 03:20:10.187 INFO Starting validator client validator_dir: "/home/runner/.lighthouse/local-testnet/node_4/validators", beacon_nodes: ["http://localhost:8100/"]
Sep 30 03:20:10.187 INFO HTTP metrics server is disabled
Sep 30 03:20:10.188 INFO Completed validator discovery new_validators: 0
Sep 30 03:20:11.433 INFO Modified key_cache saved successfully
Sep 30 03:20:11.433 INFO Initialized validators enabled: 0, disabled: 0
Sep 30 03:20:11.433 WARN No enabled validators hint: create validators via the API, or the `lighthouse account` CLI command
Sep 30 03:20:11.451 WARN Offline beacon node endpoint: http://localhost:8100/, error: Reqwest(reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(8100), path: "/eth/v1/node/version", query: None, fragment: None }, source: hyper::Error(Connect, ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })) })
Sep 30 03:20:11.451 WARN Unable to connect to a beacon node available: 0, total: 1, retry in: 2 seconds
Sep 30 03:20:13.453 WARN Offline beacon node endpoint: http://localhost:8100/, error: Reqwest(reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(8100), path: "/eth/v1/node/version", query: None, fragment: None }, source: hyper::Error(Connect, ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })) })
...
Sep 30 03:28:09.953 WARN Offline beacon node endpoint: http://localhost:8100/, error: Reqwest(reqwest::Error { kind: Request, url: Url { scheme: "http", cannot_be_a_base: false, username: "", password: None, host: Some(Domain("localhost")), port: Some(8100), path: "/eth/v1/node/version", query: None, fragment: None }, source: hyper::Error(Connect, ConnectError("tcp connect error", Os { code: 111, kind: ConnectionRefused, message: "Connection refused" })) })
Sep 30 03:28:09.953 WARN Unable to connect to a beacon node available: 0, total: 1, retry in: 2 seconds
Shutting down
./doppelganger_protection.sh: line 132: kill: (39846) - No such process
./doppelganger_protection.sh: line 132: kill: (39847) - No such process
./doppelganger_protection.sh: line 132: kill: (39848) - No such process
Sep 30 03:28:10.185 INFO Shutting down.. reason: Success("Received SIGTERM")
Done
Expected Behaviour
In a properly successful test we see the deposit being submitted and then Validator 1 .. 80 are created and then the Buliding and Creation of the Gensis state and then continuing with Starting bootnode and finishing with a list of attestations:
Run cd scripts/tests
cd scripts/tests
./doppelganger_protection.sh success
shell: /usr/bin/bash -e {0}
env:
RUSTFLAGS: -D warnings
PINNED_NIGHTLY: nightly-2021-06-09
Starting ganache
Setting up local testnet
Deposit contract address: "0x8c594691c0e592ffa21f153a16ae41db5befcaaa"
Submitting deposit for validator 0...
Submitting deposit for validator 1...
Submitting deposit for validator 2...
Submitting deposit for validator 3...
Submitting deposit for validator 4...
...
Submitting deposit for validator 77...
Submitting deposit for validator 78...
Submitting deposit for validator 79...
Specification generated at /home/runner/.lighthouse/local-testnet/testnet.
Generating 80 validators concurrently... (this may take a while)
Validator 1
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Validator 2
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Validator 3
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
...
Validator 78
Validator 79
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Validator 80
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Validators generated with keystore passwords at /home/runner/.lighthouse/local-testnet.
Building genesis state... (this might take a while)
Created genesis state in /home/runner/.lighthouse/local-testnet/testnet
Starting bootnode
Starting local beacon nodes
Starting local validator clients
Waiting an epoch before starting the next validator client
Starting the last validator client
Waiting three epochs...
Sep 30 03:39:32.771 INFO Lighthouse started version: Lighthouse/v1.5.2-30f9bb3
Sep 30 03:39:32.771 INFO Configured for network name: custom (/home/runner/.lighthouse/local-testnet/testnet)
Sep 30 03:39:32.772 INFO Starting validator client validator_dir: "/home/runner/.lighthouse/local-testnet/node_4/validators", beacon_nodes: ["http://localhost:8100/"]
Sep 30 03:39:32.772 INFO HTTP metrics server is disabled
Sep 30 03:39:32.785 INFO Completed validator discovery new_validators: 20
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Sep 30 03:39:32.796 INFO Enabled validator voting_pubkey: 0xabef42538a17a55804b634aac9d211b92b5768c4cc1263342ca287323bb3d5c768080451d1b5d652e9f8646fbb35f57c, signing_method: local_keystore
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Sep 30 03:39:32.797 INFO Enabled validator voting_pubkey: 0xa98c264dfc3bc3ed635df5dbfd54909e77600cd68480ec201d9f5c416580591daaa9735b04743e10e7fc6370a8189775, signing_method: local_keystore
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
WARN: Scrypt parameters are too weak (n: 2, p: 1, r: 8), we recommend (n: 262144, p: 1, r: 8)
Sep 30 03:39:32.798 INFO Enabled validator voting_pubkey: 0x91ae4686b0d20470409f020eaca826c3efc6c1926ed25d05e6f0f7916391ec89c2341917277c437ac8fffffe94b68111, signing_method: local_keystore
...
Sep 30 03:47:32.011 INFO Successfully published attestations type: unaggregated, slot: 195, committee_index: 0, head_block: 0x0101442ef637cf7fa3dba37fde20a0ec95ad0b7e1ab899ee582c1e071f7b3ae6, count: 1, service: attestation
Sep 30 03:47:32.501 INFO Connected to beacon node(s) synced: 1, available: 1, total: 1, service: notifier
Sep 30 03:47:32.501 INFO All validators active slot: 195, epoch: 6, total_validators: 20, active_validators: 20, proposers: 9, service: notifier
Sep 30 03:47:33.011 INFO Successfully published attestations type: aggregated, slot: 195, committee_index: 0, head_block: 0x0101442ef637cf7fa3dba37fde20a0ec95ad0b7e1ab899ee582c1e071f7b3ae6, signatures: 3, aggregator: 60, service: attestation
Sep 30 03:47:34.039 INFO Successfully published block slot: 196, graffiti: None, attestations: 1, deposits: 0, service: block
0x80a2be2c7dbce8ddc2eba03522697587c375a5a9e92d4b31ed9e3c34bee047095d93e3c70b1662b3faa301f5b19978e5 attested in epoch 4.
0x86a73886aa0114bbdbba346cb7c07376c81b549a4802c24d98ebbc54a6a1b5d2ac874ef657cfb27c3644fcb85f97a2b5 attested in epoch 4.
0x8a0d241955104bedacb3b829162f2b457915c2beb9018ede8ef8ea80f401b471c42354358da9e62b51c38d54263a78a9 attested in epoch 4.
0x8bb7aa61aa8bbd2b7825d28c340da89b625381232dcf2742276b4e3a2e4a0f42ef68794fdf005d94014636732fba2f40 attested in epoch 4.
0x8bb9e1693eab1496d7583bf22fb1f2a475934c63b4d94118940617aa187bc277f738223e0ec1ce8a5566035d9bcc5470 attested in epoch 4.
0x902ff56a7a4c5b6cc57708ea7b0b72cb54e4b821c95373f503648185f15208f6ca6281677fa0ecc14f911d7b7ca04f4e attested in epoch 4.
0x91ae4686b0d20470409f020eaca826c3efc6c1926ed25d05e6f0f7916391ec89c2341917277c437ac8fffffe94b68111 attested in epoch 4.
0x93bb1c86717fa7303f65cb8c45c9fcc8fecb88428b7cd1dd59967a132109c25ab5c97888e46c5d471ff911c573f45a34 attested in epoch 4.
0x974b2aed17665e51c1c091998ca9649875330947de3d2733a5bd2eda69b0c593cdac2e416993a87f9a17aec1ccdc2368 attested in epoch 4.
0x98f011f9a4dff94eb0352ff6e21b7df45e2a112bd5d789b5729111b89b368e7ed554e4d1c16b72f4d105090173cafed2 attested in epoch 4.
Sep 30 03:47:35.010 INFO Successfully published attestations type: unaggregated, slot: 196, committee_index: 0, head_block: 0x6b6905c4379ef1c0755770d8880f3191faedc1eb016436e92a9a157ae0797af6, count: 1, service: attestation
0x98f620aadc4e58392b5b583fed96c452b54c39ba3a9fe8c277f625fae7e1317d034f732995fd88c1461463edd0f2b86d attested in epoch 4.
0xa3177a98f653cea646f525f0f13348efb27e0d3d0cd824704c91d8d959096d259c9e577298f444acc629920c9619be50 attested in epoch 4.
0xa7f5d408af436d71ec7acfe9a4592679649d326c00ac92c6f3332423be30c3601d232f265078f1f2a5d6d6cde08de7d7 attested in epoch 4.
0xa8a18565733e70663c77bc0c80e08f50de908cc048152f1e7dae85d8cc218afbdd337d7d33a44e25400be2f06907c64a attested in epoch 4.
0xa8be337b3d0e6be415dcb037b246831f9966aacef62b69d6b609e4ff8208bc536c6473bc9fe9e3bec9a8665c8caa05c5 attested in epoch 4.
0xa8e3c2d3ac4e0e3c83380577ff7b7b5b2a98571e0d04ddebc0a6c472ce3bc5cc6a6733be728a0ee17da74b7691d2679d attested in epoch 4.
0xa98c264dfc3bc3ed635df5dbfd54909e77600cd68480ec201d9f5c416580591daaa9735b04743e10e7fc6370a8189775 attested in epoch 4.
0xaa241b2afbb33f92a5d281aec9c8bac8997c1dddc051455fc0f334de48320f160b5029b552495aed21ed9ce252aab499 attested in epoch 4.
0xabef42538a17a55804b634aac9d211b92b5768c4cc1263342ca287323bb3d5c768080451d1b5d652e9f8646fbb35f57c attested in epoch 4.
0xafe6eface52fb6de91055a81abf9aa6e42ce2ef36fd8ae0d09aec6e5d8bd40a065dfccda6104af94df3f7a5854559ef4 attested in epoch 4.
Sep 30 03:47:35.385 INFO Shutting down.. reason: Success("Received SIGTERM")
Shutting down
Done
Steps to resolve
My bug, not renaming NODE_COUNT to BN_COUNT in /scripts/tests/vars.env, is fixed. But I believe there should be some kind of test at the end of the doppelganger_protection.sh success path that actually verifies that the expected number of attestations were actually completed.
Metadata
Metadata
Assignees
Labels
No labels