Debug-log monitor update starts and completions in ChainMonitor

When a `ChannelMonitor[Update]` persistence completes, we rely on
logging in `ChannelManager` to hear about it. However, this won't
happen at all if there's still pending updates as no `MonitorEvent`
will be generated.

Thus, here, we add logging directly in `ChainMonitor`, ensuring we
can deduce when individual updates completed from debug logs.

Author: TheBlueMatt

lightning/src/chain/chainmonitor.rs

@@ -526,7 +526,7 @@ where C::Target: chain::Filter,
 		pending_monitor_updates.retain(|update_id| *update_id != completed_update_id);
 
 		match completed_update_id {
-			MonitorUpdateId { contents: UpdateOrigin::OffChain(_) } => {
+			MonitorUpdateId { contents: UpdateOrigin::OffChain(completed_update_id) } => {
 				// Note that we only check for `UpdateOrigin::OffChain` failures here - if
 				// we're being told that a `UpdateOrigin::OffChain` monitor update completed,
 				// we only care about ensuring we don't tell the `ChannelManager` to restore
@@ -537,6 +537,14 @@ where C::Target: chain::Filter,
 				// `MonitorEvent`s from the monitor back to the `ChannelManager` until they
 				// complete.
 				let monitor_is_pending_updates = monitor_data.has_pending_offchain_updates(&pending_monitor_updates);
+				log_debug!(self.logger, "Completed off-chain monitor update {} for channel with funding outpoint {:?}, {}",
+					completed_update_id,
+					funding_txo,
+					if monitor_is_pending_updates {
+						"still have pending off-chain updates"
+					} else {
+						"all off-chain updates complete, returning a MonitorEvent"
+					});
 				if monitor_is_pending_updates {
 					// If there are still monitor updates pending, we cannot yet construct a
 					// Completed event.
@@ -548,7 +556,16 @@ where C::Target: chain::Filter,
 				}], monitor_data.monitor.get_counterparty_node_id()));
 			},
 			MonitorUpdateId { contents: UpdateOrigin::ChainSync(_) } => {
-				if !monitor_data.has_pending_chainsync_updates(&pending_monitor_updates) {
+				let monitor_has_pending_updates =
+					monitor_data.has_pending_chainsync_updates(&pending_monitor_updates);
+				log_debug!(self.logger, "Completed chain sync monitor update for channel with funding outpoint {:?}, {}",
+					funding_txo,
+					if monitor_has_pending_updates {
+						"still have pending chain sync updates"
+					} else {
+						"all chain sync updates complete, releasing pending MonitorEvents"
+					});
+				if !monitor_has_pending_updates {
 					monitor_data.last_chain_persist_height.store(self.highest_chain_height.load(Ordering::Acquire), Ordering::Release);
 					// The next time release_pending_monitor_events is called, any events for this
 					// ChannelMonitor will be returned.
@@ -771,7 +788,7 @@ where C::Target: chain::Filter,
 			Some(monitor_state) => {
 				let monitor = &monitor_state.monitor;
 				let logger = WithChannelMonitor::from(&self.logger, &monitor);
-				log_trace!(logger, "Updating ChannelMonitor for channel {}", log_funding_info!(monitor));
+				log_trace!(logger, "Updating ChannelMonitor to id {} for channel {}", update.update_id, log_funding_info!(monitor));
 				let update_res = monitor.update_monitor(update, &self.broadcaster, &self.fee_estimator, &self.logger);
 
 				let update_id = MonitorUpdateId::from_monitor_update(update);