Skip to content
This repository has been archived by the owner on Nov 15, 2023. It is now read-only.

Block generation halted #183

Closed
gavofyork opened this issue May 30, 2018 · 4 comments · Fixed by #191
Closed

Block generation halted #183

gavofyork opened this issue May 30, 2018 · 4 comments · Fixed by #191
Assignees
Labels
U0-drop_everything Everyone should address the issue now.

Comments

@gavofyork
Copy link
Member

4 (of 4) validator nodes stopped generating blocks around 0330 last night. They were well connected. Restarting node 4 kickstarted block generation. No logs as yet.

@gavofyork
Copy link
Member Author

gavofyork commented May 30, 2018

Happened again, just now. Here's the logs from node 1; other nodes can have their logs grabbed if necessary.

2018-05-30 11:48:05  TRACE sync  Broadcasting BFT message LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: ae590da61fed60e95f45913575fcb4db4369e025c57e2819260558babccbe22f5d9b0ffdcd2de59c022d60fab728c6d5a66a533015b907bb1519029678e0a806 })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #3 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: 6394dcae1b34e86657c9cd46d5b43bbdae44379c36598297949a73e13d7c983b17658eca619bd2a33729cbf975e5e764ca3a0d1f11d3c5fe07f312dc66c2f60d })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #3 TRACE sync  Ignored already known BFT message from 69
2018-05-30 11:48:05 IO Worker #3 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: c1616b9883305a046e28e5b0edae5622d78d1af69d09c14085a36c9598ad12ce2a38348e426b39947a61fd6e39fe10a9076c0414217579f2dbec58dc9c293c0c })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #3 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: d4ea5053a55ac6ec6ae98572ac4fecd920f4600268c9f0922d7449a6b3d355ef1fe4891bd7af7a206ab8ab4ec031ffdf8e0bc981f45a8723802f9e345643bb0e })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05  TRACE bft  importing vote Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc) from 063d…dca5
2018-05-30 11:48:05  TRACE bft  importing vote Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc) from 4de3…77e7
2018-05-30 11:48:05  TRACE bft  Polling BFT logic. State=(1, Committed)
2018-05-30 11:48:05 IO Worker #3 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: 6394dcae1b34e86657c9cd46d5b43bbdae44379c36598297949a73e13d7c983b17658eca619bd2a33729cbf975e5e764ca3a0d1f11d3c5fe07f312dc66c2f60d })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #3 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:05 IO Worker #2 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [129, 1, 118, 79, 69, 119, 141, 73, 128, 218, 218, 206, 238, 110, 138, 242, 81, 125, 58, 185, 26, 201, 190, 201, 205, 23, 20, 250, 89, 148, 8, 28], signature: 09801cfb1e552c1a42ab1960526666a9e217f236c68ed26b546180bf190fd7bb4c82ea601f529835af923ff69ad18bbe72a20f7008029ad18147f3c3ec67950d })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #1 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: d4ea5053a55ac6ec6ae98572ac4fecd920f4600268c9f0922d7449a6b3d355ef1fe4891bd7af7a206ab8ab4ec031ffdf8e0bc981f45a8723802f9e345643bb0e })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #1 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:05  TRACE bft  importing vote Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc) from 8101…081c
2018-05-30 11:48:05  TRACE bft  observed threshold-commit for round 1
2018-05-30 11:48:05 IO Worker #0 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: c1616b9883305a046e28e5b0edae5622d78d1af69d09c14085a36c9598ad12ce2a38348e426b39947a61fd6e39fe10a9076c0414217579f2dbec58dc9c293c0c })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #0 TRACE sync  Ignored already known BFT message from 69
2018-05-30 11:48:05  TRACE bft  Polling BFT logic. State=(1, Committed)
2018-05-30 11:48:05  INFO bft  Importing block #279135 (051c…32cc) directly from BFT consensus
2018-05-30 11:48:05 IO Worker #2 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: d4ea5053a55ac6ec6ae98572ac4fecd920f4600268c9f0922d7449a6b3d355ef1fe4891bd7af7a206ab8ab4ec031ffdf8e0bc981f45a8723802f9e345643bb0e })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #2 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:05 IO Worker #1 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [129, 1, 118, 79, 69, 119, 141, 73, 128, 218, 218, 206, 238, 110, 138, 242, 81, 125, 58, 185, 26, 201, 190, 201, 205, 23, 20, 250, 89, 148, 8, 28], signature: 09801cfb1e552c1a42ab1960526666a9e217f236c68ed26b546180bf190fd7bb4c82ea601f529835af923ff69ad18bbe72a20f7008029ad18147f3c3ec67950d })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #1 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:05 main INFO polkadot  Imported #279135 (051c…32cc)
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 62
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 46
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 59
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 38
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 64
2018-05-30 11:48:05  TRACE sync  Announcing block 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc to 69
2018-05-30 11:48:05 IO Worker #1 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Commit(1, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: c1616b9883305a046e28e5b0edae5622d78d1af69d09c14085a36c9598ad12ce2a38348e426b39947a61fd6e39fe10a9076c0414217579f2dbec58dc9c293c0c })), parent_hash: 7b6a45a8395474315759f0853aca611a0e880d053431d2cae4bdbe78f55786f6 }
2018-05-30 11:48:05 IO Worker #1 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:05 IO Worker #1 TRACE sync  BlockRequest 1250 from 59: from Number(279135) to None max Some(1)
2018-05-30 11:48:05 IO Worker #2 TRACE sync  BlockRequest 1876 from 64: from Number(279135) to None max Some(1)
2018-05-30 11:48:05  TRACE bft  max_faulty_of(5)=1
2018-05-30 11:48:05 IO Worker #1 TRACE sync  Known block announce from 69: 051c…32cc
2018-05-30 11:48:05  DEBUG bft  Initialising consensus proposer. Refusing to evaluate for Duration { secs: 5, nanos: 0 } from now.
2018-05-30 11:48:05  TRACE bft  proposer for round 0 is 2477…5aa7
2018-05-30 11:48:05  TRACE bft  proposer for round 1 is 82c3…5cf5
2018-05-30 11:48:05  TRACE bft  Polling BFT logic. State=(0, Start)
2018-05-30 11:48:05  TRACE bft  proposer for round 0 is 2477…5aa7
2018-05-30 11:48:05 IO Worker #3 TRACE sync  BlockRequest 1207 from 62: from Number(279135) to None max Some(1)
2018-05-30 11:48:05 IO Worker #2 TRACE sync  BlockRequest 1586 from 46: from Number(279135) to None max Some(1)
2018-05-30 11:48:05 IO Worker #1 TRACE sync  BlockRequest 290 from 38: from Number(279135) to None max Some(1)
2018-05-30 11:48:06 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:08 IO Worker #0 DEBUG sync  Propagating transactions
2018-05-30 11:48:09  TRACE bft  Polling BFT logic. State=(0, Start)
2018-05-30 11:48:09  TRACE bft  proposer for round 0 is 2477…5aa7
2018-05-30 11:48:09  TRACE bft  Polling BFT logic. State=(0, VoteAdvance)
2018-05-30 11:48:09  TRACE sync  Broadcasting BFT message LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: ed94d2a039dd0aed9a6834dccfe4a679423db35cba6ba7b3814a466d1fac2bd4a498742d1cb99f8aa00bf8f055438d47d5b5894630cc5e6ef1946521bff9ae01 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09 IO Worker #2 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 7af833f85559a08ffd7511198a9f3116a7ab54881cef4a261148673bf52804aa77c9e26c73ad0bab2170df6062cc3091dbd2413394d4235b55c353416462f904 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09  TRACE bft  importing vote AdvanceRound(0) from 4de3…77e7
2018-05-30 11:48:09 IO Worker #1 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: 88a4419e080e0e6c45e00072f1a7eec0ec6293d1a4e11f29895f70aaf04717096b573bf9eb9491f2a29a8db4051f105b79a3f46a3e368b6a05ec6530f8c9610a })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09  TRACE bft  Polling BFT logic. State=(0, VoteAdvance)
2018-05-30 11:48:09  TRACE bft  importing vote AdvanceRound(0) from 063d…dca5
2018-05-30 11:48:09  TRACE bft  Polling BFT logic. State=(0, VoteAdvance)
2018-05-30 11:48:09 IO Worker #1 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 7af833f85559a08ffd7511198a9f3116a7ab54881cef4a261148673bf52804aa77c9e26c73ad0bab2170df6062cc3091dbd2413394d4235b55c353416462f904 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09 IO Worker #1 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:09 IO Worker #0 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 7af833f85559a08ffd7511198a9f3116a7ab54881cef4a261148673bf52804aa77c9e26c73ad0bab2170df6062cc3091dbd2413394d4235b55c353416462f904 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09 IO Worker #0 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:09 IO Worker #3 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: 88a4419e080e0e6c45e00072f1a7eec0ec6293d1a4e11f29895f70aaf04717096b573bf9eb9491f2a29a8db4051f105b79a3f46a3e368b6a05ec6530f8c9610a })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:09 IO Worker #3 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:11 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:13 IO Worker #3 DEBUG sync  Propagating transactions
2018-05-30 11:48:14 IO Worker #3 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [129, 1, 118, 79, 69, 119, 141, 73, 128, 218, 218, 206, 238, 110, 138, 242, 81, 125, 58, 185, 26, 201, 190, 201, 205, 23, 20, 250, 89, 148, 8, 28], signature: af0f8de56496516462ece96dbe39d5c858b5dd3d705dae3d9eb8eb5e03e8044d38afca4433557d3b8562d342d454f63aa68c995cc85f4b3be095781a0f872a0f })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE bft  importing vote AdvanceRound(0) from 8101…081c
2018-05-30 11:48:14  TRACE bft  Witnessed threshold advance-round messages for round 0
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(0, VoteAdvance)
2018-05-30 11:48:14  TRACE bft  advancing to round 1
2018-05-30 11:48:14  TRACE bft  proposer for round 2 is 4de3…77e7
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(1, Start)
2018-05-30 11:48:14  TRACE bft  proposer for round 1 is 82c3…5cf5
2018-05-30 11:48:14  DEBUG bft  proposing block on top of parent (279135, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc)
2018-05-30 11:48:14 IO Worker #3 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [129, 1, 118, 79, 69, 119, 141, 73, 128, 218, 218, 206, 238, 110, 138, 242, 81, 125, 58, 185, 26, 201, 190, 201, 205, 23, 20, 250, 89, 148, 8, 28], signature: af0f8de56496516462ece96dbe39d5c858b5dd3d705dae3d9eb8eb5e03e8044d38afca4433557d3b8562d342d454f63aa68c995cc85f4b3be095781a0f872a0f })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14 IO Worker #3 TRACE sync  Ignored already known BFT message from 69
2018-05-30 11:48:14 IO Worker #2 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(0), sender: [129, 1, 118, 79, 69, 119, 141, 73, 128, 218, 218, 206, 238, 110, 138, 242, 81, 125, 58, 185, 26, 201, 190, 201, 205, 23, 20, 250, 89, 148, 8, 28], signature: af0f8de56496516462ece96dbe39d5c858b5dd3d705dae3d9eb8eb5e03e8044d38afca4433557d3b8562d342d454f63aa68c995cc85f4b3be095781a0f872a0f })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14 IO Worker #2 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:14  INFO polkadot_consensus  Proposing block [number: 279136; hash: 3730…2b11; parent_hash: 051c…32cc; extrinsics: [773d…9ae5]]
2018-05-30 11:48:14  DEBUG bft  Importing proposal for round 1
2018-05-30 11:48:14  DEBUG bft  evaluating block on top of parent (279135, 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc)
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(1, Prepared(true))
2018-05-30 11:48:14  TRACE sync  Broadcasting BFT message LocalizedBftMessage { message: Consensus(Propose(SignedConsensusProposal { round_number: 1, proposal: Block { header: Header { parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc, number: 279136, state_root: 255a096e17a652889d5aac2ec008ef325258df14bd932ca34ddc64509a498cdd, extrinsics_root: 36e0c115c8222d9c1be6db7d35bea6ad892077aaf062aafa71246485657cf5c1, digest: Digest { logs: [] } }, transactions: [Extrinsic([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, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 3, 0, 126, 143, 14, 91, 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, 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, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0])] }, digest: 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11, sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], digest_signature: 2a4bfb5071b97fddd428768f08e58c1b9ca64ab09b2c9327d2cc108fce3e47cb852dadc6377215605f7185cb5e31a51ae1228a6c15c7a0934e339c172840bd07, full_signature: 98c1d3b303b9b89a0d7da761607645fea191ddae0fc3eddcd6129d095f3211fb4c8cf42076f50f4d6efc1a728a9871745c95839e1cdf9d1ae3d96ce1832c2803 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE sync  Broadcasting BFT message LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: f5229a07a9bfa1b3d234e392b1d3d615b223fdc62991d07dbaf6fbde0dcec7126c2f36f8169ca1c70f385f588d5ec0d119e43d52e2d74973886870928ecd870d })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(1, Prepared(true))
2018-05-30 11:48:14 IO Worker #0 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: f5229a07a9bfa1b3d234e392b1d3d615b223fdc62991d07dbaf6fbde0dcec7126c2f36f8169ca1c70f385f588d5ec0d119e43d52e2d74973886870928ecd870d })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14 IO Worker #0 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:14 IO Worker #1 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 8d0485957039f9467871220adf6ef3885187867babce31481dbea4914ed197884c669a49a81dd9f39d4486ac09db18608de8f1d5fc63499adeb65094f6907a08 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE bft  importing vote Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11) from 4de3…77e7
2018-05-30 11:48:14 IO Worker #3 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: f5229a07a9bfa1b3d234e392b1d3d615b223fdc62991d07dbaf6fbde0dcec7126c2f36f8169ca1c70f385f588d5ec0d119e43d52e2d74973886870928ecd870d })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(1, Prepared(true))
2018-05-30 11:48:14 IO Worker #3 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:14 IO Worker #2 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: f01585b0e3f50ec929e540deb0daf220f741fd02aa20a87e2e54e1f59289697a0bc3a0655bcd5be954a17b37003ad2b5b2a981257e607589ca01c89e55cbd906 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14  TRACE bft  importing vote Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11) from 063d…dca5
2018-05-30 11:48:14  TRACE bft  Polling BFT logic. State=(1, Prepared(true))
2018-05-30 11:48:14 IO Worker #3 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 8d0485957039f9467871220adf6ef3885187867babce31481dbea4914ed197884c669a49a81dd9f39d4486ac09db18608de8f1d5fc63499adeb65094f6907a08 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14 IO Worker #3 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:14 IO Worker #1 TRACE sync  BFT message from 62: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: Prepare(1, 373066b93b03d4c5bd1514cccd7d6dfca7fcf78dd21fd27a8a3a2d59bccb2b11), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: f01585b0e3f50ec929e540deb0daf220f741fd02aa20a87e2e54e1f59289697a0bc3a0655bcd5be954a17b37003ad2b5b2a981257e607589ca01c89e55cbd906 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:14 IO Worker #1 TRACE sync  Ignored already known BFT message from 62
2018-05-30 11:48:16 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:18 IO Worker #1 DEBUG sync  Propagating transactions
2018-05-30 11:48:21 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:22  TRACE bft  Polling BFT logic. State=(1, Prepared(true))
2018-05-30 11:48:22  TRACE bft  Polling BFT logic. State=(1, VoteAdvance)
2018-05-30 11:48:22  TRACE sync  Broadcasting BFT message LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(1), sender: [130, 195, 155, 49, 162, 183, 154, 144, 248, 230, 110, 122, 119, 253, 184, 90, 78, 213, 81, 127, 42, 227, 159, 106, 128, 86, 94, 142, 202, 232, 92, 245], signature: 6e365a7b5ead596ce217445595f5c2d20a8e82cf04566e974886494c87f7c713891a21d71addcef8711876f0deba0639a085188b5a86acda445ef28cbbfbe104 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:22 IO Worker #2 TRACE sync  BFT message from 69: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(1), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 3d42199fe62a6e82d7efa6d2e775cc7449ad5ae7c0ebe9e6f8d29c3b1873b6d1ad189a2e63d1a7501a4cff4b29f8fc467bd7a2c610ab5952cf61fb5312d55004 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:22 IO Worker #0 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(1), sender: [6, 61, 119, 135, 235, 202, 118, 139, 116, 69, 223, 235, 231, 214, 44, 187, 22, 37, 255, 77, 186, 40, 142, 163, 68, 136, 218, 38, 109, 214, 220, 165], signature: 48296dc1f554136c50f576ff2ee59bbe146ad781b352b6d49f0630a8e000063fe3e088e7785a0d38795e93b8d066989caf4a4b6ec080de4e851a5921e34d0a0b })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:22  TRACE bft  importing vote AdvanceRound(1) from 4de3…77e7
2018-05-30 11:48:22  TRACE bft  importing vote AdvanceRound(1) from 063d…dca5
2018-05-30 11:48:22  TRACE bft  Polling BFT logic. State=(1, VoteAdvance)
2018-05-30 11:48:22 IO Worker #1 TRACE sync  BFT message from 59: LocalizedBftMessage { message: Consensus(Vote(SignedConsensusVote { vote: AdvanceRound(1), sender: [77, 227, 122, 7, 86, 126, 188, 191, 140, 100, 86, 132, 40, 168, 53, 38, 154, 86, 103, 35, 104, 112, 88, 224, 23, 182, 214, 157, 176, 10, 119, 231], signature: 3d42199fe62a6e82d7efa6d2e775cc7449ad5ae7c0ebe9e6f8d29c3b1873b6d1ad189a2e63d1a7501a4cff4b29f8fc467bd7a2c610ab5952cf61fb5312d55004 })), parent_hash: 051c904815dfd695e2cd3c959f35b65213968e6e892fd6a091ade0878a4132cc }
2018-05-30 11:48:22 IO Worker #1 TRACE sync  Ignored already known BFT message from 59
2018-05-30 11:48:23 IO Worker #0 DEBUG sync  Propagating transactions
2018-05-30 11:48:26 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:28 IO Worker #0 DEBUG sync  Propagating transactions
2018-05-30 11:48:31 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:33 IO Worker #2 DEBUG sync  Propagating transactions
2018-05-30 11:48:36 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:38 IO Worker #0 DEBUG sync  Propagating transactions
2018-05-30 11:48:41 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:43 IO Worker #2 DEBUG sync  Propagating transactions
2018-05-30 11:48:46 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:48 IO Worker #3 DEBUG sync  Propagating transactions
2018-05-30 11:48:51 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:53 IO Worker #1 DEBUG sync  Propagating transactions
2018-05-30 11:48:56 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)
2018-05-30 11:48:58 IO Worker #2 DEBUG sync  Propagating transactions
2018-05-30 11:49:01 main INFO polkadot  Idle (6 peers), best: #279135 (051c…32cc)

