add a bunch of logs

Author: martinsaposnic

lightning-liquidity/src/lsps4/service.rs

@@ -145,7 +145,21 @@ where
 		&self, intercept_scid: u64, intercept_id: InterceptId, expected_outbound_amount_msat: u64,
 		payment_hash: PaymentHash,
 	) -> Result<(), APIError> {
+		log_debug!(
+			self.logger,
+			"[htlc_intercepted] HTLC intercepted with scid {}, id {:?}, expected_outbound_amount_msat {}, payment_hash {}",
+			intercept_scid,
+			intercept_id,
+			expected_outbound_amount_msat,
+			payment_hash
+		);
 		if let Some(counterparty_node_id) = self.scid_store.get_peer(intercept_scid) {
+			log_debug!(
+				self.logger,
+				"[htlc_intercepted] Intercept SCID {} matches peer {}, processing HTLC",
+				intercept_scid,
+				counterparty_node_id
+			);
 			let htlc = InterceptedHtlc::new(
 				intercept_id,
 				intercept_scid,
@@ -155,21 +169,51 @@ where
 			);
 
 			if !self.is_peer_connected(&counterparty_node_id) {
+				log_debug!(
+					self.logger,
+					"[htlc_intercepted] Peer {} not connected, storing HTLC and sending webhook",
+					counterparty_node_id
+				);
 				self.htlc_store.insert(htlc).unwrap(); // TODO: handle persistence failures
 				let mut event_queue_notifier = self.pending_events.notifier();
 				event_queue_notifier.enqueue(crate::events::LiquidityEvent::LSPS4Service(LSPS4ServiceEvent::SendWebhook {
 					counterparty_node_id: counterparty_node_id.clone(),
 				}));
 			} else {
-				let actions = self.calculate_htlc_actions_for_peer(counterparty_node_id,vec![htlc.clone()]);
+				log_debug!(
+					self.logger,
+					"[htlc_intercepted] Peer {} connected, processing HTLC immediately",
+					counterparty_node_id
+				);
+				let actions =
+					self.calculate_htlc_actions_for_peer(counterparty_node_id, vec![htlc.clone()]);
 
 				if actions.new_channel_needed_msat.is_some() {
 					self.htlc_store.insert(htlc).unwrap(); // TODO: handle persistence failures
 				}
 
+				log_debug!(
+					self.logger,
+					"[htlc_intercepted] Calculated actions for peer {}: {:?}",
+					counterparty_node_id,
+					actions
+				);
+
 				self.execute_htlc_actions(actions, counterparty_node_id.clone());
 			}
+		} else {
+			log_debug!(
+					self.logger,
+					"[htlc_intercepted] Intercept SCID {} not present in scid_store; ignoring HTLC id {:?}",
+					intercept_scid,
+					intercept_id
+				);
 		}
+		log_debug!(
+			self.logger,
+			"[htlc_intercepted] Finalizing htlc_intercepted for intercept_scid {}",
+			intercept_scid
+		);
 
 		Ok(())
 	}

lightning/src/ln/channelmanager.rs

@@ -6712,6 +6712,9 @@ where
 		&self, intercept_id: InterceptId, next_hop_channel_id: &ChannelId, next_node_id: PublicKey,
 		amt_to_forward_msat: u64,
 	) -> Result<(), APIError> {
+		let entry_logger = WithContext::from(&self.logger, Some(next_node_id), Some(*next_hop_channel_id), None);
+		log_info!(entry_logger, "forward_intercepted_htlc called: intercept_id {:?} next_hop_channel_id {} next_node_id {} amt_to_forward_msat {}",
+			intercept_id, next_hop_channel_id, next_node_id, amt_to_forward_msat);
 		let _persistence_guard = PersistenceNotifierGuard::notify_on_drop(self);
 
 		let outbound_scid_alias = {
@@ -11265,38 +11268,43 @@ This indicates a bug inside LDK. Please report this error at https://github.com/
 					// Pull this now to avoid introducing a lock order with `forward_htlcs`.
 					let is_our_scid = self.short_to_chan_info.read().unwrap().contains_key(&scid);
 
-					let payment_hash = forward_info.payment_hash;
-					let logger = WithContext::from(
-						&self.logger,
-						None,
-						Some(prev_channel_id),
-						Some(payment_hash),
+
+				let payment_hash = forward_info.payment_hash;
+				let is_intercept = fake_scid::is_valid_intercept(&self.fake_scid_rand_bytes, scid, &self.chain_hash);
+				let is_phantom = fake_scid::is_valid_phantom(&self.fake_scid_rand_bytes, scid, &self.chain_hash);
+				let logger = WithContext::from(
+					&self.logger,
+					None,
+					Some(prev_channel_id),
+					Some(payment_hash),
+				);
+				log_debug!(logger, "Forward HTLC decision: scid {} is_our_scid={} is_intercept={} is_phantom={} incoming_amt_msat={:?} outgoing_amt_msat={} prev_short_channel_id={} prev_channel_id={}",
+					scid, is_our_scid, is_intercept, is_phantom, forward_info.incoming_amt_msat, forward_info.outgoing_amt_msat, prev_outbound_scid_alias, prev_channel_id);
+				let pending_add = PendingAddHTLCInfo {
+					prev_outbound_scid_alias,
+					prev_counterparty_node_id,
+					prev_funding_outpoint,
+					prev_channel_id,
+					prev_htlc_id,
+					prev_user_channel_id,
+					forward_info,
+				};
+				let mut fail_intercepted_htlc = |pending_add: PendingAddHTLCInfo| {
+					let htlc_source =
+						HTLCSource::PreviousHopData(pending_add.htlc_previous_hop_data());
+					let reason = HTLCFailReason::from_failure_code(
+						LocalHTLCFailureReason::UnknownNextPeer,
 					);
-					let pending_add = PendingAddHTLCInfo {
-						prev_outbound_scid_alias,
-						prev_counterparty_node_id,
-						prev_funding_outpoint,
-						prev_channel_id,
-						prev_htlc_id,
-						prev_user_channel_id,
-						forward_info,
-					};
-					let mut fail_intercepted_htlc = |pending_add: PendingAddHTLCInfo| {
-						let htlc_source =
-							HTLCSource::PreviousHopData(pending_add.htlc_previous_hop_data());
-						let reason = HTLCFailReason::from_failure_code(
-							LocalHTLCFailureReason::UnknownNextPeer,
-						);
-						let failure_type = HTLCHandlingFailureType::InvalidForward {
-							requested_forward_scid: scid,
-						};
-						failed_intercept_forwards.push((
-							htlc_source,
-							payment_hash,
-							reason,
-							failure_type,
-						));
+					let failure_type = HTLCHandlingFailureType::InvalidForward {
+						requested_forward_scid: scid,
 					};
+					failed_intercept_forwards.push((
+						htlc_source,
+						payment_hash,
+						reason,
+						failure_type,
+					));
+				};
 
 					// In the case that we have an HTLC that we're supposed to hold onto until the
 					// recipient comes online *and* the outbound scid is encoded as
@@ -11391,6 +11399,7 @@ This indicates a bug inside LDK. Please report this error at https://github.com/
 			}
 
 			if !new_intercept_events.is_empty() {
+				log_info!(WithContext::from(&self.logger, None, None, None), "Queueing {} HTLCIntercepted event(s)", new_intercept_events.len());
 				let mut events = self.pending_events.lock().unwrap();
 				events.append(&mut new_intercept_events);
 			}