Wrong "state" migrating from 3.1.0 to 3.2.0

[activenodes]

Migrating from version 3.1.0 to 3.2.0 no signatures occur with this error

Cosigner failed to set nonces and sign chain_id=xxx-1 height=xxx round=0 type=prevote cosigner=1 err="unexpected state, metadata does not exist for U: xxxxx"

The steps performed:

• stop all sentry/nodes
• stop all signers
• update bin
• rm -rf /raft
• start all signers
• start sentry/nodes

The same in test with a stand-alone setup (--accept-risk) with a wrong state file.
In this last case I solved it increasing blocks without signatures and then by deleting state/priv_validator_state.json (it's a testnet)

Some idea?
Thanks

[agouin]

This is unrelated to the state files. I would avoid deleting the state files since that is a core part of horcrux' double sign protection. Waiting for blocks without signature is not always sufficient since an out of sync sentry could request a signature for an old block.

This is due to the cosigner nonce cache, and I believe it is related to #226 and think it may also be fixed by #227 in v3.2.1. Can you please try v3.2.1?

[activenodes]

@agouin tested v3.2.1 with then same problem.
Stopped everything, removed raft folders, updated, started signers, started sentry.

Co-Signer 1 and 2:

21:06:15.144] Signed with shard                            chain_id=meme-1 height=8761330 round=0 step=2
21:06:15.514] Signed with shard                            chain_id=meme-1 height=8761330 round=0 step=3
21:06:29.499] Signed with shard                            chain_id=meme-1 height=8761332 round=0 step=2
21:06:29.703] Signed with shard                            chain_id=meme-1 height=8761332 round=0 step=3
21:06:43.335] Failed to sign with shard                    chain_id=meme-1 height=8761334 round=0 step=2 error="unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2"
21:06:43.641] Failed to sign with shard                    chain_id=meme-1 height=8761334 round=0 step=3 error="unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c"
21:06:48.984] Failed to sign with shard                    chain_id=meme-1 height=8761335 round=0 step=2 error="unexpected state, metadata does not exist for U: 7bd011b7-763a-4ab1-9ecd-220dccc5df95"
21:06:49.410] Failed to sign with shard                    chain_id=meme-1 height=8761335 round=0 step=3 error="unexpected state, metadata does not exist for U: d1faf041-17f9-4955-8299-6816a808baf3"
21:06:54.770] Failed to sign with shard                    chain_id=meme-1 height=8761336 round=0 step=2 error="unexpected state, metadata does not exist for U: d7f3159a-f0bb-4429-99e4-53dadb5a472b"
21:06:55.173] Failed to sign with shard                    chain_id=meme-1 height=8761336 round=0 step=3 error="unexpected state, metadata does not exist for U: 757cc017-e0ff-4fad-b9a6-8af8b1e3e068"
21:07:00.485] Failed to sign with shard                    chain_id=meme-1 height=8761337 round=0 step=1 error="unexpected state, metadata does not exist for U: c3d07108-cb4b-4f2c-a91d-8d5526a14a9b"
21:07:03.475] Failed to sign with shard                    chain_id=meme-1 height=8761337 round=0 step=2 error="unexpected state, metadata does not exist for U: 7517f3aa-89ce-4c93-b78d-465f2b79f3aa"
21:07:03.704] Failed to sign with shard                    chain_id=meme-1 height=8761337 round=0 step=3 error="unexpected state, metadata does not exist for U: 22316ad7-4fb4-4424-80dc-623a4cfeaeee"
21:07:05.191] Failed to sign with shard                    chain_id=meme-1 height=8761337 round=1 step=2 error="unexpected state, metadata does not exist for U: 098814d1-58ee-48dd-acdf-9d93441af512"
21:07:05.596] Failed to sign with shard                    chain_id=meme-1 height=8761337 round=1 step=3 error="unexpected state, metadata does not exist for U: b2829c6c-e6f4-4acb-abd0-ef6d72c3b5fa

Co-signer 3:

