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

Testnet1 Assertion Error #307

Closed
zah opened this issue Jul 1, 2019 · 1 comment
Closed

Testnet1 Assertion Error #307

zah opened this issue Jul 1, 2019 · 1 comment

Comments

@zah
Copy link
Contributor

zah commented Jul 1, 2019

I've ran into the following crash shortly after connecting to testnet1:

Exception message: /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/validator.nim(146, 12) `shard < SHARD_COUNT` 
Exception type: [AssertionError]

Full Chronicles output:

DBG 2019-07-01 16:42:06+03:00 UPnP                                       topics="nat" tid=17453 msg="Some device found, but it's not recognised as an Internet Gateway Device. Trying anyway."                                                                                                                                
DBG 2019-07-01 16:42:06+03:00 UPnP                                       topics="nat" tid=17453 msg="Invalid Action"
DBG 2019-07-01 16:42:06+03:00 NAT-PMP                                    topics="nat" tid=17453 msg="the gateway does not support nat-pmp"
INF 2019-07-01 16:42:06+03:00 Starting LibP2P deamon                     tid=17453 announcedAddresses=@[/ip4/0.0.0.0/tcp/9100] hostAddress=/ip4/0.0.0.0/tcp/9100 keyFile=/home/zahary/.cache/nimbus/BeaconNode/testnet1/privkey.protobuf                                                                                      
INF 2019-07-01 16:42:06+03:00 Connecting to bootstrap nodes              tid=17453 bootstrapNodes="@[{PeerID: '12D3KooWQmdmkcSdRaeLy8dMf9mCMeakJtxgHfX5qGAfqmvu7wTX' Addresses: ['/ip4/188.166.38.238/tcp/9100']}]"                                                                                                           
DBG 2019-07-01 16:42:07+03:00 Peer connected. Initiating sync            tid=17453 bestSlot=15 peer=12*vu7wTX remoteBestSlot=17
DBG 2019-07-01 16:42:07+03:00 Waiting for block headers                  tid=17453 fromPeer=12*vu7wTX peer=12*vu7wTX remoteBestSlot=17
DBG 2019-07-01 16:42:07+03:00 Block headers received. Requesting block bodies tid=17453 peer=12*vu7wTX
DBG 2019-07-01 16:42:07+03:00 Block received                             tid=17453 blck="(slot: 17, parent_root: \"D4022368\", state_root: \"808B6A14\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"8f12b4e3\")" blockRoot=9E79B9D5
DBG 2019-07-01 16:42:07+03:00 Replaying state transitions                tid=17453 ancestorStateRoot=6B90F781 ancestorStateSlot=16 ancestors=1 blockRoot=D4022368 slot=16 stateSlot=0                                                                                                                                         
INF 2019-07-01 16:42:07+03:00 Block resolved                             tid=17453 blck="(slot: 17, parent_root: \"D4022368\", state_root: \"808B6A14\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"8f12b4e3\")" blockRoot=9E79B9D5 justifiedRoot=472941CA justifiedSlot=0
INF 2019-07-01 16:42:07+03:00 Forward sync imported blocks               tid=17453 len=1
INF 2019-07-01 16:42:07+03:00 Starting beacon node                       tid=17453 SECONDS_PER_SLOT=30 SHARD_COUNT=16 SLOTS_PER_EPOCH=16 SPEC_VERSION=0.7.1 slotsSinceFinalization=-566 stateSlot=17
INF 2019-07-01 16:42:07+03:00 Local validator attached                   tid=17453 pubKey=b35b6291fc83c4c6dfb549dcca471e438fedcf0ad89b48a172f59c6827e2d8ac9542a4672aa9afcd6e6def21f3dff7eb validator=b35b6291                                                                                                                 
INF 2019-07-01 16:42:07+03:00 Local validators attached                  tid=17453 count=1
INF 2019-07-01 16:42:07+03:00 Scheduling first slot action               tid=17453 fromNow=4s nextSlot=19
DBG 2019-07-01 16:42:11+03:00 Slot start                                 tid=17453 lastSlot=18 scheduledSlot=19 slot=19
DBG 2019-07-01 16:42:11+03:00 Replaying state transitions                tid=17453 ancestorStateRoot=6B90F781 ancestorStateSlot=16 ancestors=1 blockRoot=D4022368 slot=19 stateSlot=17                                                                                                                                        
DBG 2019-07-01 16:42:11+03:00 Advancing state with empty slots           tid=17453 stateSlot=16 targetSlot=19
DBG 2019-07-01 16:42:11+03:00 Preparing for fork choice                  tid=17453 connectedPeers=1 stateEpoch=1 stateRoot=6B90F781 stateSlot=19
INF 2019-07-01 16:42:11+03:00 Fork chosen                                tid=17453 newHeadBlockRoot=9E79B9D5 newHeadEpoch=1 newHeadSlot=17
DBG 2019-07-01 16:42:11+03:00 Replaying state transitions                tid=17453 ancestorStateRoot=6B90F781 ancestorStateSlot=16 ancestors=2 blockRoot=9E79B9D5 slot=17 stateSlot=19                                                                                                                                        
INF 2019-07-01 16:42:11+03:00 Updated head                               tid=17453 finalizedEpoch=0 headBlockRoot=9E79B9D5 justifiedEpoch=0 stateRoot=808B6A14 stateSlot=17
DBG 2019-07-01 16:42:11+03:00 Advancing state with empty slots           tid=17453 stateSlot=17 targetSlot=19
DBG 2019-07-01 16:42:11+03:00 Expecting proposal                         tid=17453 headRoot=9E79B9D5 proposer=8df6a168 slot=19
DBG 2019-07-01 16:42:11+03:00 Waiting to send attestations               tid=17453 fromNow=15s slot=19
DBG 2019-07-01 16:42:12+03:00 Block received                             tid=17453 blck="(slot: 19, parent_root: \"60FE7605\", state_root: \"EBC891BB\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"abd8649c\")" blockRoot=6017ADAA
DBG 2019-07-01 16:42:12+03:00 Unresolved block (parent missing)          tid=17453 blck="(slot: 19, parent_root: \"60FE7605\", state_root: \"EBC891BB\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"abd8649c\")" blockRoot=6017ADAA
INF 2019-07-01 16:42:12+03:00 Requesting detected missing blocks         tid=17453 missingBlocks="@[(root: 60FE760555F1BEF48467C61392A5CA5F107B81462A38C4A1249DC5771A9C068A, historySlots: 1)]"                                                                                                                               
DBG 2019-07-01 16:42:12+03:00 Block headers received. Requesting block bodies tid=17453 peer=12*vu7wTX
DBG 2019-07-01 16:42:12+03:00 Block received                             tid=17453 blck="(slot: 18, parent_root: \"D4022368\", state_root: \"CDA1882B\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"a9687f98\")" blockRoot=60FE7605
DBG 2019-07-01 16:42:12+03:00 Replaying state transitions                tid=17453 ancestorStateRoot=6B90F781 ancestorStateSlot=16 ancestors=1 blockRoot=D4022368 slot=17 stateSlot=19                                                                                                                                        
DBG 2019-07-01 16:42:12+03:00 Advancing state with empty slots           tid=17453 stateSlot=16 targetSlot=17
INF 2019-07-01 16:42:13+03:00 Block resolved                             tid=17453 blck="(slot: 18, parent_root: \"D4022368\", state_root: \"CDA1882B\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"a9687f98\")" blockRoot=60FE7605 justifiedRoot=472941CA justifiedSlot=0
INF 2019-07-01 16:42:13+03:00 Block resolved                             tid=17453 blck="(slot: 19, parent_root: \"60FE7605\", state_root: \"EBC891BB\", proposer_slashings_len: 0, attester_slashings_len: 0, attestations_len: 0, deposits_len: 0, voluntary_exits_len: 0, transfers_len: 0, signature: \"abd8649c\")" blockRoot=6017ADAA justifiedRoot=472941CA justifiedSlot=0
DBG 2019-07-01 16:42:26+03:00 Attestation received                       tid=17453 attestationData="(Field0: \"9E79B9D5\", Field1: 0, Field2: \"D4022368\", Field3: \"00000000\", Field4: (shard: 15, parent_root: C78009FDF07FC56A11F122370658A353AAA542ED63E44C4BC15FF4CD105AB33C, start_epoch: 0, end_epoch: 0, data_root: 0000000000000000000000000000000000000000000000000000000000000000))" signature=95d4b5c0                                                                         
DBG 2019-07-01 16:42:26+03:00 Replaying state transitions                tid=17453 ancestorStateRoot=6B90F781 ancestorStateSlot=16 ancestors=2 blockRoot=9E79B9D5 slot=19 stateSlot=19                                                                                                                                        
DBG 2019-07-01 16:42:26+03:00 Advancing state with empty slots           tid=17453 stateSlot=17 targetSlot=19
INF 2019-07-01 16:42:26+03:00 First attestation!                         tid=17453 attestationSlot=16
DBG 2019-07-01 16:42:26+03:00 Growing attestation pool                   tid=17453 attestationSlot=16 startingSlot=0
INF 2019-07-01 16:42:26+03:00 Attestation resolved                       tid=17453 attestationData="(Field0: \"9E79B9D5\", Field1: 0, Field2: \"D4022368\", Field3: \"00000000\", Field4: (shard: 15, parent_root: C78009FDF07FC56A11F122370658A353AAA542ED63E44C4BC15FF4CD105AB33C, start_epoch: 0, end_epoch: 0, data_root: 0000000000000000000000000000000000000000000000000000000000000000))" validations=1                                                                              
DBG 2019-07-01 16:42:26+03:00 Attestation received                       tid=17453 attestationData="(Field0: \"9E79B9D5\", Field1: 0, Field2: \"D4022368\", Field3: \"00000000\", Field4: (shard: 17, parent_root: C78009FDF07FC56A11F122370658A353AAA542ED63E44C4BC15FF4CD105AB33C, start_epoch: 0, end_epoch: 0, data_root: 0000000000000000000000000000000000000000000000000000000000000000))" signature=95d329a9                                                                         
DBG 2019-07-01 16:42:26+03:00 Growing attestation pool                   tid=17453 attestationSlot=18 startingSlot=0

