search

status-im / nimbus-eth2

Nim implementation of the Ethereum Beacon Chain
https://nimbus.guide
Other
534 stars 231 forks source link

Mainchain monitor crash #1003

Closed protolambda closed 4 years ago

protolambda commented 4 years ago

Bugreport: I am getting this fatal error a short while after start-up:

/home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(509) main
/home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(502) NimMain
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(996) main
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(741) start
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(699) run
/home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(941) runForever
/home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(278) poll
/home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(407) reportUnhandledError
/home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(358) reportUnhandledErrorAux
Error: unhandled exception: Stream EOF!
Async traceback:
Exception message: Stream EOF!
Exception type: [LPStreamEOFError]

And then get this before fully exiting:

TRC 2020-05-10 15:57:30+02:00 closing lpchannel                          tid=56109 file=lpchannel.nim:124 id=1 initiator=false topic=MplexChannel
TRC 2020-05-10 15:57:30+02:00 connection closed                          tid=56109 file=connection.nim:153 closed=true peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Connection
TRC 2020-05-10 15:57:30+02:00 wrapped stream closed, about to close conn tid=56109 file=connection.nim:82 closed=false peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Connection
TRC 2020-05-10 15:57:30+02:00 wrapped stream closed, closing conn        tid=56109 file=connection.nim:86 closed=false peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Connection
TRC 2020-05-10 15:57:30+02:00 closing lpchannel                          tid=56109 file=lpchannel.nim:124 id=2 initiator=true topic=MplexChannel
TRC 2020-05-10 15:57:30+02:00 about to close connection                  tid=56109 file=connection.nim:132 closed=true peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Connection
TRC 2020-05-10 15:57:30+02:00 closing lpchannel                          tid=56109 file=lpchannel.nim:124 id=2 initiator=true topic=MplexChannel
TRC 2020-05-10 15:57:30+02:00 waiting readloops                          tid=56109 file=connection.nim:148 count=0 topic=Connection
TRC 2020-05-10 15:57:30+02:00 closing lpchannel                          tid=56109 file=lpchannel.nim:124 id=2 initiator=true topic=MplexChannel
TRC 2020-05-10 15:57:30+02:00 connection closed                          tid=56109 file=connection.nim:153 closed=true peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Connection
TRC 2020-05-10 15:57:30+02:00 muxer handler completed for peer           tid=56109 file=switch.nim:120 peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=Switch
TRC 2020-05-10 15:57:30+02:00 sending encoded msgs to peer               tid=56109 file=pubsubpeer.nim:100 encoded=0af93e080112...736e61707079 peer=16Uiu2HAmNYCpko7ahZrZrzcpJRjL6bJ3JmPFiCbb9bgR3UHbHBsH topic=PubSubPeer
ERR 2020-05-10 15:57:31+02:00 UPnP port mapping deletion                 topics="nat" tid=56109 file=nat.nim:199 msg=NoSuchEntryInArray
ERR 2020-05-10 15:57:31+02:00 UPnP port mapping deletion                 topics="nat" tid=56109 file=nat.nim:199 msg=NoSuchEntryInArray

Version:

commit 592d6f65c3d65083df3e043f1eab3f5f4c23ea75 (HEAD -> devel, origin/devel)
Date:   Sat May 9 16:47:14 2020 +0200

Command I ran:

/home/proto/projects/nim-beacon-chain/build/beacon_node_shared_schlesi     --data-dir="/unimportant_for_issue"     --dump     --web3-url=wss://goerli.infura.io/ws/v3/809a18497dd74102b5f37d25aae3c85a     --bootstrap-file="/home/proto/projects/nim-beacon-chain/build/eth2-testnets/shared/schlesi/bootstrap_nodes.txt"     --log-level="TRACE"      --deposit-contract=0xA15554BF93a052669B511ae29EA21f3581677ac5     --state-snapshot="/home/proto/projects/nim-beacon-chain/build/eth2-testnets/shared/schlesi/genesis.ssz"

Update:

Running with latest changes from @arnetheduck for deposits etc., and ignoring "supportsSnappy" to just use snappy always, with trace logging, I'm now getting this:

