From 4050074e90e406f3c7314728d039e101eb21fb2b Mon Sep 17 00:00:00 2001 From: Hernando Castano Date: Thu, 4 Apr 2019 12:40:24 +0200 Subject: [PATCH 1/9] Stop breaking out of loop if a non-canonical hash is found --- ethcore/blockchain/src/blockchain.rs | 17 ++++++++++++----- 1 file changed, 12 insertions(+), 5 deletions(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index b528334cad3..efd653f42d0 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -963,6 +963,7 @@ impl BlockChain { /// Iterate over all epoch transitions. /// This will only return transitions within the canonical chain. pub fn epoch_transitions(&self) -> EpochTransitionIter { + trace!(target: "blockchain", "Iterating over all epoch transitions"); let iter = self.db.key_value().iter_from_prefix(db::COL_EXTRA, &EPOCH_KEY_PREFIX[..]); EpochTransitionIter { chain: self, @@ -988,7 +989,9 @@ impl BlockChain { pub fn epoch_transition_for(&self, parent_hash: H256) -> Option { // slow path: loop back block by block for hash in self.ancestry_iter(parent_hash)? { + trace!(target: "blockchain", "Got hash {} from ancestry_iter", hash); let details = self.block_details(&hash)?; + trace!(target: "blockchain", "Got block details for block #{}", details.number); // look for transition in database. if let Some(transition) = self.epoch_transition(details.number, hash) { @@ -1000,11 +1003,15 @@ impl BlockChain { // // if `block_hash` is canonical it will only return transitions up to // the parent. - if self.block_hash(details.number)? == hash { - return self.epoch_transitions() - .map(|(_, t)| t) - .take_while(|t| t.block_number <= details.number) - .last() + match self.block_hash(details.number) { + Some(h) if h == hash => { + return self.epoch_transitions() + .map(|(_, t)| t) + .take_while(|t| t.block_number <= details.number) + .last() + }, + Some(h) => trace!(target: "blockchain", "Found non-canonical block hash {}", h), + None => trace!(target: "blockchain", "Block hash not found in cache or DB"), } } From 88bafbe8d401c3ed970522f8d64f8228a32d5ec8 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 12:40:16 +0200 Subject: [PATCH 2/9] include expected hash in log msg --- ethcore/blockchain/src/blockchain.rs | 2 +- ethcore/src/engines/authority_round/mod.rs | 6 +++--- ethcore/src/verification/verifier.rs | 2 +- 3 files changed, 5 insertions(+), 5 deletions(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index efd653f42d0..8d4283d4616 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -1010,7 +1010,7 @@ impl BlockChain { .take_while(|t| t.block_number <= details.number) .last() }, - Some(h) => trace!(target: "blockchain", "Found non-canonical block hash {}", h), + Some(h) => trace!(target: "blockchain", "Found non-canonical block hash {} (expected {})", h, hash), None => trace!(target: "blockchain", "Block hash not found in cache or DB"), } } diff --git a/ethcore/src/engines/authority_round/mod.rs b/ethcore/src/engines/authority_round/mod.rs index 0942c0881ba..3b3d4ee8921 100644 --- a/ethcore/src/engines/authority_round/mod.rs +++ b/ethcore/src/engines/authority_round/mod.rs @@ -247,7 +247,7 @@ impl EpochManager { None => { // this really should never happen unless the block passed // hasn't got a parent in the database. - debug!(target: "engine", "No genesis transition found."); + warn!(target: "engine", "No genesis transition found."); return false; } }; @@ -280,8 +280,8 @@ impl EpochManager { true } - // note new epoch hash. this will force the next block to re-load - // the epoch set + // Note new epoch hash. This will force the next block to re-load + // the epoch set. // TODO: optimize and don't require re-loading after epoch change. fn note_new_epoch(&mut self) { self.force = true; diff --git a/ethcore/src/verification/verifier.rs b/ethcore/src/verification/verifier.rs index 76eb60b9a18..f7221dae81d 100644 --- a/ethcore/src/verification/verifier.rs +++ b/ethcore/src/verification/verifier.rs @@ -38,6 +38,6 @@ pub trait Verifier: Send + Sync /// Do a final verification check for an enacted header vs its expected counterpart. fn verify_block_final(&self, expected: &Header, got: &Header) -> Result<(), Error>; - /// Verify a block, inspecing external state. + /// Verify a block, inspecting external state. fn verify_block_external(&self, header: &Header, engine: &EthEngine) -> Result<(), Error>; } From fd2a19f00a5b773e5f9ac7d8178f49de482b4002 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 12:46:14 +0200 Subject: [PATCH 3/9] More logging --- ethcore/blockchain/src/blockchain.rs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index 8d4283d4616..287e286efc0 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -989,9 +989,9 @@ impl BlockChain { pub fn epoch_transition_for(&self, parent_hash: H256) -> Option { // slow path: loop back block by block for hash in self.ancestry_iter(parent_hash)? { - trace!(target: "blockchain", "Got hash {} from ancestry_iter", hash); + trace!(target: "blockchain", "Block #{}: Got hash {} from ancestry_iter", details.number, hash); let details = self.block_details(&hash)?; - trace!(target: "blockchain", "Got block details for block #{}", details.number); + trace!(target: "blockchain", "Block #{}: Got block details", details.number); // look for transition in database. if let Some(transition) = self.epoch_transition(details.number, hash) { @@ -1010,8 +1010,8 @@ impl BlockChain { .take_while(|t| t.block_number <= details.number) .last() }, - Some(h) => trace!(target: "blockchain", "Found non-canonical block hash {} (expected {})", h, hash), - None => trace!(target: "blockchain", "Block hash not found in cache or DB"), + Some(h) => trace!(target: "blockchain", "Block #{}: Found non-canonical block hash {} (expected {})", details.number, h, hash), + None => trace!(target: "blockchain", "Block #{}: hash {} not found in cache or DB", details.number, hash), } } From 704463d4aea4604b05b20b80a5f77be0f91920f2 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 12:49:16 +0200 Subject: [PATCH 4/9] Scope --- ethcore/blockchain/src/blockchain.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index 287e286efc0..9a8be4d9b4c 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -989,7 +989,7 @@ impl BlockChain { pub fn epoch_transition_for(&self, parent_hash: H256) -> Option { // slow path: loop back block by block for hash in self.ancestry_iter(parent_hash)? { - trace!(target: "blockchain", "Block #{}: Got hash {} from ancestry_iter", details.number, hash); + trace!(target: "blockchain", "Got parent hash {} from ancestry_iter", hash); let details = self.block_details(&hash)?; trace!(target: "blockchain", "Block #{}: Got block details", details.number); From 5f9caa57b31eef6a23bd7aedd104558623118a66 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 13:26:36 +0200 Subject: [PATCH 5/9] Syntax --- ethcore/src/engines/authority_round/finality.rs | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/ethcore/src/engines/authority_round/finality.rs b/ethcore/src/engines/authority_round/finality.rs index af57278c9f3..1f2bb559ea8 100644 --- a/ethcore/src/engines/authority_round/finality.rs +++ b/ethcore/src/engines/authority_round/finality.rs @@ -110,7 +110,16 @@ impl RollingFinality { /// Returns a list of all newly finalized headers. // TODO: optimize with smallvec. pub fn push_hash(&mut self, head: H256, signers: Vec
) -> Result, UnknownValidator> { - if signers.iter().any(|s| !self.signers.contains(s)) { return Err(UnknownValidator) } + if signers + .iter() + .any(|s| { + if !self.signers.contains(s) { + warn!(target: "finality", "Unknown validator: {}", s); + false + } else { true } + }) { + return Err(UnknownValidator) + } for signer in signers.iter() { *self.sign_count.entry(*signer).or_insert(0) += 1; @@ -141,7 +150,7 @@ impl RollingFinality { } } - trace!(target: "finality", "Blocks finalized by {:?}: {:?}", head, newly_finalized); + trace!(target: "finality", "{} Blocks finalized by {:?}: {:?}", newly_finalized.len(), head, newly_finalized); self.last_pushed = Some(head); Ok(newly_finalized) From befe9b87130d799ad830fa1435e65b480b9da0f0 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 13:41:36 +0200 Subject: [PATCH 6/9] Log in blank RollingFinality Escalate bad proposer to warning --- ethcore/src/engines/authority_round/finality.rs | 1 + ethcore/src/engines/authority_round/mod.rs | 2 +- 2 files changed, 2 insertions(+), 1 deletion(-) diff --git a/ethcore/src/engines/authority_round/finality.rs b/ethcore/src/engines/authority_round/finality.rs index 1f2bb559ea8..fef0ebb30eb 100644 --- a/ethcore/src/engines/authority_round/finality.rs +++ b/ethcore/src/engines/authority_round/finality.rs @@ -39,6 +39,7 @@ pub struct RollingFinality { impl RollingFinality { /// Create a blank finality checker under the given validator set. pub fn blank(signers: Vec
) -> Self { + trace!(target: "finality", "Instantiating blank RollingFinality with {} signers: {:?}", signers.len(), signers); RollingFinality { headers: VecDeque::new(), signers: SimpleList::new(signers), diff --git a/ethcore/src/engines/authority_round/mod.rs b/ethcore/src/engines/authority_round/mod.rs index 3b3d4ee8921..8bf838d2dc5 100644 --- a/ethcore/src/engines/authority_round/mod.rs +++ b/ethcore/src/engines/authority_round/mod.rs @@ -614,7 +614,7 @@ fn verify_external(header: &Header, validators: &ValidatorSet, empty_steps_trans }; if is_invalid_proposer { - trace!(target: "engine", "verify_block_external: bad proposer for step: {}", header_step); + warn!(target: "engine", "verify_block_external: bad proposer for step: {}", header_step); Err(EngineError::NotProposer(Mismatch { expected: correct_proposer, found: *header.author() }))? } else { Ok(()) From 4afc40b6e0ec59a033eeb9b9a4618a3792843d65 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 14:13:10 +0200 Subject: [PATCH 7/9] More readable code --- ethcore/src/engines/authority_round/finality.rs | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) diff --git a/ethcore/src/engines/authority_round/finality.rs b/ethcore/src/engines/authority_round/finality.rs index fef0ebb30eb..e88458d81aa 100644 --- a/ethcore/src/engines/authority_round/finality.rs +++ b/ethcore/src/engines/authority_round/finality.rs @@ -111,15 +111,13 @@ impl RollingFinality { /// Returns a list of all newly finalized headers. // TODO: optimize with smallvec. pub fn push_hash(&mut self, head: H256, signers: Vec
) -> Result, UnknownValidator> { - if signers - .iter() - .any(|s| { - if !self.signers.contains(s) { - warn!(target: "finality", "Unknown validator: {}", s); - false - } else { true } - }) { + // TODO: seems bad to iterate over signers twice like this. + // Can do the work in a single loop and call `clear()` if an unknown validator was found? + for their_signer in signers.iter() { + if !self.signers.contains(their_signer) { + warn!(target: "finality", "Unknown validator: {}", their_signer); return Err(UnknownValidator) + } } for signer in signers.iter() { From b6800262179b4331c2b8d9d61ffd69bee4742ba7 Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 15:19:23 +0200 Subject: [PATCH 8/9] Extensive logging on unexpected non-canonical hash --- ethcore/blockchain/src/blockchain.rs | 9 ++++++++- 1 file changed, 8 insertions(+), 1 deletion(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index 9a8be4d9b4c..b188834193c 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -1010,7 +1010,14 @@ impl BlockChain { .take_while(|t| t.block_number <= details.number) .last() }, - Some(h) => trace!(target: "blockchain", "Block #{}: Found non-canonical block hash {} (expected {})", details.number, h, hash), + Some(h) => { + warn!(target: "blockchain", "Block #{}: Found non-canonical block hash {} (expected {})", details.number, h, hash); + + trace!(target: "blockchain", "#{} {} != {} HASH UNEQUAL, #{}", details.number, hash, h, self.block_number(&h).unwrap_or_default() ); + trace!(target: "blockchain", " Version A {}: #{:#?}", hash, self.block_details(&hash)); + trace!(target: "blockchain", " Version B {}: #{:#?}", h, self.block_details(&h)); + + }, None => trace!(target: "blockchain", "Block #{}: hash {} not found in cache or DB", details.number, hash), } } From 2551e0fc6acc4c4784771f19341aec3d800c88bf Mon Sep 17 00:00:00 2001 From: David Palm Date: Mon, 10 Jun 2019 15:23:32 +0200 Subject: [PATCH 9/9] Wording --- ethcore/blockchain/src/blockchain.rs | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) diff --git a/ethcore/blockchain/src/blockchain.rs b/ethcore/blockchain/src/blockchain.rs index b188834193c..7cf6b12dd5c 100644 --- a/ethcore/blockchain/src/blockchain.rs +++ b/ethcore/blockchain/src/blockchain.rs @@ -1013,9 +1013,9 @@ impl BlockChain { Some(h) => { warn!(target: "blockchain", "Block #{}: Found non-canonical block hash {} (expected {})", details.number, h, hash); - trace!(target: "blockchain", "#{} {} != {} HASH UNEQUAL, #{}", details.number, hash, h, self.block_number(&h).unwrap_or_default() ); - trace!(target: "blockchain", " Version A {}: #{:#?}", hash, self.block_details(&hash)); - trace!(target: "blockchain", " Version B {}: #{:#?}", h, self.block_details(&h)); + trace!(target: "blockchain", "Block #{} Mismatched hashes. Ancestor {} != Own {} – Own block #{}", details.number, hash, h, self.block_number(&h).unwrap_or_default() ); + trace!(target: "blockchain", " Ancestor {}: #{:#?}", hash, self.block_details(&hash)); + trace!(target: "blockchain", " Own {}: #{:#?}", h, self.block_details(&h)); }, None => trace!(target: "blockchain", "Block #{}: hash {} not found in cache or DB", details.number, hash),