osmosis: tendermint wrong Block.Header.AppHash bug

Context

Report 1

seen on pruning settings: 100/0/10
this happened on the relayer node
This was not OOM, it just happened during regular operation. The node doesn’t actually crash it just sits in an endless loop of dialing peers and getting pong timeout. The logs that you see are a couple of blocks pre-crash.
other nodes running pruning=everything seem to work
Another node that was started from the same data folder backup is still running with an identical configuration, so it’s non-deterministic to this point.

Logs

 4:00AM INF indexed block height=3490885 module=txindex
 4:00AM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=50 numToDial=0
 4:00AM INF Timed out dur=4685.039831 height=3490886 module=consensus round=0 step=1
 4:00AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"467CC1EC467FF070ADBE4DBE22FC55C114F41D633D1E41E4CE372A19C2C97C50","parts":{"hash":"6C3F2E43DEDE6B49E7227E11CC6898161AEE78A3E06928DFC012AB0785B8886F","total":3}},"height":3490886,"pol_round":-1,"round":0,"signature":"mbzXIrrMQPoL4RiLaj4RdLdMj3CMFCJLqUl/CejYOh2s9/Ar40+DZVGPEN6nE7pGXJwK9sD20oYg+bCUmIMOAQ==","timestamp":"2022-03-07T09:00:07.314313098Z"}
 4:00AM INF received complete proposal block hash=467CC1EC467FF070ADBE4DBE22FC55C114F41D633D1E41E4CE372A19C2C97C50 height=3490886 module=consensus
 4:00AM INF finalizing commit of block hash=467CC1EC467FF070ADBE4DBE22FC55C114F41D633D1E41E4CE372A19C2C97C50 height=3490886 module=consensus num_txs=15 root=2FC146C364361339D8A274F72BF23CD96B9E4797261635B81F9196541506841B
 4:00AM INF burned tokens from module account amount=12309533ibc/987C17B11ABC2B20019178ACE62929FE9840202CE79498E29FE8E5CB02B7C0A4 from=transfer module=x/bank
 4:00AM INF packet sent dst_channel=channel-0 dst_port=transfer module=x/ibc/channel sequence=90381 src_channel=channel-75 src_port=transfer
 4:00AM INF IBC fungible token transfer amount=12309533 module=x/ibc-transfer receiver=stars1rdkfvdrvmxw7zlazwaqnuusm75ql60eqcyjmdp sender=osmo1rdkfvdrvmxw7zlazwaqnuusm75ql60eqyrkksz token=ibc/987C17B11ABC2B20019178ACE62929FE9840202CE79498E29FE8E5CB02B7C0A4
 4:00AM INF burned tokens from module account amount=36651579ibc/BE1BB42D4BE3C30D50B68D7C41DB4DFCE9678E8EF8C539F6E6A9345048894FCC from=transfer module=x/bank
 4:00AM INF packet sent dst_channel=channel-1 dst_port=transfer module=x/ibc/channel sequence=209719 src_channel=channel-72 src_port=transfer
 4:00AM INF IBC fungible token transfer amount=36651579 module=x/ibc-transfer receiver=terra1hx36chwr5c5tu05njjv37jme2t2vwwe42jffts sender=osmo1ememjxygxrtrdqe0xqr27tc3ms5aam9k5dc77u token=ibc/BE1BB42D4BE3C30D50B68D7C41DB4DFCE9678E8EF8C539F6E6A9345048894FCC
 4:00AM INF client state updated client-id=07-tendermint-1 height=4-9665606 module=x/ibc/client
 4:00AM INF packet received module=x/ibc/channel packet="{594255 transfer channel-141 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 55 56 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 97 116 111 109 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 97 50 48 52 52 117 121 118 97 52 122 100 50 57 122 121 108 102 109 113 104 99 120 119 53 118 115 53 50 50 117 102 54 101 108 99 50 53 34 44 34 115 101 110 100 101 114 34 58 34 99 111 115 109 111 115 49 97 50 48 52 52 117 121 118 97 52 122 100 50 57 122 121 108 102 109 113 104 99 120 119 53 118 115 53 50 50 117 102 106 122 118 103 117 120 34 125] 1-3490900 0}"
 4:00AM INF minted coins from module account amount=78000000ibc/27394FB092D2ECCD56123C74F36E4C1F926001CEADA9CA97EA622B25F41E5EB2 from=transfer module=x/bank
 4:00AM INF acknowledged written module=x/ibc/channel packet="{594255 transfer channel-141 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 55 56 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 97 116 111 109 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 97 50 48 52 52 117 121 118 97 52 122 100 50 57 122 121 108 102 109 113 104 99 120 119 53 118 115 53 50 50 117 102 54 101 108 99 50 53 34 44 34 115 101 110 100 101 114 34 58 34 99 111 115 109 111 115 49 97 50 48 52 52 117 121 118 97 52 122 100 50 57 122 121 108 102 109 113 104 99 120 119 53 118 115 53 50 50 117 102 106 122 118 103 117 120 34 125] 1-3490900 0}"
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{528676 transfer channel-0 transfer channel-141 [123 34 97 109 111 117 110 116 34 58 34 50 48 49 57 53 52 48 54 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 48 47 117 97 116 111 109 34 44 34 114 101 99 101 105 118 101 114 34 58 34 99 111 115 109 111 115 49 57 113 55 53 109 116 53 103 51 120 57 107 121 57 104 104 101 48 122 108 54 116 100 54 55 103 97 116 97 102 121 54 53 122 102 109 118 119 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 57 113 55 53 109 116 53 103 51 120 57 107 121 57 104 104 101 48 122 108 54 116 100 54 55 103 97 116 97 102 121 54 117 101 54 116 54 117 34 125] 4-9665747 0}"
 4:00AM INF client state updated client-id=07-tendermint-1 height=4-9665606 module=x/ibc/client
 4:00AM INF client state updated client-id=07-tendermint-1 height=4-9665606 module=x/ibc/client
 4:00AM INF client state updated client-id=07-tendermint-1 height=4-9665606 module=x/ibc/client
 4:00AM INF minted coins from module account amount=368922023284144188095228gamm/pool/5 from=gamm module=x/bank
 4:00AM INF executed block height=3490886 module=state num_invalid_txs=2 num_valid_txs=13
 4:00AM INF commit synced commit=436F6D6D697449447B5B313731203138372038312035342031392031362031323220313030203134392031333920323720323020313433203137342037372031323920383320313830203335203136332031392031383720353720383620323036203736203139372031323420393420323033203132372037335D3A3335343434367D
 4:00AM INF committed state app_hash=ABBB513613107A64958B1B148FAE4D8153B423A313BB3956CE4CC57C5ECB7F49 height=3490886 module=state num_txs=15
 4:00AM INF indexed block height=3490886 module=txindex
 4:00AM INF Timed out dur=4783.291405 height=3490887 module=consensus round=0 step=1
 4:00AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"1DAEBEEAC92B5B6D3FB1CE0576ED6D3D0DF221E8481E686FDA7F192993DBE3B8","parts":{"hash":"9909087200424547E0A60F42768B74BA3CF92E8E130F3F4840E9C9B609B077C3","total":1}},"height":3490887,"pol_round":-1,"round":0,"signature":"0jUmccX06Jw8DByVVHbsBb43R3Go+OiqDZRctHbnG1aS/1BesNWg38DR6fESkEN+BrKidkvdw4P3LaddcoXVBQ==","timestamp":"2022-03-07T09:00:13.285334062Z"}
 4:00AM INF received complete proposal block hash=1DAEBEEAC92B5B6D3FB1CE0576ED6D3D0DF221E8481E686FDA7F192993DBE3B8 height=3490887 module=consensus
 4:00AM INF finalizing commit of block hash=1DAEBEEAC92B5B6D3FB1CE0576ED6D3D0DF221E8481E686FDA7F192993DBE3B8 height=3490887 module=consensus num_txs=17 root=ABBB513613107A64958B1B148FAE4D8153B423A313BB3956CE4CC57C5ECB7F49
 4:00AM INF minted coins from module account amount=36199772072901574754gamm/pool/1 from=gamm module=x/bank
 4:00AM INF executed block height=3490887 module=state num_invalid_txs=6 num_valid_txs=11
 4:00AM INF commit synced commit=436F6D6D697449447B5B34342032343020313030203135382032303620313734203136332032323920323220363420313232203135203138332032313820343820313120313331203130312031393020313335203931203234203130372032323520323120313138203130362031203131302031303320313436203232355D3A3335343434377D
 4:00AM INF committed state app_hash=2CF0649ECEAEA3E516407A0FB7DA300B8365BE875B186BE115766A016E6792E1 height=3490887 module=state num_txs=17
 4:00AM INF indexed block height=3490887 module=txindex
 4:00AM INF client state updated client-id=07-tendermint-1457 height=1-2178766 module=x/ibc/client
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335723 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 49 48 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 104 113 53 121 121 48 115 51 119 108 48 53 119 114 57 121 119 119 56 122 108 115 114 117 113 112 97 112 112 100 50 55 112 104 121 101 51 113 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 104 113 53 121 121 48 115 51 119 108 48 53 119 114 57 121 119 119 56 122 108 115 114 117 113 112 97 112 112 100 50 55 108 55 53 106 113 119 34 125] 1-2178909 0}"
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335724 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 49 53 54 51 56 56 53 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 113 112 99 53 103 109 116 52 52 99 110 53 109 117 55 104 119 57 100 117 102 56 55 53 106 56 116 54 100 52 107 114 119 115 108 54 100 109 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 113 112 99 53 103 109 116 52 52 99 110 53 109 117 55 104 119 57 100 117 102 56 55 53 106 56 116 54 100 52 107 114 115 101 48 51 117 52 34 125] 1-2178910 0}"
 4:00AM INF Timed out dur=4815.169894 height=3490888 module=consensus round=0 step=1
 4:00AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"247C12BE0218EFCA47D1936BC389489A6A631DBE5F8EC7787EF2129DB3301A21","parts":{"hash":"BF2AE3FFD2BFC8474397CEAB679F2E32DA716DC3F88982F7349F06A70D8ADAC0","total":3}},"height":3490888,"pol_round":-1,"round":0,"signature":"zdgzoFLF9kX4OPE99sscYZXT7CFieOR7g4++dZljLlv0HogEnQKGkKW7qk0lfwI78SwW1hB0/4glRk9z9EYsCg==","timestamp":"2022-03-07T09:00:19.425930568Z"}
 4:00AM INF received complete proposal block hash=247C12BE0218EFCA47D1936BC389489A6A631DBE5F8EC7787EF2129DB3301A21 height=3490888 module=consensus
 4:00AM INF client state updated client-id=07-tendermint-1457 height=1-2178767 module=x/ibc/client
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335725 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 49 49 54 55 52 52 53 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 107 97 116 120 112 120 107 107 106 120 57 97 104 107 109 117 48 101 115 108 115 109 117 108 48 108 116 118 56 115 116 100 116 99 116 107 52 48 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 107 97 116 120 112 120 107 107 106 120 57 97 104 107 109 117 48 101 115 108 115 109 117 108 48 108 116 118 56 115 116 100 52 51 109 97 121 112 34 125] 1-2178912 0}"
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335726 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 53 49 53 55 55 50 51 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 107 112 53 108 99 104 121 54 52 120 121 102 51 100 112 121 97 109 54 54 102 116 113 99 112 103 53 109 108 54 57 104 48 102 100 114 103 97 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 107 112 53 108 99 104 121 54 52 120 121 102 51 100 112 121 97 109 54 54 102 116 113 99 112 103 53 109 108 54 57 104 51 113 97 103 101 110 34 125] 1-2178912 0}"
 4:00AM INF finalizing commit of block hash=247C12BE0218EFCA47D1936BC389489A6A631DBE5F8EC7787EF2129DB3301A21 height=3490888 module=consensus num_txs=20 root=2CF0649ECEAEA3E516407A0FB7DA300B8365BE875B186BE115766A016E6792E1
 4:00AM INF client state updated client-id=07-tendermint-1457 height=1-2178766 module=x/ibc/client
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335723 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 49 48 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 104 113 53 121 121 48 115 51 119 108 48 53 119 114 57 121 119 119 56 122 108 115 114 117 113 112 97 112 112 100 50 55 112 104 121 101 51 113 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 104 113 53 121 121 48 115 51 119 108 48 53 119 114 57 121 119 119 56 122 108 115 114 117 113 112 97 112 112 100 50 55 108 55 53 106 113 119 34 125] 1-2178909 0}"
 4:00AM INF packet acknowledged module=x/ibc/channel packet="{335724 transfer channel-42 transfer channel-0 [123 34 97 109 111 117 110 116 34 58 34 49 53 54 51 56 56 53 34 44 34 100 101 110 111 109 34 58 34 116 114 97 110 115 102 101 114 47 99 104 97 110 110 101 108 45 52 50 47 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 106 117 110 111 49 113 112 99 53 103 109 116 52 52 99 110 53 109 117 55 104 119 57 100 117 102 56 55 53 106 56 116 54 100 52 107 114 119 115 108 54 100 109 34 44 34 115 101 110 100 101 114 34 58 34 111 115 109 111 49 113 112 99 53 103 109 116 52 52 99 110 53 109 117 55 104 119 57 100 117 102 56 55 53 106 56 116 54 100 52 107 114 115 101 48 51 117 52 34 125] 1-2178910 0}"
 4:00AM INF minted coins from module account amount=28795uosmo from=superfluid module=x/bank
 4:00AM INF client state updated client-id=07-tendermint-1457 height=1-2178766 module=x/ibc/client
 4:00AM INF burned tokens from module account amount=614988ibc/27394FB092D2ECCD56123C74F36E4C1F926001CEADA9CA97EA622B25F41E5EB2 from=transfer module=x/bank
 4:00AM INF packet sent dst_channel=channel-141 dst_port=transfer module=x/ibc/channel sequence=528681 src_channel=channel-0 src_port=transfer
 4:00AM INF IBC fungible token transfer amount=614988 module=x/ibc-transfer receiver=cosmos1fadm7n8asynycdcp7uduz6y6t93qu6jjlr95nz sender=osmo1fadm7n8asynycdcp7uduz6y6t93qu6jjhcky9s token=ibc/27394FB092D2ECCD56123C74F36E4C1F926001CEADA9CA97EA622B25F41E5EB2
 4:00AM INF minted coins from module account amount=443450869341238985gamm/pool/626 from=gamm module=x/bank
 4:00AM INF client state updated client-id=07-tendermint-1666 height=1-1198292 module=x/ibc/client
 4:00AM INF packet received module=x/ibc/channel packet="{193063 transfer channel-7 transfer channel-113 [123 34 97 109 111 117 110 116 34 58 34 49 52 55 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 104 117 97 104 117 97 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 50 52 119 48 121 55 100 51 52 121 118 57 116 104 114 104 102 116 53 100 109 56 120 113 117 55 51 50 51 48 57 113 118 52 50 106 54 102 34 44 34 115 101 110 100 101 114 34 58 34 99 104 105 104 117 97 104 117 97 49 55 118 56 104 100 115 55 103 104 56 50 53 107 50 120 101 56 50 122 118 119 117 108 117 56 54 53 52 50 53 52 54 114 97 103 53 107 52 34 125] 1-3491884 0}"
 4:00AM INF minted coins from module account amount=147000000ibc/B9E0A1A524E98BB407D3CED8720EFEFD186002F90C1B1B7964811DD0CCC12228 from=transfer module=x/bank
 4:00AM INF acknowledged written module=x/ibc/channel packet="{193063 transfer channel-7 transfer channel-113 [123 34 97 109 111 117 110 116 34 58 34 49 52 55 48 48 48 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 104 117 97 104 117 97 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 50 52 119 48 121 55 100 51 52 121 118 57 116 104 114 104 102 116 53 100 109 56 120 113 117 55 51 50 51 48 57 113 118 52 50 106 54 102 34 44 34 115 101 110 100 101 114 34 58 34 99 104 105 104 117 97 104 117 97 49 55 118 56 104 100 115 55 103 104 56 50 53 107 50 120 101 56 50 122 118 119 117 108 117 56 54 53 52 50 53 52 54 114 97 103 53 107 52 34 125] 1-3491884 0}"
 4:00AM INF client state updated client-id=07-tendermint-1666 height=1-1198292 module=x/ibc/client
 message repeated 2 times: [ 4:00AM INF client state updated client-id=07-tendermint-1666 height=1-1198292 module=x/ibc/client]
 4:00AM INF executed block height=3490888 module=state num_invalid_txs=3 num_valid_txs=17
 4:00AM INF commit synced commit=436F6D6D697449447B5B31322031343120353720313220313638203134362031313520313439203231203234322031323020333320363220313933203634203233382038332031303420313120313536203136352031383120383020313330203235352031303820313436203430203136382032343420313833203235325D3A3335343434387D
 4:00AM INF committed state app_hash=0C8D390CA892739515F278213EC140EE53680B9CA5B55082FF6C9228A8F4B7FC height=3490888 module=state num_txs=20
 4:00AM INF indexed block height=3490888 module=txindex
 4:00AM INF Timed out dur=4648.25283 height=3490889 module=consensus round=0 step=1
 4:00AM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"28ACA34439C4F038DC723191F88A2193E742624D03E2FD723D50B66C2E004025","parts":{"hash":"1C12A6FEBAB55AF424276F826CFA4402C3836C19DB3F4B7F1324DFE8EFEA8CE9","total":8}},"height":3490889,"pol_round":-1,"round":0,"signature":"jOxegFZeSQpCc+lzlsUfNhioiN8YylhH1i6KBEgXuees2RJEbTRg5A6R2rfVkOZJ9/5xHtupl+RYRSOgiQUyAg==","timestamp":"2022-03-07T09:00:25.754686549Z"}
 4:00AM INF received complete proposal block hash=28ACA34439C4F038DC723191F88A2193E742624D03E2FD723D50B66C2E004025 height=3490889 module=consensus
 4:00AM ERR prevote step: ProposalBlock is invalid err="wrong Block.Header.AppHash.  Expected 0C8D390CA892739515F278213EC140EE53680B9CA5B55082FF6C9228A8F4B7FC, got BF09B47EB54FC09EA9456863ABE0EB3DB52FB929050D8ADD5E77A8E718E3740D" height=3490889 module=consensus round=0
 4:00AM INF client state updated client-id=07-tendermint-1457 height=1-2178768 module=x/ibc/client
 4:00AM INF packet received module=x/ibc/channel packet="{141496 transfer channel-0 transfer channel-42 [123 34 97 109 111 117 110 116 34 58 34 52 48 52 56 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 110 107 50 104 55 57 54 110 121 116 103 54 107 117 48 51 48 116 113 120 103 110 110 121 121 104 121 51 122 48 54 107 108 115 118 114 100 100 34 44 34 115 101 110 100 101 114 34 58 34 106 117 110 111 49 110 107 50 104 55 57 54 110 121 116 103 54 107 117 48 51 48 116 113 120 103 110 110 121 121 104 121 51 122 48 54 107 112 101 117 103 117 114 34 125] 1-3491028 0}"
 4:00AM INF minted coins from module account amount=4048000ibc/46B44899322F3CD854D2D46DEEF881958467CDD4B3B10086DA49296BBED94BED from=transfer module=x/bank
 4:00AM INF acknowledged written module=x/ibc/channel packet="{141496 transfer channel-0 transfer channel-42 [123 34 97 109 111 117 110 116 34 58 34 52 48 52 56 48 48 48 34 44 34 100 101 110 111 109 34 58 34 117 106 117 110 111 34 44 34 114 101 99 101 105 118 101 114 34 58 34 111 115 109 111 49 110 107 50 104 55 57 54 110 121 116 103 54 107 117 48 51 48 116 113 120 103 110 110 121 121 104 121 51 122 48 54 107 108 115 118 114 100 100 34 44 34 115 101 110 100 101 114 34 58 34 106 117 110 111 49 110 107 50 104 55 57 54 110 121 116 103 54 107 117 48 51 48 116 113 120 103 110 110 121 121 104 121 51 122 48 54 107 112 101 117 103 117 114 34 125] 1-3491028 0}"
 4:00AM ERR CONSENSUS FAILURE!!! err="precommit step; +2/3 prevoted for an invalid block: wrong Block.Header.AppHash.  Expected 0C8D390CA892739515F278213EC140EE53680B9CA5B55082FF6C9228A8F4B7FC, got BF09B47EB54FC09EA9456863ABE0EB3DB52FB929050D8ADD5E77A8E718E3740D" module=consensus stack="goroutine 7992376 [running]:\nruntime/debug.Stack()\n\truntime/debug/stack.go:24 +0x65\ngithub.com/tendermint/tendermint/consensus.(*State).receiveRoutine.func2()\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:726 +0x4c\npanic({0x1b0c920, 0xc20e2b16f0})\n\truntime/panic.go:1038 +0x215\ngithub.com/tendermint/tendermint/consensus.(*State).enterPrecommit(0xc0ef26aa80, 0x354449, 0x0)\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:1390 +0x171f\ngithub.com/tendermint/tendermint/consensus.(*State).addVote(0xc0ef26aa80, 0xc191f23540, {0xc0f171ad50, 0x28})\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:2104 +0x188f\ngithub.com/tendermint/tendermint/consensus.(*State).tryAddVote(0xc0ef26aa80, 0xc191f23540, {0xc0f171ad50, 0xc188c2ef00})\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:1930 +0x2c\ngithub.com/tendermint/tendermint/consensus.(*State).handleMsg(0xc0ef26aa80, {{0x2773300, 0xc27a906cc0}, {0xc0f171ad50, 0x0}})\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:838 +0x40b\ngithub.com/tendermint/tendermint/consensus.(*State).receiveRoutine(0xc0ef26aa80, 0x0)\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:762 +0x419\ncreated by github.com/tendermint/tendermint/consensus.(*State).OnStart\n\tgithub.com/tendermint/tendermint@v0.34.15/consensus/state.go:378 +0x12f\n"
 4:00AM INF Stopping baseWAL service impl={"Logger":{}} module=consensus wal=/home/osmosisd/.osmosisd/data/cs.wal/wal
 4:00AM INF Stopping Group service impl={"Dir":"/home/osmosisd/.osmosisd/data/cs.wal","Head":{"ID":"PGqUB6bhWPob:/home/osmosisd/.osmosisd/data/cs.wal/wal","Path":"/home/osmosisd/.osmosisd/data/cs.wal/wal"},"ID":"group:PGqUB6bhWPob:/home/osmosisd/.osmosisd/data/cs.wal/wal","Logger":{}} module=consensus wal=/home/osmosisd/.osmosisd/data/cs.wal/wal
 4:00AM INF Timed out dur=3000 height=3490889 module=consensus round=0 step=3
 4:00AM INF Saving AddrBook to file book=/home/osmosisd/.osmosisd/config/addrbook.json module=p2p size=1335
 4:00AM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=50 numToDial=0
 4:00AM ERR Connection failed @ sendRoutine conn={"Logger":{}} err="pong timeout" module=p2p peer={"id":"49b307f9e17f2ab3edb1c958f902b8857b2b4ce3","ip":"135.148.55.229","port":26656}
 4:00AM INF Stopping MConnection service impl={"Logger":{}} module=p2p peer={"id":"49b307f9e17f2ab3edb1c958f902b8857b2b4ce3","ip":"135.148.55.229","port":26656}
 4:00AM ERR Stopping peer for error err="pong timeout" module=p2p peer={"Data":{},"Logger":{}}
 4:00AM INF Stopping Peer service impl={"Data":{},"Logger":{}} module=p2p peer={"id":"49b307f9e17f2ab3edb1c958f902b8857b2b4ce3","ip":"135.148.55.229","port":26656}
 4:00AM INF Stopping gossipVotesRoutine for peer module=consensus peer={"Data":{},"Logger":{}}
 4:00AM INF Stopping gossipDataRoutine for peer module=consensus peer={"Data":{},"Logger":{}}
 4:00AM INF Stopping queryMaj23Routine for peer module=consensus peer={"Data":{},"Logger":{}}
 4:01AM ERR Connection failed @ sendRoutine conn={"Logger":{}} err="pong timeout" module=p2p peer={"id":"2048e1bc1f020fa210fb475e7a0ec0948919609f","ip":"185.217.125.64","port":26656}
 4:01AM INF Stopping MConnection service impl={"Logger":{}} module=p2p peer={"id":"2048e1bc1f020fa210fb475e7a0ec0948919609f","ip":"185.217.125.64","port":26656}

