Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Missed Duties followed by a crash of nimbus VC #5368

Closed
NeoPlays opened this issue Aug 29, 2023 · 1 comment
Closed

Missed Duties followed by a crash of nimbus VC #5368

NeoPlays opened this issue Aug 29, 2023 · 1 comment

Comments

@NeoPlays
Copy link

Describe the bug
Nimbus VC recognizing time offset followed by missed duties and resulting in a crash.
The VC was running just fine beforehand (no time offsets, no missed duties)

To Reproduce
Nimbus is running in Docker with statusim/nimbus-validator-client:multiarch-v23.7.0 image

Logs:

{"log":"INF 2023-08-29 03:56:47.004+00:00 Slot start                                 slot=7204782 epoch=225149 attestationIn=4s blockIn=\u003cunknown\u003e validators=500 good_nodes=2 viable_nodes=0 bad_nodes=4 delay=4ms800us139ns\n","stream":"stdout","time":"2023-08-29T03:56:47.005291
403Z"}
{"log":"INF 2023-08-29 03:56:59.003+00:00 Slot start                                 slot=7204783 epoch=225149 attestationIn=4s blockIn=\u003cunknown\u003e validators=500 good_nodes=2 viable_nodes=0 bad_nodes=4 delay=3ms40us618ns\n","stream":"stdout","time":"2023-08-29T03:56:59.0035494
45Z"}
{"log":"INF 2023-08-29 03:57:04.676+00:00 Beacon node has notable time offset        time_offset=596ms699us238ns service=fallback_service node=http://10.12.1.62:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=5 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:04.6765380
71Z"}
{"log":"WRN 2023-08-29 03:57:05.877+00:00 Beacon node has significant time offset    time_offset=2s832ms261us118ns service=fallback_service node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:05.878121314Z"}
{"log":"WRN 2023-08-29 03:57:05.877+00:00 Beacon node has enormous time offset       time_offset=2s832ms261us118ns service=fallback_service node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:05.878157704Z"}
{"log":"WRN 2023-08-29 03:57:05.878+00:00 Beacon node's clock is out of order, (beacon node is unusable) node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:05.878164366Z"}
{"log":"INF 2023-08-29 03:57:11.542+00:00 Slot start                                 slot=7204784 epoch=225149 attestationIn=4s blockIn=\u003cunknown\u003e validators=500 good_nodes=1 viable_nodes=0 bad_nodes=4 delay=542ms471us289ns\n","stream":"stdout","time":"2023-08-29T03:57:11.542851935Z"}
{"log":"WRN 2023-08-29 03:57:11.670+00:00 Beacon node down                           reason=\"Beacon node has acceptable time offset;200;checkTimeOffsetStatus()();status-update\" node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:11.670298428Z"}
{"log":"INF 2023-08-29 03:57:12.853+00:00 Beacon node has notable time offset        time_offset=913ms852us823ns service=fallback_service node=http://10.12.1.62:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=5 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:12.853519981Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=17 duties_count=3 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007327417Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=23 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007369927Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=30 duties_count=2 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007375277Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=11 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007386307Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=47 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007391237Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=0 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.00739827Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=39 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007406305Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=27 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007472891Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=45 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007479824Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=25 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007518005Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=32 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007534186Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=43 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007586223Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=4 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007598677Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=9 duties_count=2 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007638783Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=38 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007676734Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=1 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007739091Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=55 duties_count=1 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007782843Z"}
{"log":"WRN 2023-08-29 03:57:19.007+00:00 Unable to proceed attestations             slot=7204784 committee_index=20 duties_count=2 reason=\"No online beacon node(s)\" service=attestation_service\n","stream":"stdout","time":"2023-08-29T03:57:19.007795578Z"}
{"log":"NOT 2023-08-29 03:57:21.410+00:00 Beacon node is online                      agent_version=Nimbus/v23.7.0-60f0a2-stateofus node=http://10.12.1.62:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=5 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.41085529Z"}
{"log":"NOT 2023-08-29 03:57:21.428+00:00 Beacon node is online                      agent_version=Nimbus/v23.7.0-60f0a2-stateofus node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.428594517Z"}
{"log":"NOT 2023-08-29 03:57:21.480+00:00 Beacon node is compatible                  node=http://10.12.1.62:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=5 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.480468129Z"}
{"log":"NOT 2023-08-29 03:57:21.482+00:00 Beacon node is compatible                  node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.482453775Z"}
{"log":"NOT 2023-08-29 03:57:21.503+00:00 Beacon node is in sync                     head_slot=7204784 sync_distance=0 is_optimistic=false node=http://10.12.1.55:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=0 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.503179259Z"}
{"log":"NOT 2023-08-29 03:57:21.505+00:00 Beacon node is in sync                     head_slot=7204784 sync_distance=0 is_optimistic=false node=http://10.12.1.62:5052[Nimbus/v23.7.0-60f0a2-stateofus] node_index=5 node_roles=AGBSDT\n","stream":"stdout","time":"2023-08-29T03:57:21.505819437Z"}
{"log":"INF 2023-08-29 03:57:23.322+00:00 Slot start                                 slot=7204785 epoch=225149 attestationIn=4s blockIn=\u003cunknown\u003e validators=500 good_nodes=2 viable_nodes=0 bad_nodes=4 delay=322ms496us772ns\n","stream":"stdout","time":"2023-08-29T03:57:23.322832844Z"}
{"log":"WRN 2023-08-29 03:57:23.328+00:00 Unable to publish sync committee messages and contributions in time slot=7204784 timeout=11s456ms906us700ns service=sync_committee_service\n","stream":"stdout","time":"2023-08-29T03:57:23.328831842Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-libp2p/libp2p/protocols/pubsub/pubsub.nim(865) main\n","stream":"stderr","time":"2023-08-29T03:57:25.021216691Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-libp2p/libp2p/protocols/pubsub/pubsub.nim(858) NimMain\n","stream":"stderr","time":"2023-08-29T03:57:25.021256956Z"}
{"log":"/home/user/nimbus-eth2/beacon_chain/nimbus_validator_client.nim(521) main\n","stream":"stderr","time":"2023-08-29T03:57:25.021261705Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncloop.nim(1504) waitFor\n","stream":"stderr","time":"2023-08-29T03:57:25.021265562Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncloop.nim(258) poll\n","stream":"stderr","time":"2023-08-29T03:57:25.021268959Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncfutures2.nim(318) futureContinue\n","stream":"stderr","time":"2023-08-29T03:57:25.021272505Z"}
{"log":"/home/user/nimbus-eth2/beacon_chain/validator_client/api.nim(233) getAttesterDuties\n","stream":"stderr","time":"2023-08-29T03:57:25.021276212Z"}
{"log":"/home/user/nimbus-eth2/beacon_chain/validator_client/api.nim(117) apiResponseOr\n","stream":"stderr","time":"2023-08-29T03:57:25.02127999Z"}
{"log":"/home/user/nimbus-eth2/beacon_chain/validator_client/api.nim(120) apiResponseOr\n","stream":"stderr","time":"2023-08-29T03:57:25.021283446Z"}
{"log":"/home/user/nimbus-eth2/vendor/nimbus-build-system/vendor/Nim/lib/system/assertions.nim(38) failedAssertImpl\n","stream":"stderr","time":"2023-08-29T03:57:25.021287013Z"}
{"log":"/home/user/nimbus-eth2/vendor/nimbus-build-system/vendor/Nim/lib/system/assertions.nim(28) raiseAssert\n","stream":"stderr","time":"2023-08-29T03:57:25.021290509Z"}
{"log":"/home/user/nimbus-eth2/vendor/nimbus-build-system/vendor/Nim/lib/system/fatal.nim(54) sysFatal\n","stream":"stderr","time":"2023-08-29T03:57:25.021294137Z"}
{"log":"[[reraised from:\n","stream":"stderr","time":"2023-08-29T03:57:25.021297473Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-libp2p/libp2p/protocols/pubsub/pubsub.nim(865) main\n","stream":"stderr","time":"2023-08-29T03:57:25.021300749Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-libp2p/libp2p/protocols/pubsub/pubsub.nim(858) NimMain\n","stream":"stderr","time":"2023-08-29T03:57:25.021304026Z"}
{"log":"/home/user/nimbus-eth2/beacon_chain/nimbus_validator_client.nim(521) main\n","stream":"stderr","time":"2023-08-29T03:57:25.021307452Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncloop.nim(1504) waitFor\n","stream":"stderr","time":"2023-08-29T03:57:25.021310929Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncloop.nim(258) poll\n","stream":"stderr","time":"2023-08-29T03:57:25.021314245Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncfutures2.nim(318) futureContinue\n","stream":"stderr","time":"2023-08-29T03:57:25.021317641Z"}
{"log":"/home/user/nimbus-eth2/vendor/nim-chronos/chronos/asyncmacro2.nim(197) getAttesterDuties\n","stream":"stderr","time":"2023-08-29T03:57:25.021320867Z"}
{"log":"]]\n","stream":"stderr","time":"2023-08-29T03:57:25.021324264Z"}
{"log":"Error: unhandled exception: /home/user/nimbus-eth2/beacon_chain/validator_client/api.nim(120, 13) `not (future.cancelled())`  [AssertionDefect]\n","stream":"stderr","time":"2023-08-29T03:57:25.02132757Z"}

@cheatfate
Copy link
Contributor

Thank you for your report!
This issue was fixed in 4a84457

Current release 23.8.0 also has this fix.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants