Extend logging of ignored candidates
[rust-lightning] / lightning / src / routing / router.rs
index e7fa3c82b9442093910355b3c4371dc2d99372aa..8db682ebdfedf63552c7bbcadee50556a76574f1 100644 (file)
@@ -139,7 +139,7 @@ impl<'a, SP: Sized, Sc: 'a + ScoreLookUp<ScoreParams = SP>, S: Deref<Target = Sc
                        source, target, short_channel_id
                ) {
                        let usage = ChannelUsage {
-                               inflight_htlc_msat: usage.inflight_htlc_msat + used_liquidity,
+                               inflight_htlc_msat: usage.inflight_htlc_msat.saturating_add(used_liquidity),
                                ..usage
                        };
 
@@ -1265,7 +1265,11 @@ impl<'a> PaymentPath<'a> {
        // Note that this function is not aware of the available_liquidity limit, and thus does not
        // support increasing the value being transferred beyond what was selected during the initial
        // routing passes.
-       fn update_value_and_recompute_fees(&mut self, value_msat: u64) {
+       //
+       // Returns the amount that this path contributes to the total payment value, which may be greater
+       // than `value_msat` if we had to overpay to meet the final node's `htlc_minimum_msat`.
+       fn update_value_and_recompute_fees(&mut self, value_msat: u64) -> u64 {
+               let mut extra_contribution_msat = 0;
                let mut total_fee_paid_msat = 0 as u64;
                for i in (0..self.hops.len()).rev() {
                        let last_hop = i == self.hops.len() - 1;
@@ -1280,6 +1284,7 @@ impl<'a> PaymentPath<'a> {
 
                        let cur_hop = &mut self.hops.get_mut(i).unwrap().0;
                        cur_hop.next_hops_fee_msat = total_fee_paid_msat;
+                       cur_hop.path_penalty_msat += extra_contribution_msat;
                        // Overpay in fees if we can't save these funds due to htlc_minimum_msat.
                        // We try to account for htlc_minimum_msat in scoring (add_entry!), so that nodes don't
                        // set it too high just to maliciously take more fees by exploiting this
@@ -1295,8 +1300,15 @@ impl<'a> PaymentPath<'a> {
                                // Also, this can't be exploited more heavily than *announce a free path and fail
                                // all payments*.
                                cur_hop_transferred_amount_msat += extra_fees_msat;
-                               total_fee_paid_msat += extra_fees_msat;
-                               cur_hop_fees_msat += extra_fees_msat;
+
+                               // We remember and return the extra fees on the final hop to allow accounting for
+                               // them in the path's value contribution.
+                               if last_hop {
+                                       extra_contribution_msat = extra_fees_msat;
+                               } else {
+                                       total_fee_paid_msat += extra_fees_msat;
+                                       cur_hop_fees_msat += extra_fees_msat;
+                               }
                        }
 
                        if last_hop {
@@ -1324,6 +1336,7 @@ impl<'a> PaymentPath<'a> {
                                }
                        }
                }
+               value_msat + extra_contribution_msat
        }
 }
 
@@ -1705,6 +1718,8 @@ where L::Target: Logger {
        let mut num_ignored_cltv_delta_limit = 0;
        let mut num_ignored_previously_failed = 0;
        let mut num_ignored_total_fee_limit = 0;
+       let mut num_ignored_avoid_overpayment = 0;
+       let mut num_ignored_htlc_minimum_msat_limit = 0;
 
        macro_rules! add_entry {
                // Adds entry which goes from $src_node_id to $dest_node_id over the $candidate hop.
@@ -1813,16 +1828,23 @@ where L::Target: Logger {
                                                }
                                                num_ignored_previously_failed += 1;
                                        } else if may_overpay_to_meet_path_minimum_msat {
+                                               if should_log_candidate {
+                                                       log_trace!(logger,
+                                                               "Ignoring {} to avoid overpaying to meet htlc_minimum_msat limit.",
+                                                               LoggedCandidateHop(&$candidate));
+                                               }
+                                               num_ignored_avoid_overpayment += 1;
                                                hit_minimum_limit = true;
                                        } else if over_path_minimum_msat {
                                                // Note that low contribution here (limited by available_liquidity_msat)
                                                // might violate htlc_minimum_msat on the hops which are next along the
                                                // payment path (upstream to the payee). To avoid that, we recompute
                                                // path fees knowing the final path contribution after constructing it.
-                                               let path_htlc_minimum_msat = cmp::max(
-                                                       compute_fees_saturating($next_hops_path_htlc_minimum_msat, $candidate.fees())
-                                                               .saturating_add($next_hops_path_htlc_minimum_msat),
-                                                       $candidate.htlc_minimum_msat());
+                                               let curr_min = cmp::max(
+                                                       $next_hops_path_htlc_minimum_msat, $candidate.htlc_minimum_msat()
+                                               );
+                                               let path_htlc_minimum_msat = compute_fees_saturating(curr_min, $candidate.fees())
+                                                       .saturating_add(curr_min);
                                                let hm_entry = dist.entry($src_node_id);
                                                let old_entry = hm_entry.or_insert_with(|| {
                                                        // If there was previously no known way to access the source node
@@ -1962,6 +1984,13 @@ where L::Target: Logger {
                                                                }
                                                        }
                                                }
+                                       } else {
+                                               if should_log_candidate {
+                                                       log_trace!(logger,
+                                                               "Ignoring {} due to its htlc_minimum_msat limit.",
+                                                               LoggedCandidateHop(&$candidate));
+                                               }
+                                               num_ignored_htlc_minimum_msat_limit += 1;
                                        }
                                }
                        }
@@ -2102,9 +2131,10 @@ where L::Target: Logger {
                                                Some(fee) => fee,
                                                None => continue
                                        };
+                                       let path_min = candidate.htlc_minimum_msat().saturating_add(
+                                               compute_fees_saturating(candidate.htlc_minimum_msat(), candidate.fees()));
                                        add_entry!(first_hop_candidate, our_node_id, intro_node_id, blinded_path_fee,
-                                               path_contribution_msat, candidate.htlc_minimum_msat(), 0_u64,
-                                               candidate.cltv_expiry_delta(),
+                                               path_contribution_msat, path_min, 0_u64, candidate.cltv_expiry_delta(),
                                                candidate.blinded_path().map_or(1, |bp| bp.blinded_hops.len() as u8));
                                }
                        }
