Lighthouse: Don't count invalid deposits

[q9f]

Description

Apparently, lighthouse counts deposits regardless of their validity. Don't count them unless they are valid.

Version

master @ ddd63c0de146133ce7877bee218710a2b41defd8

Present Behaviour

❯ lighthouse bn --http \
--testnet-dir ~/.opt/goerli/witti/lighthouse \
--eth1-endpoint http://127.0.0.1:8545

May 19 14:53:27.507 WARN Ethereum 2.0 is pre-release. This software is experimental.
May 19 14:53:27.508 INFO Data directory initialised              datadir: /home/user/.lighthouse
May 19 14:53:27.536 INFO Waiting for eth2 genesis from eth1      deposit_contract: 0x6225f431644ecf8a30b672d42b77c28297542b13, contract_deploy_block: 2723358, eth1_endpoint: http://127.0.0.1:8545, service: beacon
May 19 17:13:32.804 INFO Imported deposit log(s)                 new: 32, total: 32, latest_block: 2723546, service: beacon
May 19 17:13:46.837 INFO Imported deposit log(s)                 new: 32, total: 32, latest_block: 2723546, service: beacon
May 19 17:58:00.246 INFO Imported deposit log(s)                 new: 1, total: 33, latest_block: 2723724, service: beacon
May 19 17:58:14.290 INFO Imported deposit log(s)                 new: 32, total: 64, latest_block: 2723725, service: beacon
May 19 17:58:28.320 INFO Imported deposit log(s)                 new: 31, total: 64, latest_block: 2723725, service: beacon
May 19 18:19:17.820 INFO Imported deposit log(s)                 new: 2, total: 66, latest_block: 2723809, service: beacon
May 19 18:19:31.875 INFO Imported deposit log(s)                 new: 3, total: 67, latest_block: 2723810, service: beacon
May 19 18:19:45.906 INFO Imported deposit log(s)                 new: 15, total: 81, latest_block: 2723811, service: beacon
May 19 18:19:59.937 INFO Imported deposit log(s)                 new: 15, total: 82, latest_block: 2723812, service: beacon
May 19 18:20:13.966 INFO Imported deposit log(s)                 new: 15, total: 96, latest_block: 2723813, service: beacon
May 19 18:20:13.966 INFO Minimum genesis deposit count met       block_number: 2723813, deposit_count: 96, service: beacon
May 19 18:20:28.007 INFO Imported deposit log(s)                 new: 14, total: 96, latest_block: 2723813, service: beacon
May 19 23:11:23.400 INFO Imported deposit log(s)                 new: 1, total: 97, latest_block: 2724977, service: beacon
May 19 23:11:37.471 INFO Imported deposit log(s)                 new: 1, total: 97, latest_block: 2724977, service: beacon
May 20 00:50:58.651 INFO Imported deposit log(s)                 new: 1, total: 98, latest_block: 2725375, service: beacon
May 20 00:51:12.699 INFO Imported deposit log(s)                 new: 1, total: 98, latest_block: 2725375, service: beacon
May 20 00:55:11.757 INFO Imported deposit log(s)                 new: 1, total: 99, latest_block: 2725392, service: beacon
May 20 00:55:25.802 INFO Imported deposit log(s)                 new: 1, total: 99, latest_block: 2725392, service: beacon

The line Minimum genesis deposit count met indicates that the client might believe those deposits are all valid. However, it turns out that at least 32 are invalid: https://gist.github.com/ajsutton/8e03db5aea6e094d16333a7a0a0e5e39

I don't think you accept invalid deposits, it's probably just the counting happening before the validation.

Expected Behaviour

Only count valid deposits.

Steps to resolve

Yes.

[paulhauner]

This is addressed in #1103. From a logging perspective we have three stages:

Waiting for more deposits

When we have less deposits than required validators, so it's impossible to trigger genesis.

May 25 16:02:29.783 INFO Waiting for more deposits           total_deposits: 8, min_genesis_active_validators: 60, service: beacon

Waiting for more validators

We have enough deposits, but not enough of the deposits result in active validators.

May 25 16:02:29.783 INFO Waiting for more validators         active_validators: 59, total_deposits: 62, min_genesis_active_validator_count: 60, service: beacon

Waiting for adequate eth1 timestamp

We have enough active validators but we haven't reached the minimum genesis time yet.

May 25 16:27:24.133 INFO Waiting for adequate eth1 timestamp     estimated_wait: 62-362 mins, service: beacon

Let me know if you see anything weird/lacking :)

[q9f]

Hey @paulhauner,

I'm on the faster-genesis branch, it appears to work, some nitpicks:

May 25 18:55:06.550 INFO Imported deposit log(s)                 new: 2, total: 6, latest_block: 2758489, service: beacon
May 25 18:55:06.550 INFO Importing eth1 blocks                   service: beacon
May 25 18:55:06.558 INFO Waiting for adequate eth1 timestamp     estimated_wait: 26505180-26506620 mins, service: beacon
May 25 18:55:13.590 INFO Waiting for adequate eth1 timestamp     estimated_wait: 26505180-26506620 mins, service: beacon
May 25 18:55:20.621 INFO Imported deposit log(s)                 new: 2, total: 6, latest_block: 2758489, service: beacon
May 25 18:55:20.758 INFO Genesis ceremony complete               genesis_time: 1590537600, genesis_validators: 6, service: beacon
May 25 18:55:20.766 INFO Block production enabled                method: json rpc via http, endpoint: http://127.0.0.1:9779
May 25 18:55:20.770 INFO Beacon chain initialized                head_slot: 0, head_block: 0x19aa…ba12, head_state: 0x773c…5b17, service: beacon

• Several statements are always getting printed twice.
• The _estimated wait_ seems off, the genesis time is correct though.

[paulhauner]

Thanks for the nits! I've removed the estimated wait time, it was proving tricky. I'm going to leave the duplicate logs for now, I'm trying to focus on core functionality and I'll come back for polish :)