Merge pull request #1318 from jurvis/jurvis/2022-02-log-router-penalty-data-4

Implement custom debug for PathBuildingHop

diff --combined lightning/src/routing/router.rs
index eab14c1e17f3119a748f58458aa1742aa3b6b1a7,45dab242675c498e8003c5cdafe373c0f4569d40..d661a7813a35a6d28253c8d05c83be8a0c7f5395
--- 1/lightning/src/routing/router.rs
--- 2/lightning/src/routing/router.rs
+++ b/lightning/src/routing/router.rs
@@@ -423,7 -423,7 +423,7 @@@ impl<'a> CandidateRouteHop<'a> 
  /// so that we can choose cheaper paths (as per Dijkstra's algorithm).
  /// Fee values should be updated only in the context of the whole path, see update_value_and_recompute_fees.
  /// These fee values are useful to choose hops as we traverse the graph "payee-to-payer".
- #[derive(Clone, Debug)]
+ #[derive(Clone)]
  struct PathBuildingHop<'a> {
        // Note that this should be dropped in favor of loading it from CandidateRouteHop, but doing so
        // is a larger refactor and will require careful performance analysis.
@@@ -455,7 -455,7 +455,7 @@@
        /// decrease as well. Thus, we have to explicitly track which nodes have been processed and
        /// avoid processing them again.
        was_processed: bool,
 -      #[cfg(any(test, feature = "fuzztarget"))]
 +      #[cfg(all(not(feature = "_bench_unstable"), any(test, fuzzing)))]
        // In tests, we apply further sanity checks on cases where we skip nodes we already processed
        // to ensure it is specifically in cases where the fee has gone down because of a decrease in
        // value_contribution_msat, which requires tracking it here. See comments below where it is
@@@ -463,6 -463,22 +463,22 @@@
        value_contribution_msat: u64,
  }
  
+ impl<'a> core::fmt::Debug for PathBuildingHop<'a> {
+       fn fmt(&self, f: &mut core::fmt::Formatter) -> Result<(), core::fmt::Error> {
+               f.debug_struct("PathBuildingHop")
+                       .field("node_id", &self.node_id)
+                       .field("short_channel_id", &self.candidate.short_channel_id())
+                       .field("total_fee_msat", &self.total_fee_msat)
+                       .field("next_hops_fee_msat", &self.next_hops_fee_msat)
+                       .field("hop_use_fee_msat", &self.hop_use_fee_msat)
+                       .field("total_fee_msat - (next_hops_fee_msat + hop_use_fee_msat)", &(&self.total_fee_msat - (&self.next_hops_fee_msat + &self.hop_use_fee_msat)))
+                       .field("path_penalty_msat", &self.path_penalty_msat)
+                       .field("path_htlc_minimum_msat", &self.path_htlc_minimum_msat)
+                       .field("cltv_expiry_delta", &self.candidate.cltv_expiry_delta())
+                       .finish()
+       }
+ }
+ 
  // Instantiated with a list of hops with correct data in them collected during path finding,
  // an instance of this struct should be further modified only via given methods.
  #[derive(Clone)]
@@@ -719,9 -735,8 +735,9 @@@ where L::Target: Logger 
                        node_info.features.supports_basic_mpp()
                } else { false }
        } else { false };
 -      log_trace!(logger, "Searching for a route from payer {} to payee {} {} MPP", our_node_pubkey,
 -              payment_params.payee_pubkey, if allow_mpp { "with" } else { "without" });
 +      log_trace!(logger, "Searching for a route from payer {} to payee {} {} MPP and {} first hops {}overriding the network graph", our_node_pubkey,
 +              payment_params.payee_pubkey, if allow_mpp { "with" } else { "without" },
 +              first_hops.map(|hops| hops.len()).unwrap_or(0), if first_hops.is_some() { "" } else { "not " });
  
        // Step (1).
        // Prepare the data we'll use for payee-to-payer search by
@@@ -897,14 -912,14 +913,14 @@@
                                                                path_htlc_minimum_msat,
                                                                path_penalty_msat: u64::max_value(),
                                                                was_processed: false,
 -                                                              #[cfg(any(test, feature = "fuzztarget"))]
 +                                                              #[cfg(all(not(feature = "_bench_unstable"), any(test, fuzzing)))]
                                                                value_contribution_msat,
                                                        }
                                                });
  
                                                #[allow(unused_mut)] // We only use the mut in cfg(test)
                                                let mut should_process = !old_entry.was_processed;
 -                                              #[cfg(any(test, feature = "fuzztarget"))]
 +                                              #[cfg(all(not(feature = "_bench_unstable"), any(test, fuzzing)))]
                                                {
                                                        // In test/fuzzing builds, we do extra checks to make sure the skipping
                                                        // of already-seen nodes only happens in cases we expect (see below).
@@@ -993,13 -1008,13 +1009,13 @@@
                                                                old_entry.fee_msat = 0; // This value will be later filled with hop_use_fee_msat of the following channel
                                                                old_entry.path_htlc_minimum_msat = path_htlc_minimum_msat;
                                                                old_entry.path_penalty_msat = path_penalty_msat;
 -                                                              #[cfg(any(test, feature = "fuzztarget"))]
 +                                                              #[cfg(all(not(feature = "_bench_unstable"), any(test, fuzzing)))]
                                                                {
                                                                        old_entry.value_contribution_msat = value_contribution_msat;
                                                                }
                                                                did_add_update_path_to_src_node = true;
                                                        } else if old_entry.was_processed && new_cost < old_cost {
 -                                                              #[cfg(any(test, feature = "fuzztarget"))]
 +                                                              #[cfg(all(not(feature = "_bench_unstable"), any(test, fuzzing)))]
                                                                {
                                                                        // If we're skipping processing a node which was previously
                                                                        // processed even though we found another path to it with a
@@@ -1300,8 -1315,8 +1316,8 @@@
                                ordered_hops.last_mut().unwrap().0.fee_msat = value_contribution_msat;
                                ordered_hops.last_mut().unwrap().0.hop_use_fee_msat = 0;
  
-                               log_trace!(logger, "Found a path back to us from the target with {} hops contributing up to {} msat: {:?}",
-                                       ordered_hops.len(), value_contribution_msat, ordered_hops);
+                               log_trace!(logger, "Found a path back to us from the target with {} hops contributing up to {} msat: \n {:#?}",
+                                       ordered_hops.len(), value_contribution_msat, ordered_hops.iter().map(|h| &(h.0)).collect::<Vec<&PathBuildingHop>>());
  
                                let mut payment_path = PaymentPath {hops: ordered_hops};
  
@@@ -4977,7 -4992,7 +4993,7 @@@ pub(crate) mod test_utils 
        }
  }
  
 -#[cfg(all(test, feature = "unstable", not(feature = "no-std")))]
 +#[cfg(all(test, feature = "_bench_unstable", not(feature = "no-std")))]
  mod benches {
        use super::*;
        use bitcoin::hashes::Hash;