@@ -2328,8 +2358,8 @@ where L::Target: Logger {
                                // recompute the fees again, so that if that's the case, we match the currently
                                // underpaid htlc_minimum_msat with fees.
                                debug_assert_eq!(payment_path.get_value_msat(), value_contribution_msat);
-                               value_contribution_msat = cmp::min(value_contribution_msat, final_value_msat);
-                               payment_path.update_value_and_recompute_fees(value_contribution_msat);
+                               let desired_value_contribution = cmp::min(value_contribution_msat, final_value_msat);
+                               value_contribution_msat = payment_path.update_value_and_recompute_fees(desired_value_contribution);
 
                                // Since a path allows to transfer as much value as
                                // the smallest channel it has ("bottleneck"), we should recompute
@@ -2428,15 +2458,22 @@ where L::Target: Logger {
                                log_trace!(logger, "Collected exactly our payment amount on the first pass, without hitting an htlc_minimum_msat limit, exiting.");
                                break 'paths_collection;
                        }
-                       log_trace!(logger, "Collected our payment amount on the first pass, but running again to collect extra paths with a potentially higher limit.");
+                       log_trace!(logger, "Collected our payment amount on the first pass, but running again to collect extra paths with a potentially higher value to meet htlc_minimum_msat limit.");
                        path_value_msat = recommended_value_msat;
                }
        }
 
        let num_ignored_total = num_ignored_value_contribution + num_ignored_path_length_limit +
