dymensionxyz / dymint

Sequencing Engine for Dymension RollApps
Other
90 stars 61 forks source link

rollapp evm on devnet crashing with `LastResultHash mismatch` #365

Closed omritoptix closed 1 year ago

omritoptix commented 1 year ago

We need to understand what's the cause of it and make sure it's not producable in current version. Important to not upgrade before we understand the cause.

mtsitrin commented 1 year ago
time="2023-06-17T02:19:55Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-17T02:19:55Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-17T02:19:55Z" level=error msg="failed to submit batch to SL layer[startHeight 7500001 endHeight 7501500 error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager
time="2023-06-17T02:19:55Z" level=error msg="Failed to submit batch to SL Layer[startHeight 7500001 endHeight 7501500 error failed to submit batch to SL layer: rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager

After the reset:

time="2023-06-17T02:20:19Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Synced, Starting to produce[current height 19485031 syncTarget 7500000]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Synced at height[height 19485031]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Using pending block[height 19485032]" module=BlockManager
time="2023-06-17T02:20:19Z" level=debug msg="Gossiping block[len 1909]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="Applying block[height 19485032 source produced]" module=BlockManager
time="2023-06-17T02:20:19Z" level=error msg="Failed to execute block[error LastResultsHash mismatch]" module=BlockManager
time="2023-06-17T02:20:19Z" level=error msg="error while producing block[error LastResultsHash mismatch]" module=BlockManager
mtsitrin commented 1 year ago

So For at least a day the sequencer had no funds

The rollapp once in a while resets because of it:

time="2023-06-16T20:00:21Z" level=info msg="Unlocking keyring[]"
time="2023-06-16T20:08:24Z" level=info msg="Unlocking keyring[]"
time="2023-06-16T20:16:24Z" level=info msg="Unlocking keyring[]"
time="2023-06-16T20:24:06Z" level=info msg="Unlocking keyring[]"
time="2023-06-16T20:32:06Z" level=info msg="Unlocking keyring[]"
...

most of the time it starts by creating new block

me="2023-06-16T20:00:51Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-16T20:00:51Z" level=info msg="Started retrieve loop[]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Started sync target loop[]" module=BlockManager
time="2023-06-16T20:00:51Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-16T20:00:51Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Synced, Starting to produce[current height 19376919 syncTarget 7500000]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Synced at height[height 19376919]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Synced at height[height 19376919]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="Creating block[height 19376920]" module=BlockManager
time="2023-06-16T20:00:51Z" level=debug msg="block info[num_tx 0]" module=BlockManager
time="2023-06-16T20:00:51Z" level=debug msg="Gossiping block[len 529]" module=p2p
time="2023-06-16T20:00:51Z" level=info msg="Applying block[height 19376920 source produced]" module=BlockManager
time="2023-06-16T20:00:51Z" level=info msg="commit synced[commit 436F6D6D697449447B5B3431203833203839203134203134362038392037362031372031313520323433203438203231352035342031333520363320353320323436203134302031383220323820313630203132312031342031353620313620353320313020313839203535203234322037312036375D3A313237414231387D]"
time="2023-06-16T20:00:51Z" level=info msg="indexed block[height 19376920]" module=txindex
time="2023-06-16T20:00:51Z" level=debug msg="indexed block txs[height 19376920 num_txs 0]" module=txindex

ONCE it used the pending block:

time="2023-06-16T22:22:49Z" level=debug msg="Submitting batch to settlement layer[start height 7500001 end height 7501500]" module=settlement_client
time="2023-06-16T22:22:49Z" level=info msg="Creating block[height 19417476]" module=BlockManager
time="2023-06-16T22:22:49Z" level=debug msg="block info[num_tx 0]" module=BlockManager
time="2023-06-16T22:22:49Z" level=debug msg="Gossiping block[len 529]" module=p2p
time="2023-06-16T22:22:49Z" level=info msg="Applying block[height 19417476 source produced]" module=BlockManager
time="2023-06-16T22:22:49Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-16T22:22:49Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-16T22:22:49Z" level=error msg="failed to submit batch to SL layer[startHeight 7500001 endHeight 7501500 error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager
time="2023-06-16T22:22:49Z" level=error msg="Failed to submit batch to SL Layer[startHeight 7500001 endHeight 7501500 error failed to submit batch to SL layer: rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager
time="2023-06-16T22:22:55Z" level=info msg="Unlocking keyring[]"
time="2023-06-16T22:22:55Z" level=info msg="starting ABCI with Dymint[]"
time="2023-06-16T22:22:55Z" level=error msg="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.[]"
time="2023-06-16T22:23:12Z" level=info msg="starting node with ABCI dymint in-process[]"
time="2023-06-16T22:23:12Z" level=info msg="service start[msg Starting multiAppConn service impl multiAppConn]" module=proxy
...
time="2023-06-16T22:23:13Z" level=debug msg="settlement Layer Client starting.[]" module=settlement_client
time="2023-06-16T22:23:13Z" level=info msg="started state updates handler loop[]" module=settlement_client
time="2023-06-16T22:23:13Z" level=info msg="serve[msg Starting RPC HTTP server on [::]:1317]" module=api-server
time="2023-06-16T22:23:13Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-16T22:23:13Z" level=info msg="Started retrieve loop[]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Started sync target loop[]" module=BlockManager
time="2023-06-16T22:23:13Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-16T22:23:13Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Synced at height[height 19417475]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Synced, Starting to produce[current height 19417475 syncTarget 7500000]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Synced at height[height 19417475]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="Using pending block[height 19417476]" module=BlockManager
time="2023-06-16T22:23:13Z" level=debug msg="Gossiping block[len 529]" module=p2p
time="2023-06-16T22:23:13Z" level=info msg="Applying block[height 19417476 source produced]" module=BlockManager
time="2023-06-16T22:23:13Z" level=info msg="commit synced[commit 436F6D6D697449447B5B3136322031333520323237203732203134382038332031352031383520313137203931203230312035382031333120353020323430203737203834203234342032323320343120313334203234372031393920313837203231332031313820313638203231332033322038392031312037335D3A313238343938347D]"
time="2023-06-16T22:23:13Z" level=info msg="indexed block[height 19417476]" module=txindex
time="2023-06-16T22:23:13Z" level=debug msg="indexed block txs[height 19417476 num_txs 0]" module=txindex
mtsitrin commented 1 year ago

In the "broken" state


time="2023-06-17T02:19:55Z" level=info msg="client state updated[client-id 07-tendermint-0 height 0-1005806]" module=x/ibc/client
time="2023-06-17T02:19:55Z" level=debug msg="inserted new valid transaction[priority 0 tx 14A86795B001815FFF4D6F6C77993E5D0BC5774C98844D34770179A8A25CABE5 height 19485031 num_txs 1]"
time="2023-06-17T02:19:55Z" level=debug msg="Gossiping TX[len 1376]" module=p2p
time="2023-06-17T02:19:55Z" level=debug msg="Submitting batch to settlement layer[start height 7500001 end height 7501500]" module=settlement_client
time="2023-06-17T02:19:55Z" level=info msg="Creating block[height 19485032]" module=BlockManager
time="2023-06-17T02:19:55Z" level=debug msg="block info[num_tx 1]" module=BlockManager
time="2023-06-17T02:19:55Z" level=debug msg="Gossiping block[len 1909]" module=p2p
time="2023-06-17T02:19:55Z" level=info msg="Applying block[height 19485032 source produced]" module=BlockManager
time="2023-06-17T02:19:55Z" level=info msg="client state updated[client-id 07-tendermint-0 height 0-1005806]" module=x/ibc/client
time="2023-06-17T02:19:55Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-17T02:19:55Z" level=error msg="Error sending batch to settlement layer[error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=settlement_client
time="2023-06-17T02:19:55Z" level=error msg="failed to submit batch to SL layer[startHeight 7500001 endHeight 7501500 error rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager
time="2023-06-17T02:19:55Z" level=error msg="Failed to submit batch to SL Layer[startHeight 7500001 endHeight 7501500 error failed to submit batch to SL layer: rpc error: code = Unknown desc = rpc error: code = Unknown desc = 0udym is smaller than 2000000udym: insufficient funds: insufficient funds [cosmos/cosmos-sdk@v0.45.10/x/auth/ante/fee.go:139] With gas wanted: '0' and gas used: '1146560' : unknown request]" module=BlockManager

