add logging around handling of orphan blocks (#500)

add some unrelated block validation comments

chain/src/chain.rs

@@ -159,10 +159,29 @@ impl Chain {
 				self.check_orphans();
 			}
 			Ok(None) => {}
-			Err(Error::Orphan) => if b.header.height < height + (MAX_ORPHANS as u64) {
+			Err(Error::Orphan) => {
-				let mut orphans = self.orphans.lock().unwrap();
+				// TODO - Do we want to check that orphan height is > current height?
-				orphans.push_front((opts, b));
+				// TODO - Just check heights here? Or should we be checking total_difficulty as well?
-				orphans.truncate(MAX_ORPHANS);
+				let block_hash = b.hash();
+				if b.header.height < height + (MAX_ORPHANS as u64) {
+					let mut orphans = self.orphans.lock().unwrap();
+					orphans.push_front((opts, b));
+					orphans.truncate(MAX_ORPHANS);
+					debug!(
+						LOGGER,
+						"process_block: orphan: {:?}, # orphans {}",
+						block_hash,
+						orphans.len(),
+					);
+				} else {
+					debug!(
+						LOGGER,
+						"process_block: orphan: {:?}, (dropping, height {} vs {})",
+						block_hash,
+						b.header.height,
+						height,
+					);
+				}
 			},
 			Err(Error::Unfit(ref msg)) => {
 				debug!(
@@ -211,6 +230,7 @@ impl Chain {
 		}
 	}
 
+	/// Check if hash is for a known orphan.
 	pub fn is_orphan(&self, hash: &Hash) -> bool {
 		let orphans = self.orphans.lock().unwrap();
 		orphans.iter().any(|&(_, ref x)| x.hash() == hash.clone())
@@ -219,12 +239,13 @@ impl Chain {
 	/// Pop orphans out of the queue and check if we can now accept them.
 	fn check_orphans(&self) {
 		// first check how many we have to retry, unfort. we can't extend the lock
-  // in the loop as it needs to be freed before going in process_block
+		// in the loop as it needs to be freed before going in process_block
 		let orphan_count;
 		{
 			let orphans = self.orphans.lock().unwrap();
 			orphan_count = orphans.len();
 		}
+		debug!(LOGGER, "check_orphans: # orphans {}", orphan_count);
 
 		// pop each orphan and retry, if still orphaned, will be pushed again
 		for _ in 0..orphan_count {

chain/src/pipe.rs

@@ -151,7 +151,7 @@ fn check_known(bh: Hash, ctx: &mut BlockContext) -> Result<(), Error> {
 	Ok(())
 }
 
-/// First level of black validation that only needs to act on the block header
+/// First level of block validation that only needs to act on the block header
 /// to make it as cheap as possible. The different validations are also
 /// arranged by order of cost to have as little DoS surface as possible.
 /// TODO require only the block header (with length information)
@@ -171,7 +171,7 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 		> time::now_utc() + time::Duration::seconds(12 * (consensus::BLOCK_TIME_SEC as i64))
 	{
 		// refuse blocks more than 12 blocks intervals in future (as in bitcoin)
-  // TODO add warning in p2p code if local time is too different from peers
+		// TODO add warning in p2p code if local time is too different from peers
 		return Err(Error::InvalidBlockTime);
 	}
 
@@ -196,6 +196,8 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 	if header.height != prev.height + 1 {
 		return Err(Error::InvalidBlockHeight);
 	}
+
+	// TODO - get rid of the automated testing mode check here somehow
 	if header.timestamp <= prev.timestamp && !global::is_automated_testing_mode() {
 		// prevent time warp attacks and some timestamp manipulations by forcing strict
 		// time progression (but not in CI mode)
@@ -211,10 +213,14 @@ fn validate_header(header: &BlockHeader, ctx: &mut BlockContext) -> Result<(), E
 			return Err(Error::DifficultyTooLow);
 		}
 
+		// explicit check to ensure total_difficulty has increased by exactly
+		// the difficulty of the previous block
 		if header.total_difficulty != prev.total_difficulty.clone() + prev.pow.to_difficulty() {
 			return Err(Error::WrongTotalDifficulty);
 		}
 
+		// now check that the difficulty is not less than that calculated by the
+		// difficulty iterator based on the previous block
 		let diff_iter = store::DifficultyIter::from(header.previous, ctx.store.clone());
 		let difficulty =
 			consensus::next_difficulty(diff_iter).map_err(|e| Error::Other(e.to_string()))?;
@@ -312,8 +318,6 @@ fn validate_block(
 				if let Ok(output_header) = ctx.store
 					.get_block_header_by_output_commit(&input.commitment())
 				{
-					// TODO - make sure we are not off-by-1 here vs. the equivalent tansaction
-					// validation rule
 					if b.header.height <= output_header.height + global::coinbase_maturity() {
 						return Err(Error::ImmatureCoinbase);
 					}