Relevant Slack Thread:

https://osmosis-network.slack.com/archives/C033UPJQ0TG/p1647274578316029

About this issue

Original URL
State: closed
Created 2 years ago
Comments: 26 (26 by maintainers)

Most upvoted comments

Separated the most important details from the latest app hash log (the original was 1.5GB): https://drive.google.com/file/d/1w-fIH-lssZTWDAn5sXuhC6so7tatNGtH/view?usp=sharing

TODOs:

query archive node to see which store happens to cause app hash mismatch

inspect code for more data races

With regards to these logs, the store that committed wrong data was bank. I verified this by comparing the logs to the actual data.

The logs:

 1:09PM INF committed KVStore commit_store_hash=97499994BFCEE4E8C43E544E840E305C8494B02CC20E83B330B0A1CCFBE38C8E height=3829411 key=bank
 1:09PM INF calculated commit hash commit_hash=15FA048896B62972C6D0A4079999D9F2FF8A0700D97AD41FA1A35B16F2F0C52C height=3829411 keys=["acc","authz","bank","bech32ibc","capability","claim","distribution","epochs","evidence","gamm","gov","ibc","incentives","lockup","mem_capability","mint","params","poolincentives","slashing","staking","superfluid","transfer","txfees","upgrade","wasm"]

Actual:

