Resyncing ropsten always ends up on a wrong chain

[phahulin]

• Parity Ethereum version: Parity-Ethereum/v2.6.4-beta-badb045-20190926/x86_64-linux-gnu/rustc1.36.0
• Operating system: Linux
• Installation: binary
• Fully synchronized: ?
• Network: ropsten
• Restarted: yes

We're trying to resync full archive ropsten node. Every time when sync appears to complete (comparing to https://ropsten.etherscan.io) we get this error in logs

2019-10-08 20:02:44 UTC Syncing #6534859 0xfd88…1df8     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6485453   24/25 peers    928 KiB chain   18 MiB db  0 bytes queue   57 MiB sync  RPC:  0 conn,    0 req/s,   52 µs
2019-10-08 20:02:45 UTC Stage 5 block verification failed for #6485846 (0x5bd0…dc6b)
Error: Block(InvalidStateRoot(Mismatch { expected: 0x4e375b7954a00d4e6ec68cc173a6ce55bcb84ed5a82e5fac81afeb8925918a87, found: 0x790b498389f3a20cceb696d3a825883a4d7437f8e13b8e001b56ec0b24a62014 }))
2019-10-08 20:02:45 UTC
Bad block detected: Block(InvalidStateRoot(Mismatch { expected: 0x4e375b7954a00d4e6ec68cc173a6ce55bcb84ed5a82e5fac81afeb8925918a87, found: 0x790b498389f3a20cceb696d3a825883a4d7437f8e13b8e001b56ec0b24a62014 }))
RLP: f902b6f90202a0a43cc5f1d5400380672643493b6e819cf471603c0a18fd373c82030f6bd8c5c1a01dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d4934794bbf5029fd710d227630c8b7d338051b8e76d50b3a04e375b7954a00d4e6ec68cc173a6ce55bcb84ed5a82e5fac81afeb8925918a87a005297ce912990e99c89ccecd39b60039b66ada00f43d7cbeb783ebed52743791a0f3efdddfcddc0279ef713fafa61f690707b51006eddc101170d4ea7021002239b90100000000000000040000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000002000000000000000000000000000000000000000200000000000000000000000000000000000000000000400000000000000000020000000000000000000000000000000000000000000000000000000000000000003000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000400000000000000000000000000000000000000080000000000000000000000000000000000000000008488dbe0588362f756837a121d830278f9845d91789e8474657374a027f33e1b6ac8d047bcbaa555d2fd44cf45e197217c95e80b0ba444131a2d1bec8858d6fcc0032becfff8aef8ac8277ba8501d5283d18833d090094d06e3de5c19efaedce5b03fc5394c5aebb75b7c980b8447824e7d197f304b386ff510eb5ec38b7ecb6953f7c469a2bd9843cea1168a47c6975449b000000000000000000000000000000000000000000000000000000000004f2c429a0c0314a2cceb26778a8796d272e60825830d74e6150b6c0fa11914f9417094f3da0623c1d4467deef3c5f36595940e6d06d0fa43775489789ff8fdeefb55b4fef11c0Oct 08 20:02:45 ip-10-0-0-46.poa.internal parity[5952]: Header: Header { parent_hash: 0xa43cc5f1d5400380672643493b6e819cf471603c0a18fd373c82030f6bd8c5c1, timestamp: 1569814686, number: 6485846, author: 0xbbf5029fd710d227630c8b7d338051b8e76d50b3, transactions_root: 0x05297ce912990e99c89ccecd39b60039b66ada00f43d7cbeb783ebed52743791, uncles_hash: 0x1dcc4de8dec75d7aab85b567b6ccd41ad312451b948a7413f0a142fd40d49347, extra_data: [116, 101, 115, 116], state_root: 0x4e375b7954a00d4e6ec68cc173a6ce55bcb84ed5a82e5fac81afeb8925918a87, receipts_root: 0xf3efdddfcddc0279ef713fafa61f690707b51006eddc101170d4ea7021002239, log_bloom: 0x00000000000004000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000200000000000000000000000000000000000000020000000000000000000000000000000000000000000040000000000000000002000000000000000000000000000000000000000000000000000000000000000000300000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000040000000000000000000000000000000000000008000000000000000000000000000000000000000000, gas_used: 162041, gas_limit: 8000029, difficulty: 2296111192, seal: [[160, 39, 243, 62, 27, 106, 200, 208, 71, 188, 186, 165, 85, 210, 253, 68, 207, 69, 225, 151, 33, 124, 149, 232, 11, 11, 164, 68, 19, 26, 45, 27, 236], [136, 88, 214, 252, 192, 3, 43, 236, 255]], hash: Some(0x5bd02cabf0bedac8168e43e25e0c306d1140139b5f5b02a08b18464dd9b5dc6b) }
Uncles:
Transactions:[Tx 0] UnverifiedTransaction { unsigned: Transaction { nonce: 30650, gas_price: 7871151384, gas: 4000000, action: Call(0xd06e3de5c19efaedce5b03fc5394c5aebb75b7c9), value: 0, data: [120, 36, 231, 209, 151, 243, 4, 179, 134, 255, 81, 14, 181, 236, 56, 183, 236, 182, 149, 63, 124, 70, 154, 43, 217, 132, 60, 234, 17, 104, 164, 124, 105, 117, 68, 155, 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, 4, 242, 196] }, v: 41, r: 86931154371396326564701560872762213814608130339217192994883374630545992011581, s: 44432871979906115394900105204925851633779519970510416868084488446303701823249, hash: 0xa18915222e16543aab076d05b5f9ec804906ca1767cf208986e32df67b6ffeaa }
2019-10-08 20:02:56 UTC Imported #6534860 0x01e9…bfcc (89 txs, 8.00 Mgas, 33 ms, 10.74 KiB)
2019-10-08 20:03:04 UTC Imported #6534861 0xe67d…c134 (70 txs, 5.28 Mgas, 19 ms, 13.75 KiB)

