Merge pull request #2637 from Sharmalm/2348

Improve block connection logging and filtered txids

Author: TheBlueMatt

lightning/src/chain/chainmonitor.rs

@@ -402,7 +402,8 @@ where C::Target: chain::Filter,
 						outpoint: OutPoint { txid, index: idx as u16 },
 						script_pubkey: output.script_pubkey,
 					};
-					chain_source.register_output(output)
+					log_trace!(logger, "Adding monitoring for spends of outpoint {} to the filter", output.outpoint);
+					chain_source.register_output(output);
 				}
 			}
 		}
@@ -741,7 +742,7 @@ where C::Target: chain::Filter,
 			},
 		}
 		if let Some(ref chain_source) = self.chain_source {
-			monitor.load_outputs_to_watch(chain_source);
+			monitor.load_outputs_to_watch(chain_source , &self.logger);
 		}
 		entry.insert(MonitorHolder {
 			monitor,

lightning/src/chain/channelmonitor.rs

@@ -1382,15 +1382,22 @@ impl<Signer: WriteableEcdsaChannelSigner> ChannelMonitor<Signer> {
 	/// Loads the funding txo and outputs to watch into the given `chain::Filter` by repeatedly
 	/// calling `chain::Filter::register_output` and `chain::Filter::register_tx` until all outputs
 	/// have been registered.
-	pub fn load_outputs_to_watch<F: Deref>(&self, filter: &F) where F::Target: chain::Filter {
+	pub fn load_outputs_to_watch<F: Deref, L: Deref>(&self, filter: &F, logger: &L) 
+	where 
+		F::Target: chain::Filter, L::Target: Logger,
+	{
 		let lock = self.inner.lock().unwrap();
+		let logger = WithChannelMonitor::from_impl(logger, &*lock);
+		log_trace!(&logger, "Registering funding outpoint {}", &lock.get_funding_txo().0);
 		filter.register_tx(&lock.get_funding_txo().0.txid, &lock.get_funding_txo().1);
 		for (txid, outputs) in lock.get_outputs_to_watch().iter() {
 			for (index, script_pubkey) in outputs.iter() {
 				assert!(*index <= u16::max_value() as u32);
+				let outpoint = OutPoint { txid: *txid, index: *index as u16 };
+				log_trace!(logger, "Registering outpoint {} with the filter for monitoring spends", outpoint);
 				filter.register_output(WatchedOutput {
 					block_hash: None,
-					outpoint: OutPoint { txid: *txid, index: *index as u16 },
+					outpoint,
 					script_pubkey: script_pubkey.clone(),
 				});
 			}
@@ -3458,9 +3465,11 @@ impl<Signer: WriteableEcdsaChannelSigner> ChannelMonitorImpl<Signer> {
 
 		if height > self.best_block.height() {
 			self.best_block = BestBlock::new(block_hash, height);
+			log_trace!(logger, "Connecting new block {} at height {}", block_hash, height);
 			self.block_confirmed(height, block_hash, vec![], vec![], vec![], &broadcaster, &fee_estimator, logger)
 		} else if block_hash != self.best_block.block_hash() {
 			self.best_block = BestBlock::new(block_hash, height);
+			log_trace!(logger, "Best block re-orged, replaced with new block {} at height {}", block_hash, height);
 			self.onchain_events_awaiting_threshold_conf.retain(|ref entry| entry.height <= height);
 			self.onchain_tx_handler.block_disconnected(height + 1, broadcaster, fee_estimator, logger);
 			Vec::new()
@@ -3497,6 +3506,7 @@ impl<Signer: WriteableEcdsaChannelSigner> ChannelMonitorImpl<Signer> {
 		let mut claimable_outpoints = Vec::new();
 		'tx_iter: for tx in &txn_matched {
 			let txid = tx.txid();
+			log_trace!(logger, "Transaction {} confirmed in block {}", txid , block_hash);
 			// If a transaction has already been confirmed, ensure we don't bother processing it duplicatively.
 			if Some(txid) == self.funding_spend_confirmed {
 				log_debug!(logger, "Skipping redundant processing of funding-spend tx {} as it was previously confirmed", txid);