Full error traceback:

/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(802) beacon_node
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(717) start
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(690) run
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(832) runForever
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(266) poll
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(36) pubsubLoop_continue
/home/zahary/nimbus/vendor/nim-libp2p/libp2p/daemon/daemonapi.nim(1230) pubsubLoopIter
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(306) :anonymous
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(36) anonymous_continue
/home/zahary/nimbus/vendor/nim-serialization/serialization.nim(84) anonymousIter
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(670) :anonymous
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(410) onAttestation
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/attestation_pool.nim(184) add
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/beaconstate.nim(412) get_attesting_indices_seq
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/beaconstate.nim(399) get_attesting_indices
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/validator.nim(146) get_crosslink_committee
/home/zahary/nimbus/vendor/Nim/lib/system.nim(3879) failedAssertImpl
/home/zahary/nimbus/vendor/Nim/lib/system.nim(3872) raiseAssert
/home/zahary/nimbus/vendor/Nim/lib/system.nim(2918) sysFatal
[[reraised from:
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(802) beacon_node
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(717) start
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(690) run
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(832) runForever
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(266) poll
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(39) pubsubLoop_continue
/home/zahary/nimbus/vendor/nim-libp2p/libp2p/daemon/daemonapi.nim(1230) pubsubLoopIter
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncfutures2.nim(377) read
]]
[[reraised from:
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(802) beacon_node
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(717) start
/home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(690) run
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(832) runForever
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(266) poll
/home/zahary/nimbus/vendor/nim-chronos/chronos/asyncfutures2.nim(422) cb
]]
Error: unhandled exception: /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/validator.nim(146, 12) `shard < SHARD_COUNT` 
Async traceback:
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(802)      beacon_node
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(717)      start
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(690)      run
  /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(832)                  runForever
  /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(266)                  poll
  /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(36)                 pubsubLoop_continue
  /home/zahary/nimbus/vendor/nim-libp2p/libp2p/daemon/daemonapi.nim(1230)            pubsubLoopIter
  /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(306)                :anonymous
  /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(36)                 anonymous_continue
  /home/zahary/nimbus/vendor/nim-serialization/serialization.nim(84)                 anonymousIter
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(670)      :anonymous
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(410)      onAttestation
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/attestation_pool.nim(184) add
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/beaconstate.nim(412) get_attesting_indices_seq
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/beaconstate.nim(399) get_attesting_indices
  /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/validator.nim(146)   get_crosslink_committee
  /home/zahary/nimbus/vendor/Nim/lib/system.nim(3879)                                failedAssertImpl
  /home/zahary/nimbus/vendor/Nim/lib/system.nim(3872)                                raiseAssert
  /home/zahary/nimbus/vendor/Nim/lib/system.nim(2918)                                sysFatal
  #[
    /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(802)      beacon_node
    /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(717)      start
    /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/beacon_node.nim(690)      run
    /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(832)                  runForever
    /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncloop.nim(266)                  poll
    /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncmacro2.nim(39)                 pubsubLoop_continue
    /home/zahary/nimbus/vendor/nim-libp2p/libp2p/daemon/daemonapi.nim(1230)            pubsubLoopIter
    /home/zahary/nimbus/vendor/nim-chronos/chronos/asyncfutures2.nim(377)              read
  ]#