21:06:32.966] Loading additional nonces to meet demand     target=12 remaining=9 additional=3 noncesPerMin=30.767431126805818
21:06:32.981] Loaded nonces                                desired=3 added=3
21:06:35.966] Cosigner nonce cache ahead of demand         target=11 remaining=12 noncesPerMin=23.075573345104363
21:06:37.573] I am the leader. Managing the sign process for this block chain_id=meme-1 height=8761333 round=0 type=prevote
21:06:37.597] Signed                                       chain_id=meme-1 height=8761333 round=0 type=prevote duration_ms=24.473
21:06:37.598] Signed                                       type=prevote chain_id=meme-1 height=8761333 round=0 sig=DC4FBF1A4FFD ts="2023-11-30 21:06:37.566695767 +0000 UTC"
21:06:37.865] I am the leader. Managing the sign process for this block chain_id=meme-1 height=8761333 round=0 type=precommit
21:06:37.888] Signed                                       chain_id=meme-1 height=8761333 round=0 type=precommit duration_ms=22.077
21:06:37.888] Signed                                       type=precommit chain_id=meme-1 height=8761333 round=0 sig=F95D08E9F615 ts="2023-11-30 21:06:37.858772909 +0000 UTC"
21:06:38.966] Loading additional nonces to meet demand     target=11 remaining=10 additional=1 noncesPerMin=27.30645279732423
21:06:38.977] Loaded nonces                                desired=1 added=1
21:06:41.966] Cosigner nonce cache ahead of demand         target=11 remaining=11 noncesPerMin=20.479839597993173
21:06:43.317] I am the leader. Managing the sign process for this block chain_id=meme-1 height=8761334 round=0 type=prevote
21:06:43.318] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=prevote cosigner=2 err="unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2"
21:06:43.328] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=prevote cosigner=3 err="rpc error: code = Unknown desc = unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2"
21:06:43.340] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=prevote cosigner=1 err="rpc error: code = Unknown desc = unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2"
21:06:43.340] Failed to sign                               type=prevote chain_id=meme-1 height=8761334 round=0 error="error from cosigner(s): unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2"
21:06:43.623] I am the leader. Managing the sign process for this block chain_id=meme-1 height=8761334 round=0 type=precommit
21:06:43.623] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=precommit cosigner=2 err="unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c"
21:06:43.633] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=precommit cosigner=3 err="rpc error: code = Unknown desc = unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c"
21:06:43.644] Cosigner failed to set nonces and sign       chain_id=meme-1 height=8761334 round=0 type=precommit cosigner=1 err="rpc error: code = Unknown desc = unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c"
21:06:43.644] Failed to sign                               type=precommit chain_id=meme-1 height=8761334 round=0 error="error from cosigner(s): unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c"
21:06:44.967] Loading additional nonces to meet demand     target=11 remaining=9 additional=2 noncesPerMin=25.356954547729277

Sentry:

9:06PM INF committed state app_hash=BBFB5CA7AEC9C56602097166C3FE434D038E9440A05ABFAFD2482BE529B777AF height=8761331 module=state num_txs=0
9:06PM INF indexed block height=8761331 module=txindex
9:06PM INF Timed out dur=4823.925795 height=8761332 module=consensus round=0 step=1
9:06PM INF Timed out dur=3000 height=8761332 module=consensus round=0 step=3
9:06PM INF Timed out dur=1000 height=8761332 module=consensus round=0 step=7
9:06PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"BC0BD372339A30ECCCFCBB0D3D6FFF4CB4D1AA8DA31AE63C4416A50970DC88DD","parts":{"hash":"DEF7B0CB49BCDC4E53B0BB84402C613B9CE61412EBE97917EB33216B9C013177","total":1}},"height":8761332,"pol_round":-1,"round":1,"signature":"76g6y9CtDcL79GAtajLshD270OF2t6tSr6ne5SuOLj/HKFktyzfu9z4LSscMA8wrIHhnQgG0yzLXE2aAMdn2Cg==","timestamp":"2023-11-30T21:06:31.239779021Z"}
9:06PM INF received complete proposal block hash=BC0BD372339A30ECCCFCBB0D3D6FFF4CB4D1AA8DA31AE63C4416A50970DC88DD height=8761332 module=consensus
9:06PM INF finalizing commit of block hash={} height=8761332 module=consensus num_txs=0 root=BBFB5CA7AEC9C56602097166C3FE434D038E9440A05ABFAFD2482BE529B777AF
9:06PM INF minted coins from module account amount=684109770umeme from=mint module=x/bank
9:06PM INF executed block height=8761332 module=state num_invalid_txs=0 num_valid_txs=0
9:06PM INF commit synced commit=436F6D6D697449447B5B31383220323239203139332032322030203136382032313720323430203133203137322035362031343820313331203230332031343220323331203131322036342035342031393920323238203135352032323620313333203131332035352032343120313833203231312031343220323720345D3A3835414646347D
9:06PM INF committed state app_hash=B6E5C11600A8D9F00DAC389483CB8EE7704036C7E49BE2857137F1B7D38E1B04 height=8761332 module=state num_txs=0
9:06PM INF indexed block height=8761332 module=txindex
9:06PM INF Timed out dur=4838.608692 height=8761333 module=consensus round=0 step=1
9:06PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"64F8872267881A7AF616F23513636B52A17F89F1E1AA15B550E1C316BE4620A4","parts":{"hash":"7953B835C4E2F765E6D477B5D0C889A2B6251929D4EF72D49FC9B3ACF8C13F3C","total":1}},"height":8761333,"pol_round":-1,"round":0,"signature":"ga/L2JRX9gUszXW4ZJhsBQsV6JgvrnTIUxfSEIttVrPycUERlUD7DrdFSaBS6jiZJZqsQatnAwq3QNR+UUbaAg==","timestamp":"2023-11-30T21:06:37.266227321Z"}
9:06PM INF received complete proposal block hash=64F8872267881A7AF616F23513636B52A17F89F1E1AA15B550E1C316BE4620A4 height=8761333 module=consensus
9:06PM INF Ensure peers module=pex numDialing=0 numInPeers=0 numOutPeers=5 numToDial=10
9:06PM INF service start impl="Peer{MConn{49.12.246.204:23656} 40e748da7a72c039f8ba47b2c6bd90cc0e203587 out}" module=p2p msg={} peer={"id":"40e748da7a72c039f8ba47b2c6bd90cc0e203587","ip":"49.12.246.204","port":23656}
9:06PM INF service start impl=MConn{49.12.246.204:23656} module=p2p msg={} peer={"id":"40e748da7a72c039f8ba47b2c6bd90cc0e203587","ip":"49.12.246.204","port":23656}
9:06PM INF Added peer module=p2p peer={"Data":{},"Logger":{}}
9:06PM INF service start impl="Peer{MConn{165.140.242.34:26656} f3ee4c635b8b6165c25abef548c164c53014b90e out}" module=p2p msg={} peer={"id":"f3ee4c635b8b6165c25abef548c164c53014b90e","ip":"165.140.242.34","port":26656}
9:06PM INF service start impl=MConn{165.140.242.34:26656} module=p2p msg={} peer={"id":"f3ee4c635b8b6165c25abef548c164c53014b90e","ip":"165.140.242.34","port":26656}
9:06PM INF Added peer module=p2p peer={"Data":{},"Logger":{}}
9:06PM INF finalizing commit of block hash={} height=8761333 module=consensus num_txs=0 root=B6E5C11600A8D9F00DAC389483CB8EE7704036C7E49BE2857137F1B7D38E1B04
9:06PM INF minted coins from module account amount=684109810umeme from=mint module=x/bank
9:06PM INF executed block height=8761333 module=state num_invalid_txs=0 num_valid_txs=0
9:06PM INF commit synced commit=436F6D6D697449447B5B37372036322032323020323234203233342034382038342031363620323430203931203134382031392032332031393620313739203936203233382032333820313031203131312031313120383920313339203637203238203232382032333320323035203232312037302038352037305D3A3835414646357D
9:06PM INF committed state app_hash=4D3EDCE0EA3054A6F05B941317C4B360EEEE656F6F598B431CE4E9CDDD465546 height=8761333 module=state num_txs=0
9:06PM INF indexed block height=8761333 module=txindex
9:06PM INF Connection is closed @ recvRoutine (likely by the other side) conn={"Logger":{}} module=p2p peer={"id":"f3ee4c635b8b6165c25abef548c164c53014b90e","ip":"165.140.242.34","port":26656}
9:06PM INF service stop impl={"Logger":{}} module=p2p msg={} peer={"id":"f3ee4c635b8b6165c25abef548c164c53014b90e","ip":"165.140.242.34","port":26656}
9:06PM ERR Stopping peer for error err=EOF module=p2p peer={"Data":{},"Logger":{}}
9:06PM INF service stop impl={"Data":{},"Logger":{}} module=p2p msg={} peer={"id":"f3ee4c635b8b6165c25abef548c164c53014b90e","ip":"165.140.242.34","port":26656}
9:06PM INF Timed out dur=4837.839049 height=8761334 module=consensus round=0 step=1
9:06PM INF received proposal module=consensus proposal={"Type":32,"block_id":{"hash":"97DEF0B49374089A295A169DE2888D482FA901DB71DCFCC14CE93DCD29126AB3","parts":{"hash":"3EC6582D593890D722F113E477633120735DE4A59242480057C8579C7C8AE0D9","total":1}},"height":8761334,"pol_round":-1,"round":0,"signature":"3t3ZnXlRhFinyPq9Jskdi8gn1IlQpEMKzmg4bzY2sneD1y/lFgN37yxFbbrJddmWlaHqEe8eE9WgBXvpvC+cCg==","timestamp":"2023-11-30T21:06:43.083040287Z"}
9:06PM INF received complete proposal block hash=97DEF0B49374089A295A169DE2888D482FA901DB71DCFCC14CE93DCD29126AB3 height=8761334 module=consensus
9:06PM ERR failed signing vote err="signerEndpoint returned error #0: error from cosigner(s): unexpected state, metadata does not exist for U: a060e073-95c9-484e-aa7f-dac298a03bd2" height=8761334 module=consensus round=0 vote={"block_id":{"hash":"97DEF0B49374089A295A169DE2888D482FA901DB71DCFCC14CE93DCD29126AB3","parts":{"hash":"3EC6582D593890D722F113E477633120735DE4A59242480057C8579C7C8AE0D9","total":1}},"height":8761334,"round":0,"signature":null,"timestamp":"2023-11-30T21:06:43.310868212Z","type":1,"validator_address":"0612533DC923673B77AB99A1E552DAE41C372544","validator_index":8}
9:06PM ERR failed signing vote err="signerEndpoint returned error #0: error from cosigner(s): unexpected state, metadata does not exist for U: 8519f0f0-412c-476e-93df-b42d141a649c" height=8761334 module=consensus round=0 vote={"block_id":{"hash":"97DEF0B49374089A295A169DE2888D482FA901DB71DCFCC14CE93DCD29126AB3","parts":{"hash":"3EC6582D593890D722F113E477633120735DE4A59242480057C8579C7C8AE0D9","total":1}},"height":8761334,"round":0,"signature":null,"timestamp":"2023-11-30T21:06:43.61630897Z","type":2,"validator_address":"0612533DC923673B77AB99A1E552DAE41C372544","validator_index":8}
9:06PM INF finalizing commit of block hash={} height=8761334 module=consensus num_txs=0 root=4D3EDCE0EA3054A6F05B941317C4B360EEEE656F6F598B431CE4E9CDDD465546
9:06PM INF minted coins from module account amount=684109851umeme from=mint module=x/bank

Version:

{
  "version": "3.2.1",
  "commit": "6a974bb7cdda7283a08c524e546075c83f259e2b",
  "go_version": "go1.21.4 linux/amd64",
  "cosmos_sdk_version": "v0.50.1",
  "cometbft_version": "v0.38.0"
}

[unl1k3ly]

worked for me!