-               num_ignored_cltv_delta_limit + num_ignored_previously_failed + num_ignored_total_fee_limit;
+               num_ignored_cltv_delta_limit + num_ignored_previously_failed +
+               num_ignored_avoid_overpayment + num_ignored_htlc_minimum_msat_limit +
+               num_ignored_total_fee_limit;
        if num_ignored_total > 0 {
-               log_trace!(logger, "Ignored {} candidate hops due to insufficient value contribution, {} due to path length limit, {} due to CLTV delta limit, {} due to previous payment failure, {} due to maximum total fee limit. Total: {} ignored candidates.", num_ignored_value_contribution, num_ignored_path_length_limit, num_ignored_cltv_delta_limit, num_ignored_previously_failed, num_ignored_total_fee_limit, num_ignored_total);
+               log_trace!(logger,
+                       "Ignored {} candidate hops due to insufficient value contribution, {} due to path length limit, {} due to CLTV delta limit, {} due to previous payment failure, {} due to htlc_minimum_msat limit, {} to avoid overpaying, {} due to maximum total fee limit. Total: {} ignored candidates.",
+                       num_ignored_value_contribution, num_ignored_path_length_limit,
+                       num_ignored_cltv_delta_limit, num_ignored_previously_failed,
+                       num_ignored_htlc_minimum_msat_limit, num_ignored_avoid_overpayment,
+                       num_ignored_total_fee_limit, num_ignored_total);
        }
 
        // Step (5).
