Synchronize fails with POA network using reporting contract after adding validators

[mills-nick]

I have an issue with POA via contract on parity v1.5.11-stable.
My reporting contract seems to be working no problem.
Basically the problem is that if I add a new validator using the reporting contract during mining then begin mining with the new validator,
subsequent attempts to add new parity nodes fail at the verification stage.
The steps to reproduce are as below:

1. Start with a private POA network one validator mining.
2. Mine some blocks.
3. Add a validator using the validator contract.
4. Continue mining with old validator and the new validator.
5. Try to join the POA network with a new parity node.
6. Can't pass verification stage at new parity node.

The verification errors are:
...
2017-03-22 02:52:20 UTC Stage 2 block verification failed for 6221…5e98: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for bfac…c1cf: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for b4eb…a75f: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for 2e60…b597: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for 0ca1…22b7: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for 7ae7…e35e: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for e3e9…887c: Block(InvalidSeal)
2017-03-22 02:52:20 UTC Stage 2 block verification failed for 25de…42fd: Block(InvalidSeal)
...

parity is started from the command line with:
parity --force-sealing --geth --config parity-node.toml

'Files attached with .txt extension to workaround github file upload restrictions)
parity-node.toml.txt

[mills-nick]

chain-spec.json.txt
The reporting contract. This is very simple and seems to be working fine.
TestList.sol.txt

[keorn]

Can you please run latest Parity 1.6 if you want to use contracts, there was an overhaul of those (wiki mentions 1.6 req). Let me know how it goes.

[mills-nick]

Using version Parity/v1.6.3-beta-ccc5732-20170314/x86_64-linux-gnu/rustc1.15.1
I am still unable to sync a new parity node after having added a new validator as described above.
I get sync errors as below:

2017-03-23 05:28:51 UTC IO Worker #1 INFO import  Syncing       #0 dc3f…1a05     0 blk/s    0 tx/s   0 Mgas/s      0+    0 Qed        #0    0/ 1/25 peers    10 KiB db    7 KiB chain  0 bytes queue   10 KiB sync  RPC:  0 conn,  0 req/s,   0 µs
2017-03-23 05:28:51 UTC IO Worker #0 DEBUG network  Connecting peers: 1 sessions, 0 pending, 0 started
2017-03-23 05:28:52 UTC IO Worker #0 DEBUG network  Connecting peers: 1 sessions, 0 pending, 0 started
2017-03-23 05:28:52 UTC Verifier #0 DEBUG miner  minimal_gas_price: recalibrating...
2017-03-23 05:28:52 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e]
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for bc8c…c9b2: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for 5d40…d89b: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for 4322…38b9: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for 38ce…cfe0: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for e9dc…1254: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for 1186…7c46: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for f832…0e40: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for c993…c40e: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for e064…b4dd: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:52 UTC Verifier #0 WARN client  Stage 2 block verification failed for 8aae…d039: Engine(NotProposer(Mismatch { expected: 00bd138abd70e2f00903268f3db08f2d25677c9e, found: 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4 }))
2017-03-23 05:28:53 UTC IO Worker #2 DEBUG network  Connecting peers: 1 sessions, 0 pending, 0 started
2017-03-23 05:28:54 UTC IO Worker #2 DEBUG network  Connecting peers: 1 sessions, 0 pending, 0 started
2017-03-23 05:28:55 UTC IO Worker #2 DEBUG sync  Bad new block 2abf62316f48c35c23312d1c8a6aa8b4242952fe9bac4382fa61a149b17b2aeb : Import(KnownBad)
2017-03-23 05:28:55 UTC IO Worker #2 DEBUG sync  Disconnected 0
2017-03-23 05:28:55 UTC IO Worker #0 DEBUG network  Connecting peers: 0 sessions, 0 pending, 0 started

[mills-nick]

Something I noticed from the logs is that the set of latest validators doesn't seem to be getting queried at each block, as it is when new blocks are created.
The line below only occurs once in the sync log:

2017-03-23 10:28:41 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e]

[mills-nick]

Tried the test without the --geth option, but this does not fix the issue.

[keorn]

Indeed, #4789 is missing from the beta. Will backport it for the next release. In the meantime you can use master or a nightly build.

[mills-nick]

This is great news for us since we will make use of this functionality in our private blockchain service:
https://guide.blockchain.z.com/en/
https://docs.blockchain.z.com/en/
Thank you and great work!

[mills-nick]

I confirmed that this is working properly with the nightly build.

From my log I can see the per block querying of validators, and I can see the state change after I added my new validator.

...
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]
2017-03-24 04:57:48 UTC Verifier #0 DEBUG engine  Set of validators obtained: [00bd138abd70e2f00903268f3db08f2d25677c9e, 00458ab1934c6aba4f8e0d1c1112bd8b4b0a91b4]