commit_hash=6223A32BBAEFCCC618A304A64B7F6726CA4F4B5C68A8E9C042CE8A63A09E1C0D
bank=88AB92B3CD444CF2F2BB02885CF6C40789AFFF1E52572B1B372AED7A91474D5B

All other stores had correct commit_store_hash. Therefore, the incorrect bank store commit_store_hash caused the commit_hash to be wrong.

However, since we observed wrong Block.Header.LastResultsHash which happens during DeliverTx() while wrong Block.Header.AppHash is caused by a faulty commit, it is likely that a data race/bug is still present in IAVL and is not specific to Commit().

I also don’t think that the error is specific to the bank module only. It is likely possible for it to happen in other stores. However, there is no proof of that yet. We will need more data to make a conclusion.

Currently, there is still no way to reproduce this. From the discussion with the team, we will focus on our e2e test and hope to expose this problem there. At the same time, we will wait for more logs from node operators to determine if the issue is specific to the bank module or not.

p0mvn on Apr 7, 2022

It is much less apparent but, as far as I know, it is still present in v8. We would like to keep this open until we have the ability to deterministically reproduce this

p0mvn on May 31, 2022

@p0mvn I’m hoping we don’t run some special snowflake of a node 🙂

The only not as common setup is that these nodes run in docker containers. We have 13 other networks that run in this setup though, and none of them have had an issue as this one so far.

The only configuration options we change from default are pruning which is set to 5000/0/509 and p2p send_rate and recv_rate which are both set to 51200000.

You can have a look at our complete node config here: https://github.com/cephalopodequipment/config/tree/main/cosmos-sdk/0.44.x

mircea-c on Apr 8, 2022