Some additional logging in `ChannelMonitor` update completion

diff --git a/lightning/src/chain/chainmonitor.rs b/lightning/src/chain/chainmonitor.rs
index 9a74f891b1e985b371f2640ccf23f7c992e626ec..5d0dfd22b7afb750e29e2d430e0a6d5afc54a221 100644 (file)
--- a/lightning/src/chain/chainmonitor.rs
+++ b/lightning/src/chain/chainmonitor.rs
@@ -45,7 +45,7 @@ use core::ops::Deref;
 use core::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
 use bitcoin::secp256k1::PublicKey;
 
-#[derive(Clone, Copy, Hash, PartialEq, Eq)]
+#[derive(Clone, Copy, Debug, Hash, PartialEq, Eq)]
 /// A specific update's ID stored in a `MonitorUpdateId`, separated out to make the contents
 /// entirely opaque.
 enum UpdateOrigin {
@@ -441,6 +441,8 @@ where C::Target: chain::Filter,
                let mut pending_monitor_updates = monitor_data.pending_monitor_updates.lock().unwrap();
                pending_monitor_updates.retain(|update_id| *update_id != completed_update_id);
 
+               log_trace!(self.logger, "Received a channel_monitor_updated for id: {:?}",
+                       completed_update_id.contents);
                match completed_update_id {
                        MonitorUpdateId { contents: UpdateOrigin::OffChain(_) } => {
                                // Note that we only check for `UpdateOrigin::OffChain` failures here - if
@@ -457,6 +459,9 @@ where C::Target: chain::Filter,
                                        // If there are still monitor updates pending (or an old monitor update
                                        // finished after a later one perm-failed), we cannot yet construct an
                                        // Completed event.
+                                       log_debug!(self.logger,
+                                               "Have pending monitor update for channel {:?}, refusing to generate a Completed event",
+                                               funding_txo);
                                        return Ok(());
                                }
                                self.pending_monitor_events.lock().unwrap().push((funding_txo, vec![MonitorEvent::Completed {
@@ -699,6 +704,8 @@ where C::Target: chain::Filter,
 
        fn release_pending_monitor_events(&self) -> Vec<(OutPoint, Vec<MonitorEvent>, Option<PublicKey>)> {
                let mut pending_monitor_events = self.pending_monitor_events.lock().unwrap().split_off(0);
+               log_trace!(self.logger, "Got {} monitor events from ChainMonitor for release.",
+                       pending_monitor_events.len());
                for monitor_state in self.monitors.read().unwrap().values() {
                        let is_pending_monitor_update = monitor_state.has_pending_chainsync_updates(&monitor_state.pending_monitor_updates.lock().unwrap());
                        if is_pending_monitor_update &&
@@ -724,8 +731,10 @@ where C::Target: chain::Filter,
                                        log_error!(self.logger, "   This may cause duplicate payment events to be generated.");
                                }
                                let monitor_events = monitor_state.monitor.get_and_clear_pending_monitor_events();
+                               let monitor_outpoint = monitor_state.monitor.get_funding_txo().0;
+                               log_trace!(self.logger, "Got {} monitor events from ChannelMonitor {:?}",
+                                       monitor_events.len(), monitor_outpoint);
                                if monitor_events.len() > 0 {
-                                       let monitor_outpoint = monitor_state.monitor.get_funding_txo().0;
                                        let counterparty_node_id = monitor_state.monitor.get_counterparty_node_id();
                                        pending_monitor_events.push((monitor_outpoint, monitor_events, counterparty_node_id));
                                }

diff --git a/lightning/src/ln/channelmanager.rs b/lightning/src/ln/channelmanager.rs
index 61de296c1442f3096fcb8b88efbd341157c4de6d..49cd27881c9876ccca678ab6a0804cf434b16bc9 100644 (file)
--- a/lightning/src/ln/channelmanager.rs
+++ b/lightning/src/ln/channelmanager.rs
@@ -4173,23 +4173,38 @@ where
                                let id_to_peer = self.id_to_peer.lock().unwrap();
                                match id_to_peer.get(&funding_txo.to_channel_id()) {
                                        Some(cp_id) => cp_id.clone(),
-                                       None => return,
+                                       None => {
+                                               log_debug!(self.logger,
+                                                       "Got a monitor update completion for a since-closed channel: {:?}",
+                                                       funding_txo);
+                                               return
+                                       },
                                }
                        }
                };
                let per_peer_state = self.per_peer_state.read().unwrap();
                let mut peer_state_lock;
                let peer_state_mutex_opt = per_peer_state.get(&counterparty_node_id);
-               if peer_state_mutex_opt.is_none() { return }
+               if peer_state_mutex_opt.is_none() {
+                       log_debug!(self.logger,
+                               "Got a monitor update completion for a peer we have no channels with anymore: {}",
+                               counterparty_node_id);
+                       return;
+               }
                peer_state_lock = peer_state_mutex_opt.unwrap().lock().unwrap();
                let peer_state = &mut *peer_state_lock;
                let mut channel = {
                        match peer_state.channel_by_id.entry(funding_txo.to_channel_id()){
                                hash_map::Entry::Occupied(chan) => chan,
-                               hash_map::Entry::Vacant(_) => return,
+                               hash_map::Entry::Vacant(_) => {
+                                       log_debug!(self.logger,
+                                               "Got a monitor update completion for a channel we have since closed: {:?}",
+                                               funding_txo);
+                                       return;
+                               },
                        }
                };
-               log_trace!(self.logger, "ChannelMonitor updated to {}. Current highest is {}",
+               log_debug!(self.logger, "ChannelMonitor updated to {}. Current highest is {}",
                        highest_applied_update_id, channel.get().get_latest_monitor_update_id());
                if !channel.get().is_awaiting_monitor_update() || channel.get().get_latest_monitor_update_id() != highest_applied_update_id {
                        return;
@@ -5105,6 +5120,8 @@ where
        fn process_pending_monitor_events(&self) -> bool {
                let mut failed_channels = Vec::new();
                let mut pending_monitor_events = self.chain_monitor.release_pending_monitor_events();
+               log_trace!(self.logger, "Got {} monitor events from ChainMonitor",
+                       pending_monitor_events.len());
                let has_pending_monitor_events = !pending_monitor_events.is_empty();
                for (funding_outpoint, mut monitor_events, counterparty_node_id) in pending_monitor_events.drain(..) {
                        for monitor_event in monitor_events.drain(..) {