Merge pull request #1435 from TheBlueMatt/2022-04-1126-first-step
authorMatt Corallo <649246+TheBlueMatt@users.noreply.github.com>
Thu, 28 Apr 2022 02:43:04 +0000 (02:43 +0000)
committerGitHub <noreply@github.com>
Thu, 28 Apr 2022 02:43:04 +0000 (02:43 +0000)
lightning-background-processor/src/lib.rs
lightning-block-sync/src/init.rs
lightning-block-sync/src/test_utils.rs
lightning-persister/src/util.rs
lightning/src/chain/chainmonitor.rs
lightning/src/chain/channelmonitor.rs
lightning/src/chain/mod.rs
lightning/src/ln/channelmanager.rs
lightning/src/ln/peer_handler.rs
lightning/src/routing/router.rs
lightning/src/routing/scoring.rs

index 6beee915b309772ae500bd61211a929e6382682d..e23737c0adcf16fec641c0d48aac940645c54716 100644 (file)
@@ -203,10 +203,22 @@ impl BackgroundProcessor {
                        let mut have_pruned = false;
 
                        loop {
-                               peer_manager.process_events(); // Note that this may block on ChannelManager's locking
                                channel_manager.process_pending_events(&event_handler);
                                chain_monitor.process_pending_events(&event_handler);
 
+                               // Note that the PeerManager::process_events may block on ChannelManager's locks,
+                               // hence it comes last here. When the ChannelManager finishes whatever it's doing,
+                               // we want to ensure we get into `persist_manager` as quickly as we can, especially
+                               // without running the normal event processing above and handing events to users.
+                               //
+                               // Specifically, on an *extremely* slow machine, we may see ChannelManager start
+                               // processing a message effectively at any point during this loop. In order to
+                               // minimize the time between such processing completing and persisting the updated
+                               // ChannelManager, we want to minimize methods blocking on a ChannelManager
+                               // generally, and as a fallback place such blocking only immediately before
+                               // persistence.
+                               peer_manager.process_events();
+
                                // We wait up to 100ms, but track how long it takes to detect being put to sleep,
                                // see `await_start`'s use below.
                                let await_start = Instant::now();
@@ -335,10 +347,9 @@ mod tests {
        use bitcoin::blockdata::constants::genesis_block;
        use bitcoin::blockdata::transaction::{Transaction, TxOut};
        use bitcoin::network::constants::Network;
-       use lightning::chain::chaininterface::{BroadcasterInterface, FeeEstimator};
-       use lightning::chain::{BestBlock, Confirm, chainmonitor, self};
+       use lightning::chain::{BestBlock, Confirm, chainmonitor};
        use lightning::chain::channelmonitor::ANTI_REORG_DELAY;
-       use lightning::chain::keysinterface::{InMemorySigner, Recipient, KeysInterface, KeysManager, Sign};
+       use lightning::chain::keysinterface::{InMemorySigner, Recipient, KeysInterface, KeysManager};
        use lightning::chain::transaction::OutPoint;
        use lightning::get_event_msg;
        use lightning::ln::channelmanager::{BREAKDOWN_TIMEOUT, ChainParameters, ChannelManager, SimpleArcChannelManager};
@@ -348,15 +359,13 @@ mod tests {
        use lightning::routing::network_graph::{NetworkGraph, NetGraphMsgHandler};
        use lightning::util::config::UserConfig;
        use lightning::util::events::{Event, MessageSendEventsProvider, MessageSendEvent};
-       use lightning::util::logger::Logger;
        use lightning::util::ser::Writeable;
        use lightning::util::test_utils;
        use lightning::util::persist::KVStorePersister;
        use lightning_invoice::payment::{InvoicePayer, RetryAttempts};
        use lightning_invoice::utils::DefaultRouter;
        use lightning_persister::FilesystemPersister;
-       use std::fs::{self, File};
-       use std::ops::Deref;
+       use std::fs;
        use std::path::PathBuf;
        use std::sync::{Arc, Mutex};
        use std::time::Duration;
@@ -399,7 +408,6 @@ mod tests {
        }
 
        struct Persister {
-               data_dir: String,
                graph_error: Option<(std::io::ErrorKind, &'static str)>,
                manager_error: Option<(std::io::ErrorKind, &'static str)>,
                filesystem_persister: FilesystemPersister,
@@ -408,7 +416,7 @@ mod tests {
        impl Persister {
                fn new(data_dir: String) -> Self {
                        let filesystem_persister = FilesystemPersister::new(data_dir.clone());
-                       Self { data_dir, graph_error: None, manager_error: None, filesystem_persister }
+                       Self { graph_error: None, manager_error: None, filesystem_persister }
                }
 
                fn with_graph_error(self, error: std::io::ErrorKind, message: &'static str) -> Self {
index f5d839d21ca31931ca08199a24c00e8f14867f06..b3f745bd26e361e670e66436abb7b1dae7310979 100644 (file)
@@ -4,7 +4,7 @@
 use crate::{BlockSource, BlockSourceResult, Cache, ChainNotifier};
 use crate::poll::{ChainPoller, Validate, ValidatedBlockHeader};
 
-use bitcoin::blockdata::block::{Block, BlockHeader};
+use bitcoin::blockdata::block::BlockHeader;
 use bitcoin::hash_types::BlockHash;
 use bitcoin::network::constants::Network;
 
@@ -203,7 +203,7 @@ impl<'a, C: Cache> Cache for ReadOnlyCache<'a, C> {
 struct DynamicChainListener<'a, L: chain::Listen + ?Sized>(&'a L);
 
 impl<'a, L: chain::Listen + ?Sized> chain::Listen for DynamicChainListener<'a, L> {
-       fn block_connected(&self, _block: &Block, _height: u32) {
+       fn filtered_block_connected(&self, _header: &BlockHeader, _txdata: &chain::transaction::TransactionData, _height: u32) {
                unreachable!()
        }
 
@@ -216,10 +216,10 @@ impl<'a, L: chain::Listen + ?Sized> chain::Listen for DynamicChainListener<'a, L
 struct ChainListenerSet<'a, L: chain::Listen + ?Sized>(Vec<(u32, &'a L)>);
 
 impl<'a, L: chain::Listen + ?Sized> chain::Listen for ChainListenerSet<'a, L> {
-       fn block_connected(&self, block: &Block, height: u32) {
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &chain::transaction::TransactionData, height: u32) {
                for (starting_height, chain_listener) in self.0.iter() {
                        if height > *starting_height {
-                               chain_listener.block_connected(block, height);
+                               chain_listener.filtered_block_connected(header, txdata, height);
                        }
                }
        }
index fe57c0c606d02d5cfbc5bf79f3bba1637904711f..c101d4bd3e8f0bdd516d2c0039cb579ceb5d5b89 100644 (file)
@@ -166,7 +166,7 @@ impl BlockSource for Blockchain {
 pub struct NullChainListener;
 
 impl chain::Listen for NullChainListener {
-       fn block_connected(&self, _block: &Block, _height: u32) {}
+       fn filtered_block_connected(&self, _header: &BlockHeader, _txdata: &chain::transaction::TransactionData, _height: u32) {}
        fn block_disconnected(&self, _header: &BlockHeader, _height: u32) {}
 }
 
@@ -195,13 +195,13 @@ impl MockChainListener {
 }
 
 impl chain::Listen for MockChainListener {
-       fn block_connected(&self, block: &Block, height: u32) {
+       fn filtered_block_connected(&self, header: &BlockHeader, _txdata: &chain::transaction::TransactionData, height: u32) {
                match self.expected_blocks_connected.borrow_mut().pop_front() {
                        None => {
-                               panic!("Unexpected block connected: {:?}", block.block_hash());
+                               panic!("Unexpected block connected: {:?}", header.block_hash());
                        },
                        Some(expected_block) => {
-                               assert_eq!(block.block_hash(), expected_block.header.block_hash());
+                               assert_eq!(header.block_hash(), expected_block.header.block_hash());
                                assert_eq!(height, expected_block.height);
                        },
                }
index 25bd00f5e9539ee8b486b79cb7436278015a5698..4adbb33e5b26fd886fb64d05d3d315efd3f28b16 100644 (file)
@@ -84,7 +84,6 @@ mod tests {
        use super::{write_to_file};
        use std::fs;
        use std::io;
-       use std::io::Write;
        use std::path::PathBuf;
 
        struct TestWriteable{}
index 19095fa2375a6d8c3a52a61262736af9ac2fd61c..aae260e735bdbae5c0a538af8024e7e2ef2a78cb 100644 (file)
@@ -23,7 +23,7 @@
 //! events. The remote server would make use of [`ChainMonitor`] for block processing and for
 //! servicing [`ChannelMonitor`] updates from the client.
 
-use bitcoin::blockdata::block::{Block, BlockHeader};
+use bitcoin::blockdata::block::BlockHeader;
 use bitcoin::hash_types::Txid;
 
 use chain;
@@ -501,9 +501,7 @@ where
        L::Target: Logger,
        P::Target: Persist<ChannelSigner>,
 {
-       fn block_connected(&self, block: &Block, height: u32) {
-               let header = &block.header;
-               let txdata: Vec<_> = block.txdata.iter().enumerate().collect();
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
                log_debug!(self.logger, "New best block {} at height {} provided via block_connected", header.block_hash(), height);
                self.process_chain_data(header, Some(height), &txdata, |monitor, txdata| {
                        monitor.block_connected(
index fb2cbaddf533a9aa56cbc8586ba7f68f997345f7..681d895f27e05fa6ef42105f468bae7a1a258250 100644 (file)
@@ -20,7 +20,7 @@
 //! security-domain-separated system design, you should consider having multiple paths for
 //! ChannelMonitors to get out of the HSM and onto monitoring devices.
 
-use bitcoin::blockdata::block::{Block, BlockHeader};
+use bitcoin::blockdata::block::BlockHeader;
 use bitcoin::blockdata::transaction::{TxOut,Transaction};
 use bitcoin::blockdata::script::{Script, Builder};
 use bitcoin::blockdata::opcodes;
@@ -3007,9 +3007,8 @@ where
        F::Target: FeeEstimator,
        L::Target: Logger,
 {
-       fn block_connected(&self, block: &Block, height: u32) {
-               let txdata: Vec<_> = block.txdata.iter().enumerate().collect();
-               self.0.block_connected(&block.header, &txdata, height, &*self.1, &*self.2, &*self.3);
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
+               self.0.block_connected(header, txdata, height, &*self.1, &*self.2, &*self.3);
        }
 
        fn block_disconnected(&self, header: &BlockHeader, height: u32) {
index 25e5a97d288df42d4a2baf2263aae9e9d493f28e..24eb09e7090b212ea9867aba9844ed6993c83735 100644 (file)
@@ -87,9 +87,20 @@ pub trait Access {
 /// sourcing chain data using a block-oriented API should prefer this interface over [`Confirm`].
 /// Such clients fetch the entire header chain whereas clients using [`Confirm`] only fetch headers
 /// when needed.
+///
+/// By using [`Listen::filtered_block_connected`] this interface supports clients fetching the
+/// entire header chain and only blocks with matching transaction data using BIP 157 filters or
+/// other similar filtering.
 pub trait Listen {
+       /// Notifies the listener that a block was added at the given height, with the transaction data
+       /// possibly filtered.
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32);
+
        /// Notifies the listener that a block was added at the given height.
-       fn block_connected(&self, block: &Block, height: u32);
+       fn block_connected(&self, block: &Block, height: u32) {
+               let txdata: Vec<_> = block.txdata.iter().enumerate().collect();
+               self.filtered_block_connected(&block.header, &txdata, height);
+       }
 
        /// Notifies the listener that a block was removed at the given height.
        fn block_disconnected(&self, header: &BlockHeader, height: u32);
@@ -355,8 +366,8 @@ pub struct WatchedOutput {
 }
 
 impl<T: Listen> Listen for core::ops::Deref<Target = T> {
-       fn block_connected(&self, block: &Block, height: u32) {
-               (**self).block_connected(block, height);
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
+               (**self).filtered_block_connected(header, txdata, height);
        }
 
        fn block_disconnected(&self, header: &BlockHeader, height: u32) {
@@ -369,9 +380,9 @@ where
        T::Target: Listen,
        U::Target: Listen,
 {
-       fn block_connected(&self, block: &Block, height: u32) {
-               self.0.block_connected(block, height);
-               self.1.block_connected(block, height);
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
+               self.0.filtered_block_connected(header, txdata, height);
+               self.1.filtered_block_connected(header, txdata, height);
        }
 
        fn block_disconnected(&self, header: &BlockHeader, height: u32) {
index 4ac575ff6f4c13270c0a27604c5860453d40ba3a..d7f2aeb6e4132374cc7a16d1c04361f65a3db358 100644 (file)
@@ -18,7 +18,7 @@
 //! imply it needs to fail HTLCs/payments/channels it manages).
 //!
 
-use bitcoin::blockdata::block::{Block, BlockHeader};
+use bitcoin::blockdata::block::BlockHeader;
 use bitcoin::blockdata::transaction::Transaction;
 use bitcoin::blockdata::constants::genesis_block;
 use bitcoin::network::constants::Network;
@@ -5310,18 +5310,17 @@ where
        F::Target: FeeEstimator,
        L::Target: Logger,
 {
-       fn block_connected(&self, block: &Block, height: u32) {
+       fn filtered_block_connected(&self, header: &BlockHeader, txdata: &TransactionData, height: u32) {
                {
                        let best_block = self.best_block.read().unwrap();
-                       assert_eq!(best_block.block_hash(), block.header.prev_blockhash,
+                       assert_eq!(best_block.block_hash(), header.prev_blockhash,
                                "Blocks must be connected in chain-order - the connected header must build on the last connected header");
                        assert_eq!(best_block.height(), height - 1,
                                "Blocks must be connected in chain-order - the connected block height must be one greater than the previous height");
                }
 
-               let txdata: Vec<_> = block.txdata.iter().enumerate().collect();
-               self.transactions_confirmed(&block.header, &txdata, height);
-               self.best_block_updated(&block.header, height);
+               self.transactions_confirmed(header, txdata, height);
+               self.best_block_updated(header, height);
        }
 
        fn block_disconnected(&self, header: &BlockHeader, height: u32) {
index d12f8c06eed0409630864359e54c20d3b714930d..c09df17525972ea242fefc1184a5babf070c9802 100644 (file)
@@ -1707,7 +1707,11 @@ fn is_gossip_msg(type_id: u16) -> bool {
        match type_id {
                msgs::ChannelAnnouncement::TYPE |
                msgs::ChannelUpdate::TYPE |
-               msgs::NodeAnnouncement::TYPE => true,
+               msgs::NodeAnnouncement::TYPE |
+               msgs::QueryChannelRange::TYPE |
+               msgs::ReplyChannelRange::TYPE |
+               msgs::QueryShortChannelIds::TYPE |
+               msgs::ReplyShortChannelIdsEnd::TYPE => true,
                _ => false
        }
 }
index 2d7e1d202810c51596a5dbe7273d98e77f3d2e08..816dfaad3cb4494fcc769bce8dc09ca77e27166f 100644 (file)
@@ -5352,8 +5352,9 @@ mod tests {
                                let payment_params = PaymentParameters::from_node_id(dst);
                                let amt = seed as u64 % 200_000_000;
                                let params = ProbabilisticScoringParameters::default();
-                               let scorer = ProbabilisticScorer::new(params, &graph);
-                               if get_route(src, &payment_params, &graph.read_only(), None, amt, 42, &test_utils::TestLogger::new(), &scorer, &random_seed_bytes).is_ok() {
+                               let logger = test_utils::TestLogger::new();
+                               let scorer = ProbabilisticScorer::new(params, &graph, &logger);
+                               if get_route(src, &payment_params, &graph.read_only(), None, amt, 42, &logger, &scorer, &random_seed_bytes).is_ok() {
                                        continue 'load_endpoints;
                                }
                        }
@@ -5388,8 +5389,9 @@ mod tests {
                                let payment_params = PaymentParameters::from_node_id(dst).with_features(InvoiceFeatures::known());
                                let amt = seed as u64 % 200_000_000;
                                let params = ProbabilisticScoringParameters::default();
-                               let scorer = ProbabilisticScorer::new(params, &graph);
-                               if get_route(src, &payment_params, &graph.read_only(), None, amt, 42, &test_utils::TestLogger::new(), &scorer, &random_seed_bytes).is_ok() {
+                               let logger = test_utils::TestLogger::new();
+                               let scorer = ProbabilisticScorer::new(params, &graph, &logger);
+                               if get_route(src, &payment_params, &graph.read_only(), None, amt, 42, &logger, &scorer, &random_seed_bytes).is_ok() {
                                        continue 'load_endpoints;
                                }
                        }
@@ -5435,6 +5437,7 @@ mod benches {
        use ln::features::{InitFeatures, InvoiceFeatures};
        use routing::scoring::{FixedPenaltyScorer, ProbabilisticScorer, ProbabilisticScoringParameters, Scorer};
        use util::logger::{Logger, Record};
+       use util::test_utils::TestLogger;
 
        use test::Bencher;
 
@@ -5519,17 +5522,19 @@ mod benches {
 
        #[bench]
        fn generate_routes_with_probabilistic_scorer(bench: &mut Bencher) {
+               let logger = TestLogger::new();
                let network_graph = read_network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                generate_routes(bench, &network_graph, scorer, InvoiceFeatures::empty());
        }
 
        #[bench]
        fn generate_mpp_routes_with_probabilistic_scorer(bench: &mut Bencher) {
+               let logger = TestLogger::new();
                let network_graph = read_network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                generate_routes(bench, &network_graph, scorer, InvoiceFeatures::known());
        }
 
index 206cc0a83a5b0635acf3a98b48ba04fd4e0e4893..0e04c63903392b8ccfc36d72c3fa87109b86c17b 100644 (file)
 //! #
 //! // Use the default channel penalties.
 //! let params = ProbabilisticScoringParameters::default();
-//! let scorer = ProbabilisticScorer::new(params, &network_graph);
+//! let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
 //!
 //! // Or use custom channel penalties.
 //! let params = ProbabilisticScoringParameters {
 //!     liquidity_penalty_multiplier_msat: 2 * 1000,
 //!     ..ProbabilisticScoringParameters::default()
 //! };
-//! let scorer = ProbabilisticScorer::new(params, &network_graph);
+//! let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
 //! # let random_seed_bytes = [42u8; 32];
 //!
 //! let route = find_route(&payer, &route_params, &network_graph, None, &logger, &scorer, &random_seed_bytes);
@@ -58,8 +58,10 @@ use ln::msgs::DecodeError;
 use routing::network_graph::{NetworkGraph, NodeId};
 use routing::router::RouteHop;
 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;
@@ -503,14 +505,15 @@ impl<T: Time> Readable for ChannelFailure<T> {
 /// behavior.
 ///
 /// [1]: https://arxiv.org/abs/2107.05322
-pub type ProbabilisticScorer<G> = ProbabilisticScorerUsingTime::<G, ConfiguredTime>;
+pub type ProbabilisticScorer<G, L> = ProbabilisticScorerUsingTime::<G, L, ConfiguredTime>;
 
 /// Probabilistic [`Score`] implementation.
 ///
 /// (C-not exported) generally all users should use the [`ProbabilisticScorer`] type alias.
-pub struct ProbabilisticScorerUsingTime<G: Deref<Target = NetworkGraph>, T: Time> {
+pub struct ProbabilisticScorerUsingTime<G: Deref<Target = NetworkGraph>, L: Deref, T: Time> where L::Target: Logger {
        params: ProbabilisticScoringParameters,
        network_graph: G,
+       logger: L,
        // TODO: Remove entries of closed channels.
        channel_liquidities: HashMap<u64, ChannelLiquidity<T>>,
 }
@@ -603,13 +606,14 @@ struct DirectedChannelLiquidity<L: Deref<Target = u64>, T: Time, U: Deref<Target
        half_life: Duration,
 }
 
-impl<G: Deref<Target = NetworkGraph>, T: Time> ProbabilisticScorerUsingTime<G, T> {
+impl<G: Deref<Target = NetworkGraph>, L: Deref, T: Time> ProbabilisticScorerUsingTime<G, L, T> where L::Target: Logger {
        /// Creates a new scorer using the given scoring parameters for sending payments from a node
        /// through a network graph.
-       pub fn new(params: ProbabilisticScoringParameters, network_graph: G) -> Self {
+       pub fn new(params: ProbabilisticScoringParameters, network_graph: G, logger: L) -> Self {
                Self {
                        params,
                        network_graph,
+                       logger,
                        channel_liquidities: HashMap::new(),
                }
        }
@@ -787,22 +791,29 @@ impl<L: Deref<Target = u64>, T: Time, U: Deref<Target = T>> DirectedChannelLiqui
 
 impl<L: DerefMut<Target = u64>, T: Time, U: DerefMut<Target = T>> DirectedChannelLiquidity<L, T, U> {
        /// 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<Log: Deref>(&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<Log: Deref>(&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<Log: Deref>(&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);
        }
 
@@ -829,7 +840,7 @@ impl<L: DerefMut<Target = u64>, T: Time, U: DerefMut<Target = T>> DirectedChanne
        }
 }
 
-impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsingTime<G, T> {
+impl<G: Deref<Target = NetworkGraph>, L: Deref, T: Time> Score for ProbabilisticScorerUsingTime<G, L, T> where L::Target: Logger {
        fn channel_penalty_msat(
                &self, short_channel_id: u64, amount_msat: u64, capacity_msat: u64, source: &NodeId,
                target: &NodeId
@@ -845,13 +856,18 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsin
        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();
@@ -860,7 +876,7 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsin
                                                .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;
                                }
 
@@ -868,7 +884,10 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsin
                                        .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);
                        }
                }
        }
@@ -876,6 +895,8 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsin
        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);
@@ -890,7 +911,10 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Score for ProbabilisticScorerUsin
                                        .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);
                        }
                }
        }
@@ -1206,7 +1230,7 @@ mod approx {
        }
 }
 
-impl<G: Deref<Target = NetworkGraph>, T: Time> Writeable for ProbabilisticScorerUsingTime<G, T> {
+impl<G: Deref<Target = NetworkGraph>, L: Deref, T: Time> Writeable for ProbabilisticScorerUsingTime<G, L, T> where L::Target: Logger {
        #[inline]
        fn write<W: Writer>(&self, w: &mut W) -> Result<(), io::Error> {
                write_tlv_fields!(w, {
@@ -1216,13 +1240,13 @@ impl<G: Deref<Target = NetworkGraph>, T: Time> Writeable for ProbabilisticScorer
        }
 }
 
-impl<G: Deref<Target = NetworkGraph>, T: Time>
-ReadableArgs<(ProbabilisticScoringParameters, G)> for ProbabilisticScorerUsingTime<G, T> {
+impl<G: Deref<Target = NetworkGraph>, L: Deref, T: Time>
+ReadableArgs<(ProbabilisticScoringParameters, G, L)> for ProbabilisticScorerUsingTime<G, L, T> where L::Target: Logger {
        #[inline]
        fn read<R: Read>(
-               r: &mut R, args: (ProbabilisticScoringParameters, G)
+               r: &mut R, args: (ProbabilisticScoringParameters, G, L)
        ) -> Result<Self, DecodeError> {
-               let (params, network_graph) = args;
+               let (params, network_graph, logger) = args;
                let mut channel_liquidities = HashMap::new();
                read_tlv_fields!(r, {
                        (0, channel_liquidities, required)
@@ -1230,6 +1254,7 @@ ReadableArgs<(ProbabilisticScoringParameters, G)> for ProbabilisticScorerUsingTi
                Ok(Self {
                        params,
                        network_graph,
+                       logger,
                        channel_liquidities,
                })
        }
@@ -1351,6 +1376,7 @@ mod tests {
        use routing::network_graph::{NetworkGraph, NodeId};
        use routing::router::RouteHop;
        use util::ser::{Readable, ReadableArgs, Writeable};
+       use util::test_utils::TestLogger;
 
        use bitcoin::blockdata::constants::genesis_block;
        use bitcoin::hashes::Hash;
@@ -1695,7 +1721,7 @@ mod tests {
        // `ProbabilisticScorer` tests
 
        /// A probabilistic scorer for testing with time that can be manually advanced.
-       type ProbabilisticScorer<'a> = ProbabilisticScorerUsingTime::<&'a NetworkGraph, SinceEpoch>;
+       type ProbabilisticScorer<'a> = ProbabilisticScorerUsingTime::<&'a NetworkGraph, &'a TestLogger, SinceEpoch>;
 
        fn sender_privkey() -> SecretKey {
                SecretKey::from_slice(&[41; 32]).unwrap()
@@ -1821,10 +1847,11 @@ mod tests {
 
        #[test]
        fn liquidity_bounds_directed_from_lowest_node_id() {
+               let logger = TestLogger::new();
                let last_updated = SinceEpoch::now();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph)
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger)
                        .with_channel(42,
                                ChannelLiquidity {
                                        min_liquidity_offset_msat: 700, max_liquidity_offset_msat: 100, last_updated
@@ -1895,10 +1922,11 @@ mod tests {
 
        #[test]
        fn resets_liquidity_upper_bound_when_crossed_by_lower_bound() {
+               let logger = TestLogger::new();
                let last_updated = SinceEpoch::now();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph)
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger)
                        .with_channel(42,
                                ChannelLiquidity {
                                        min_liquidity_offset_msat: 200, max_liquidity_offset_msat: 400, last_updated
@@ -1952,10 +1980,11 @@ mod tests {
 
        #[test]
        fn resets_liquidity_lower_bound_when_crossed_by_upper_bound() {
+               let logger = TestLogger::new();
                let last_updated = SinceEpoch::now();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph)
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger)
                        .with_channel(42,
                                ChannelLiquidity {
                                        min_liquidity_offset_msat: 200, max_liquidity_offset_msat: 400, last_updated
@@ -2009,12 +2038,13 @@ mod tests {
 
        #[test]
        fn increased_penalty_nearing_liquidity_upper_bound() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2034,13 +2064,14 @@ mod tests {
 
        #[test]
        fn constant_penalty_outside_liquidity_bounds() {
+               let logger = TestLogger::new();
                let last_updated = SinceEpoch::now();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph)
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger)
                        .with_channel(42,
                                ChannelLiquidity {
                                        min_liquidity_offset_msat: 40, max_liquidity_offset_msat: 40, last_updated
@@ -2056,12 +2087,13 @@ mod tests {
 
        #[test]
        fn does_not_further_penalize_own_channel() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let sender = sender_node_id();
                let source = source_node_id();
                let failed_path = payment_path_for_amount(500);
@@ -2078,12 +2110,13 @@ mod tests {
 
        #[test]
        fn sets_liquidity_lower_bound_on_downstream_failure() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
                let path = payment_path_for_amount(500);
@@ -2101,12 +2134,13 @@ mod tests {
 
        #[test]
        fn sets_liquidity_upper_bound_on_failure() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
                let path = payment_path_for_amount(500);
@@ -2124,12 +2158,13 @@ mod tests {
 
        #[test]
        fn reduces_liquidity_upper_bound_along_path_on_success() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let sender = sender_node_id();
                let source = source_node_id();
                let target = target_node_id();
@@ -2149,13 +2184,14 @@ mod tests {
 
        #[test]
        fn decays_liquidity_bounds_over_time() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        liquidity_offset_half_life: Duration::from_secs(10),
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2201,13 +2237,14 @@ mod tests {
 
        #[test]
        fn decays_liquidity_bounds_without_shift_overflow() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        liquidity_offset_half_life: Duration::from_secs(10),
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
                assert_eq!(scorer.channel_penalty_msat(42, 256, 1_024, &source, &target), 125);
@@ -2226,13 +2263,14 @@ mod tests {
 
        #[test]
        fn restricts_liquidity_bounds_after_decay() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        liquidity_offset_half_life: Duration::from_secs(10),
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2264,13 +2302,14 @@ mod tests {
 
        #[test]
        fn restores_persisted_liquidity_bounds() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        liquidity_offset_half_life: Duration::from_secs(10),
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2288,19 +2327,20 @@ mod tests {
 
                let mut serialized_scorer = io::Cursor::new(&serialized_scorer);
                let deserialized_scorer =
-                       <ProbabilisticScorer>::read(&mut serialized_scorer, (params, &network_graph)).unwrap();
+                       <ProbabilisticScorer>::read(&mut serialized_scorer, (params, &network_graph, &logger)).unwrap();
                assert_eq!(deserialized_scorer.channel_penalty_msat(42, 500, 1_000, &source, &target), 300);
        }
 
        #[test]
        fn decays_persisted_liquidity_bounds() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters {
                        liquidity_penalty_multiplier_msat: 1_000,
                        liquidity_offset_half_life: Duration::from_secs(10),
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let mut scorer = ProbabilisticScorer::new(params, &network_graph);
+               let mut scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2314,7 +2354,7 @@ mod tests {
 
                let mut serialized_scorer = io::Cursor::new(&serialized_scorer);
                let deserialized_scorer =
-                       <ProbabilisticScorer>::read(&mut serialized_scorer, (params, &network_graph)).unwrap();
+                       <ProbabilisticScorer>::read(&mut serialized_scorer, (params, &network_graph, &logger)).unwrap();
                assert_eq!(deserialized_scorer.channel_penalty_msat(42, 500, 1_000, &source, &target), 473);
 
                scorer.payment_path_failed(&payment_path_for_amount(250).iter().collect::<Vec<_>>(), 43);
@@ -2328,9 +2368,10 @@ mod tests {
        fn scores_realistic_payments() {
                // Shows the scores of "realistic" sends of 100k sats over channels of 1-10m sats (with a
                // 50k sat reserve).
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let params = ProbabilisticScoringParameters::default();
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                let source = source_node_id();
                let target = target_node_id();
 
@@ -2349,6 +2390,7 @@ mod tests {
 
        #[test]
        fn adds_base_penalty_to_liquidity_penalty() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let source = source_node_id();
                let target = target_node_id();
@@ -2357,18 +2399,19 @@ mod tests {
                        liquidity_penalty_multiplier_msat: 1_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                assert_eq!(scorer.channel_penalty_msat(42, 128, 1_024, &source, &target), 58);
 
                let params = ProbabilisticScoringParameters {
                        base_penalty_msat: 500, liquidity_penalty_multiplier_msat: 1_000, ..Default::default()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                assert_eq!(scorer.channel_penalty_msat(42, 128, 1_024, &source, &target), 558);
        }
 
        #[test]
        fn adds_amount_penalty_to_liquidity_penalty() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let source = source_node_id();
                let target = target_node_id();
@@ -2378,7 +2421,7 @@ mod tests {
                        amount_penalty_multiplier_msat: 0,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                assert_eq!(scorer.channel_penalty_msat(42, 512_000, 1_024_000, &source, &target), 300);
 
                let params = ProbabilisticScoringParameters {
@@ -2386,12 +2429,13 @@ mod tests {
                        amount_penalty_multiplier_msat: 256,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                assert_eq!(scorer.channel_penalty_msat(42, 512_000, 1_024_000, &source, &target), 337);
        }
 
        #[test]
        fn calculates_log10_without_overflowing_u64_max_value() {
+               let logger = TestLogger::new();
                let network_graph = network_graph();
                let source = source_node_id();
                let target = target_node_id();
@@ -2400,7 +2444,7 @@ mod tests {
                        liquidity_penalty_multiplier_msat: 40_000,
                        ..ProbabilisticScoringParameters::zero_penalty()
                };
-               let scorer = ProbabilisticScorer::new(params, &network_graph);
+               let scorer = ProbabilisticScorer::new(params, &network_graph, &logger);
                assert_eq!(
                        scorer.channel_penalty_msat(42, u64::max_value(), u64::max_value(), &source, &target),
                        80_000,