X-Git-Url: http://git.bitcoin.ninja/index.cgi?a=blobdiff_plain;f=lightning%2Fsrc%2Frouting%2Fscoring.rs;h=0093513ee8982628ad5626a0beb14490b1231ae6;hb=9fbafd4b6cc7a290fbd952d8baf58d6017fc3078;hp=89de0deffde5651d58276f85df50e559a15ecc90;hpb=8baa4c1945a5af2e8e68c418923a8bab86f79f47;p=rust-lightning diff --git a/lightning/src/routing/scoring.rs b/lightning/src/routing/scoring.rs index 89de0def..0093513e 100644 --- a/lightning/src/routing/scoring.rs +++ b/lightning/src/routing/scoring.rs @@ -61,6 +61,7 @@ use util::ser::{Readable, ReadableArgs, Writeable, Writer}; use util::logger::Logger; use prelude::*; +use core::fmt; use core::cell::{RefCell, RefMut}; use core::ops::{Deref, DerefMut}; use core::time::Duration; @@ -136,6 +137,14 @@ pub trait LockableScore<'a> { fn lock(&'a self) -> Self::Locked; } +/// Refers to a scorer that is accessible under lock and also writeable to disk +/// +/// We need this trait to be able to pass in a scorer to `lightning-background-processor` that will enable us to +/// use the Persister to persist it. +pub trait WriteableScore<'a>: LockableScore<'a> + Writeable {} + +impl<'a, T> WriteableScore<'a> for T where T: LockableScore<'a> + Writeable {} + /// (C-not exported) impl<'a, T: 'a + Score> LockableScore<'a> for Mutex { type Locked = MutexGuard<'a, T>; @@ -622,6 +631,33 @@ impl, L: Deref, T: Time> ProbabilisticScorerUsin assert!(self.channel_liquidities.insert(short_channel_id, liquidity).is_none()); self } + + /// Dump the contents of this scorer into the configured logger. + /// + /// Note that this writes roughly one line per channel for which we have a liquidity estimate, + /// which may be a substantial amount of log output. + pub fn debug_log_liquidity_stats(&self) { + let graph = self.network_graph.read_only(); + for (scid, liq) in self.channel_liquidities.iter() { + if let Some(chan_debug) = graph.channels().get(scid) { + let log_direction = |source, target| { + if let Some((directed_info, _)) = chan_debug.as_directed_to(target) { + let amt = directed_info.effective_capacity().as_msat(); + let dir_liq = liq.as_directed(source, target, amt, self.params.liquidity_offset_half_life); + log_debug!(self.logger, "Liquidity from {:?} to {:?} via {} is in the range ({}, {})", + source, target, scid, dir_liq.min_liquidity_msat(), dir_liq.max_liquidity_msat()); + } else { + log_debug!(self.logger, "No amount known for SCID {} from {:?} to {:?}", scid, source, target); + } + }; + + log_direction(&chan_debug.node_one, &chan_debug.node_two); + log_direction(&chan_debug.node_two, &chan_debug.node_one); + } else { + log_debug!(self.logger, "No network graph entry for SCID {}", scid); + } + } + } } impl ProbabilisticScoringParameters { @@ -790,22 +826,29 @@ impl, T: Time, U: Deref> DirectedChannelLiqui impl, T: Time, U: DerefMut> DirectedChannelLiquidity { /// Adjusts the channel liquidity balance bounds when failing to route `amount_msat`. - fn failed_at_channel(&mut self, amount_msat: u64) { + fn failed_at_channel(&mut self, amount_msat: u64, chan_descr: fmt::Arguments, logger: &Log) where Log::Target: Logger { if amount_msat < self.max_liquidity_msat() { + log_debug!(logger, "Setting max liquidity of {} to {}", chan_descr, amount_msat); self.set_max_liquidity_msat(amount_msat); + } else { + log_trace!(logger, "Max liquidity of {} already more than {}", chan_descr, amount_msat); } } /// Adjusts the channel liquidity balance bounds when failing to route `amount_msat` downstream. - fn failed_downstream(&mut self, amount_msat: u64) { + fn failed_downstream(&mut self, amount_msat: u64, chan_descr: fmt::Arguments, logger: &Log) where Log::Target: Logger { if amount_msat > self.min_liquidity_msat() { + log_debug!(logger, "Setting min liquidity of {} to {}", chan_descr, amount_msat); self.set_min_liquidity_msat(amount_msat); + } else { + log_trace!(logger, "Min liquidity of {} already less than {}", chan_descr, amount_msat); } } /// Adjusts the channel liquidity balance bounds when successfully routing `amount_msat`. - fn successful(&mut self, amount_msat: u64) { + fn successful(&mut self, amount_msat: u64, chan_descr: fmt::Arguments, logger: &Log) where Log::Target: Logger { let max_liquidity_msat = self.max_liquidity_msat().checked_sub(amount_msat).unwrap_or(0); + log_debug!(logger, "Subtracting {} from max liquidity of {} (setting it to {})", amount_msat, chan_descr, max_liquidity_msat); self.set_max_liquidity_msat(max_liquidity_msat); } @@ -848,13 +891,18 @@ impl, L: Deref, T: Time> Score for Probabilistic fn payment_path_failed(&mut self, path: &[&RouteHop], short_channel_id: u64) { let amount_msat = path.split_last().map(|(hop, _)| hop.fee_msat).unwrap_or(0); let liquidity_offset_half_life = self.params.liquidity_offset_half_life; + log_trace!(self.logger, "Scoring path through to SCID {} as having failed at {} msat", short_channel_id, amount_msat); let network_graph = self.network_graph.read_only(); - for hop in path { + for (hop_idx, hop) in path.iter().enumerate() { let target = NodeId::from_pubkey(&hop.pubkey); let channel_directed_from_source = network_graph.channels() .get(&hop.short_channel_id) .and_then(|channel| channel.as_directed_to(&target)); + if hop.short_channel_id == short_channel_id && hop_idx == 0 { + log_warn!(self.logger, "Payment failed at the first hop - we do not attempt to learn channel info in such cases as we can directly observe local state.\n\tBecause we know the local state, we should generally not see failures here - this may be an indication that your channel peer on channel {} is broken and you may wish to close the channel.", hop.short_channel_id); + } + // Only score announced channels. if let Some((channel, source)) = channel_directed_from_source { let capacity_msat = channel.effective_capacity().as_msat(); @@ -863,7 +911,7 @@ impl, L: Deref, T: Time> Score for Probabilistic .entry(hop.short_channel_id) .or_insert_with(ChannelLiquidity::new) .as_directed_mut(source, &target, capacity_msat, liquidity_offset_half_life) - .failed_at_channel(amount_msat); + .failed_at_channel(amount_msat, format_args!("SCID {}, towards {:?}", hop.short_channel_id, target), &self.logger); break; } @@ -871,7 +919,10 @@ impl, L: Deref, T: Time> Score for Probabilistic .entry(hop.short_channel_id) .or_insert_with(ChannelLiquidity::new) .as_directed_mut(source, &target, capacity_msat, liquidity_offset_half_life) - .failed_downstream(amount_msat); + .failed_downstream(amount_msat, format_args!("SCID {}, towards {:?}", hop.short_channel_id, target), &self.logger); + } else { + log_debug!(self.logger, "Not able to penalize channel with SCID {} as we do not have graph info for it (likely a route-hint last-hop).", + hop.short_channel_id); } } } @@ -879,6 +930,8 @@ impl, L: Deref, T: Time> Score for Probabilistic fn payment_path_successful(&mut self, path: &[&RouteHop]) { let amount_msat = path.split_last().map(|(hop, _)| hop.fee_msat).unwrap_or(0); let liquidity_offset_half_life = self.params.liquidity_offset_half_life; + log_trace!(self.logger, "Scoring path through SCID {} as having succeeded at {} msat.", + path.split_last().map(|(hop, _)| hop.short_channel_id).unwrap_or(0), amount_msat); let network_graph = self.network_graph.read_only(); for hop in path { let target = NodeId::from_pubkey(&hop.pubkey); @@ -893,7 +946,10 @@ impl, L: Deref, T: Time> Score for Probabilistic .entry(hop.short_channel_id) .or_insert_with(ChannelLiquidity::new) .as_directed_mut(source, &target, capacity_msat, liquidity_offset_half_life) - .successful(amount_msat); + .successful(amount_msat, format_args!("SCID {}, towards {:?}", hop.short_channel_id, target), &self.logger); + } else { + log_debug!(self.logger, "Not able to learn for channel with SCID {} as we do not have graph info for it (likely a route-hint last-hop).", + hop.short_channel_id); } } }