@gavofyork
Copy link
Member Author

Happened again. Logs attached.
output-node1.log
output-node2.log
output-node3.log
output-node4.log

@gavofyork gavofyork added the U0-drop_everything Everyone should address the issue now. label May 31, 2018
@arkpar
Copy link
Member

arkpar commented May 31, 2018

Ok, so here is a quick summary of what happened after the investigation that we did with @rphmeier:
The systems expects 5 validators, so 3 votes are required. Only 4 nodes a are running.
Node4 begins importing a block, which takes some time.
Voting messages on the next block are queued on node4 while the block is still being imported.
Node4 receives block announcements from other peers and downloads the block that is being imported again. It finished importing the block and them imports it again, sending the import notification twice. The message queue is cleared because it expects notifications not come in order.

@rphmeier
Copy link
Contributor

right, there are actually 5 validators in the system because someone registered their node as one. Since max_faulty_of(5)=1, we need 4 messages to exceed a 2/3 majority, and one of the 4 nodes we run was having the issues which Arkadiy described, leading to a consensus halt.

lamafab pushed a commit to lamafab/substrate that referenced this issue Jun 16, 2020
* Rebuild runtime

* Remove invalid value from chainspec (paritytech#68)

* service: use grandpa block import for locally sealed aura blocks (paritytech#85)

* bump version to v0.3.1

* Update lock file.

* limit number of transactions when building blocks (paritytech#91)

* Update to latest Substrate

* Bump to 0.3.2

* Actually bump.

* v0.3.2 (paritytech#98)

* bump substrate version

* fix polkadot-collator

* point to alexander-backports of substrate

* bump version

* cli: fix node shutdown (paritytech#100)

* update to latest substrate, change to v0.3.4

* update to latest substrate, bump version to 0.3.5

* v0.3.6

* try to build on every v0.3 commit and update alexander-backports

* bump to v0.3.7

* bump to 0.3.8

* Bump to 0.3.9: network and pruning improvements

* Bump to 0.3.10: reduce network bandwidth usage

* Use libp2p-kad 0.3.2 (paritytech#122)

* Bump libp2p-identify to 0.3.1 (paritytech#123)

* Bump to 0.3.12 (paritytech#127)

* Update Substrate again (paritytech#128)

* update substrate and bump version to v0.3.13

* bump version to v0.3.14: fix --reserved-nodes

* add a manually curated grandpa module (paritytech#136)

* updating v0.3 to use substrate v0.10 (paritytech#146)

* updating to latest substrate v0.10

* better handling of outer poll

* nit

* fix tests

* remove comment

* reduce indentation

* use self.poll

* bring oneshot into scope

* spaces

* wrap

* remove match

* wrap

* Update primitives/Cargo.toml

Co-Authored-By: gterzian <2792687+gterzian@users.noreply.github.com>

* Update runtime/wasm/Cargo.toml

Co-Authored-By: gterzian <2792687+gterzian@users.noreply.github.com>

* Update runtime/wasm/Cargo.toml

Co-Authored-By: gterzian <2792687+gterzian@users.noreply.github.com>

* Update test-parachains/adder/collator/src/main.rs

Co-Authored-By: gterzian <2792687+gterzian@users.noreply.github.com>

* indent

* add paranthese

* config: fix wrong ip for alexander bootnode (paritytech#161)

* fix curated-grandpa and rebuild wasm (paritytech#162)

* [v0.3] Integrates new gossip system into Polkadot (paritytech#166)

* new gossip validation in network

* integrate new gossip into service

* network: guard validation network future under exit signal (paritytech#168)

* bump version to v0.3.15: substrate v0.10

* [v0.3] update to substrate master (paritytech#175)

* update to substrate master

* fix test

* service: fix telemetry endpoints on alexander chainspec (paritytech#169) (paritytech#178)

* Update v0.3 to latest Substrate master (paritytech#177)

* update substrate v0.3 to latest master

* bump spec version

* update to latest master: remove fees module

* update runtime blobs

* bump version to 0.3.16

* replace sr25519 accountid with anysigner

* bump version to v0.3.17

* Some PoC-3 GRANDPA tweaks (paritytech#181)

* call on_finalise after triggering curated_grandpa change

* make grandpa rounds shorter for faster finalization

* use authorities when calculating duty roster (paritytech#185)

* [v0.3] Update to substrate master (paritytech#183)

* update to latest substrate master

* bump version to 0.3.18

* update to latest substrate master

* bump spec version

* update runtime wasm blobs

* remove current_offline_slash from chain spec

* update to substrate master: bump version to v0.3.19 (paritytech#188)

* update to substrate master: bump version to v0.3.19

libp2p network improvements

* network: replace NodeIndex with PeerId

* network: fix tests

* polkadot v0.3.20 (paritytech#190)

* update to substrate master: bump version to 0.3.20

* runtime: add offchain worker trait

* runtime: rebuild wasm blobs

* bump spec version (paritytech#191)

* Fix compilation

* Update version to 0.4.0

* Switch to use `polkadot-master` branch from substrate

* Remove unused struct

* Remove `grandpa::SyncedAuthorities` from `OnSessionChange`
liuchengxu pushed a commit to chainx-org/substrate that referenced this issue Aug 23, 2021
* refactor assets

change free/reserved balance to assetbalance

* refactor related module
liuchengxu added a commit to chainx-org/substrate that referenced this issue Aug 23, 2021
* Consider the migration offset of session reward

* grammer

* Remove MinimumValidatorCount const

Close paritytech#182

* Fix test

* .
liuchengxu pushed a commit to autonomys/substrate that referenced this issue Jun 3, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
U0-drop_everything Everyone should address the issue now.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

3 participants