panic: precommit length (3) doesn't match valset length (4) at height 2

[enakshipriya]

Description:

I had a live net with three nodes having voting power 1 for each. I added a validator node to this node with voting power 1 using validator transaction of persistent_kvstore. So now i have four nodes each with voting power 1. The setup worked fine and transactions were adding until i killed the tendermint process and tried to restart the nodes again.

Tendermint version- 0.26.0-c086d0a3
ABCI app- persistent_kvstore

I got the following error:
panic: precommit length (3) doesn't match valset length (4) at height 2

I expected it to start normally without any errors but the nodes failed to start with the above panic
I have not tried the latest version.

To reproduce it, you can perform the above steps mentioned in description.

Logs:

I[6026-02-06|16:15:27.672] ABCI Handshake App Info                      module=consensus height=0 hash= software-version=0.15.0 protocol-version=1
I[6026-02-06|16:15:27.672] ABCI Replay Blocks                           module=consensus appHeight=0 storeHeight=1044 stateHeight=1044
I[6026-02-06|16:15:27.680] Applying block                               module=consensus height=1
I[6026-02-06|16:15:27.680] Executed block                               module=consensus height=1 validTxs=0 invalidTxs=0
I[6026-02-06|16:15:27.680] Applying block                               module=consensus height=2
panic: precommit length (3) doesn't match valset length (4) at height 2

[Vote{0:9116D5EAC14B 1/00/2(Precommit) 11247FB2743B DBE489B66808 @ 2019-01-28T05:14:16.205782408Z} Vote{1:95DB5E7BBCED 1/00/2(Precommit) 11247FB2743B 27A82FD1C2BB @ 2019-01-28T05:14:16.307820398Z} Vote{2:BCE6656D816C 1/00/2(Precommit) 11247FB2743B 97E5533044AC @ 2019-01-28T05:14:16.111161146Z}]

[Validator{1B84700AA312C51236167E9DEF49EBEB8B5A1CE0 PubKeyEd25519{255ACC7349033507E019324654BA7309462B453BF11918FF2A7627BAC3E3B7F9} VP:1 A:1} Validator{9116D5EAC14BA35ED0612799A26EF5D1A91E8ED8 PubKeyEd25519{92AFD1331415F6740C33C52F8A5820F689CB597C02282D8E36943F33FDBB157C} VP:1 A:0} Validator{95DB5E7BBCED9D355376483A9A6EE984953E20A1 PubKeyEd25519{F3264CD718B77415A7B1B247CCE51D558FDBCDD5A2FCCE6BCA6CA91F7CEE754F} VP:1 A:0} Validator{BCE6656D816C418278140261FFDBDF1F34046B41 PubKeyEd25519{EA033C4C6559A2C965AC5ABA3CC210D9BA9ABB635A94AB293EC8E7B42141FD0B} VP:1 A:-1}]

I am not sure if this error happened because the new validator should have voting power strictly less than 1/3rd of total/max(unclear) voting power as mentioned here: (https://tendermint.com/docs/app-dev/app-development.html#endblock)

or is it because of some bug.

This is my thought:
i think adding validators as transaction is creating this problem. What I mean is, maybe in state.db it updated the validator state from 3 to 4 but the transactions that got executed before the validator change transaction does not know of these changes. So when i tried to restart the nodes, it got stuck at height 2 while replaying the blocks.

Any suggestion/work-around will be of great help in troubleshooting this.

[kunaldhariwal]

@melekes Looks like this is related to this #3006 or #3067 Pull Request?

[melekes]

What are you using persistent_kvstore for?

[enakshipriya]

@melekes I am using it for making the validator changes(add/remove/update) while live net is up.

[enakshipriya]

hey @melekes , any updates on this?

[ebuchman]

Are you sure all nodes are being started properly with the persistent kv store? If the node being restarted uses the non persistent kv store, that would cause this issue (due to #3067)

[enakshipriya]

Hey yes @ebuchman . I am sure of it that I started it with persistent_kvstore.

[ebuchman]

In your opening comment, you have this in the logs:

I[6026-02-06|16:15:27.672] ABCI Replay Blocks                           module=consensus appHeight=0 storeHeight=1044 stateHeight=1044

Note this says the appHeight=0. But the whole point of persistent_kvstore is that it persists the latest state in the app, so it doesn't restart from 0. When I restart a persistent_kvstore, I get the expected result, eg:

I[2019-03-01|09:56:51.948] ABCI Replay Blocks                           module=consensus appHeight=15 storeHeight=15 stateHeight=15

So it seems like something must be wrong in the way you're running the persistent_kvstore - it seems like, at least from that log, that it's just running the kvstore, not the persistent version

[enakshipriya]

Hey @ebuchman , there is no logic in persistent_kvstore to persist the latest state. For persisting the latest state, it is calling the kvstore app internally(app.app.state.Height). So if kvstore has the logic for persisting state, it will happen automatically for persistent_kvstore(if you see the latest code in the master) and persistent_kvstore mainly has validator update logic. Please let me know if my understanding is wrong. So this error should not come if our kvstore is correct.

[melekes]

persistent_kvstore uses GoLevelDB

tendermint/abci/example/kvstore/persistent_kvstore.go

Line 35 in 52771e1

db, err := dbm.NewGoLevelDB(name, dbDir)

kvstore stores state in memory

tendermint/abci/example/kvstore/kvstore.go

Line 66 in 52771e1

state := loadState(dbm.NewMemDB())

So if you're using NewMemDB, changes won't be persisted across restarts.

[ebuchman]

Closing this. Please open a new one if you're still having issues.