Expensive fork-choice queued attestation mutation

[dapplion]

Description

Debugging a Holesky node we noted that the split_off here was moving ~1 GB of data every time we process an attestation

lighthouse/consensus/fork_choice/src/fork_choice.rs

Line 258 in c52c598

let remaining = queued_attestations.split_off(

Questions:

1. Why did the queued attestations Vec grow so large?
2. Why is it being mutated every call?
3. Do we have to use a Vec for this?

Tackling 2 and 3, we could switch to a HashMap<Slot, Vec<QueuedAttestation>> as time strictly advances forward, so each slot Vec is strictly append-only.

WIP of this approach: https://github.com/sigp/lighthouse/compare/stable...dapplion:lighthouse:fork-choice-queued-attestations?expand=1

However we should answer 1 too as there may be some other lingering issue

[michaelsproul]

Nice detective work @jimmygchen !

[jimmygchen]

I've done some further investigation and noticed an invalid attestation (bad data.slot) in fork choice, causing this strange behaviour. However I think it's not possible for this to happen as the validation here prevents this invalid attestation to be queued at all.

I think it might be worth running a memtest on the machine.

[jimmygchen]

Further investigation shows that this cannot happen (see the link above) and @michaelsproul found that the bad attestation's slot actually has 1 bit flipped compared to its correct slot, so it could very well be a memory / disk issue.

I couldn't get anything from memtests on that machine. I think we could deploy v5.3.0 to more testnet nodes and see if it happens elsewhere (including slasher), if it doesn't we could probably conclude this bug to be likely a hardware issue, and move this issue out of v5.3.0.

[michaelsproul]

If this happens more often with nodes that have been running slashers, maybe it is some UB in the slasher code, potentially the C database code!

We could try running a slasher node under valgrind

[jimmygchen]

This undefined behaviour might have surfaced since the recent refactor in #4529, which revealed a bug in the LMDB bindings. See #6211 for a workaround fix.

Under normal circumstances the queued attestations vec should be quite small as there are validations to prevent attestations for future slots to be queued. It would be useful to add a metric for this though.

[dapplion]

@jimmygchen this PR adds a metric for the queued attestations vec:

• Add metrics inside fork-choice crate #6205

Closing this issue as won't fix

[michaelsproul]

For reference, the metric to check for this issue is beacon_fork_choice_process_attestation_seconds_*. Processing attestations in fork choice should be very quick (<5ms per attestation), but if this issue is occurring then that metric will blow way up (we've seen it >100ms per attestation).

cc @chong-he