Improve validator status logging

[philknows]

Is your feature request related to a problem? Please describe.

There has been multiple occasions where feedback was given to clarify the meaning of the Discovered new validators = x as to what this statement actually means for the user.

Please correct if not true: Currently, this line is logged when a user starts the validator client. When the user's validator pubkey is active (deposit is recognized from logs) on the beacon chain, that increments this count by 1.

However there is a period of time, generally when deposits have been made recently on the execution chain (e.g. a new staker and now setting up beacon infrastructure), it can be misleading to see their logs state:

info: 3 local keystores
info: 0x000000...
info: 0x000001...
info: 0x000002...
info: Discovered new validator count = 0

Although we've clearly stated that the validator client recognizes 3 local keystores successfully decrypted and ready to process duties once activated, Discovered new validator count = 0 in its current phrasing is counter-intuitive as these are technically new validators that haven't been discovered yet by the beacon chain. This is a sensitive time period for stakers and better UX is justified to reduce confusion. This confusion is common as users generally make deposits to their validators slightly before, during or after setting up their beacon infrastructure.

In addition, if a user adds an additional key to their client, the way it's phrased confuses a user about whether it reflects "new validators" added since the previous run.

This is not an issue after pubkeys have been recognized and activated on the beacon chain since the proper number of validator keys will be reflected in the log.

Describe the solution you'd like

Would like to see if there is better phrasing to reflect the reality of what we're logging to the user. An example:
Validators currently activated on the beacon chain = x

Do we need to add a small disclaimer for users about needing to wait for some time so it can be activated?
(New deposits may take some time for activation)

Additional context

[dapplion]

Please correct if not true: Currently, this line is logged when a user starts the validator client. When the user's validator pubkey is active (deposit is recognized from logs) on the beacon chain, that increments this count by 1

Not really. The validator knows about the public key of a validator and asks the beacon node to resolve that public key to and index. When the vc prints "discovered" means that it can resolve pubkey to index. In that call the beacon respond also with the status of the validator (pending, active, exited) so the vc could also print that.

@philknows Could you check what Prysm or Lighthouse log in that case? Maybe being closer to clients people are familiar with is a good starting point.

[philknows]

For Lighthouse, it looks like it does a validator discovery, logs the voting pubkeys, then logs the initialized validators. When tested, the following logs show up for 2 validators already activated by the beacon chain. It also then logs the validator config with fee_recipient, validator index, pubkey for each of the validators:

Nov 23 08:24:23.190 INFO Logging to file                         path: "/root/.lighthouse/goerli/validators/logs/validator.log"
Nov 23 08:24:23.190 INFO Lighthouse started                      version: Lighthouse/v3.2.1-6d5a2b5
Nov 23 08:24:23.190 INFO Configured for network                  name: goerli
Nov 23 08:24:23.190 INFO Starting validator client               validator_dir: "/root/.lighthouse/goerli/validators", beacon_nodes: ["http://localhost:5052/"]
Nov 23 08:24:23.190 INFO HTTP metrics server is disabled
Nov 23 08:24:23.200 INFO Completed validator discovery           new_validators: 0
Nov 23 08:24:23.744 INFO Enabled validator                       voting_pubkey: 0x0001, signing_method: local_keystore
Nov 23 08:24:23.744 INFO Enabled validator                       voting_pubkey: 0x0002, signing_method: local_keystore
Nov 23 08:24:23.745 INFO Initialized validators                  enabled: 2, disabled: 0
Nov 23 08:24:23.757 INFO Connected to beacon node                endpoint: http://localhost:5052/, version: Lighthouse/v3.2.1-6d5a2b5/x86_64-linux
Nov 23 08:24:23.758 INFO Initialized beacon node connections     available: 1, total: 1
Nov 23 08:24:23.758 INFO Loaded validator keypair store          voting_validators: 2
Nov 23 08:24:23.764 INFO Validator exists in beacon chain        fee_recipient: 0x0000…abcd, validator_index: 123456, pubkey: 0x00001, service: duties
Nov 23 08:24:23.764 INFO Validator exists in beacon chain        fee_recipient: 0x0000…abcd, validator_index: 123457, pubkey: 0x00001, service: duties

[philknows]

For Prysm, it's interesting as they don't do any counts as part of their logging. It just logs out the keys you have locally. If there's any keys that are not activated, it will just log Waiting for deposit to be observed by beacon node and if it's activated, will just log validator: Validator activated index=123456 publicKey=0x00000000001 for each one that's activated.

[2022-11-23 09:40:13]  INFO node: Opened validator wallet keymanager-kind=direct wallet=/wallet/direct
[2022-11-23 09:40:13]  WARN node: Slashing protection file /validatorDB/validator.db is missing.
If you changed your --wallet-dir or --datadir, please copy your previous "validator.db" file into your current --datadir.
Disregard this warning if this is the first time you are running this set of keys.
[2022-11-23 09:40:13]  INFO node: Checking DB databasePath=/validatorDB
Adding optimizations for validator slashing protection 100% [=========]  [0s:0s]
[2022-11-23 09:40:13]  WARN validator: You are using an insecure gRPC connection. If you are running your beacon node and validator on the same machines, you can ignore this message. If you want to know how to enable secure connections, see: https://docs.prylabs.network/docs/prysm-usage/secure-grpc
[2022-11-23 09:40:13]  INFO node: Starting validator node version=Prysm/v3.1.2-rc.2/648ab9f2c249f1d06d0aad4328e8df429ceaf66c. Built at: 2022-10-27 14:53:24+00:00
[2022-11-23 09:40:13]  INFO validator: Syncing with beacon node to align on chain genesis info
[2022-11-23 09:40:13]  INFO validator: Beacon chain started genesisTime=2021-03-23 14:00:00 +0000 UTC
[2022-11-23 09:40:14]  INFO validator: Validating for public key publicKey=0x00000000001
[2022-11-23 09:40:14]  INFO validator: Validating for public key publicKey=0x00000000002
[2022-11-23 09:40:14]  INFO validator: Waiting for deposit to be observed by beacon node pubKey=0x0000000003 status=UNKNOWN_STATUS
[2022-11-23 09:40:14]  INFO validator: Validator activated index=123456 publicKey=0x00000000001
[2022-11-23 09:40:14]  INFO validator: Validator activated index=123457 publicKey=0x00000000002

[g11tech]

i think every epoch we should log the pubkey count with the validator grouped by status as lighthouse is doing