From 52ecce9e281f1f904202c34ad0ddf732f4b20fdd Mon Sep 17 00:00:00 2001
From: Elias Rohrer <dev@tnull.de>
Date: Mon, 4 Dec 2023 15:39:13 +0100
Subject: [PATCH] Log additional details when ignoring first hops

Users are often confused when we fail to find a route due to some
requirements on the first hop are not being met. While we now take note
and log such candidates, we still previously required users to check
additional details to figure out why exactly the router refused to route
over a particular first hop.

Here, we add additional TRACE logging, in particular for
`ChannelDetails::next_outbound_htlc_limit_msat` and
`ChannelDetails::next_outbound_htlc_minimum_msat` when they are
relevant.
---
 lightning/src/routing/router.rs | 49 +++++++++++++++++++++++++++++----
 1 file changed, 43 insertions(+), 6 deletions(-)

diff --git a/lightning/src/routing/router.rs b/lightning/src/routing/router.rs
index 2d8dd0d67..395731502 100644
--- a/lightning/src/routing/router.rs
+++ b/lightning/src/routing/router.rs
@@ -1795,12 +1795,12 @@ where L::Target: Logger {
 					let payment_failed_on_this_channel = scid_opt.map_or(false,
 						|scid| payment_params.previously_failed_channels.contains(&scid));
 
-					let should_log_candidate = match $candidate {
-						CandidateRouteHop::FirstHop { .. } => true,
-						CandidateRouteHop::PrivateHop { .. } => true,
-						CandidateRouteHop::Blinded { .. } => true,
-						CandidateRouteHop::OneHopBlinded { .. } => true,
-						_ => false,
+					let (should_log_candidate, first_hop_details) = match $candidate {
+						CandidateRouteHop::FirstHop { details } => (true, Some(details)),
+						CandidateRouteHop::PrivateHop { .. } => (true, None),
+						CandidateRouteHop::Blinded { .. } => (true, None),
+						CandidateRouteHop::OneHopBlinded { .. } => (true, None),
+						_ => (false, None),
 					};
 
 					// If HTLC minimum is larger than the amount we're going to transfer, we shouldn't
@@ -1810,6 +1810,13 @@ where L::Target: Logger {
 					if !contributes_sufficient_value {
 						if should_log_candidate {
 							log_trace!(logger, "Ignoring {} due to insufficient value contribution.", LoggedCandidateHop(&$candidate));
+
+							if let Some(details) = first_hop_details {
+								log_trace!(logger,
+									"First hop candidate next_outbound_htlc_limit_msat: {}",
+									details.next_outbound_htlc_limit_msat,
+								);
+							}
 						}
 						num_ignored_value_contribution += 1;
 					} else if exceeds_max_path_length {
@@ -1820,6 +1827,14 @@ where L::Target: Logger {
 					} else if exceeds_cltv_delta_limit {
 						if should_log_candidate {
 							log_trace!(logger, "Ignoring {} due to exceeding CLTV delta limit.", LoggedCandidateHop(&$candidate));
+
+							if let Some(_) = first_hop_details {
+								log_trace!(logger,
+									"First hop candidate cltv_expiry_delta: {}. Limit: {}",
+									hop_total_cltv_delta,
+									max_total_cltv_expiry_delta,
+								);
+							}
 						}
 						num_ignored_cltv_delta_limit += 1;
 					} else if payment_failed_on_this_channel {
@@ -1832,6 +1847,13 @@ where L::Target: Logger {
 							log_trace!(logger,
 								"Ignoring {} to avoid overpaying to meet htlc_minimum_msat limit.",
 								LoggedCandidateHop(&$candidate));
+
+							if let Some(details) = first_hop_details {
+								log_trace!(logger,
+									"First hop candidate next_outbound_htlc_minimum_msat: {}",
+									details.next_outbound_htlc_minimum_msat,
+								);
+							}
 						}
 						num_ignored_avoid_overpayment += 1;
 						hit_minimum_limit = true;
@@ -1893,6 +1915,14 @@ where L::Target: Logger {
 							if total_fee_msat > max_total_routing_fee_msat {
 								if should_log_candidate {
 									log_trace!(logger, "Ignoring {} due to exceeding max total routing fee limit.", LoggedCandidateHop(&$candidate));
+
+									if let Some(_) = first_hop_details {
+										log_trace!(logger,
+											"First hop candidate routing fee: {}. Limit: {}",
+											total_fee_msat,
+											max_total_routing_fee_msat,
+										);
+									}
 								}
 								num_ignored_total_fee_limit += 1;
 							} else {
@@ -1988,6 +2018,13 @@ where L::Target: Logger {
 							log_trace!(logger,
 								"Ignoring {} due to its htlc_minimum_msat limit.",
 								LoggedCandidateHop(&$candidate));
+
+							if let Some(details) = first_hop_details {
+								log_trace!(logger,
+									"First hop candidate next_outbound_htlc_minimum_msat: {}",
+									details.next_outbound_htlc_minimum_msat,
+								);
+							}
 						}
 						num_ignored_htlc_minimum_msat_limit += 1;
 					}
-- 
2.39.5