Log chain calls in ChainMonitor, reducing logs in ChannelMonitor

For users with many ChannelMonitors, we log a large volume per
block simply because each ChannelMonitor lots several times per
block. Instead, we move to log only once at the TRACE level per
block call in ChannelMonitors, relying instead on a DEBUG level
log in ChainMonitor before we call any ChannelMonitor functions.

For most users, this will reduce redundant logging and also log at
the DEBUG level for block events, which is appropriate.

Fixes #980.

Author: TheBlueMatt

lightning/src/chain/chainmonitor.rs

@@ -162,6 +162,7 @@ where
 	fn block_connected(&self, block: &Block, height: u32) {
 		let header = &block.header;
 		let txdata: Vec<_> = block.txdata.iter().enumerate().collect();
+		log_debug!(self.logger, "New best block {} at height {} provided via block_connected", header.block_hash(), height);
 		self.process_chain_data(header, &txdata, |monitor, txdata| {
 			monitor.block_connected(
 				header, txdata, height, &*self.broadcaster, &*self.fee_estimator, &*self.logger)
@@ -170,6 +171,7 @@ where
 
 	fn block_disconnected(&self, header: &BlockHeader, height: u32) {
 		let monitors = self.monitors.read().unwrap();
+		log_debug!(self.logger, "Latest block disconnected, new best block {} at height {} provided via block_disconnected", header.block_hash(), height);
 		for monitor in monitors.values() {
 			monitor.block_disconnected(
 				header, height, &*self.broadcaster, &*self.fee_estimator, &*self.logger);
@@ -187,20 +189,23 @@ where
 	P::Target: channelmonitor::Persist<ChannelSigner>,
 {
 	fn transactions_confirmed(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
+		log_debug!(self.logger, "{} transactions confirmed at height {} in block {}", txdata.len(), height, header.block_hash());
 		self.process_chain_data(header, txdata, |monitor, txdata| {
 			monitor.transactions_confirmed(
 				header, txdata, height, &*self.broadcaster, &*self.fee_estimator, &*self.logger)
 		});
 	}
 
 	fn transaction_unconfirmed(&self, txid: &Txid) {
+		log_debug!(self.logger, "{} reorganized out of chain", txid);
 		let monitors = self.monitors.read().unwrap();
 		for monitor in monitors.values() {
 			monitor.transaction_unconfirmed(txid, &*self.broadcaster, &*self.fee_estimator, &*self.logger);
 		}
 	}
 
 	fn best_block_updated(&self, header: &BlockHeader, height: u32) {
+		log_debug!(self.logger, "New best block {} at height {} provided via best_block_updated", header.block_hash(), height);
 		self.process_chain_data(header, &[], |monitor, txdata| {
 			// While in practice there shouldn't be any recursive calls when given empty txdata,
 			// it's still possible if a chain::Filter implementation returns a transaction.

lightning/src/chain/channelmonitor.rs

@@ -1913,7 +1913,6 @@ impl<Signer: Sign> ChannelMonitorImpl<Signer> {
 					L::Target: Logger,
 	{
 		let block_hash = header.block_hash();
-		log_trace!(logger, "New best block {} at height {}", block_hash, height);
 		self.best_block = BestBlock::new(block_hash, height);
 
 		self.transactions_confirmed(header, txdata, height, broadcaster, fee_estimator, logger)
@@ -1933,7 +1932,6 @@ impl<Signer: Sign> ChannelMonitorImpl<Signer> {
 		L::Target: Logger,
 	{
 		let block_hash = header.block_hash();
-		log_trace!(logger, "New best block {} at height {}", block_hash, height);
 
 		if height > self.best_block.height() {
 			self.best_block = BestBlock::new(block_hash, height);
@@ -1971,7 +1969,6 @@ impl<Signer: Sign> ChannelMonitorImpl<Signer> {
 		}
 
 		let block_hash = header.block_hash();
-		log_trace!(logger, "Block {} at height {} connected with {} txn matched", block_hash, height, txn_matched.len());
 
 		let mut watch_outputs = Vec::new();
 		let mut claimable_outpoints = Vec::new();
@@ -2044,6 +2041,7 @@ impl<Signer: Sign> ChannelMonitorImpl<Signer> {
 		F::Target: FeeEstimator,
 		L::Target: Logger,
 	{
+		log_trace!(logger, "Processing {} transactions for block at height {}.", txn_matched.len(), conf_height);
 		debug_assert!(self.best_block.height() >= conf_height);
 
 		let should_broadcast = self.should_broadcast_holder_commitment_txn(logger);