Exception message: /home/zahary/nimbus/vendor/nim-beacon-chain/beacon_chain/spec/validator.nim(146, 12) `shard < SHARD_COUNT` 
Exception type: [AssertionError]
@tersec
Copy link
Contributor

tersec commented Jul 2, 2019

https://github.com/ethereum/eth2.0-specs/blob/v0.8.0/specs/core/0_beacon-chain.md#get_crosslink_committee doesn't actually contain that assertion. It's something I added to understand how this was working, but it's another maybe-spurious thing that via (shard + SHARD_COUNT - get_start_shard(state, epoch)) mod SHARD_COUNT, would get quashed down to the correct range regardless.

Also, while I reproduced it once, now, when I've been instrumenting things more, it's just churning along, slot by slot, block by block, up to slot 2949, on testnet1.

And, it's something that shouldn't crash, as such -- it's not internally calculated data we can be sure is internally consistent. It comes from the attestation:

  let committee =
    get_crosslink_committee(
      state, attestation_data.target_epoch, attestation_data.crosslink.shard,
      stateCache)

So my inclination is just to remove that assertion and continue on until something else comes up, since otherwise we're going to crash anytime some puts a too-high shard number in their attestation. Whether or not we're doing it, that's another bug if so, but in get_attesting_indices is the wrong place to handle this regardless. It should be upstream, when there's some attestation validation (which to be fair needs to be reimplemented, post-data-structure-change).

So, I'm going to remove that assertion, push the change, and close this bug, unless you see compelling reason otherwise.

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