Error processing attestation on a restart

[twoeths]

Describe the bug

On a restart, we can get an error like, see https://discord.com/channels/593655374469660673/593655641445367808/1123615328761552958

Jun-28 09:39:18.639[chain]            �[33mwarn�[39m: Error processing attestations from block slot=6761276, erroredAttestations=5 code=FORKCHOICE_ERROR_INVALID_ATTESTATION, err=code=UNKNOWN_HEAD_BLOCK, beaconBlockRoot=0x961ee2ae2a7b0cb8f2623edcb1c7a408c8258ddfcd3a2a5c71cb6640ed2e5ed0
Error: FORKCHOICE_ERROR_INVALID_ATTESTATION
    at ForkChoice.validateAttestationData (file:///home/seamonkey/Downloads/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:1048:13)
    at ForkChoice.validateOnAttestation (file:///home/seamonkey/Downloads/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:976:12)
    at ForkChoice.onAttestation (file:///home/seamonkey/Downloads/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:517:10)
    at BeaconChain.importBlock (file:///home/seamonkey/Downloads/lodestar/packages/beacon-node/src/chain/blocks/importBlock.ts:129:27)
    at BeaconChain.processBlocks (file:///home/seamonkey/Downloads/lodestar/packages/beacon-node/src/chain/blocks/index.ts:111:7)
    at JobItemQueue.runJob (file:///home/seamonkey/Downloads/lodestar/packages/beacon-node/src/util/queue/itemQueue.ts:101:22)

beacon-2023-06-28-trunc.log

@nflaig also got this error consistently

Jun-30 10:15:54.899[chain]            warn: Error processing attestations from block slot=5967650, erroredAttestations=17 code=FORKCHOICE_ERROR_INVALID_ATTESTATION, err=code=UNKNOWN_TARGET_ROOT, root=0xc4d460df1cc7c4da058433f035f9a4b40cb9bc4ef2b4011e93425dc20b5259b5
Error: FORKCHOICE_ERROR_INVALID_ATTESTATION
    at ForkChoice.validateAttestationData (file:///home/devops/goerli/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:1028:13)
    at ForkChoice.validateOnAttestation (file:///home/devops/goerli/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:975:12)
    at ForkChoice.onAttestation (file:///home/devops/goerli/lodestar/packages/fork-choice/src/forkChoice/forkChoice.ts:516:10)
    at BeaconChain.importBlock (file:///home/devops/goerli/lodestar/packages/beacon-node/src/chain/blocks/importBlock.ts:133:27)
    at BeaconChain.processBlocks (file:///home/devops/goerli/lodestar/packages/beacon-node/src/chain/blocks/index.ts:111:7)
    at JobItemQueue.runJob (file:///home/devops/goerli/lodestar/packages/beacon-node/src/util/queue/itemQueue.ts:101:22)

Expected behavior

• Investigate the error
• If there's no other way and it does not affect the sync, consider using verbose/debug log level

Steps to reproduce

No response

Additional context

No response

Operating system

Linux

Lodestar version or commit hash

v1.9.0

[twoeths]

the block 0x961ee2ae2a7b0cb8f2623edcb1c7a408c8258ddfcd3a2a5c71cb6640ed2e5ed0 really does not part of canonical chain, that's why we got the error https://beaconcha.in/slot/0x961ee2ae2a7b0cb8f2623edcb1c7a408c8258ddfcd3a2a5c71cb6640ed2e5ed0

[twoeths]

The other error in the log file is

Jun-28 09:39:11.349[chain]         �[36mverbose�[39m: Clock slot slot=6761294
Jun-28 09:39:11.350[api]             �[31merror�[39m: Error on submitPoolAttestations [0] slot=6761293, index=2 code=ATTESTATION_ERROR_UNKNOWN_OR_PREFINALIZED_BEACON_BLOCK_ROOT, root=0x8668b5a0199c5b52276f4529d309c5b080b30ee59d7ef68d592ea5c8e1f288f6
Error: ATTESTATION_ERROR_UNKNOWN_OR_PREFINALIZED_BEACON_BLOCK_ROOT

the request is likely from a fallbackUrl setup, node is syncing so UnknownBlock service is not enabled, so error was returned when next clock slot comes. I'd suggest having a better log to inform user in this case

[twoeths]

@nflaig's error is the same, target root was really not part of canonical chain https://goerli.beaconcha.in/slot/c4d460df1cc7c4da058433f035f9a4b40cb9bc4ef2b4011e93425dc20b5259b5

when node is synced, we'll search for this block and there maybe no error but after a restart, this error will happen since req/resp only returns canonical chain. I think let it as is and reducing log level is enough, if possible we'll add "node is syncing" to the log to investigate this issue easier in the future

[philknows]

According to logging policy, these errors should probably be debug logs