search

Agoric / agoric-sdk

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

agoric-upgrade-10 panics after application #7622

Closed arirubinstein closed 1 year ago

arirubinstein commented 1 year ago

Shortly after the agoric-upgrade-10 upgrade handler is run, the chain panics with the following output:

1:13AM ERR WARNING: The minimum-gas-prices config in app.toml is set to the empty string. This defaults to 0 in the current version, but will error in the next version (SDK v0.45). Please explicitly put the desired minimum-gas-prices in your app.toml.
1:13AM INF Start chain delegating to JS executable args=["ag-chain-cosmos","--home","/root/.agoric","start","--home","netstate"]
1:13AM ERR WARNING: The minimum-gas-prices config in app.toml is set to the empty string. This defaults to 0 in the current version, but will error in the next version (SDK v0.45). Please explicitly put the desired minimum-gas-prices in your app.toml.
1:13AM INF starting node with ABCI Tendermint in-process
1:13AM INF service start impl=multiAppConn module=proxy msg={}
1:13AM INF service start connection=query impl=committingClient module=abci-client msg={}
1:13AM INF service start connection=snapshot impl=committingClient module=abci-client msg={}
1:13AM INF service start connection=mempool impl=committingClient module=abci-client msg={}
1:13AM INF service start connection=consensus impl=committingClient module=abci-client msg={}
1:13AM INF service start impl=EventBus module=events msg={}
1:13AM INF service start impl=PubSub module=pubsub msg={}
1:13AM INF service start impl=IndexerService module=txindex msg={}
1:13AM INF ABCI Handshake App Info hash="\vA��\a���;\x0f�\x18MY;���G�x4?�Sq}�/�\f�" height=133 module=consensus protocol-version=0 software-version=0.32.2
1:13AM INF ABCI Replay Blocks appHeight=133 module=consensus stateHeight=133 storeHeight=134
1:13AM INF Replay last block using real app module=consensus
1:13AM INF applying upgrade "agorictest-upgrade-10" at height: 134
1:13AM INF minted coins from module account amount=205977508ubld from=mint module=x/bank
Loading slog sender modules: @agoric/telemetry/src/flight-recorder.js
2023-05-05T01:13:41.973Z launch-chain: Launching SwingSet kernel
2023-05-05T01:14:09.981Z block-manager: block 134 begin
1:14AM INF executed block height=134 module=consensus num_invalid_txs=0 num_valid_txs=0
2023-05-05T01:14:10.462Z block-manager: block 134 commit
1:14AM INF commit synced commit=436F6D6D697449447B5B38372035342032343220313734203139372031393120353620323335203139392031353420333620343320353120313738203130302033342032333220313439203220313433203331203939203230322032352031313320313532203134332032303620313738203235352031322036315D3A38367D
1:14AM INF committed state app_hash=5736F2AEC5BF38EBC79A242B33B26422E895028F1F63CA1971988FCEB2FF0C3D height=134 module=consensus num_txs=0
1:14AM INF Completed ABCI Handshake - Tendermint and App are synced appHash="\vA��\a���;\x0f�\x18MY;���G�x4?�Sq}�/�\f�" appHeight=133 module=consensus
1:14AM INF Version info block=11 p2p=8 tendermint_version=0.34.23
1:14AM INF This node is a validator addr=EBCB14D90C0A8767CDA4BD33E5A9F0ABDFCD32DA module=consensus pubKey=Wa1t0C9g3FWgcvGHvTMl51LauUCcZBFynSdtFJoq/xM=
1:14AM INF indexed block exents height=134 module=txindex
1:14AM INF P2P Node ID ID=f47224b10f1080ec5185b66941c05bf1c69395e2 file=netstate/config/node_key.json module=p2p
1:14AM INF Adding persistent peers addrs=[] module=p2p
1:14AM INF Adding unconditional peer ids ids=[] module=p2p
1:14AM INF Add our address to book addr={"id":"f47224b10f1080ec5185b66941c05bf1c69395e2","ip":"0.0.0.0","port":26656} book=netstate/config/addrbook.json module=p2p
1:14AM INF service start impl=Node msg={}
1:14AM INF Starting pprof server laddr=localhost:6060
1:14AM INF service start impl="P2P Switch" module=p2p msg={}
1:14AM INF service start impl=BlockchainReactor module=blockchain msg={}
1:14AM INF service start impl=ConsensusReactor module=consensus msg={}
1:14AM INF Reactor  module=consensus waitSync=false
1:14AM INF service start impl=ConsensusState module=consensus msg={}
1:14AM INF serve module=rpc-server msg={}
1:14AM INF service start impl=baseWAL module=consensus msg={} wal=netstate/data/cs.wal/wal
1:14AM INF service start impl=Group module=consensus msg={} wal=netstate/data/cs.wal/wal
1:14AM INF service start impl=TimeoutTicker module=consensus msg={}
1:14AM INF Searching for height height=135 max=0 min=0 module=consensus wal=netstate/data/cs.wal/wal
1:14AM INF Searching for height height=134 max=0 min=0 module=consensus wal=netstate/data/cs.wal/wal
1:14AM INF Found height=134 index=0 module=consensus wal=netstate/data/cs.wal/wal
1:14AM INF Catchup by replaying consensus messages height=135 module=consensus
1:14AM INF Replay: Done module=consensus
1:14AM INF service start impl=Evidence module=evidence msg={}
1:14AM INF service start impl=StateSync module=statesync msg={}
1:14AM INF service start impl=PEX module=pex msg={}
1:14AM INF service start book=netstate/config/addrbook.json impl=AddrBook module=p2p msg={}
1:14AM INF Saving AddrBook to file book=netstate/config/addrbook.json module=p2p size=0
1:14AM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=0 numToDial=10
1:14AM INF No addresses to dial. Falling back to seeds module=pex
1:14AM INF Timed out dur=994.869917 height=135 module=consensus round=0 step=1
1:14AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"9E0FE9D16415E48A2123D873F70E9CC73F91CE764E3C91064A97CAF030FE7303","parts":{"hash":"92A0042BB0C3ED3D67DAA330034F14F87DB887FB1AEE5284DE6E4032BE24CD5C","total":1}},"height":135,"pol_round":-1,"round":0,"signature":"5ok5N5oaYKBrOCz0N3X/ms88vGZFnMlOQ1MJwmmKjLlKIsGCtMLYJvqi5RBXBAa783tXmQpY2pd2HfNCv2NcBQ==","timestamp":"2023-05-05T01:14:11.562160429Z"}
1:14AM INF received complete proposal block hash=9E0FE9D16415E48A2123D873F70E9CC73F91CE764E3C91064A97CAF030FE7303 height=135 module=consensus
1:14AM INF finalizing commit of block hash={} height=135 module=consensus num_txs=0 root=5736F2AEC5BF38EBC79A242B33B26422E895028F1F63CA1971988FCEB2FF0C3D
1:14AM INF minted coins from module account amount=205977544ubld from=mint module=x/bank
2023-05-05T01:14:11.574Z block-manager: block 135 begin
1:14AM INF executed block height=135 module=state num_invalid_txs=0 num_valid_txs=0
2023-05-05T01:14:12.128Z block-manager: block 135 commit
1:14AM INF commit synced commit=436F6D6D697449447B5B3239203837203231372031313120313836203731203134372032313020313735203836203335203235332032323120313520333020313533203235302032333520313234203730203137362031373520363020342034342031363320363020313534203235322031333520313338203233345D3A38377D
1:14AM INF committed state app_hash=1D57D96FBA4793D2AF5623FDDD0F1E99FAEB7C46B0AF3C042CA33C9AFC878AEA height=135 module=state num_txs=0
1:14AM INF indexed block exents height=135 module=txindex
1:14AM INF Timed out dur=437.037958 height=136 module=consensus round=0 step=1
1:14AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"6EC55A86541809BABF52670FA4BD249DAF521815354F8D51E2B0C08B3ABAEB22","parts":{"hash":"5C6A4A218100877E3749B3D19E9C7CBE9D794C4619662E88C56468CC68468B64","total":1}},"height":136,"pol_round":-1,"round":0,"signature":"IOea6RLVBxmNZWol3rFfuVw3xfQH5ZntMz6arg43Ixo4IX+qg+N1s7JWMBix8Gzpmx2ZrwdjKxr08HtWUYwyBQ==","timestamp":"2023-05-05T01:14:12.573004179Z"}
1:14AM INF received complete proposal block hash=6EC55A86541809BABF52670FA4BD249DAF521815354F8D51E2B0C08B3ABAEB22 height=136 module=consensus
1:14AM INF finalizing commit of block hash={} height=136 module=consensus num_txs=0 root=1D57D96FBA4793D2AF5623FDDD0F1E99FAEB7C46B0AF3C042CA33C9AFC878AEA
1:14AM INF minted coins from module account amount=205977581ubld from=mint module=x/bank
2023-05-05T01:14:12.585Z block-manager: block 136 begin
1:14AM INF Timed out dur=3000 height=136 module=consensus round=0 step=3
panic: account is not a module account

