Give ManyChannelMonitor a logger and trace add_update events

Author: TheBlueMatt

fuzz/fuzz_targets/full_stack_target.rs

@@ -280,7 +280,7 @@ pub fn do_test(data: &[u8], logger: &Arc<Logger>) {
 
 	let watch = Arc::new(ChainWatchInterfaceUtil::new(Network::Bitcoin, Arc::clone(&logger)));
 	let broadcast = Arc::new(TestBroadcaster{});
-	let monitor = channelmonitor::SimpleManyChannelMonitor::new(watch.clone(), broadcast.clone());
+	let monitor = channelmonitor::SimpleManyChannelMonitor::new(watch.clone(), broadcast.clone(), Arc::clone(&logger));
 
 	let keys_manager = Arc::new(KeyProvider { node_secret: our_network_key.clone() });
 	let channelmanager = ChannelManager::new(slice_to_be32(get_slice!(4)), get_slice!(1)[0] != 0, Network::Bitcoin, fee_est.clone(), monitor.clone(), watch.clone(), broadcast.clone(), Arc::clone(&logger), keys_manager.clone()).unwrap();

src/ln/channelmanager.rs

@@ -4051,7 +4051,7 @@ mod tests {
 			let mut seed = [0; 32];
 			rng.fill_bytes(&mut seed);
 			let keys_manager = Arc::new(keysinterface::KeysManager::new(&seed, Network::Testnet, Arc::clone(&logger)));
-			let chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(chain_monitor.clone(), tx_broadcaster.clone()));
+			let chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(chain_monitor.clone(), tx_broadcaster.clone(), logger.clone()));
 			let node = ChannelManager::new(0, true, Network::Testnet, feeest.clone(), chan_monitor.clone(), chain_monitor.clone(), tx_broadcaster.clone(), Arc::clone(&logger), keys_manager.clone()).unwrap();
 			let router = Router::new(PublicKey::from_secret_key(&secp_ctx, &keys_manager.get_node_secret()), chain_monitor.clone(), Arc::clone(&logger));
 			nodes.push(Node { chain_monitor, tx_broadcaster, chan_monitor, node, router, node_seed: seed,
@@ -6881,7 +6881,7 @@ mod tests {
 		let mut chan_0_monitor_serialized = VecWriter(Vec::new());
 		nodes[0].chan_monitor.simple_monitor.monitors.lock().unwrap().iter().next().unwrap().1.write_for_disk(&mut chan_0_monitor_serialized).unwrap();
 
-		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone()));
+		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone(), Arc::new(test_utils::TestLogger::new())));
 		let mut chan_0_monitor_read = &chan_0_monitor_serialized.0[..];
 		let (_, chan_0_monitor) = <(Sha256dHash, ChannelMonitor)>::read(&mut chan_0_monitor_read, Arc::new(test_utils::TestLogger::new())).unwrap();
 		assert!(chan_0_monitor_read.is_empty());
@@ -6945,7 +6945,7 @@ mod tests {
 		let mut chan_0_monitor_serialized = VecWriter(Vec::new());
 		nodes[0].chan_monitor.simple_monitor.monitors.lock().unwrap().iter().next().unwrap().1.write_for_disk(&mut chan_0_monitor_serialized).unwrap();
 
-		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone()));
+		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone(), Arc::new(test_utils::TestLogger::new())));
 		let mut chan_0_monitor_read = &chan_0_monitor_serialized.0[..];
 		let (_, chan_0_monitor) = <(Sha256dHash, ChannelMonitor)>::read(&mut chan_0_monitor_read, Arc::new(test_utils::TestLogger::new())).unwrap();
 		assert!(chan_0_monitor_read.is_empty());
@@ -7004,7 +7004,7 @@ mod tests {
 			node_0_monitors_serialized.push(writer.0);
 		}
 