Note that it appears long after offending block 6485846 is imported, during its import there are no errors:

2019-10-08 19:21:59 UTC Syncing #6485770 0xec29…3e47    29.60 blk/s  138.0 tx/s   24.0 Mgas/s      0+ 1697 Qed  #6487479   32/50 peers      4 MiB chain   18 MiB db   53 MiB queue  107 MiB sync  RPC:  0 conn,    0 req/s,   52 µs
2019-10-08 19:22:04 UTC Syncing #6485864 0x94d6…d8f8    18.80 blk/s  322.8 tx/s   42.0 Mgas/s      0+ 1613 Qed  #6487479   32/50 peers      5 MiB chain   18 MiB db   51 MiB queue  107 MiB sync  RPC:  0 conn,    0 req/s,   52 µs

Now after every parity restart we get this same error message and parity stays in the Syncing... state (not Imported...), but hashes of new blocks agree with etherscan:

2019-10-09 08:49:40 UTC Syncing #6538894 0xd905…ddff     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6482376   28/50 peers      9 MiB chain    2 MiB db  0 bytes queue   23 MiB sync  RPC:  0 conn,    0 req/s,   56 µs
2019-10-09 08:49:48 UTC eth_accounts is deprecated and will be removed in future versions: Account management is being phased out see #9997 for alternatives.
2019-10-09 08:49:55 UTC Syncing #6538894 0xd905…ddff     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6410363   28/50 peers      3 MiB chain    2 MiB db  0 bytes queue   22 MiB sync  RPC:  0 conn,    6 req/s,   56 µs
2019-10-09 08:50:00 UTC Syncing #6538894 0xd905…ddff     0.00 blk/s    0.0 tx/s    0.0 Mgas/s      0+    0 Qed  #6413284   28/50 peers      3 MiB chain    2 MiB db  0 bytes queue   22 MiB sync  RPC:  0 conn,    0 req/s,   56 µs
2019-10-09 08:50:05 UTC Syncing #6538895 0xb974…0396     0.20 blk/s   10.2 tx/s    1.6 Mgas/s      0+    0 Qed  #6478694   28/50 peers      3 MiB chain  

Also notice that second block number on each log line jumps up and down (6482376 -> 6410363 -> 6413284 -> 6478694) which reminds me of an old bug #9300 addressed in #9531

---

Questions:

1. is our current node broken? I'm confused, because block hashes agree but it's not Importing new blocks and this error message appears after every restart..
2. if it's broken, how can we resync it and ensure that we always stay on the correct chain and reject incorrect blocks?

Thanks in advance

[niklasad1]

I think this is a duplicate of #11117

Thus, should be fixed on master

/cc @joshua-mir

[phahulin]

We are not having 0 peers as it's described in that issue

2019-10-10 08:06:25 UTC   29/50 peers      6 MiB chain    5 MiB db  0 bytes queue   18 MiB sync  RPC:  0 conn,    0 req/s,   52 µs