Lots of correctlyVotedHead=false Epochs

[torfbolt]

If I understand correctly, the voting summary should normally show all epochs as correctly voted. However, I get lots (>50%) of epochs where only source & target are correct and the head vote is incorrect. This is also reflected in the attestation rewards, which are generally low or even negative for my validator (index 41644).

As far as I can tell there are no warnings or errors for the incorrect epochs, neither in the validator nor the beacon-client logs.

Is this a common issue? What could be the reason, network issues?

Setup is an ARM64 machine running prysm 0.3.8, but earlier versions & earlier testing on an AMD64 machine showed the same picture. Newtork-wise I am on LTE broadband, so NAT with no publicly accessible ports. Goerli is provided by a locally running geth instance.

[terencechain]

Likely network propagation issues. Will cont monitor this next testnet release

[nisdas]

I think it might be a cosmetic bug, I saw the same in a local testnet. I had all my validators hosted on 1 validator client and the below log is what I got

[2020-04-01 00:36:27]  INFO validator: Previous epoch voting summary correctlyVotedHead=false correctlyVotedSource=false correctlyVotedTarget=false epoch=3 inclusionDistance=18446744073709551615 inclusionSlot=18446744073709551615 newBalance=31.999828274 oldBalance=31.999914137 percentChange=-0.00027% pubKey=0xb88add150c36e8c3

It doesn't make sense that I have all that , when that validator holds all the running proposers/attesters in the network.
@terencechain any idea ?

[torfbolt]

From what I can see it's not cosmetic in the sense that my validator balance is actually decreasing. @nisdas Looks like that also happens in your local testnet? Is it frequent / reproducible for you as well?

[nisdas]

it did happen very often in my local testnet. Although some caveats for my testnet, the chain had not been finalized in a while and i was running less than the required number of validators to finalize. so that might be a reason for this ? @torfbolt did this happen in periods of no finality ?

[torfbolt]

I just checked the raw logs again without using my (in this case obviously misleading) monitor script and there are indeed lots of warnings of this kind, for many of the epochs:

time="2020-04-01 08:26:12" level=warning msg="Resolving fork due to new attestation: head at slot 592896 with weight 12635 is not eligible, finalizedEpoch 18526 != 18526, justifiedEpoch 18527 != 18528" prefix=blockchain

Is this expected for the public testnet? There should be enough validators for finalization there...

[nisdas]

I think that might be a different issue, if I am not wrong that log is harmless and mostly means that the forkchoice in the node is trying to resolve it to the appropriate head. @terencechain can probably confirm

[torfbolt]

Update: Switched to 0.3.9 today, still happening, currently with a consistent 100% of epochs correctlyVotedHead=false.

I also noticed this error appearing from time to time in the logs:
time="2020-04-01 17:43:37" level=error msg="Failed to handle p2p pubsub" error="could not process block: could not execute state transition: could not process slot: context deadline exceeded" prefix=sync topic="/eth2/beacon_block/ssz"

Could this have something to do with it?

[rauljordan]

Hi @torfbolt are you still encountering this issue? Could you retry with latest master and report your findings? Thank you

[torfbolt]

For the moment this issue seems to have disappeared on the topaz testnet. I get mostly full reward epochs there.