Lighthouse: DB inconsistent after restart

[protolambda]

Description

After shutdown (I think gracefully) and restarting, it ended in this state.

Version

Docker (sigp/lighthouse) image sha256:fd7c8fb668656c91bb78faa6d8ff45c5794eaff6d286018530f213b0ff8d45b5

Present Behaviour

Aug 07 14:51:46.344 WARN Ethereum 2.0 is pre-release. This software is experimental.
Aug 07 14:51:46.344 INFO Configured for testnet                  name: medalla
Aug 07 14:51:46.344 INFO Data directory initialised              datadir: /data
Aug 07 14:51:46.387 INFO Starting beacon chain                   method: resume, service: beacon
Failed to start beacon node: DB error when reading finalized state: HotColdDBError(MissingEpochBoundaryState(0x065b8d96448421b81f0e06efada28b0606f6fbc31d716d5cbfe8110effefe7ef))

Missing logs of shutdown, automated restarts filled up the log space before I discovered this.

Expected Behaviour

At any point of shutdown, or even when crashing, being able to recover from the finalized state is useful.

Steps to resolve

Not sure. Check DB persistence and consistency.

[michaelsproul]

I'll check this out.

I'm guessing you didn't tweak the --slots-per-restore-point flag at all?

[protolambda]

Didn't change that flag

[michaelsproul]

I'm going to come back to this on Monday. I suspect it's something to do with the fact that the state root 0x065b8d96448421b81f0e06efada28b0606f6fbc31d716d5cbfe8110effefe7ef corresponds to slot 22016, which was a skipped slot on an epoch boundary. Will investigate

[michaelsproul]

Seen again on Discord with state root 0x0aa87bb8831ac00dd4c6dc0bb0855f1c4b56892a591932a15e201531d11ac010 from slot 20064.

Again, it's an epoch boundary state with a skipped slot (latest block was at 20063)

[michaelsproul]

I've been trying to reproduce this locally but haven't been able to.

First I tried resuming from a finalized block that itself did not lie on an epoch boundary, and that worked fine.

I also tried finalizing two epochs in a row with their first blocks missing, and that worked fine too. Interestingly, that is the case for both the examples we have (slots 20096 and 22048 are both skipped slots)

[adaszko]

Another instance at slot 98304:

[beacon_node/store/src/iter.rs:328] new_state_root = 0x20d14bd33bfd07df9bc08a98b6998098ac40c942aa3e146ab22687e2e323c88e
[beacon_node/store/src/iter.rs:328] new_state_slot = Slot(114688)
[beacon_node/store/src/iter.rs:328] new_state_root = 0x70876e08515f49904cbb2fb6e5af344d40f0c76d2a3976eb4accf0bf729b3cfe
[beacon_node/store/src/iter.rs:328] new_state_slot = Slot(106496)
[beacon_node/store/src/iter.rs:328] new_state_root = 0x3c9083c24dbafe5614369126c77549355de0563002a87dc20f69e5b53cbf3d19
[beacon_node/store/src/iter.rs:328] new_state_slot = Slot(98304)
Aug 20 13:29:07.343 ERRO Unable to obtain root iter              error: DBError(BeaconStateError(MissingBeaconState(BeaconStateHash(0x3c9083c24dbafe5614369126
c77549355de0563002a87dc20f69e5b53cbf3d19))))

It's also a skipped slot according to https://beaconcha.in/blocks?q=98304

[AgeManning]

I've seen two more errors of this from users during sync (the root hash of an epoch is known by us, but when attempting to process blocks on top of it, we get ParentUnknown). One was at a very low epoch (18).

I've restarted my node and have also seen:

ERRO Unable to obtain root iter              error: DBError(BeaconStateError(MissingBeaconState(BeaconStateHash(0x3c9083c24dbafe5614369126c77549355de0563002a87dc20f69e5b53cbf3d19))))

Which is consistent with @adaszko

[michaelsproul]

I've found the root cause – a bug in pruning that causes it to delete states at skipped slots from the finalized chain if they are shared by a pruned fork. I will finish and test the fix next week, and we'll ship a new release