Skip to content

Commit 0b1a64f

Browse files
wpaulinowpaulino
authored
Merge pull request #2046 from TheBlueMatt/2023-02-rgs-robust-and-log
Do not fail to apply RGS updates for removed channels
2 parents 8311581 + d2f5dc0 commit 0b1a64f

File tree

5 files changed

+46
-63
lines changed

5 files changed

+46
-63
lines changed

‎fuzz/src/process_network_graph.rs

+1-1
Original file line numberDiff line numberDiff line change
@@ -7,7 +7,7 @@ use crate::utils::test_logger;
77
fn do_test<Out: test_logger::Output>(data: &[u8], out: Out) {
88
let logger = test_logger::TestLogger::new("".to_owned(), out);
99
let network_graph = lightning::routing::gossip::NetworkGraph::new(bitcoin::Network::Bitcoin, &logger);
10-
let rapid_sync = RapidGossipSync::new(&network_graph);
10+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
1111
let _ = rapid_sync.update_network_graph(data);
1212
}
1313

‎lightning-background-processor/src/lib.rs

+1-1
Original file line numberDiff line numberDiff line change
@@ -953,7 +953,7 @@ mod tests {
953953
let params = ChainParameters { network, best_block };
954954
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));
955955
let p2p_gossip_sync = Arc::new(P2PGossipSync::new(network_graph.clone(), Some(chain_source.clone()), logger.clone()));
956-
let rapid_gossip_sync = Arc::new(RapidGossipSync::new(network_graph.clone()));
956+
let rapid_gossip_sync = Arc::new(RapidGossipSync::new(network_graph.clone(), logger.clone()));
957957
let msg_handler = MessageHandler { chan_handler: Arc::new(test_utils::TestChannelMessageHandler::new()), route_handler: Arc::new(test_utils::TestRoutingMessageHandler::new()), onion_message_handler: IgnoringMessageHandler{}};
958958
let peer_manager = Arc::new(PeerManager::new(msg_handler, 0, &seed, logger.clone(), IgnoringMessageHandler{}, keys_manager.clone()));
959959
let node = Node { node: manager, p2p_gossip_sync, rapid_gossip_sync, peer_manager, chain_monitor, persister, tx_broadcaster, network_graph, logger, best_block, scorer };

‎lightning-rapid-gossip-sync/src/lib.rs

+7-5
Original file line numberDiff line numberDiff line change
@@ -54,7 +54,7 @@
5454
//! # let logger = FakeLogger {};
5555
//!
5656
//! let network_graph = NetworkGraph::new(Network::Bitcoin, &logger);
57-
//! let rapid_sync = RapidGossipSync::new(&network_graph);
57+
//! let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
5858
//! let snapshot_contents: &[u8] = &[0; 0];
5959
//! let new_last_sync_timestamp_result = rapid_sync.update_network_graph(snapshot_contents);
6060
//! ```
@@ -94,14 +94,16 @@ mod processing;
9494
pub struct RapidGossipSync<NG: Deref<Target=NetworkGraph<L>>, L: Deref>
9595
where L::Target: Logger {
9696
network_graph: NG,
97+
logger: L,
9798
is_initial_sync_complete: AtomicBool
9899
}
99100

