lighthouse stop sync when it about to catch up with the latest slot

[rekyyang]

Description

lighthouse stop sync when it about to catch up with the latest slot
I tried to reboot many times, and the issue occurs everytime
And log printing also stopped

Version

5.1.3

Here are logs

Aug 20 20:10:47.240 WARN Background file logging is disabled error: File exists (os error 17)
Failed to initialize libp2p rolling file appender
Aug 20 20:10:47.241 INFO Lighthouse started version: Lighthouse/v5.1.3-3058b96
Aug 20 20:10:47.241 INFO Configured for network name: mainnet
Aug 20 20:10:47.241 INFO Data directory initialised datadir: /server/beacon-chain-data
Aug 20 20:10:47.245 INFO Deposit contract address: 0x00000000219ab540356cbb839cbe05303d7705fa, deploy_block: 11184524
Aug 20 20:10:50.175 INFO Hot-Cold DB initialized split_state: 0x200cc73574f181eab8fc645fd444c1d9bc7909e74e28ebd26abf04745e964504, split_slot: 9779808, service: freezer_db
Aug 20 20:10:50.175 INFO Blob DB initialized oldest_blob_slot: Some(Slot(9648896)), path: "/server/beacon-chain-data/beacon/blobs_db", service: freezer_db
Aug 20 20:10:50.223 INFO Refusing to checkpoint sync msg: database already exists, use --purge-db to force checkpoint sync, service: beacon
Aug 20 20:10:50.223 INFO Starting beacon chain method: resume, service: beacon
Aug 20 20:12:42.938 INFO Block production enabled method: json rpc via http, endpoint: Auth { endpoint: "http://localhost:8551/", jwt_path: "/server/jwt/jwt.hex", jwt_id: None, jwt_version: None }
Aug 20 20:12:45.515 INFO Beacon chain initialized head_slot: 9779937, head_block: 0xf008…cb6c, head_state: 0x2b5d…b47a, service: beacon
Aug 20 20:12:45.515 ERRO State reconstruction failed error: MissingHistoricBlocks { oldest_block_slot: Slot(708736) }, service: beacon
Aug 20 20:12:45.515 INFO Timer service started service: node_timer
Aug 20 20:12:45.516 INFO UPnP Attempting to initialise routes
Aug 20 20:12:45.518 INFO ENR Initialised quic6: None, quic4: Some(9001), udp6: None, tcp6: None, tcp4: Some(9000), udp4: None, ip4: None, id: 0xcfd0..c4e5, seq: 356, enr: enr:-Le4QBVKCaiUi6p6juwXrdtbwkgXzI4aqqegOoxDx420xqrhfDMV-ykWMfIJ4LxIhyPs8bNMbm1Z47KPGTPpvwH1_k2CAWSHYXR0bmV0c4gAAAAAAAAAAIRldGgykGqVoakEAAAA__________-CaWSCdjSEcXVpY4IjKYlzZWNwMjU2azGhAuWrQ-MB9IxFKwJaG2uKsV4FbXxOFhCluLO8kbpCyfOQiHN5bmNuZXRzAIN0Y3CCIyg, service: libp2p
Aug 20 20:12:45.519 INFO Libp2p Starting bandwidth_config: 3-Average, peer_id: 16Uiu2HAmAtCoy4N1Th3vJE6fVrEG9BVPLVnaJTDgaf22YowGCZtT, service: libp2p
Aug 20 20:12:45.519 INFO Listening established address: /ip4/0.0.0.0/tcp/9000/p2p/16Uiu2HAmAtCoy4N1Th3vJE6fVrEG9BVPLVnaJTDgaf22YowGCZtT, service: libp2p
Aug 20 20:12:45.520 INFO Listening established address: /ip4/0.0.0.0/udp/9001/quic-v1/p2p/16Uiu2HAmAtCoy4N1Th3vJE6fVrEG9BVPLVnaJTDgaf22YowGCZtT, service: libp2p
Aug 20 20:12:45.547 INFO Deterministic long lived subnets enabled, subscription_duration_in_epochs: 256, subnets_per_node: 2, service: attestation_service
Aug 20 20:12:45.547 INFO Subscribing to long-lived subnets subnets: [SubnetId(41), SubnetId(42)], service: attestation_service
Aug 20 20:12:45.549 INFO Updated local ENR udp6: None, tcp6: None, tcp4: Some(9000), udp4: None, ip4: None, id: 0xcfd0..c4e5, seq: 359, enr: enr:-Le4QMt3kSI-RcR0zM6psK8OHsxmyTRrvLNQ2IO4cwEH-SkhB4FgMSqO_ASQ56RAAZA5uBCLQfXSmjICV7tcQ2VDCqWCAWeHYXR0bmV0c4gAAAAAAAYAAIRldGgykGqVoakEAAAA__________-CaWSCdjSEcXVpY4IjKYlzZWNwMjU2azGhAuWrQ-MB9IxFKwJaG2uKsV4FbXxOFhCluLO8kbpCyfOQiHN5bmNuZXRzAIN0Y3CCIyg, service: libp2p
Aug 20 20:12:45.549 INFO Updated local ENR udp6: None, tcp6: None, tcp4: Some(9000), udp4: None, ip4: None, id: 0xcfd0..c4e5, seq: 360, enr: enr:-Le4QORVO8qO-GtbIPrQQcOi2P8yWvLFrPss2vQIbQalMhFlBkP3AvRsd1C5fpRtA6icJbLzjxQMy7SI3w6vljuvY8GCAWiHYXR0bmV0c4gAAAAAAAYAAIRldGgykGqVoakEAAAA__________-CaWSCdjSEcXVpY4IjKYlzZWNwMjU2azGhAuWrQ-MB9IxFKwJaG2uKsV4FbXxOFhCluLO8kbpCyfOQiHN5bmNuZXRzAIN0Y3CCIyg, service: libp2p
Aug 20 20:12:45.550 INFO Updated local ENR udp6: None, tcp6: None, tcp4: Some(9000), udp4: None, ip4: None, id: 0xcfd0..c4e5, seq: 361, enr: enr:-Le4QP7osT9Vy4Q62BEhKtdv4FAIQaTn1At7_zZf7qI4OKZQdq2XT0QtVz5YxhaJmdY0_cClNoahgxdxTnzJ6o9Cp-qCAWmHYXR0bmV0c4gAAAAAAAYAAIRldGgykGqVoakEAAAA__________-CaWSCdjSEcXVpY4IjKYlzZWNwMjU2azGhAuWrQ-MB9IxFKwJaG2uKsV4FbXxOFhCluLO8kbpCyfOQiHN5bmNuZXRzAIN0Y3CCIyg, service: libp2p
Aug 20 20:12:45.550 INFO Updated local ENR udp6: None, tcp6: None, tcp4: Some(9000), udp4: None, ip4: None, id: 0xcfd0..c4e5, seq: 362, enr: enr:-Le4QE2eidHo9qM7l8Z3AlI2FeEUdgcF5Chr9MwrMtuQtb_yLIDdZInMxfgBPMW5m7Legm7c-iHPNf2raD81bRHdeKuCAWqHYXR0bmV0c4gAAAAAAAYAAIRldGgykGqVoakEAAAA__________-CaWSCdjSEcXVpY4IjKYlzZWNwMjU2azGhAuWrQ-MB9IxFKwJaG2uKsV4FbXxOFhCluLO8kbpCyfOQiHN5bmNuZXRzAIN0Y3CCIyg, service: libp2p
Aug 20 20:12:45.568 INFO HTTP API started listen_address: 0.0.0.0:5052
Aug 20 20:12:45.568 INFO Metrics HTTP server started listen_address: 0.0.0.0:5054
Aug 20 20:12:45.569 INFO Execution engine online service: exec
Aug 20 20:12:45.569 INFO Issuing forkchoiceUpdated forkchoice_state: ForkchoiceState { head_block_hash: 0xafc9f20f7adef24139e7c16e39795b5ead33d7416f61c2c93801f9f9be871526, safe_block_hash: 0x012ea22a5f0cbe745b503af686068ea7e47789381799bfd246d09e0031ecc761, finalized_block_hash: 0x7d6c95ff32ccb61867c211e596f3e86c79bd68aeea25eb22c24a12eb1dfbbde2 }, service: exec
Aug 20 20:12:46.452 INFO Sync state updated new_state: Syncing Finalized Chain, old_state: Stalled, service: sync
Aug 20 20:12:46.452 INFO Sync state updated new_state: Stalled, old_state: Syncing Finalized Chain, service: sync
Aug 20 20:12:46.604 INFO Sync state updated new_state: Syncing Finalized Chain, old_state: Stalled, service: sync
Aug 20 20:12:46.605 INFO Sync state updated new_state: Stalled, old_state: Syncing Finalized Chain, service: sync
Aug 20 20:12:49.274 INFO Execution payloads are pruned service: freezer_db
Aug 20 20:12:49.524 INFO Sync state updated new_state: Syncing Finalized Chain, old_state: Stalled, service: sync
Aug 20 20:12:53.000 WARN Low peer count peer_count: 1, service: slot_notifier
Aug 20 20:12:53.000 INFO Syncing est_time: --, distance: 125 slots (25 mins), peers: 1, service: slot_notifier
Aug 20 20:12:53.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:12:55.518 INFO Could not UPnP map Discovery port error: Gateway does not support UPnP
Aug 20 20:12:55.520 INFO UPnP not available service: libp2p
Aug 20 20:12:57.119 WARN Blocks and blobs request for range received invalid data, error: MissingBlobs, batch_id: 305626, peer_id: 16Uiu2HAm3T89981943VW9UPxFMEwoRiDR5H7K1Am2CD9onpXA75e, service: sync
Aug 20 20:13:05.000 INFO Syncing est_time: --, distance: 126 slots (25 mins), peers: 7, service: slot_notifier
Aug 20 20:13:05.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:13:16.821 INFO Starting database compaction new_finalized_epoch: 305622, old_finalized_epoch: 305619, service: beacon
Aug 20 20:13:17.000 INFO Syncing est_time: 1 min, speed: 1.25 slots/sec, distance: 97 slots (19 mins), peers: 14, service: slot_notifier
Aug 20 20:13:17.001 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:13:29.000 INFO Syncing est_time: 0 mins, speed: 1.72 slots/sec, distance: 66 slots (13 mins), peers: 18, service: slot_notifier
Aug 20 20:13:29.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:13:41.000 INFO Syncing est_time: 0 mins, speed: 1.96 slots/sec, distance: 35 slots (7 mins), peers: 28, service: slot_notifier
Aug 20 20:13:41.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:13:53.000 INFO Syncing est_time: 0 mins, speed: 1.96 slots/sec, distance: 36 slots (7 mins), peers: 33, service: slot_notifier
Aug 20 20:13:53.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:13:54.807 WARN Blocks and blobs request for range received invalid data, error: MissingBlobs, batch_id: 305626, peer_id: 16Uiu2HAmTjTtR4UPRDx1hmcgVVFsisVpEFwL7WQAok5BMZExN8kM, service: sync
Aug 20 20:14:05.000 INFO Syncing est_time: 0 mins, speed: 1.33 slots/sec, distance: 37 slots (7 mins), peers: 32, service: slot_notifier
Aug 20 20:14:05.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:14:17.000 INFO Syncing est_time: 0 mins, speed: 0.67 slots/sec, distance: 38 slots (7 mins), peers: 41, service: slot_notifier
Aug 20 20:14:17.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:14:29.000 INFO Syncing est_time: --, distance: 39 slots (7 mins), peers: 46, service: slot_notifier
Aug 20 20:14:29.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:14:41.000 INFO Syncing est_time: --, distance: 40 slots (8 mins), peers: 48, service: slot_notifier
Aug 20 20:14:41.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier
Aug 20 20:14:53.000 INFO Syncing est_time: --, distance: 41 slots (8 mins), peers: 48, service: slot_notifier
Aug 20 20:14:53.000 WARN Syncing deposit contract block cache est_blocks_remaining: initializing deposits, service: slot_notifier

[jimmygchen]

Hi @rekyyang
Thanks for reporting. There were a few sync related bugs fixed in the last few releases.

Could you upgrade to v5.3.0 and see if this bug persists?