goroutine 17 [running, locked to thread]:
github.com/cosmos/cosmos-sdk/x/auth/keeper.accountKeeper.GetModuleAccountAndPermissions({{0xffff831d78c0, 0x40002252d0}, {0xffff831f80e0, 0x4000e860d0}, {{0xffff831f80e0, 0x4000e860d0}, 0x4000558000, {0xffff831d78c0, 0x4000225340}, {0xffff831d7910, ...}, ...}, ...}, ...)
        /go/pkg/mod/github.com/agoric-labs/cosmos-sdk@v0.45.11-alpha.agoric.2/x/auth/keeper/keeper.go:235 +0x350
github.com/cosmos/cosmos-sdk/x/auth/keeper.accountKeeper.GetModuleAccount(...)
        /go/pkg/mod/github.com/agoric-labs/cosmos-sdk@v0.45.11-alpha.agoric.2/x/auth/keeper/keeper.go:251
github.com/Agoric/agoric-sdk/golang/cosmos/x/vbank/keeper.Keeper.GetModuleAccountAddress({{0xffff831d78c0, 0x4000225520}, {0xffff831fcd58, 0x4000e860d0}, {{0xffff831f80e0, 0x4000e860d0}, 0x4000558000, {0xffff831d78c0, 0x4000225340}, {0xffff831d7910, ...}, ...}, ...}, ...)
        /usr/src/agoric-sdk/golang/cosmos/x/vbank/keeper/keeper.go:83 +0x64
