Not able to prune checkpoint state during nft of holesky

[twoeths]

Describe the bug

Feb-25 02:22:59.925[chain]           ^[[34mdebug^[[39m: Error processing block state blockRootHex=0x2db899881ed8546476d0b92c6aa9110bea9a4cd0dbeb5519eb0ea69575f1f359, slot=3711006 - Can only get block root in the past currentSlot=3711006 slot=3711008
Error: Can only get block root in the past currentSlot=3711006 slot=3711008
    at getBlockRootAtSlot (file:///usr/app/packages/state-transition/src/util/blockRoot.ts:21:11)
    at PersistentCheckpointStateCache.processPastEpoch (file:///usr/app/packages/beacon-node/src/chain/stateCache/persistentCheckpointsCache.ts:627:66)
    at PersistentCheckpointStateCache.processState (file:///usr/app/packages/beacon-node/src/chain/stateCache/persistentCheckpointsCache.ts:478:34)
Feb-25 02:22:59.934[sync]          ^[[36mverbose^[[39m: Batch download error id=Head, startEpoch=115972, status=Downloading, peer=16...YDwG3Y, code=REQUEST_ERROR_DIAL_ERROR, error=unexpected end of input
Error: unexpected end of input
    at Object.read (file:///usr/app/node_modules/it-byte-stream/dist/src/index.js:86:31)
    at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
    at async Object.read (file:///usr/app/node_modules/it-length-prefixed-stream/dist/src/index.js:51:37)
    at async read (file:///usr/app/node_modules/@libp2p/multistream-select/dist/src/multistream.js:22:17)
    at async Module.readString (file:///usr/app/node_modules/@libp2p/multistream-select/dist/src/multistream.js:33:17)
    at async Module.select (file:///usr/app/node_modules/@libp2p/multistream-select/dist/src/select.js:72:20)
    at async ConnectionImpl.newStream [as _newStream] (file:///usr/app/node_modules/libp2p/dist/src/upgrader.js:330:50)
    at async ConnectionImpl.newStream (file:///usr/app/node_modules/libp2p/dist/src/connection/index.js:94:24)
    at async file:///usr/app/packages/reqresp/lib/request/index.js:57:26
    at async withTimeout (file:///usr/app/packages/utils/lib/timeout.js:12:16)
Error: REQUEST_ERROR_DIAL_ERROR
    at file:///usr/app/packages/reqresp/lib/request/index.js:65:19
    at process.processTicksAndRejections (node:internal/process/task_queues:105:5)
    at async sendRequest (file:///usr/app/packages/reqresp/lib/request/index.js:55:24)
    at async ReqRespBeaconNode.sendRequest (file:///usr/app/packages/reqresp/lib/ReqResp.js:110:13)
    at async AsyncIterableBridgeHandler.onRequest (file:///usr/app/packages/beacon-node/lib/util/asyncIterableToEvents.js:99:30)

while block state cache is consistently at 64, checkpoint state cache spiked due to the error

Expected behavior

no error, checkpoint state cache's epoch should be consistently <=4

Steps to reproduce

No response

Additional context

No response

Operating system

Linux

Lodestar version or commit hash

v1.27.1

[twoeths]

we tried to process checkpoint state for a very old block state, and tried to persist checkpoint states of recent epochs which does not exist

that error is not the root cause of the issue, just need to handle this case to have nicer log. Still need to investigate why states are added to checkpoint cache in this period (Feb 25 2:33:00 to 2:34:00)

[twoeths]

holesky is at a crazy forky condition, there were a lot of epoch transition at the time with "processBlocksInEpoch" reason

that all comes from a single block built on block slot 3711917

grep -e "Feb-25 02:33" -rn beacon-2025-02-25.log | grep "Block processed"
78823:Feb-25 02:33:03.549[chain]         verbose: Block processed slot=3711913, root=0xcd2f0403e62139d1e77440d66df9abacc2c706e45527e95cc51569c9d328de9a, delaySec=5427.5490000247955
78832:Feb-25 02:33:04.323[chain]         verbose: Block processed slot=3711917, root=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8, delaySec=5380.322999954224

grep -e "Feb-25 02:33" -rn beacon-2025-02-25.log | grep "Added checkpoint state to memory"
78773:Feb-25 02:33:01.725[chain]         verbose: Added checkpoint state to memory epoch=115997, rootHex=0xe372ed53b4badda9eb1f8db5549649a77886c88e91aa92f5ff3b0c934562bc1c
78850:Feb-25 02:33:06.981[chain]         verbose: Added checkpoint state to memory epoch=115998, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
78870:Feb-25 02:33:11.551[chain]         verbose: Added checkpoint state to memory epoch=115999, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
78896:Feb-25 02:33:14.694[chain]         verbose: Added checkpoint state to memory epoch=116000, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
78921:Feb-25 02:33:17.582[chain]         verbose: Added checkpoint state to memory epoch=116001, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
78940:Feb-25 02:33:22.377[chain]         verbose: Added checkpoint state to memory epoch=116002, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
78968:Feb-25 02:33:25.458[chain]         verbose: Added checkpoint state to memory epoch=116003, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
79026:Feb-25 02:33:30.709[chain]         verbose: Added checkpoint state to memory epoch=116004, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
79056:Feb-25 02:33:33.750[chain]         verbose: Added checkpoint state to memory epoch=116005, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
79070:Feb-25 02:33:39.485[chain]         verbose: Added checkpoint state to memory epoch=116006, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
79124:Feb-25 02:33:44.442[chain]         verbose: Added checkpoint state to memory epoch=116007, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8
79147:Feb-25 02:33:49.585[chain]         verbose: Added checkpoint state to memory epoch=116008, rootHex=0x69a749989af18cf9f77f433b4af321ee3d0f2ffaecde9c84c86cddd7fc13f2b8

not able to figure out which one since node crashed right after that

grep -e "Feb-25 02:3" -rn beacon-2025-02-25.log | grep "network="
79328:Feb-25 02:34:09.391[]                 info: Lodestar network=holesky, version=v1.27.1/ff574a5, commit=ff574a59114e6e8524de8478b6474e2b554fec3d

[twoeths]

got a bunch of this same error when syncing holesky closer to head

grep -e "Error processing block state" -rn beacon-2025-02-27.log |wc -l
830

one of them is like

debug: Error processing block state blockRootHex=0xf000d2c551fe5d228977013b5b747515ebe50e228c67a8c994c9e6380e8c47c9, slot=3721496 - Cannot get block root more than 8192 in the past

this prevents the CheckpointStateCache to prune states