X-Git-Url: http://git.bitcoin.ninja/index.cgi?a=blobdiff_plain;f=lightning-rapid-gossip-sync%2Fsrc%2Fprocessing.rs;h=400fe1ccc5d4f803d395fbfa2adc2d066146957d;hb=ba1349982ba28657c9e2d03a5b02c3ecc054b5cc;hp=4b6de04c6556a5ef302d4dced78f1b833f5e5380;hpb=2c3e12e30925b007b7eec235b29236171ad2ed0e;p=rust-lightning diff --git a/lightning-rapid-gossip-sync/src/processing.rs b/lightning-rapid-gossip-sync/src/processing.rs index 4b6de04c..400fe1cc 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_debug, log_warn, log_trace, log_given_level, log_gossip}; use lightning::util::ser::{BigSize, Readable}; use lightning::io; @@ -41,7 +42,7 @@ impl>, L: Deref> RapidGossipSync where L &self, read_cursor: &mut R, ) -> Result { - #[allow(unused_mut)] + #[allow(unused_mut, unused_assignments)] let mut current_time_unix = None; #[cfg(all(feature = "std", not(test)))] { @@ -57,6 +58,7 @@ impl>, L: Deref> RapidGossipSync where L mut read_cursor: &mut R, current_time_unix: Option ) -> Result { + log_trace!(self.logger, "Processing RGS data..."); let mut prefix = [0u8; 4]; read_cursor.read_exact(&mut prefix)?; @@ -109,6 +111,9 @@ impl>, L: Deref> RapidGossipSync where L let node_id_1 = node_ids[node_id_1_index.0 as usize]; let node_id_2 = node_ids[node_id_2_index.0 as usize]; + log_gossip!(self.logger, "Adding channel {} from RGS announcement at {}", + short_channel_id, latest_seen_timestamp); + let announcement_result = network_graph.add_channel_from_partial_announcement( short_channel_id, backdated_timestamp as u64, @@ -120,6 +125,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()); } } @@ -128,6 +134,8 @@ impl>, L: Deref> RapidGossipSync where L previous_scid = 0; // updates start at a new scid let update_count: u32 = Readable::read(read_cursor)?; + log_debug!(self.logger, "Processing RGS update from {} with {} nodes, {} channel announcements and {} channel updates.", + latest_seen_timestamp, node_id_count, announcement_count, update_count); if update_count == 0 { return Ok(latest_seen_timestamp); } @@ -169,24 +177,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; } }; @@ -220,10 +223,14 @@ impl>, L: Deref> RapidGossipSync where L continue; } + log_gossip!(self.logger, "Updating channel {} with flags {} from RGS announcement at {}", + short_channel_id, channel_flags, latest_seen_timestamp); 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()), } @@ -231,6 +238,7 @@ impl>, L: Deref> RapidGossipSync where L self.network_graph.set_last_rapid_gossip_sync_timestamp(latest_seen_timestamp); self.is_initial_sync_complete.store(true, Ordering::Release); + log_trace!(self.logger, "Done processing RGS data from {}", latest_seen_timestamp); Ok(latest_seen_timestamp) } } @@ -287,7 +295,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 +320,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 +348,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 +375,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 +404,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 +432,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 +491,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 +516,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 +547,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 +566,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 +576,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 +612,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());