diff --git a/fuzz/src/process_network_graph.rs b/fuzz/src/process_network_graph.rs index c900a7d38d5..b4c6a29e8a9 100644 --- a/fuzz/src/process_network_graph.rs +++ b/fuzz/src/process_network_graph.rs @@ -7,7 +7,7 @@ use crate::utils::test_logger; fn do_test(data: &[u8], out: Out) { let logger = test_logger::TestLogger::new("".to_owned(), out); let network_graph = lightning::routing::gossip::NetworkGraph::new(bitcoin::Network::Bitcoin, &logger); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let _ = rapid_sync.update_network_graph(data); } diff --git a/lightning-background-processor/src/lib.rs b/lightning-background-processor/src/lib.rs index 8711a4aeb58..f7f1296b98e 100644 --- a/lightning-background-processor/src/lib.rs +++ b/lightning-background-processor/src/lib.rs @@ -953,7 +953,7 @@ mod tests { let params = ChainParameters { network, best_block }; let manager = Arc::new(ChannelManager::new(fee_estimator.clone(), chain_monitor.clone(), tx_broadcaster.clone(), router.clone(), logger.clone(), keys_manager.clone(), keys_manager.clone(), keys_manager.clone(), UserConfig::default(), params)); let p2p_gossip_sync = Arc::new(P2PGossipSync::new(network_graph.clone(), Some(chain_source.clone()), logger.clone())); - let rapid_gossip_sync = Arc::new(RapidGossipSync::new(network_graph.clone())); + let rapid_gossip_sync = Arc::new(RapidGossipSync::new(network_graph.clone(), logger.clone())); let msg_handler = MessageHandler { chan_handler: Arc::new(test_utils::TestChannelMessageHandler::new()), route_handler: Arc::new(test_utils::TestRoutingMessageHandler::new()), onion_message_handler: IgnoringMessageHandler{}}; let peer_manager = Arc::new(PeerManager::new(msg_handler, 0, &seed, logger.clone(), IgnoringMessageHandler{}, keys_manager.clone())); let node = Node { node: manager, p2p_gossip_sync, rapid_gossip_sync, peer_manager, chain_monitor, persister, tx_broadcaster, network_graph, logger, best_block, scorer }; diff --git a/lightning-rapid-gossip-sync/src/lib.rs b/lightning-rapid-gossip-sync/src/lib.rs index 3bceb2e28e9..af235b1c422 100644 --- a/lightning-rapid-gossip-sync/src/lib.rs +++ b/lightning-rapid-gossip-sync/src/lib.rs @@ -54,7 +54,7 @@ //! # let logger = FakeLogger {}; //! //! let network_graph = NetworkGraph::new(Network::Bitcoin, &logger); -//! let rapid_sync = RapidGossipSync::new(&network_graph); +//! let rapid_sync = RapidGossipSync::new(&network_graph, &logger); //! let snapshot_contents: &[u8] = &[0; 0]; //! let new_last_sync_timestamp_result = rapid_sync.update_network_graph(snapshot_contents); //! ``` @@ -94,14 +94,16 @@ mod processing; pub struct RapidGossipSync>, L: Deref> where L::Target: Logger { network_graph: NG, + logger: L, is_initial_sync_complete: AtomicBool } impl>, L: Deref> RapidGossipSync where L::Target: Logger { /// Instantiate a new [`RapidGossipSync`] instance. - pub fn new(network_graph: NG) -> Self { + pub fn new(network_graph: NG, logger: L) -> Self { Self { network_graph, + logger, is_initial_sync_complete: AtomicBool::new(false) } } @@ -228,7 +230,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let sync_result = rapid_sync.sync_network_graph_with_file_path(&graph_sync_test_file); if sync_result.is_err() { @@ -260,7 +262,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let start = std::time::Instant::now(); let sync_result = rapid_sync .sync_network_graph_with_file_path("./res/full_graph.lngossip"); @@ -299,7 +301,7 @@ pub mod bench { let logger = TestLogger::new(); b.iter(|| { let network_graph = NetworkGraph::new(Network::Bitcoin, &logger); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let sync_result = rapid_sync.sync_network_graph_with_file_path("./res/full_graph.lngossip"); if let Err(crate::error::GraphSyncError::DecodeError(DecodeError::Io(io_error))) = &sync_result { let error_string = format!("Input file lightning-rapid-gossip-sync/res/full_graph.lngossip is missing! Download it from https://bitcoin.ninja/ldk-compressed_graph-bc08df7542-2022-05-05.bin\n\n{:?}", io_error); diff --git a/lightning-rapid-gossip-sync/src/processing.rs b/lightning-rapid-gossip-sync/src/processing.rs index 4b6de04c655..8a52d234388 100644 --- a/lightning-rapid-gossip-sync/src/processing.rs +++ b/lightning-rapid-gossip-sync/src/processing.rs @@ -10,6 +10,7 @@ use lightning::ln::msgs::{ }; use lightning::routing::gossip::NetworkGraph; use lightning::util::logger::Logger; +use lightning::{log_warn, log_trace, log_given_level}; use lightning::util::ser::{BigSize, Readable}; use lightning::io; @@ -120,6 +121,7 @@ impl>, L: Deref> RapidGossipSync where L if let ErrorAction::IgnoreDuplicateGossip = lightning_error.action { // everything is fine, just a duplicate channel announcement } else { + log_warn!(self.logger, "Failed to process channel announcement: {:?}", lightning_error); return Err(lightning_error.into()); } } @@ -169,24 +171,19 @@ impl>, L: Deref> RapidGossipSync where L if (channel_flags & 0b_1000_0000) != 0 { // incremental update, field flags will indicate mutated values let read_only_network_graph = network_graph.read_only(); - if let Some(channel) = read_only_network_graph - .channels() - .get(&short_channel_id) { - - let directional_info = channel - .get_directional_info(channel_flags) - .ok_or(LightningError { - err: "Couldn't find previous directional data for update".to_owned(), - action: ErrorAction::IgnoreError, - })?; - + if let Some(directional_info) = + read_only_network_graph.channels().get(&short_channel_id) + .and_then(|channel| channel.get_directional_info(channel_flags)) + { synthetic_update.cltv_expiry_delta = directional_info.cltv_expiry_delta; synthetic_update.htlc_minimum_msat = directional_info.htlc_minimum_msat; synthetic_update.htlc_maximum_msat = directional_info.htlc_maximum_msat; synthetic_update.fee_base_msat = directional_info.fees.base_msat; synthetic_update.fee_proportional_millionths = directional_info.fees.proportional_millionths; - } else { + log_trace!(self.logger, + "Skipping application of channel update for chan {} with flags {} as original data is missing.", + short_channel_id, channel_flags); skip_update_for_unknown_channel = true; } }; @@ -223,7 +220,9 @@ impl>, L: Deref> RapidGossipSync where L match network_graph.update_channel_unsigned(&synthetic_update) { Ok(_) => {}, Err(LightningError { action: ErrorAction::IgnoreDuplicateGossip, .. }) => {}, - Err(LightningError { action: ErrorAction::IgnoreAndLog(_), .. }) => {}, + Err(LightningError { action: ErrorAction::IgnoreAndLog(level), err }) => { + log_given_level!(self.logger, level, "Failed to apply channel update: {:?}", err); + }, Err(LightningError { action: ErrorAction::IgnoreError, .. }) => {}, Err(e) => return Err(e.into()), } @@ -287,7 +286,7 @@ mod tests { 0, 0, 0, 0, 0, 1, 0, 0, 0, 0, 58, 85, 116, 216, 255, 2, 68, 226, 0, 6, 11, 0, 1, 24, 0, 0, 3, 232, 0, 0, 0, ]; - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph(&example_input[..]); assert!(update_result.is_err()); if let Err(GraphSyncError::DecodeError(DecodeError::ShortRead)) = update_result { @@ -312,7 +311,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph(&incremental_update_input[..]); assert!(update_result.is_ok()); } @@ -340,17 +339,8 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); - let update_result = rapid_sync.update_network_graph(&announced_update_input[..]); - assert!(update_result.is_err()); - if let Err(GraphSyncError::LightningError(lightning_error)) = update_result { - assert_eq!( - lightning_error.err, - "Couldn't find previous directional data for update" - ); - } else { - panic!("Unexpected update result: {:?}", update_result) - } + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); + rapid_sync.update_network_graph(&announced_update_input[..]).unwrap(); } #[test] @@ -376,7 +366,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]); if initialization_result.is_err() { panic!( @@ -405,16 +395,7 @@ mod tests { 0, 0, 0, 0, 0, 0, 0, 0, 0, 255, 8, 153, 192, 0, 2, 27, 0, 0, 136, 0, 0, 0, 221, 255, 2, 68, 226, 0, 6, 11, 0, 1, 128, ]; - let update_result = rapid_sync.update_network_graph(&opposite_direction_incremental_update_input[..]); - assert!(update_result.is_err()); - if let Err(GraphSyncError::LightningError(lightning_error)) = update_result { - assert_eq!( - lightning_error.err, - "Couldn't find previous directional data for update" - ); - } else { - panic!("Unexpected update result: {:?}", update_result) - } + rapid_sync.update_network_graph(&opposite_direction_incremental_update_input[..]).unwrap(); } #[test] @@ -442,7 +423,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]); assert!(initialization_result.is_ok()); @@ -501,7 +482,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]); assert!(initialization_result.is_ok()); @@ -526,7 +507,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph(&VALID_RGS_BINARY); if update_result.is_err() { panic!("Unexpected update result: {:?}", update_result) @@ -557,7 +538,7 @@ mod tests { assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); // this is mostly for checking uint underflow issues before the fuzzer does let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(0)); assert!(update_result.is_ok()); @@ -576,7 +557,7 @@ mod tests { let network_graph = NetworkGraph::new(Network::Bitcoin, &logger); assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(latest_succeeding_time)); assert!(update_result.is_ok()); assert_eq!(network_graph.read_only().channels().len(), 2); @@ -586,7 +567,7 @@ mod tests { let network_graph = NetworkGraph::new(Network::Bitcoin, &logger); assert_eq!(network_graph.read_only().channels().len(), 0); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(earliest_failing_time)); assert!(update_result.is_err()); if let Err(GraphSyncError::LightningError(lightning_error)) = update_result { @@ -622,7 +603,7 @@ mod tests { let logger = TestLogger::new(); let network_graph = NetworkGraph::new(Network::Bitcoin, &logger); - let rapid_sync = RapidGossipSync::new(&network_graph); + let rapid_sync = RapidGossipSync::new(&network_graph, &logger); let update_result = rapid_sync.update_network_graph(&unknown_version_input[..]); assert!(update_result.is_err()); diff --git a/lightning/src/util/macro_logger.rs b/lightning/src/util/macro_logger.rs index e83e6e2ee48..6e98272f317 100644 --- a/lightning/src/util/macro_logger.rs +++ b/lightning/src/util/macro_logger.rs @@ -167,17 +167,17 @@ macro_rules! log_given_level { ($logger: expr, $lvl:expr, $($arg:tt)+) => ( match $lvl { #[cfg(not(any(feature = "max_level_off")))] - $crate::util::logger::Level::Error => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Error => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(not(any(feature = "max_level_off", feature = "max_level_error")))] - $crate::util::logger::Level::Warn => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Warn => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn")))] - $crate::util::logger::Level::Info => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Info => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info")))] - $crate::util::logger::Level::Debug => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Debug => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info", feature = "max_level_debug")))] - $crate::util::logger::Level::Trace => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Trace => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info", feature = "max_level_debug", feature = "max_level_trace")))] - $crate::util::logger::Level::Gossip => log_internal!($logger, $lvl, $($arg)*), + $crate::util::logger::Level::Gossip => $crate::log_internal!($logger, $lvl, $($arg)*), #[cfg(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info", feature = "max_level_debug", feature = "max_level_trace"))] _ => { @@ -191,7 +191,7 @@ macro_rules! log_given_level { #[macro_export] macro_rules! log_error { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Error, $($arg)*); + $crate::log_given_level!($logger, $crate::util::logger::Level::Error, $($arg)*); ) } @@ -199,7 +199,7 @@ macro_rules! log_error { #[macro_export] macro_rules! log_warn { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Warn, $($arg)*); + $crate::log_given_level!($logger, $crate::util::logger::Level::Warn, $($arg)*); ) } @@ -207,7 +207,7 @@ macro_rules! log_warn { #[macro_export] macro_rules! log_info { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Info, $($arg)*); + $crate::log_given_level!($logger, $crate::util::logger::Level::Info, $($arg)*); ) } @@ -215,7 +215,7 @@ macro_rules! log_info { #[macro_export] macro_rules! log_debug { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Debug, $($arg)*); + $crate::log_given_level!($logger, $crate::util::logger::Level::Debug, $($arg)*); ) } @@ -223,7 +223,7 @@ macro_rules! log_debug { #[macro_export] macro_rules! log_trace { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Trace, $($arg)*) + $crate::log_given_level!($logger, $crate::util::logger::Level::Trace, $($arg)*) ) } @@ -231,6 +231,6 @@ macro_rules! log_trace { #[macro_export] macro_rules! log_gossip { ($logger: expr, $($arg:tt)*) => ( - log_given_level!($logger, $crate::util::logger::Level::Gossip, $($arg)*); + $crate::log_given_level!($logger, $crate::util::logger::Level::Gossip, $($arg)*); ) }