TRC 2020-05-11 16:17:36+02:00 topic not in gossip array, skipping        tid=44161 file=gossipsub.nim:337 topic=GossipSub topicID=/eth2/9925efd6/committee_index47_beacon_attestation/ssz
TRC 2020-05-11 16:17:36+02:00 topic not in gossip array, skipping        tid=44161 file=gossipsub.nim:337 topic=GossipSub topicID=/eth2/9925efd6/committee_index56_beacon_attestation/ssz_snappy
TRC 2020-05-11 16:17:36+02:00 Decoding failed (no keys)                  tid=44161 file=encoding.nim:321 sender=136.34.190.41:12000:12000
DBG 2020-05-11 16:17:36+02:00 Could not decrypt packet, respond with whoareyou topics="discv5" tid=44161 file=protocol.nim:314 address=136.34.190.41:12000:12000 localNode=Node[0.0.0.0:9000]
TRC 2020-05-11 16:17:36+02:00 sending who are you                        topics="discv5" tid=44161 file=protocol.nim:185 to=16475527652659362905493773158066698644297416586623814681168308987219820761958 toAddress=136.34.190.41:12000:12000
TRC 2020-05-11 16:17:36+02:00 Exception occurred                         tid=44161 file=mplex.nim:128 exception="Stream EOF!\nAsync traceback:\nException message: Stream EOF!\nException type:" topic=Mplex
TRC 2020-05-11 16:17:36+02:00 stopping mplex main loop                   tid=44161 file=mplex.nim:130 topic=Mplex
TRC 2020-05-11 16:17:36+02:00 closing mplex muxer                        tid=44161 file=mplex.nim:158 topic=Mplex
 peers: 1 ❯ epoch: 3190, slot: 7/32 (102087) ❯ finalized epoch: 0 (c9cbcb8c)                                                                                                                                                     ETH: 0 Traceback (most recent call last, using override)
/home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(509) main
/home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(502) NimMain
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(975) main
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(720) start
/home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(678) run
/home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(941) runForever
/home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(278) poll
/home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncmacro2.nim(66) disconnect_continue
/home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(407) reportUnhandledError
/home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(358) reportUnhandledErrorAux
Error: unhandled exception: An attempt was made to complete a Future more than once. Details:
  Future ID: 1225
  Creation location:
    peerinfo.nim(45)    libp2p.peerinfo.lifetime
  First completion location:
    peerinfo.nim(74)    [unspecified]
  Second completion location:
    peerinfo.nim(74)    [unspecified]
  Stack trace to moment of creation:
    Traceback (most recent call last, using override)
    /home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(509) main
    /home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(502) NimMain
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(975) main
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(720) start
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(678) run
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(941) runForever
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(278) poll
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncmacro2.nim(36) handleConn_continue
    /home/proto/projects/nim-beacon-chain/vendor/nim-libp2p/libp2p/protocols/secure/secure.nim(37) handleConn
    /home/proto/projects/nim-beacon-chain/vendor/nim-libp2p/libp2p/peerinfo.nim(45) init
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncfutures2.nim(69) newFuture
    /home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(502) getStackTrace
  Stack trace to moment of secondary completion:
    Traceback (most recent call last, using override)
    /home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(509) main
    /home/proto/projects/nim-beacon-chain/beacon_chain/mainchain_monitor.nim(502) NimMain
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(975) main
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(720) start
    /home/proto/projects/nim-beacon-chain/beacon_chain/beacon_node.nim(678) run
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(941) runForever
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncloop.nim(278) poll
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncmacro2.nim(36) disconnect_continue
    /home/proto/projects/nim-beacon-chain/beacon_chain/eth2_network.nim(223) disconnect
    /home/proto/projects/nim-beacon-chain/vendor/nim-libp2p/libp2p/peerinfo.nim(74) close
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncfutures2.nim(204) complete
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncfutures2.nim(207) checkFinished
    /home/proto/projects/nim-beacon-chain/vendor/nim-chronos/chronos/asyncfutures2.nim(164) checkFinished
    /home/proto/projects/nim-beacon-chain/vendor/nimbus-build-system/vendor/Nim/lib/system/excpt.nim(502) getStackTrace

 [FutureDefect]
arnetheduck commented 4 years ago

this was fixed in chronos and libp2p