github.com/Agoric/agoric-sdk/golang/cosmos/x/vbank.portHandler.Receive({{{}, {{0xffff831d78c0, 0x4000225520}, {0xffff831fcd58, 0x4000e860d0}, {{...}, 0x4000558000, {...}, {...}, {...}, ...}, ...}}, ...}, ...)
        /usr/src/agoric-sdk/golang/cosmos/x/vbank/vbank.go:227 +0xd08
github.com/Agoric/agoric-sdk/golang/cosmos/vm.ReceiveFromController(0xffff824d7764?, {0x40050dee60, 0x4a})
        /usr/src/agoric-sdk/golang/cosmos/vm/controller.go:79 +0x70
main.SendToGo(0x3, 0x4000002680?)
        /usr/src/agoric-sdk/golang/cosmos/cmd/libdaemon/main.go:124 +0x40
/usr/src/agoric-sdk/ut_start_dest.sh: line 4:     7 Aborted                 agd start --home "$STATEDIR"

To Reproduce:

  1. git clone git@github.com:Agoric/docker-upgrade-test.git && cd docker-upgrade-test
  2. docker build .
  3. docker run --expose 26656 --expose 26657 --rm -it <image_id_from_step_2>
JimLarson commented 1 year ago

The Go panic comes from a bridge message VBANK_GET_MODULE_ACCOUNT_ADDRESS naming something that isn't a module account. The Swingset side seems to generate that request only for vbank/reserve and vbank/provision, which app.go seems to think are module addresses. Strange. I'll see if something has changed since upgrade-9.

JimLarson commented 1 year ago

The address is fine as a module address, but the underlying account was created as a normal account. Presumably this happened by transferring funds into the provision account, since it's exempted from the usual prohibition of transferring external funds into a module account. We specifically exclude it from the list of blocked addresses: https://github.com/Agoric/agoric-sdk/blob/35e5e303bf8d98a8c2fe4a0815bafe8ff00317b5/golang/cosmos/app/app.go#L914

@raphdev verified this in the reproduction scenario, and we can see the offending transfer: https://github.com/Agoric/docker-upgrade-test/blob/46a021460f9d503a28465ea18172510f6d1defaf/ut_chainsetup_from.sh#L7

However, the test should stay as-is, as this premature account creation seems to have happened on mainnet:

$ agd query auth module-account vbank/provision --chain-id agoric-3 --node https://main.rpc.agoric.net:443
Error: rpc error: code = Unknown desc = account is not a module account: panic
...

$ agd query auth account agoric1megzytg65cyrgzs6fvzxgrcqvwwl7ugpt62346 --chain-id agoric-3 --node https://main.rpc.agoric.net:443
'@type': /cosmos.auth.v1beta1.BaseAccount
account_number: "59646"
address: agoric1megzytg65cyrgzs6fvzxgrcqvwwl7ugpt62346
pub_key: null
sequence: "0"

Note that @michaelfig predicted this yesterday.

I'll modify the upgrade handler to convert the account type for the provision account.