100101
impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L::Target: Logger {
101102
/// Instantiate a new [`RapidGossipSync`] instance.
102-
pub fn new(network_graph: NG) -> Self {
103+
pub fn new(network_graph: NG, logger: L) -> Self {
103104
Self {
104105
network_graph,
106+
logger,
105107
is_initial_sync_complete: AtomicBool::new(false)
106108
}
107109
}
@@ -228,7 +230,7 @@ mod tests {
228230

229231
assert_eq!(network_graph.read_only().channels().len(), 0);
230232

231-
let rapid_sync = RapidGossipSync::new(&network_graph);
233+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
232234
let sync_result = rapid_sync.sync_network_graph_with_file_path(&graph_sync_test_file);
233235

234236
if sync_result.is_err() {
@@ -260,7 +262,7 @@ mod tests {
260262

261263
assert_eq!(network_graph.read_only().channels().len(), 0);
262264

263-
let rapid_sync = RapidGossipSync::new(&network_graph);
265+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
264266
let start = std::time::Instant::now();
265267
let sync_result = rapid_sync
266268
.sync_network_graph_with_file_path("./res/full_graph.lngossip");
@@ -299,7 +301,7 @@ pub mod bench {
299301
let logger = TestLogger::new();
300302
b.iter(|| {
301303
let network_graph = NetworkGraph::new(Network::Bitcoin, &logger);
302-
let rapid_sync = RapidGossipSync::new(&network_graph);
304+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
303305
let sync_result = rapid_sync.sync_network_graph_with_file_path("./res/full_graph.lngossip");
304306
if let Err(crate::error::GraphSyncError::DecodeError(DecodeError::Io(io_error))) = &sync_result {
305307
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);

‎lightning-rapid-gossip-sync/src/processing.rs

+25-44
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,7 @@ use lightning::ln::msgs::{
1010
};
1111
use lightning::routing::gossip::NetworkGraph;
1212
use lightning::util::logger::Logger;
13+
use lightning::{log_warn, log_trace, log_given_level};
1314
use lightning::util::ser::{BigSize, Readable};
1415
use lightning::io;
1516

@@ -120,6 +121,7 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
120121
if let ErrorAction::IgnoreDuplicateGossip = lightning_error.action {
121122
// everything is fine, just a duplicate channel announcement
122123
} else {
124+
log_warn!(self.logger, "Failed to process channel announcement: {:?}", lightning_error);
123125
return Err(lightning_error.into());
124126
}
125127
}
@@ -169,24 +171,19 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
169171
if (channel_flags & 0b_1000_0000) != 0 {
170172
// incremental update, field flags will indicate mutated values
171173
let read_only_network_graph = network_graph.read_only();
172-
if let Some(channel) = read_only_network_graph
173-
.channels()
174-
.get(&short_channel_id) {
175-
176-
let directional_info = channel
177-
.get_directional_info(channel_flags)
178-
.ok_or(LightningError {
179-
err: "Couldn't find previous directional data for update".to_owned(),
180-
action: ErrorAction::IgnoreError,
181-
})?;
182-
174+
if let Some(directional_info) =
175+
read_only_network_graph.channels().get(&short_channel_id)
176+
.and_then(|channel| channel.get_directional_info(channel_flags))
177+
{
183178
synthetic_update.cltv_expiry_delta = directional_info.cltv_expiry_delta;
184179
synthetic_update.htlc_minimum_msat = directional_info.htlc_minimum_msat;
185180
synthetic_update.htlc_maximum_msat = directional_info.htlc_maximum_msat;
186181
synthetic_update.fee_base_msat = directional_info.fees.base_msat;
187182
synthetic_update.fee_proportional_millionths = directional_info.fees.proportional_millionths;
188-
189183
} else {
184+
log_trace!(self.logger,
185+
"Skipping application of channel update for chan {} with flags {} as original data is missing.",
186+
short_channel_id, channel_flags);
190187
skip_update_for_unknown_channel = true;
191188
}
192189
};
@@ -223,7 +220,9 @@ impl<NG: Deref<Target=NetworkGraph<L>>, L: Deref> RapidGossipSync<NG, L> where L
223220
match network_graph.update_channel_unsigned(&synthetic_update) {
224221
Ok(_) => {},
225222
Err(LightningError { action: ErrorAction::IgnoreDuplicateGossip, .. }) => {},
226-
Err(LightningError { action: ErrorAction::IgnoreAndLog(_), .. }) => {},
223+
Err(LightningError { action: ErrorAction::IgnoreAndLog(level), err }) => {
224+
log_given_level!(self.logger, level, "Failed to apply channel update: {:?}", err);
225+
},
227226
Err(LightningError { action: ErrorAction::IgnoreError, .. }) => {},
228227
Err(e) => return Err(e.into()),
229228
}
@@ -287,7 +286,7 @@ mod tests {
287286
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,
288287
0, 3, 232, 0, 0, 0,
289288
];
290-
let rapid_sync = RapidGossipSync::new(&network_graph);
289+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
291290
let update_result = rapid_sync.update_network_graph(&example_input[..]);
292291
assert!(update_result.is_err());
293292
if let Err(GraphSyncError::DecodeError(DecodeError::ShortRead)) = update_result {
@@ -312,7 +311,7 @@ mod tests {
312311

313312
assert_eq!(network_graph.read_only().channels().len(), 0);
314313

315-
let rapid_sync = RapidGossipSync::new(&network_graph);
314+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
316315
let update_result = rapid_sync.update_network_graph(&incremental_update_input[..]);
317316
assert!(update_result.is_ok());
318317
}
@@ -340,17 +339,8 @@ mod tests {
340339

341340
assert_eq!(network_graph.read_only().channels().len(), 0);
342341

343-
let rapid_sync = RapidGossipSync::new(&network_graph);
344-
let update_result = rapid_sync.update_network_graph(&announced_update_input[..]);
345-
assert!(update_result.is_err());
346-
if let Err(GraphSyncError::LightningError(lightning_error)) = update_result {
347-
assert_eq!(
348-
lightning_error.err,
349-
"Couldn't find previous directional data for update"
350-
);
351-
} else {
352-
panic!("Unexpected update result: {:?}", update_result)
353-
}
342+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
343+
rapid_sync.update_network_graph(&announced_update_input[..]).unwrap();
354344
}
355345

356346
#[test]
@@ -376,7 +366,7 @@ mod tests {
376366

377367
assert_eq!(network_graph.read_only().channels().len(), 0);
378368

379-
let rapid_sync = RapidGossipSync::new(&network_graph);
369+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
380370
let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]);
381371
if initialization_result.is_err() {
382372
panic!(
@@ -405,16 +395,7 @@ mod tests {
405395
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,
406396
68, 226, 0, 6, 11, 0, 1, 128,
407397
];
408-
let update_result = rapid_sync.update_network_graph(&opposite_direction_incremental_update_input[..]);
409-
assert!(update_result.is_err());
410-
if let Err(GraphSyncError::LightningError(lightning_error)) = update_result {
411-
assert_eq!(
412-
lightning_error.err,
413-
"Couldn't find previous directional data for update"
414-
);
415-
} else {
416-
panic!("Unexpected update result: {:?}", update_result)
417-
}
398+
rapid_sync.update_network_graph(&opposite_direction_incremental_update_input[..]).unwrap();
418399
}
419400

420401
#[test]
@@ -442,7 +423,7 @@ mod tests {
442423

443424
assert_eq!(network_graph.read_only().channels().len(), 0);
444425

445-
let rapid_sync = RapidGossipSync::new(&network_graph);
426+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
446427
let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]);
447428
assert!(initialization_result.is_ok());
448429

@@ -501,7 +482,7 @@ mod tests {
501482

502483
assert_eq!(network_graph.read_only().channels().len(), 0);
503484

504-
let rapid_sync = RapidGossipSync::new(&network_graph);
485+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
505486
let initialization_result = rapid_sync.update_network_graph(&initialization_input[..]);
506487
assert!(initialization_result.is_ok());
507488

@@ -526,7 +507,7 @@ mod tests {
526507

527508
assert_eq!(network_graph.read_only().channels().len(), 0);
528509

529-
let rapid_sync = RapidGossipSync::new(&network_graph);
510+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
530511
let update_result = rapid_sync.update_network_graph(&VALID_RGS_BINARY);
531512
if update_result.is_err() {
532513
panic!("Unexpected update result: {:?}", update_result)
@@ -557,7 +538,7 @@ mod tests {
557538

558539
assert_eq!(network_graph.read_only().channels().len(), 0);
559540

560-
let rapid_sync = RapidGossipSync::new(&network_graph);
541+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
561542
// this is mostly for checking uint underflow issues before the fuzzer does
562543
let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(0));
563544
assert!(update_result.is_ok());
@@ -576,7 +557,7 @@ mod tests {
576557
let network_graph = NetworkGraph::new(Network::Bitcoin, &logger);
577558
assert_eq!(network_graph.read_only().channels().len(), 0);
578559

579-
let rapid_sync = RapidGossipSync::new(&network_graph);
560+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
580561
let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(latest_succeeding_time));
581562
assert!(update_result.is_ok());
582563
assert_eq!(network_graph.read_only().channels().len(), 2);
@@ -586,7 +567,7 @@ mod tests {
586567
let network_graph = NetworkGraph::new(Network::Bitcoin, &logger);
587568
assert_eq!(network_graph.read_only().channels().len(), 0);
588569

589-
let rapid_sync = RapidGossipSync::new(&network_graph);
570+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
590571
let update_result = rapid_sync.update_network_graph_no_std(&VALID_RGS_BINARY, Some(earliest_failing_time));
591572
assert!(update_result.is_err());
592573
if let Err(GraphSyncError::LightningError(lightning_error)) = update_result {
@@ -622,7 +603,7 @@ mod tests {
622603

623604
let logger = TestLogger::new();
624605
let network_graph = NetworkGraph::new(Network::Bitcoin, &logger);
625-
let rapid_sync = RapidGossipSync::new(&network_graph);
606+
let rapid_sync = RapidGossipSync::new(&network_graph, &logger);
626607
let update_result = rapid_sync.update_network_graph(&unknown_version_input[..]);
627608

628609
assert!(update_result.is_err());

‎lightning/src/util/macro_logger.rs

+12-12
Original file line numberDiff line numberDiff line change
@@ -167,17 +167,17 @@ macro_rules! log_given_level {
167167
($logger: expr, $lvl:expr, $($arg:tt)+) => (
168168
match $lvl {
169169
#[cfg(not(any(feature = "max_level_off")))]
170-
$crate::util::logger::Level::Error => log_internal!($logger, $lvl, $($arg)*),
170+
$crate::util::logger::Level::Error => $crate::log_internal!($logger, $lvl, $($arg)*),
171171
#[cfg(not(any(feature = "max_level_off", feature = "max_level_error")))]
172-
$crate::util::logger::Level::Warn => log_internal!($logger, $lvl, $($arg)*),
172+
$crate::util::logger::Level::Warn => $crate::log_internal!($logger, $lvl, $($arg)*),
173173
#[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn")))]
174-
$crate::util::logger::Level::Info => log_internal!($logger, $lvl, $($arg)*),
174+
$crate::util::logger::Level::Info => $crate::log_internal!($logger, $lvl, $($arg)*),
175175
#[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info")))]
176-
$crate::util::logger::Level::Debug => log_internal!($logger, $lvl, $($arg)*),
176+
$crate::util::logger::Level::Debug => $crate::log_internal!($logger, $lvl, $($arg)*),
177177
#[cfg(not(any(feature = "max_level_off", feature = "max_level_error", feature = "max_level_warn", feature = "max_level_info", feature = "max_level_debug")))]
178-
$crate::util::logger::Level::Trace => log_internal!($logger, $lvl, $($arg)*),
178+
$crate::util::logger::Level::Trace => $crate::log_internal!($logger, $lvl, $($arg)*),
179179
#[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")))]
180-
$crate::util::logger::Level::Gossip => log_internal!($logger, $lvl, $($arg)*),
180+
$crate::util::logger::Level::Gossip => $crate::log_internal!($logger, $lvl, $($arg)*),
181181

182182
#[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"))]
183183
_ => {
@@ -191,46 +191,46 @@ macro_rules! log_given_level {
191191
#[macro_export]
192192
macro_rules! log_error {
193193
($logger: expr, $($arg:tt)*) => (
194-
log_given_level!($logger, $crate::util::logger::Level::Error, $($arg)*);
194+
$crate::log_given_level!($logger, $crate::util::logger::Level::Error, $($arg)*);
195195
)
196196
}
197197

198198
/// Log at the `WARN` level.
199199
#[macro_export]
200200
macro_rules! log_warn {
201201
($logger: expr, $($arg:tt)*) => (
202-
log_given_level!($logger, $crate::util::logger::Level::Warn, $($arg)*);
202+
$crate::log_given_level!($logger, $crate::util::logger::Level::Warn, $($arg)*);
203203
)
204204
}
205205

206206
/// Log at the `INFO` level.
207207
#[macro_export]
208208
macro_rules! log_info {
209209
($logger: expr, $($arg:tt)*) => (
210-
log_given_level!($logger, $crate::util::logger::Level::Info, $($arg)*);
210+
$crate::log_given_level!($logger, $crate::util::logger::Level::Info, $($arg)*);
211211
)
212212
}
213213

214214
/// Log at the `DEBUG` level.
215215
#[macro_export]
216216
macro_rules! log_debug {
217217
($logger: expr, $($arg:tt)*) => (
218-
log_given_level!($logger, $crate::util::logger::Level::Debug, $($arg)*);
218+
$crate::log_given_level!($logger, $crate::util::logger::Level::Debug, $($arg)*);
219219
)
220220
}
221221

222222
/// Log at the `TRACE` level.
223223
#[macro_export]
224224
macro_rules! log_trace {
225225
($logger: expr, $($arg:tt)*) => (
226-
log_given_level!($logger, $crate::util::logger::Level::Trace, $($arg)*)
226+
$crate::log_given_level!($logger, $crate::util::logger::Level::Trace, $($arg)*)
227227
)
228228
}
229229

230230
/// Log at the `GOSSIP` level.
231231
#[macro_export]
232232
macro_rules! log_gossip {
233233
($logger: expr, $($arg:tt)*) => (
234-
log_given_level!($logger, $crate::util::logger::Level::Gossip, $($arg)*);
234+
$crate::log_given_level!($logger, $crate::util::logger::Level::Gossip, $($arg)*);
235235
)
236236
}

0 commit comments

Comments
 (0)