-		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone()));
+		nodes[0].chan_monitor = Arc::new(test_utils::TestChannelMonitor::new(nodes[0].chain_monitor.clone(), nodes[0].tx_broadcaster.clone(), Arc::new(test_utils::TestLogger::new())));
 		let mut node_0_monitors = Vec::new();
 		for serialized in node_0_monitors_serialized.iter() {
 			let mut read = &serialized[..];

src/ln/channelmonitor.rs

@@ -112,6 +112,7 @@ pub struct SimpleManyChannelMonitor<Key> {
 	chain_monitor: Arc<ChainWatchInterface>,
 	broadcaster: Arc<BroadcasterInterface>,
 	pending_events: Mutex<Vec<events::Event>>,
+	logger: Arc<Logger>,
 }
 
 impl<Key : Send + cmp::Eq + hash::Hash> ChainListener for SimpleManyChannelMonitor<Key> {
@@ -144,12 +145,13 @@ impl<Key : Send + cmp::Eq + hash::Hash> ChainListener for SimpleManyChannelMonit
 impl<Key : Send + cmp::Eq + hash::Hash + 'static> SimpleManyChannelMonitor<Key> {
 	/// Creates a new object which can be used to monitor several channels given the chain
 	/// interface with which to register to receive notifications.
-	pub fn new(chain_monitor: Arc<ChainWatchInterface>, broadcaster: Arc<BroadcasterInterface>) -> Arc<SimpleManyChannelMonitor<Key>> {
+	pub fn new(chain_monitor: Arc<ChainWatchInterface>, broadcaster: Arc<BroadcasterInterface>, logger: Arc<Logger>) -> Arc<SimpleManyChannelMonitor<Key>> {
 		let res = Arc::new(SimpleManyChannelMonitor {
 			monitors: Mutex::new(HashMap::new()),
 			chain_monitor,
 			broadcaster,
 			pending_events: Mutex::new(Vec::new()),
+			logger,
 		});
 		let weak_res = Arc::downgrade(&res);
 		res.chain_monitor.register_listener(weak_res);
@@ -160,12 +162,19 @@ impl<Key : Send + cmp::Eq + hash::Hash + 'static> SimpleManyChannelMonitor<Key>
 	pub fn add_update_monitor_by_key(&self, key: Key, monitor: ChannelMonitor) -> Result<(), HandleError> {
 		let mut monitors = self.monitors.lock().unwrap();
 		match monitors.get_mut(&key) {
-			Some(orig_monitor) => return orig_monitor.insert_combine(monitor),
+			Some(orig_monitor) => {
+				log_trace!(self, "Updating Channel Monitor for channel {}", log_funding_option!(monitor.funding_txo));
+				return orig_monitor.insert_combine(monitor);
+			},
 			None => {}
 		};
 		match &monitor.funding_txo {
-			&None => self.chain_monitor.watch_all_txn(),
+			&None => {
+				log_trace!(self, "Got new Channel Monitor for no-funding-set channel (monitoring all txn!)");
+				self.chain_monitor.watch_all_txn()
+			},
 			&Some((ref outpoint, ref script)) => {
+				log_trace!(self, "Got new Channel Monitor for channel {}", log_bytes!(outpoint.to_channel_id()[..]));
 				self.chain_monitor.install_watch_tx(&outpoint.txid, script);
 				self.chain_monitor.install_watch_outpoint((outpoint.txid, outpoint.index as u32), script);
 			},

src/util/macro_logger.rs

@@ -52,6 +52,21 @@ macro_rules! log_funding_channel_id {
 	}
 }
 
+pub(crate) struct DebugFundingOption<'a, T: 'a>(pub &'a Option<(OutPoint, T)>);
+impl<'a, T> std::fmt::Display for DebugFundingOption<'a, T> {
+	fn fmt(&self, f: &mut std::fmt::Formatter) -> Result<(), std::fmt::Error> {
+		match self.0.as_ref() {
+			Some(&(ref funding_output, _)) => DebugBytes(&funding_output.to_channel_id()[..]).fmt(f),
+			None => write!(f, "without funding output set"),
+		}
+	}
+}
+macro_rules! log_funding_option {
+	($funding_option: expr) => {
+		::util::macro_logger::DebugFundingOption(&$funding_option)
+	}
+}
+
 pub(crate) struct DebugRoute<'a>(pub &'a Route);
 impl<'a> std::fmt::Display for DebugRoute<'a> {
 	fn fmt(&self, f: &mut std::fmt::Formatter) -> Result<(), std::fmt::Error> {

src/util/test_utils.rs

@@ -42,10 +42,10 @@ pub struct TestChannelMonitor {
 	pub update_ret: Mutex<Result<(), channelmonitor::ChannelMonitorUpdateErr>>,
 }
 impl TestChannelMonitor {
-	pub fn new(chain_monitor: Arc<chaininterface::ChainWatchInterface>, broadcaster: Arc<chaininterface::BroadcasterInterface>) -> Self {
+	pub fn new(chain_monitor: Arc<chaininterface::ChainWatchInterface>, broadcaster: Arc<chaininterface::BroadcasterInterface>, logger: Arc<Logger>) -> Self {
 		Self {
 			added_monitors: Mutex::new(Vec::new()),
-			simple_monitor: channelmonitor::SimpleManyChannelMonitor::new(chain_monitor, broadcaster),
+			simple_monitor: channelmonitor::SimpleManyChannelMonitor::new(chain_monitor, broadcaster, logger),
 			update_ret: Mutex::new(Ok(())),
 		}
 	}