Description
The sync manager shut down and I temporarily lost finality on Schlesi Testnet.
thread 'tokio-runtime-worker-7' panicked at 'elapsed=7481664; when=7481664', /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:244:5
Version
Using Lighthouse from this branch #1052 @ 310cc4fb504f6b3d6f4b0e9a5f53715a0c848138
Using Schlesi config: https://github.com/goerli/schlesi
Present Behavior
Connected a validator client to a beacon node locally, lost sync manager on the beacon node:
Apr 27 13:18:00.206 INFO Block from local validator block_slot: 390, block_root: 0x7e2d…96d0, service: http
Apr 27 13:18:06.000 INFO Synced slot: 390, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:18:16.020 INFO Attestation from local validator slot: 391, index: 0, source: 11, target: 11, service: http
Apr 27 13:18:18.001 INFO Synced slot: 391, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:18:20.041 INFO Attestation from local validator slot: 391, index: 0, source: 11, target: 11, service: http
thread 'tokio-runtime-worker-7' panicked at 'elapsed=7481664; when=7481664', /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/tokio-timer-0.2.13/src/wheel/mod.rs:244:5
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Apr 27 13:18:21.453 INFO Sync Manager shutdown service: sync, service: network
Apr 27 13:18:30.001 INFO Synced slot: 392, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:18:36.146 ERRO No valid eth1_data votes, `votes_to_consider` empty, outcome: casting `state.eth1_data` as eth1 vote, genesis_time: 1587981600, earliest_block_timestamp: 1587974284, lowest_block_number: 2596126, service: beacon
Apr 27 13:18:36.177 INFO Block from local validator block_slot: 393, block_root: 0x7d1e…64e9, service: http
Apr 27 13:18:42.001 INFO Synced slot: 393, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:18:54.001 INFO Synced slot: 394, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:19:00.170 ERRO No valid eth1_data votes, `votes_to_consider` empty, outcome: casting `state.eth1_data` as eth1 vote, genesis_time: 1587981600, earliest_block_timestamp: 1587974284, lowest_block_number: 2596126, service: beacon
Apr 27 13:19:00.244 INFO Block from local validator block_slot: 395, block_root: 0xfcac…31d4, service: http
Apr 27 13:19:06.001 INFO Synced slot: 395, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Apr 27 13:19:18.001 INFO Synced slot: 396, epoch: 12, finalized_epoch: 10, finalized_root: 0xd017…bed4, peers: 6, service: slot_notifier
Validator lost ability to submit blocks:
Apr 27 13:18:04.002 INFO Successfully subscribed validators failed_validators: 2, validators: 2, service: attestation
Apr 27 13:18:06.001 INFO Some validators active slot: 390, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:18:16.002 INFO Successfully subscribed validators failed_validators: 2, validators: 2, service: attestation
Apr 27 13:18:16.020 INFO Successfully published attestations slot: 391, committee_index: 0, head_block: 0x0f3fbc341d18706b67578838e9bdda5314d0a7eb87b9e48d26825dd9fd84ca0d, count: 1, service: attestation
Apr 27 13:18:18.001 INFO Some validators active slot: 391, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:18:20.042 INFO Successfully published aggregate attestations, slot: 391, committee_index: 0, head_block: 0x0f3f…ca0d, signatures: 1, service: attestation
Apr 27 13:18:28.002 CRIT Error during attestation production error: Failed to subscribe validators: ReqwestError(Error(Status(500), "http://localhost:5052/validator/subscribe")), service: attestation
Apr 27 13:18:30.001 INFO Some validators active slot: 392, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:18:36.177 CRIT Error whilst producing block message: Error from beacon node when publishing block: ReqwestError(Error(Status(500), "http://localhost:5052/validator/block")), service: block
Apr 27 13:18:40.002 CRIT Error during attestation production error: Failed to subscribe validators: ReqwestError(Error(Status(500), "http://localhost:5052/validator/subscribe")), service: attestation
Apr 27 13:18:42.001 INFO Some validators active slot: 393, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:18:52.001 CRIT Error during attestation production error: Failed to subscribe validators: ReqwestError(Error(Status(500), "http://localhost:5052/validator/subscribe")), service: attestation
Apr 27 13:18:54.001 INFO Some validators active slot: 394, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:19:00.244 CRIT Error whilst producing block message: Error from beacon node when publishing block: ReqwestError(Error(Status(500), "http://localhost:5052/validator/block")), service: block
Apr 27 13:19:04.002 CRIT Error during attestation production error: Failed to subscribe validators: ReqwestError(Error(Status(500), "http://localhost:5052/validator/subscribe")), service: attestation
Apr 27 13:19:06.001 INFO Some validators active slot: 395, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Apr 27 13:19:16.002 CRIT Error during attestation production error: Failed to subscribe validators: ReqwestError(Error(Status(500), "http://localhost:5052/validator/subscribe")), service: attestation
Apr 27 13:19:18.001 INFO Some validators active slot: 396, epoch: 12, total_validators: 3, active_validators: 2, proposers: 2, service: notifier
Expected Behavior
Should not panic :)
Steps to resolve
A restart was able to resolve this.