Skip to content

Fix announcements of our own gossip #1169

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
13 changes: 7 additions & 6 deletions lightning-background-processor/src/lib.rs
Original file line number Diff line number Diff line change
Expand Up @@ -493,9 +493,10 @@ mod tests {

macro_rules! check_persisted_data {
($node: expr, $filepath: expr, $expected_bytes: expr) => {
match $node.write(&mut $expected_bytes) {
Ok(()) => {
loop {
loop {
$expected_bytes.clear();
match $node.write(&mut $expected_bytes) {
Ok(()) => {
match std::fs::read($filepath) {
Ok(bytes) => {
if bytes == $expected_bytes {
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

When I was debugging the CI hang, I got as far as figuring out that this is the line that it loops on repeatedly (unless it's repeatedly erroring on fs::read). So, I think this patch would fix CI (though IDK what problem that might indicate in the FilesystemPersister)

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

At least for the purposes of this PR, the issue is that the ChannelManager can now change out from under us - the ChannelManager changes by a byte or two after one or two timer ticks, and thus the original version written at the top of the loop isn't necessarily the version that gets written to disk. It's not actually an issue, though.

Expand All @@ -506,9 +507,9 @@ mod tests {
},
Err(_) => continue
}
}
},
Err(e) => panic!("Unexpected error: {}", e)
},
Err(e) => panic!("Unexpected error: {}", e)
}
}
}
}
Expand Down
8 changes: 7 additions & 1 deletion lightning/src/ln/channel.rs
Original file line number Diff line number Diff line change
Expand Up @@ -481,9 +481,14 @@ pub(super) struct Channel<Signer: Sign> {
holding_cell_update_fee: Option<u32>,
next_holder_htlc_id: u64,
next_counterparty_htlc_id: u64,
update_time_counter: u32,
feerate_per_kw: u32,

/// The timestamp set on our latest `channel_update` message for this channel. It is updated
/// when the channel is updated in ways which may impact the `channel_update` message or when a
/// new block is received, ensuring it's always at least moderately close to the current real
/// time.
update_time_counter: u32,

#[cfg(debug_assertions)]
/// Max to_local and to_remote outputs in a locally-generated commitment transaction
holder_max_commitment_tx_output: Mutex<(u64, u64)>,
Expand Down Expand Up @@ -4167,6 +4172,7 @@ impl<Signer: Sign> Channel<Signer> {
}

pub fn set_channel_update_status(&mut self, status: ChannelUpdateStatus) {
self.update_time_counter += 1;
self.channel_update_status = status;
}

Expand Down
21 changes: 12 additions & 9 deletions lightning/src/ln/functional_tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -7313,9 +7313,9 @@ fn test_announce_disable_channels() {
let node_chanmgrs = create_node_chanmgrs(2, &node_cfgs, &[None, None]);
let nodes = create_network(2, &node_cfgs, &node_chanmgrs);

let short_id_1 = create_announced_chan_between_nodes(&nodes, 0, 1, InitFeatures::known(), InitFeatures::known()).0.contents.short_channel_id;
let short_id_2 = create_announced_chan_between_nodes(&nodes, 1, 0, InitFeatures::known(), InitFeatures::known()).0.contents.short_channel_id;
let short_id_3 = create_announced_chan_between_nodes(&nodes, 0, 1, InitFeatures::known(), InitFeatures::known()).0.contents.short_channel_id;
create_announced_chan_between_nodes(&nodes, 0, 1, InitFeatures::known(), InitFeatures::known());
create_announced_chan_between_nodes(&nodes, 1, 0, InitFeatures::known(), InitFeatures::known());
create_announced_chan_between_nodes(&nodes, 0, 1, InitFeatures::known(), InitFeatures::known());

// Disconnect peers
nodes[0].node.peer_disconnected(&nodes[1].node.get_our_node_id(), false);
Expand All @@ -7325,13 +7325,13 @@ fn test_announce_disable_channels() {
nodes[0].node.timer_tick_occurred(); // DisabledStaged -> Disabled
let msg_events = nodes[0].node.get_and_clear_pending_msg_events();
assert_eq!(msg_events.len(), 3);
let mut chans_disabled: HashSet<u64> = [short_id_1, short_id_2, short_id_3].iter().map(|a| *a).collect();
let mut chans_disabled = HashMap::new();
for e in msg_events {
match e {
MessageSendEvent::BroadcastChannelUpdate { ref msg } => {
assert_eq!(msg.contents.flags & (1<<1), 1<<1); // The "channel disabled" bit should be set
// Check that each channel gets updated exactly once
if !chans_disabled.remove(&msg.contents.short_channel_id) {
if chans_disabled.insert(msg.contents.short_channel_id, msg.contents.timestamp).is_some() {
panic!("Generated ChannelUpdate for wrong chan!");
}
},
Expand Down Expand Up @@ -7367,19 +7367,22 @@ fn test_announce_disable_channels() {
nodes[0].node.timer_tick_occurred();
let msg_events = nodes[0].node.get_and_clear_pending_msg_events();
assert_eq!(msg_events.len(), 3);
chans_disabled = [short_id_1, short_id_2, short_id_3].iter().map(|a| *a).collect();
for e in msg_events {
match e {
MessageSendEvent::BroadcastChannelUpdate { ref msg } => {
assert_eq!(msg.contents.flags & (1<<1), 0); // The "channel disabled" bit should be off
// Check that each channel gets updated exactly once
if !chans_disabled.remove(&msg.contents.short_channel_id) {
panic!("Generated ChannelUpdate for wrong chan!");
match chans_disabled.remove(&msg.contents.short_channel_id) {
// Each update should have a higher timestamp than the previous one, replacing
// the old one.
Some(prev_timestamp) => assert!(msg.contents.timestamp > prev_timestamp),
None => panic!("Generated ChannelUpdate for wrong chan!"),
}
},
_ => panic!("Unexpected event"),
}
}
// Check that each channel gets updated exactly once
assert!(chans_disabled.is_empty());
}

#[test]
Expand Down
4 changes: 4 additions & 0 deletions lightning/src/ln/msgs.rs
Original file line number Diff line number Diff line change
Expand Up @@ -715,6 +715,10 @@ pub enum ErrorAction {
/// The peer did something harmless that we weren't able to meaningfully process.
/// If the error is logged, log it at the given level.
IgnoreAndLog(logger::Level),
/// The peer provided us with a gossip message which we'd already seen. In most cases this
/// should be ignored, but it may result in the message being forwarded if it is a duplicate of
/// our own channel announcements.
IgnoreDuplicateGossip,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm I think just DuplicateGossip would be more accurate

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm, its used in a field titled action in the error itself. Feels a bit say to say the action to be taken on this error is DuplicateGossip.

/// The peer did something incorrect. Tell them.
SendErrorMessage {
/// The message to send.
Expand Down
26 changes: 19 additions & 7 deletions lightning/src/ln/peer_handler.rs
Original file line number Diff line number Diff line change
Expand Up @@ -811,6 +811,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
log_given_level!(self.logger, level, "Error handling message{}; ignoring: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
continue
},
msgs::ErrorAction::IgnoreDuplicateGossip => continue, // Don't even bother logging these
msgs::ErrorAction::IgnoreError => {
log_debug!(self.logger, "Error handling message{}; ignoring: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
continue;
Expand Down Expand Up @@ -1351,21 +1352,31 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
},
MessageSendEvent::BroadcastChannelAnnouncement { msg, update_msg } => {
log_debug!(self.logger, "Handling BroadcastChannelAnnouncement event in peer_handler for short channel id {}", msg.contents.short_channel_id);
if self.message_handler.route_handler.handle_channel_announcement(&msg).is_ok() && self.message_handler.route_handler.handle_channel_update(&update_msg).is_ok() {
self.forward_broadcast_msg(peers, &wire::Message::ChannelAnnouncement(msg), None);
self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(update_msg), None);
match self.message_handler.route_handler.handle_channel_announcement(&msg) {
Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
self.forward_broadcast_msg(peers, &wire::Message::ChannelAnnouncement(msg), None),
_ => {},
}
match self.message_handler.route_handler.handle_channel_update(&update_msg) {
Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(update_msg), None),
_ => {},
}
},
MessageSendEvent::BroadcastNodeAnnouncement { msg } => {
log_debug!(self.logger, "Handling BroadcastNodeAnnouncement event in peer_handler");
if self.message_handler.route_handler.handle_node_announcement(&msg).is_ok() {
self.forward_broadcast_msg(peers, &wire::Message::NodeAnnouncement(msg), None);
match self.message_handler.route_handler.handle_node_announcement(&msg) {
Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
self.forward_broadcast_msg(peers, &wire::Message::NodeAnnouncement(msg), None),
_ => {},
}
},
MessageSendEvent::BroadcastChannelUpdate { msg } => {
log_debug!(self.logger, "Handling BroadcastChannelUpdate event in peer_handler for short channel id {}", msg.contents.short_channel_id);
if self.message_handler.route_handler.handle_channel_update(&msg).is_ok() {
self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(msg), None);
match self.message_handler.route_handler.handle_channel_update(&msg) {
Ok(_) | Err(LightningError { action: msgs::ErrorAction::IgnoreDuplicateGossip, .. }) =>
self.forward_broadcast_msg(peers, &wire::Message::ChannelUpdate(msg), None),
_ => {},
}
},
MessageSendEvent::SendChannelUpdate { ref node_id, ref msg } => {
Expand Down Expand Up @@ -1398,6 +1409,7 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
msgs::ErrorAction::IgnoreAndLog(level) => {
log_given_level!(self.logger, level, "Received a HandleError event to be ignored for node {}", log_pubkey!(node_id));
},
msgs::ErrorAction::IgnoreDuplicateGossip => {},
msgs::ErrorAction::IgnoreError => {
log_debug!(self.logger, "Received a HandleError event to be ignored for node {}", log_pubkey!(node_id));
},
Expand Down
21 changes: 17 additions & 4 deletions lightning/src/routing/network_graph.rs
Original file line number Diff line number Diff line change
Expand Up @@ -847,8 +847,13 @@ impl NetworkGraph {
None => Err(LightningError{err: "No existing channels for node_announcement".to_owned(), action: ErrorAction::IgnoreError}),
Some(node) => {
if let Some(node_info) = node.announcement_info.as_ref() {
if node_info.last_update >= msg.timestamp {
// The timestamp field is somewhat of a misnomer - the BOLTs use it to order
// updates to ensure you always have the latest one, only vaguely suggesting
// that it be at least the current time.
if node_info.last_update > msg.timestamp {
return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Gossip)});
} else if node_info.last_update == msg.timestamp {
return Err(LightningError{err: "Update had the same timestamp as last processed update".to_owned(), action: ErrorAction::IgnoreDuplicateGossip});
}
}

Expand Down Expand Up @@ -977,7 +982,7 @@ impl NetworkGraph {
Self::remove_channel_in_nodes(&mut nodes, &entry.get(), msg.short_channel_id);
*entry.get_mut() = chan_info;
} else {
return Err(LightningError{err: "Already have knowledge of channel".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Gossip)})
return Err(LightningError{err: "Already have knowledge of channel".to_owned(), action: ErrorAction::IgnoreDuplicateGossip});
}
},
BtreeEntry::Vacant(entry) => {
Expand Down Expand Up @@ -1082,8 +1087,16 @@ impl NetworkGraph {
macro_rules! maybe_update_channel_info {
( $target: expr, $src_node: expr) => {
if let Some(existing_chan_info) = $target.as_ref() {
if existing_chan_info.last_update >= msg.timestamp {
// The timestamp field is somewhat of a misnomer - the BOLTs use it to
// order updates to ensure you always have the latest one, only
// suggesting that it be at least the current time. For
// channel_updates specifically, the BOLTs discuss the possibility of
// pruning based on the timestamp field being more than two weeks old,
// but only in the non-normative section.
if existing_chan_info.last_update > msg.timestamp {
return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreAndLog(Level::Gossip)});
} else if existing_chan_info.last_update == msg.timestamp {
return Err(LightningError{err: "Update had same timestamp as last processed update".to_owned(), action: ErrorAction::IgnoreDuplicateGossip});
}
chan_was_enabled = existing_chan_info.enabled;
} else {
Expand Down Expand Up @@ -1720,7 +1733,7 @@ mod tests {

match net_graph_msg_handler.handle_channel_update(&valid_channel_update) {
Ok(_) => panic!(),
Err(e) => assert_eq!(e.err, "Update older than last processed update")
Err(e) => assert_eq!(e.err, "Update had same timestamp as last processed update")
};
unsigned_channel_update.timestamp += 500;

Expand Down