@@ -7286,6 +7323,10 @@ mod tests {
 
        #[test]
        fn min_htlc_overpay_violates_max_htlc() {
+               do_min_htlc_overpay_violates_max_htlc(true);
+               do_min_htlc_overpay_violates_max_htlc(false);
+       }
+       fn do_min_htlc_overpay_violates_max_htlc(blinded_payee: bool) {
                // Test that if overpaying to meet a later hop's min_htlc and causes us to violate an earlier
                // hop's max_htlc, we don't consider that candidate hop valid. Previously we would add this hop
                // to `targets` and build an invalid path with it, and subsquently hit a debug panic asserting
@@ -7309,7 +7350,27 @@ mod tests {
 
                let base_fee = 1_6778_3453;
                let htlc_min = 2_5165_8240;
-               let payment_params =  {
+               let payment_params = if blinded_payee {
+                       let blinded_path = BlindedPath {
+                               introduction_node_id: nodes[0],
+                               blinding_point: ln_test_utils::pubkey(42),
+                               blinded_hops: vec![
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() },
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() }
+                               ],
+                       };
+                       let blinded_payinfo = BlindedPayInfo {
+                               fee_base_msat: base_fee,
+                               fee_proportional_millionths: 0,
+                               htlc_minimum_msat: htlc_min,
+                               htlc_maximum_msat: htlc_min * 1000,
+                               cltv_expiry_delta: 0,
+                               features: BlindedHopFeatures::empty(),
+                       };
+                       let bolt12_features: Bolt12InvoiceFeatures = channelmanager::provided_invoice_features(&config).to_context();
+                       PaymentParameters::blinded(vec![(blinded_payinfo, blinded_path)])
+                               .with_bolt12_features(bolt12_features.clone()).unwrap()
+               } else {
                        let route_hint = RouteHint(vec![RouteHintHop {
                                src_node_id: nodes[0],
                                short_channel_id: 42,
@@ -7340,6 +7401,11 @@ mod tests {
 
        #[test]
        fn previously_used_liquidity_violates_max_htlc() {
+               do_previously_used_liquidity_violates_max_htlc(true);
+               do_previously_used_liquidity_violates_max_htlc(false);
+
+       }
+       fn do_previously_used_liquidity_violates_max_htlc(blinded_payee: bool) {
                // Test that if a candidate first_hop<>route_hint_src_node channel does not have enough
                // contribution amount to cover the next hop's min_htlc plus fees, we will not consider that
                // candidate. In this case, the candidate does not have enough due to a previous path taking up
@@ -7364,7 +7430,30 @@ mod tests {
 
                let base_fees = [0, 425_9840, 0, 0];
                let htlc_mins = [1_4392, 19_7401, 1027, 6_5535];
-               let payment_params = {
+               let payment_params = if blinded_payee {
+                       let blinded_path = BlindedPath {
+                               introduction_node_id: nodes[0],
+                               blinding_point: ln_test_utils::pubkey(42),
+                               blinded_hops: vec![
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() },
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() }
+                               ],
+                       };
+                       let mut blinded_hints = Vec::new();
+                       for (base_fee, htlc_min) in base_fees.iter().zip(htlc_mins.iter()) {
+                               blinded_hints.push((BlindedPayInfo {
+                                       fee_base_msat: *base_fee,
+                                       fee_proportional_millionths: 0,
+                                       htlc_minimum_msat: *htlc_min,
+                                       htlc_maximum_msat: htlc_min * 100,
+                                       cltv_expiry_delta: 10,
+                                       features: BlindedHopFeatures::empty(),
+                               }, blinded_path.clone()));
+                       }
+                       let bolt12_features: Bolt12InvoiceFeatures = channelmanager::provided_invoice_features(&config).to_context();
+                       PaymentParameters::blinded(blinded_hints.clone())
+                               .with_bolt12_features(bolt12_features.clone()).unwrap()
+               } else {
                        let mut route_hints = Vec::new();
                        for (idx, (base_fee, htlc_min)) in base_fees.iter().zip(htlc_mins.iter()).enumerate() {
                                route_hints.push(RouteHint(vec![RouteHintHop {
@@ -7395,6 +7484,139 @@ mod tests {
                assert_eq!(route.paths.len(), 1);
                assert_eq!(route.get_total_amount(), amt_msat);
        }
+
+       #[test]
+       fn candidate_path_min() {
+               // Test that if a candidate first_hop<>network_node channel does not have enough contribution
+               // amount to cover the next channel's min htlc plus fees, we will not consider that candidate.
+               // Previously, we were storing RouteGraphNodes with a path_min that did not include fees, and
+               // would add a connecting first_hop node that did not have enough contribution amount, leading
+               // to a debug panic upon invalid path construction.
+               let secp_ctx = Secp256k1::new();
+               let logger = Arc::new(ln_test_utils::TestLogger::new());
+               let network_graph = Arc::new(NetworkGraph::new(Network::Testnet, Arc::clone(&logger)));
+               let gossip_sync = P2PGossipSync::new(network_graph.clone(), None, logger.clone());
+               let scorer = ProbabilisticScorer::new(ProbabilisticScoringDecayParameters::default(), network_graph.clone(), logger.clone());
+               let keys_manager = ln_test_utils::TestKeysInterface::new(&[0u8; 32], Network::Testnet);
+               let random_seed_bytes = keys_manager.get_secure_random_bytes();
+               let config = UserConfig::default();
+
+               // Values are taken from the fuzz input that uncovered this panic.
+               let amt_msat = 7_4009_8048;
+               let (_, our_id, privkeys, nodes) = get_nodes(&secp_ctx);
+               let first_hops = vec![get_channel_details(
+                       Some(200), nodes[0], channelmanager::provided_init_features(&config), 2_7345_2000
+               )];
+
+               add_channel(&gossip_sync, &secp_ctx, &privkeys[0], &privkeys[6], ChannelFeatures::from_le_bytes(id_to_feature_flags(6)), 6);
+               update_channel(&gossip_sync, &secp_ctx, &privkeys[0], UnsignedChannelUpdate {
+                       chain_hash: genesis_block(Network::Testnet).header.block_hash(),
+                       short_channel_id: 6,
+                       timestamp: 1,
+                       flags: 0,
+                       cltv_expiry_delta: (6 << 4) | 0,
+                       htlc_minimum_msat: 0,
+                       htlc_maximum_msat: MAX_VALUE_MSAT,
+                       fee_base_msat: 0,
+                       fee_proportional_millionths: 0,
+                       excess_data: Vec::new()
+               });
+               add_or_update_node(&gossip_sync, &secp_ctx, &privkeys[0], NodeFeatures::from_le_bytes(id_to_feature_flags(1)), 0);
+
+               let htlc_min = 2_5165_8240;
+               let blinded_hints = vec![
+                       (BlindedPayInfo {
+                               fee_base_msat: 1_6778_3453,
+                               fee_proportional_millionths: 0,
+                               htlc_minimum_msat: htlc_min,
+                               htlc_maximum_msat: htlc_min * 100,
+                               cltv_expiry_delta: 10,
+                               features: BlindedHopFeatures::empty(),
+                       }, BlindedPath {
+                               introduction_node_id: nodes[0],
+                               blinding_point: ln_test_utils::pubkey(42),
+                               blinded_hops: vec![
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() },
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() }
+                               ],
+                       })
+               ];
+               let bolt12_features: Bolt12InvoiceFeatures = channelmanager::provided_invoice_features(&config).to_context();
+               let payment_params = PaymentParameters::blinded(blinded_hints.clone())
+                       .with_bolt12_features(bolt12_features.clone()).unwrap();
+               let route_params = RouteParameters::from_payment_params_and_value(
+                       payment_params, amt_msat);
+               let netgraph = network_graph.read_only();
+
+               if let Err(LightningError { err, .. }) = get_route(
+                       &our_id, &route_params, &netgraph, Some(&first_hops.iter().collect::<Vec<_>>()),
+                       Arc::clone(&logger), &scorer, &ProbabilisticScoringFeeParameters::default(),
+                       &random_seed_bytes
+               ) {
+                       assert_eq!(err, "Failed to find a path to the given destination");
+               } else { panic!() }
+       }
+
+       #[test]
+       fn path_contribution_includes_min_htlc_overpay() {
+               // Previously, the fuzzer hit a debug panic because we wouldn't include the amount overpaid to
+               // meet a last hop's min_htlc in the total collected paths value. We now include this value and
+               // also penalize hops along the overpaying path to ensure that it gets deprioritized in path
+               // selection, both tested here.
+               let secp_ctx = Secp256k1::new();
+               let logger = Arc::new(ln_test_utils::TestLogger::new());
+               let network_graph = Arc::new(NetworkGraph::new(Network::Testnet, Arc::clone(&logger)));
+               let scorer = ProbabilisticScorer::new(ProbabilisticScoringDecayParameters::default(), network_graph.clone(), logger.clone());
+               let keys_manager = ln_test_utils::TestKeysInterface::new(&[0u8; 32], Network::Testnet);
+               let random_seed_bytes = keys_manager.get_secure_random_bytes();
+               let config = UserConfig::default();
+
+               // Values are taken from the fuzz input that uncovered this panic.
+               let amt_msat = 562_0000;
+               let (_, our_id, _, nodes) = get_nodes(&secp_ctx);
+               let first_hops = vec![
+                       get_channel_details(
+                               Some(83), nodes[0], channelmanager::provided_init_features(&config), 2199_0000,
+                       ),
+               ];
+
+               let htlc_mins = [49_0000, 1125_0000];
+               let payment_params = {
+                       let blinded_path = BlindedPath {
+                               introduction_node_id: nodes[0],
+                               blinding_point: ln_test_utils::pubkey(42),
+                               blinded_hops: vec![
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() },
+                                       BlindedHop { blinded_node_id: ln_test_utils::pubkey(42 as u8), encrypted_payload: Vec::new() }
+                               ],
+                       };
+                       let mut blinded_hints = Vec::new();
+                       for htlc_min in htlc_mins.iter() {
+                               blinded_hints.push((BlindedPayInfo {
+                                       fee_base_msat: 0,
+                                       fee_proportional_millionths: 0,
+                                       htlc_minimum_msat: *htlc_min,
+                                       htlc_maximum_msat: *htlc_min * 100,
+                                       cltv_expiry_delta: 10,
+                                       features: BlindedHopFeatures::empty(),
+                               }, blinded_path.clone()));
+                       }
+                       let bolt12_features: Bolt12InvoiceFeatures = channelmanager::provided_invoice_features(&config).to_context();
+                       PaymentParameters::blinded(blinded_hints.clone())
+                               .with_bolt12_features(bolt12_features.clone()).unwrap()
+               };
+
+               let netgraph = network_graph.read_only();
+               let route_params = RouteParameters::from_payment_params_and_value(
+                       payment_params, amt_msat);
+               let route = get_route(
+                       &our_id, &route_params, &netgraph, Some(&first_hops.iter().collect::<Vec<_>>()),
+                       Arc::clone(&logger), &scorer, &ProbabilisticScoringFeeParameters::default(),
+                       &random_seed_bytes
+               ).unwrap();
+               assert_eq!(route.paths.len(), 1);
+               assert_eq!(route.get_total_amount(), amt_msat);
+       }
 }
 
 #[cfg(all(any(test, ldk_bench), not(feature = "no-std")))]