time="2023-06-17T02:20:00Z" level=info msg="Unlocking keyring[]"
time="2023-06-17T02:20:00Z" level=info msg="starting ABCI with Dymint[]"
time="2023-06-17T02:20:00Z" level=error msg="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.[]"
time="2023-06-17T02:20:19Z" level=info msg="starting node with ABCI dymint in-process[]"
time="2023-06-17T02:20:19Z" level=info msg="service start[msg Starting multiAppConn service impl multiAppConn]" module=proxy
...
time="2023-06-17T02:20:19Z" level=info msg="service start[msg Starting Node service impl Node]"
time="2023-06-17T02:20:19Z" level=info msg="starting P2P client[]"
time="2023-06-17T02:20:19Z" level=debug msg="starting P2P client[]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="serving HTTP[listen address [::]:26657]"
time="2023-06-17T02:20:19Z" level=info msg="listening on[address /ip4/172.31.86.169/tcp/26656/p2p/12D3KooWCzqXCZTuh4jSvo7drQ7wRHgrkC6Vq8icHuKiNvPG2e78]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="listening on[address /ip4/127.0.0.1/tcp/26656/p2p/12D3KooWCzqXCZTuh4jSvo7drQ7wRHgrkC6Vq8icHuKiNvPG2e78]" module=p2p
time="2023-06-17T02:20:19Z" level=debug msg="setting up gossiping[]" module=p2p
time="2023-06-17T02:20:19Z" level=debug msg="setting up DHT[]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="no seed nodes - only listening for connections[]" module=p2p
time="2023-06-17T02:20:19Z" level=debug msg="setting up active peer discovery[]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="starting Celestia Data Availability Layer Client[baseURL http://172.31.31.92:26659]" module=da_client
time="2023-06-17T02:20:19Z" level=debug msg="settlement Layer Client starting.[]" module=settlement_client
time="2023-06-17T02:20:19Z" level=info msg="started state updates handler loop[]" module=settlement_client
time="2023-06-17T02:20:19Z" level=info msg="serve[msg Starting RPC HTTP server on [::]:1317]" module=api-server
time="2023-06-17T02:20:19Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-17T02:20:19Z" level=info msg="Started retrieve loop[]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Started sync target loop[]" module=BlockManager
time="2023-06-17T02:20:19Z" level=debug msg="Getting latest batch from settlement layer[]" module=settlement_client
time="2023-06-17T02:20:19Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Received new syncTarget[syncTarget 7500000]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Synced, Starting to produce[current height 19485031 syncTarget 7500000]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Synced at height[height 19485031]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Using pending block[height 19485032]" module=BlockManager
time="2023-06-17T02:20:19Z" level=debug msg="Gossiping block[len 1909]" module=p2p
time="2023-06-17T02:20:19Z" level=info msg="Applying block[height 19485032 source produced]" module=BlockManager
time="2023-06-17T02:20:19Z" level=error msg="Failed to execute block[error LastResultsHash mismatch]" module=BlockManager
time="2023-06-17T02:20:19Z" level=error msg="error while producing block[error LastResultsHash mismatch]" module=BlockManager
time="2023-06-17T02:20:19Z" level=info msg="Using pending block[height 19485032]" module=BlockManager
mtsitrin commented 1 year ago

It's the current snapshot of the db:

LastBlockHeight: 19485032
LastStoreHeight: 19485031
LastBlockHeight != LastStoreHeight
Parsed state: {Version:{Consensus:{Block:11 App:0} Software:0.34.24} ChainID:rollappevm_100_1 InitialHeight:1 LastBlockHeight:19485032 LastBlockID:4A325EFD5BE1023E25DEE8BEDCA9F1A50B8EC1661B982B69F3A59B5B8F16353B:0:000000000000 LastBlockTime:2023-06-17 02:19:55.238666634 +0000 UTC SLStateIndex:0 NextValidators:ValidatorSet{
  Proposer: Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
  Validators:
    Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
} Validators:ValidatorSet{
  Proposer: Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
  Validators:
    Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
} LastValidators:ValidatorSet{
  Proposer: Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
  Validators:
    Validator{575921FE274B4C7B4AB039AF036703BB8E654842 PubKeyEd25519{8B3A747AD24746B17F12C846A0654852729BB000CAF5C18DD8D5C6B889B0EC1D} VP:1 A:0}
} LastHeightValidatorsChanged:1 ConsensusParams:{Block:{MaxBytes:22020096 MaxGas:40000000 TimeIotaMs:1000} Evidence:{MaxAgeNumBlocks:100000 MaxAgeDuration:48h0m0s MaxBytes:1048576} Validator:{PubKeyTypes:[ed25519]} Version:{AppVersion:0}} LastHeightConsensusParamsChanged:1 LastResultsHash:[200 188 36 236 17 249 56 156 11 173 172 105 124 10 111 204 232 206 167 70 200 196 101 127 74 165 53 206 92 1 49 57] LastStoreHeight:19485031 AppHash:[122 221 146 109 190 105 103 48 222 147 121 149 66 6 48 174 49 120 0 155 22 79 183 112 75 12 33 191 43 96 166 210]}
========================================
Parsed block: &{Header:{Version:{Block:11 App:0} NamespaceID:[0 0 0 0 0 0 255 255] Height:19485031 Time:1686968395039596535 LastHeaderHash:[255 194 126 24 138 88 65 5 248 246 239 158 105 253 111 149 225 230 249 120 2 196 74 192 40 145 85 248 197 215 56 105] LastCommitHash:[190 14 42 128 67 215 178 21 39 147 14 130 79 56 49 162 246 156 118 169 224 68 23 141 190 85 22 12 80 253 41 205] DataHash:[227 176 196 66 152 252 28 20 154 251 244 200 153 111 185 36 39 174 65 228 100 155 147 76 164 149 153 27 120 82 184 85] ConsensusHash:[0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0] AppHash:[180 172 176 192 92 174 141 206 113 36 28 66 128 193 153 193 218 43 22 136 98 223 210 32 129 200 83 43 154 184 149 27] LastResultsHash:[227 176 196 66 152 252 28 20 154 251 244 200 153 111 185 36 39 174 65 228 100 155 147 76 164 149 153 27 120 82 184 85] ProposerAddress:[87 89 33 254 39 75 76 123 74 176 57 175 3 103 3 187 142 101 72 66] AggregatorsHash:[96 96 235 35 11 62 121 200 156 121 28 92 255 78 181 124 30 206 223 196 31 203 145 80 159 109 161 89 94 62 203 36] ChainID:rollappevm_100_1} Data:{Txs:[] IntermediateStateRoots:{RawRootsList:[]} Evidence:{Evidence:[]}} LastCommit:{Height:19485030 HeaderHash:[255 194 126 24 138 88 65 5 248 246 239 158 105 253 111 149 225 230 249 120 2 196 74 192 40 145 85 248 197 215 56 105] Signatures:[[236 214 154 48 109 103 116 252 39 156 180 142 206 57 81 44 199 25 7 253 243 83 114 18 146 2 221 224 238 40 168 46 185 143 170 178 126 47 140 46 1 96 28 228 41 149 41 146 30 196 229 225 200 202 0 50 13 101 143 52 168 58 149 11]]}}