Agoric / agoric-sdk

monorepo for the Agoric Javascript smart contract platform
Apache License 2.0
327 stars 208 forks source link

crash in `agoric start local-chain` on beta branch #2882

Closed warner closed 3 years ago

warner commented 3 years ago

Describe the bug

With agoric-sdk at release 2.17.1 (commit abe343518781c164255f71e47dc28c7d45717690), I did yarn && yarn build, using go1.15.8 on linux. From that environment, I checked out https://github.com/Agoric/testnet-load-generator , did agoric install, and agoric start local-chain. Usually this takes a few minutes and then turns into a running single-validator chain process. This time, I saw the following crash:

agoric: start: ag-chain-cosmos start --home=_agstate/agoric-servers/local-chain-26657
3:54PM INF starting ABCI with Tendermint
3:54PM INF Starting multiAppConn service impl=multiAppConn module=proxy
3:54PM INF Starting localClient service connection=query impl=localClient module=abci-client
3:54PM INF Starting localClient service connection=snapshot impl=localClient module=abci-client
3:54PM INF Starting localClient service connection=mempool impl=localClient module=abci-client
3:54PM INF Starting localClient service connection=consensus impl=localClient module=abci-client
3:54PM INF Starting EventBus service impl=EventBus module=events
3:54PM INF Starting PubSub service impl=PubSub module=pubsub
3:54PM INF Starting IndexerService service impl=IndexerService module=txindex
3:54PM INF ABCI Handshake App Info hash= height=0 module=consensus protocol-version=0 software-version=
3:54PM INF ABCI Replay Blocks appHeight=0 module=consensus stateHeight=0 storeHeight=0
2021-04-14T22:54:03.522Z launch-chain: Launching SwingSet kernel
Module level directives cause errors when bundled, 'use jessie' was ignored.
Module level directives cause errors when bundled, 'use jessie' was ignored.
Module level directives cause errors when bundled, 'use jessie' was ignored.
Module level directives cause errors when bundled, 'use jessie' was ignored.
Module level directives cause errors when bundled, 'use jessie' was ignored.
Module level directives cause errors when bundled, 'use jessie' was ignored.
3:54PM INF asserting crisis invariants inv=0/11 module=x/crisis name=gov/module-account
3:54PM INF asserting crisis invariants inv=1/11 module=x/crisis name=bank/nonnegative-outstanding
3:54PM INF asserting crisis invariants inv=2/11 module=x/crisis name=bank/total-supply
3:54PM INF asserting crisis invariants inv=3/11 module=x/crisis name=distribution/nonnegative-outstanding
3:54PM INF asserting crisis invariants inv=4/11 module=x/crisis name=distribution/can-withdraw
3:54PM INF asserting crisis invariants inv=5/11 module=x/crisis name=distribution/reference-count
3:54PM INF asserting crisis invariants inv=6/11 module=x/crisis name=distribution/module-account
3:54PM INF asserting crisis invariants inv=7/11 module=x/crisis name=staking/module-accounts
3:54PM INF asserting crisis invariants inv=8/11 module=x/crisis name=staking/nonnegative-power
3:54PM INF asserting crisis invariants inv=9/11 module=x/crisis name=staking/positive-delegation
3:54PM INF asserting crisis invariants inv=10/11 module=x/crisis name=staking/delegator-shares
3:54PM INF asserted all invariants duration=0.885958 height=0 module=x/crisis
3:54PM INF created new capability module=ibc name=ports/transfer
3:54PM INF port binded module=x/ibc/port port=transfer
3:54PM INF claimed capability capability=1 module=transfer name=ports/transfer
3:54PM INF Completed ABCI Handshake - Tendermint and App are synced appHash= appHeight=0 module=consensus
3:54PM INF Version info block=11 p2p=8 software=
3:54PM INF This node is a validator addr=7C4BFEF55FE141CCE0D4C3C8D49ABAE6CB37B628 module=consensus pubKey=QNuBzC1o1lECmB+kmTzDBtpAUgwiMcU6KiPE28UfG3U=
3:54PM INF P2P Node ID ID=c0e91dfc811e1675aad2c8acb4594888afe24297 file=_agstate/agoric-servers/local-chain-26657/config/node_key.json module=p2p
3:54PM INF Adding persistent peers addrs=[] module=p2p
3:54PM INF Adding unconditional peer ids ids=[] module=p2p
3:54PM INF Add our address to book addr={"id":"c0e91dfc811e1675aad2c8acb4594888afe24297","ip":"0.0.0.0","port":26656} book=_agstate/agoric-servers/local-chain-26657/config/addrbook.json module=p2p
3:54PM INF Starting Node service impl=Node
3:54PM INF Starting pprof server laddr=localhost:6060
3:54PM INF Starting P2P Switch service impl="P2P Switch" module=p2p
3:54PM INF Starting StateSync service impl=StateSync module=statesync
3:54PM INF Starting PEX service impl=PEX module=pex
3:54PM INF Starting AddrBook service book=_agstate/agoric-servers/local-chain-26657/config/addrbook.json impl=AddrBook module=p2p
3:54PM INF Starting RPC HTTP server on [::]:26657 module=rpc-server
3:54PM INF Starting Mempool service impl=Mempool module=mempool
3:54PM INF Starting BlockchainReactor service impl=BlockchainReactor module=blockchain
3:54PM INF Starting Consensus service impl=ConsensusReactor module=consensus
3:54PM INF Reactor  module=consensus waitSync=false
3:54PM INF Starting State service impl=ConsensusState module=consensus
3:54PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:54PM INF No addresses to dial. Falling back to seeds module=pex
3:54PM INF Starting baseWAL service impl=baseWAL module=consensus wal=_agstate/agoric-servers/local-chain-26657/data/cs.wal/wal
3:54PM INF Starting Group service impl=Group module=consensus wal=_agstate/agoric-servers/local-chain-26657/data/cs.wal/wal
3:54PM INF Searching for height height=1 max=0 min=0 module=consensus wal=_agstate/agoric-servers/local-chain-26657/data/cs.wal/wal
3:54PM INF Searching for height height=0 max=0 min=0 module=consensus wal=_agstate/agoric-servers/local-chain-26657/data/cs.wal/wal
3:54PM INF Found height=0 index=0 module=consensus wal=_agstate/agoric-servers/local-chain-26657/data/cs.wal/wal
3:54PM INF Catchup by replaying consensus messages height=1 module=consensus
3:54PM INF Replay: Done module=consensus
3:54PM INF Starting TimeoutTicker service impl=TimeoutTicker module=consensus
3:54PM INF Starting Evidence service impl=Evidence module=evidence
3:54PM INF Saving AddrBook to file book=_agstate/agoric-servers/local-chain-26657/config/addrbook.json module=p2p size=0
3:54PM INF Timed out dur=4991.876946 height=1 module=consensus round=0 step=1
3:54PM INF signed proposal height=1 module=consensus proposal={"Type":32,"block_id":{"hash":"DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880","parts":{"hash":"B3BE2CB6EF1192D078FE76FC9ADAA50AF9D4E134F0F50AF435EA55E05525CCF1","total":1}},"height":1,"pol_round":-1,"round":0,"signature":"jRVad9pI45ac3sxLqIU/f2UVo6p6OHqKTV6cheYVg50AC2XPVRXTQMbO4OFJXMGEdT/cbM7yIawiSWvPymYiAw==","timestamp":"2021-04-14T22:54:29.688087382Z"} round=0
3:54PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880","parts":{"hash":"B3BE2CB6EF1192D078FE76FC9ADAA50AF9D4E134F0F50AF435EA55E05525CCF1","total":1}},"height":1,"pol_round":-1,"round":0,"signature":"jRVad9pI45ac3sxLqIU/f2UVo6p6OHqKTV6cheYVg50AC2XPVRXTQMbO4OFJXMGEdT/cbM7yIawiSWvPymYiAw==","timestamp":"2021-04-14T22:54:29.688087382Z"}
3:54PM INF received complete proposal block hash=DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880 height=1 module=consensus
3:54PM INF signed and pushed vote height=1 module=consensus round=0 vote={"block_id":{"hash":"DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880","parts":{"hash":"B3BE2CB6EF1192D078FE76FC9ADAA50AF9D4E134F0F50AF435EA55E05525CCF1","total":1}},"height":1,"round":0,"signature":"QUbDdWFt44HIKn8Y6m2TGn2uvbj2ssUodTkJFszG1p+9i/KjPi4smBNg0VJzLY8LNhUdmYKrTGbehwUHrMLCAg==","timestamp":"2021-04-14T22:54:29.713461432Z","type":1,"validator_address":"7C4BFEF55FE141CCE0D4C3C8D49ABAE6CB37B628","validator_index":0}
3:54PM INF signed and pushed vote height=1 module=consensus round=0 vote={"block_id":{"hash":"DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880","parts":{"hash":"B3BE2CB6EF1192D078FE76FC9ADAA50AF9D4E134F0F50AF435EA55E05525CCF1","total":1}},"height":1,"round":0,"signature":"4hGvutyzOPpxDm6+hx4kw83txHWOi+LIv4PdnGedhVUCiBUUl3RtEQK7j5JaiTa8sIkx52S6fP3UR6WX5HLgAg==","timestamp":"2021-04-14T22:54:29.733832668Z","type":2,"validator_address":"7C4BFEF55FE141CCE0D4C3C8D49ABAE6CB37B628","validator_index":0}
3:54PM INF added vote to precommit module=consensus precommits="VoteSet{H:1 R:0 T:SIGNED_MSG_TYPE_PRECOMMIT +2/3:DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880:1:B3BE2CB6EF11(1) BA{1:x} map[]}" vote={"block_id":{"hash":"DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880","parts":{"hash":"B3BE2CB6EF1192D078FE76FC9ADAA50AF9D4E134F0F50AF435EA55E05525CCF1","total":1}},"height":1,"round":0,"signature":"4hGvutyzOPpxDm6+hx4kw83txHWOi+LIv4PdnGedhVUCiBUUl3RtEQK7j5JaiTa8sIkx52S6fP3UR6WX5HLgAg==","timestamp":"2021-04-14T22:54:29.733832668Z","type":2,"validator_address":"7C4BFEF55FE141CCE0D4C3C8D49ABAE6CB37B628","validator_index":0}
3:54PM INF finalizing commit of block hash=DEC7C657EB7BEBF879EBDEB67A23F6FDDA6FC508519F0682990D72D1913C0880 height=1 module=consensus num_txs=0 root=E3B0C44298FC1C149AFBF4C8996FB92427AE41E4649B934CA495991B7852B855
2021-04-14T22:54:29.764Z block-manager: block 1 begin
3:54PM INF Timed out dur=3000 height=1 module=consensus round=0 step=3
3:54PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:54PM INF No addresses to dial. Falling back to seeds module=pex
3:55PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:55PM INF No addresses to dial. Falling back to seeds module=pex
3:55PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:55PM INF No addresses to dial. Falling back to seeds module=pex
3:56PM INF Saving AddrBook to file book=_agstate/agoric-servers/local-chain-26657/config/addrbook.json module=p2p size=0
3:56PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:56PM INF No addresses to dial. Falling back to seeds module=pex
3:56PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:56PM INF No addresses to dial. Falling back to seeds module=pex
3:57PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:57PM INF No addresses to dial. Falling back to seeds module=pex
3:57PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
3:57PM INF No addresses to dial. Falling back to seeds module=pex
3:58PM INF created new capability module=ibc name=ports/echo
3:58PM INF port binded module=x/ibc/port port=echo
3:58PM INF claimed capability capability=2 module=dibc name=ports/echo
panic: port transfer is already bound

goroutine 17 [running, locked to thread]:
github.com/cosmos/cosmos-sdk/x/ibc/core/05-port/keeper.(*Keeper).BindPort(0xc00000c730, 0x7f55133f3b00, 0xc0000440c0, 0x7f55134092a0, 0xc001159780, 0xb, 0x0, 0xc0011d1b6a, 0x6, 0x1, ...)
    /home/warner/go/pkg/mod/github.com/cosmos/cosmos-sdk@v0.42.0/x/ibc/core/05-port/keeper/keeper.go:48 +0x58e
github.com/Agoric/agoric-sdk/golang/cosmos/x/dibc/keeper.Keeper.BindPort(0x7f55133d3e80, 0xc0011d2180, 0x7f551340ebc0, 0xc0005923c0, 0x7f55134009a0, 0xc0000d3b80, 0x7f55133b52c0, 0xc00000c730, 0x7f55134098a0, 0xc0005923c0, ...)
    /home/warner/stuff/agoric/agoric-sdk/golang/cosmos/x/dibc/keeper/keeper.go:131 +0x95
github.com/Agoric/agoric-sdk/golang/cosmos/x/dibc.portHandler.Receive(0x7f55134061c0, 0xc0000d3c30, 0x7f55133d3e80, 0xc0011d2180, 0x7f551340ebc0, 0xc0005923c0, 0x7f55134009a0, 0xc0000d3b80, 0x7f55133b52c0, 0xc00000c730, ...)
    /home/warner/stuff/agoric/agoric-sdk/golang/cosmos/x/dibc/ibc.go:155 +0x34b
github.com/Agoric/agoric-sdk/golang/cosmos/x/swingset.ReceiveFromController(0x2, 0xc0004e8000, 0x4d, 0xc000cbbe20, 0xc000cbbe80, 0x7f551155e8cd, 0xc00010a058)
    /home/warner/stuff/agoric/agoric-sdk/golang/cosmos/x/swingset/controller.go:58 +0x169
main.SendToGo(0xc000000002, 0x56fcf10, 0x0)
    /home/warner/stuff/agoric/agoric-sdk/golang/cosmos/cmd/libdaemon/main.go:105 +0x47
main._cgoexpwrap_5b25723df7b2_SendToGo(0x7ffd00000002, 0x56fcf10, 0x0)
    _cgo_gotypes.go:121 +0x6a

cc @michaelfig

warner commented 3 years ago

Ok, nevermind, this turned out to be the result of a stale cosmic-swingset directory: one must run cd packages/cosmic-swingset && make after updating to a branch with significant changes to that package, and yarn build does not do that for you.

I'll file a ticket about making yarn build rebuild the golang binary iff it already exists; that should reduce some of this confusion in the future.