Skip to content
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

Create and handle warning messages #1013

Merged
merged 6 commits into from
Jan 11, 2022
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
1 change: 1 addition & 0 deletions fuzz/src/msg_targets/gen_target.sh
Original file line number Diff line number Diff line change
Expand Up @@ -43,4 +43,5 @@ GEN_TEST QueryShortChannelIds test_msg ""
GEN_TEST ReplyChannelRange test_msg ""

GEN_TEST ErrorMessage test_msg_hole ", 32, 2"
GEN_TEST WarningMessage test_msg_hole ", 32, 2"
GEN_TEST ChannelUpdate test_msg_hole ", 108, 1"
1 change: 1 addition & 0 deletions fuzz/src/msg_targets/mod.rs
Original file line number Diff line number Diff line change
Expand Up @@ -28,4 +28,5 @@ pub mod msg_node_announcement;
pub mod msg_query_short_channel_ids;
pub mod msg_reply_channel_range;
pub mod msg_error_message;
pub mod msg_warning_message;
pub mod msg_channel_update;
27 changes: 27 additions & 0 deletions fuzz/src/msg_targets/msg_warning_message.rs
Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
// This file is Copyright its original authors, visible in version control
// history.
//
// This file is licensed under the Apache License, Version 2.0 <LICENSE-APACHE
// or http://www.apache.org/licenses/LICENSE-2.0> or the MIT license
// <LICENSE-MIT or http://opensource.org/licenses/MIT>, at your option.
// You may not use this file except in accordance with one or both of these
// licenses.

// This file is auto-generated by gen_target.sh based on msg_target_template.txt
// To modify it, modify msg_target_template.txt and run gen_target.sh instead.

use lightning::ln::msgs;

use msg_targets::utils::VecWriter;
use utils::test_logger;

#[inline]
pub fn msg_warning_message_test<Out: test_logger::Output>(data: &[u8], _out: Out) {
test_msg_hole!(msgs::WarningMessage, data, 32, 2);
}

#[no_mangle]
pub extern "C" fn msg_warning_message_run(data: *const u8, datalen: usize) {
let data = unsafe { std::slice::from_raw_parts(data, datalen) };
test_msg_hole!(msgs::WarningMessage, data, 32, 2);
}
4 changes: 2 additions & 2 deletions lightning/src/ln/channel.rs
Original file line number Diff line number Diff line change
Expand Up @@ -3723,12 +3723,12 @@ impl<Signer: Sign> Channel<Signer> {
assert_eq!(self.channel_state & ChannelState::ShutdownComplete as u32, 0);

if !script::is_bolt2_compliant(&msg.scriptpubkey, their_features) {
return Err(ChannelError::Close(format!("Got a nonstandard scriptpubkey ({}) from remote peer", msg.scriptpubkey.to_bytes().to_hex())));
return Err(ChannelError::Warn(format!("Got a nonstandard scriptpubkey ({}) from remote peer", msg.scriptpubkey.to_bytes().to_hex())));
}

if self.counterparty_shutdown_scriptpubkey.is_some() {
if Some(&msg.scriptpubkey) != self.counterparty_shutdown_scriptpubkey.as_ref() {
return Err(ChannelError::Close(format!("Got shutdown request with a scriptpubkey ({}) which did not match their previous scriptpubkey.", msg.scriptpubkey.to_bytes().to_hex())));
return Err(ChannelError::Warn(format!("Got shutdown request with a scriptpubkey ({}) which did not match their previous scriptpubkey.", msg.scriptpubkey.to_bytes().to_hex())));
}
} else {
self.counterparty_shutdown_scriptpubkey = Some(msg.scriptpubkey.clone());
Expand Down
14 changes: 9 additions & 5 deletions lightning/src/ln/channelmanager.rs
Original file line number Diff line number Diff line change
Expand Up @@ -613,8 +613,14 @@ impl MsgHandleErrInternal {
Self {
err: match err {
ChannelError::Warn(msg) => LightningError {
err: msg,
action: msgs::ErrorAction::IgnoreError,
err: msg.clone(),
action: msgs::ErrorAction::SendWarningMessage {
msg: msgs::WarningMessage {
channel_id,
data: msg
},
log_level: Level::Warn,
},
},
ChannelError::Ignore(msg) => LightningError {
err: msg,
Expand Down Expand Up @@ -1373,9 +1379,7 @@ macro_rules! convert_chan_err {
($self: ident, $err: expr, $short_to_id: expr, $channel: expr, $channel_id: expr) => {
match $err {
ChannelError::Warn(msg) => {
//TODO: Once warning messages are merged, we should send a `warning` message to our
//peer here.
(false, MsgHandleErrInternal::from_chan_no_close(ChannelError::Ignore(msg), $channel_id.clone()))
(false, MsgHandleErrInternal::from_chan_no_close(ChannelError::Warn(msg), $channel_id.clone()))
},
ChannelError::Ignore(msg) => {
(false, MsgHandleErrInternal::from_chan_no_close(ChannelError::Ignore(msg), $channel_id.clone()))
Expand Down
16 changes: 16 additions & 0 deletions lightning/src/ln/functional_test_utils.rs
Original file line number Diff line number Diff line change
Expand Up @@ -780,6 +780,22 @@ macro_rules! get_closing_signed_broadcast {
}
}

#[cfg(test)]
macro_rules! check_warn_msg {
($node: expr, $recipient_node_id: expr, $chan_id: expr) => {{
let msg_events = $node.node.get_and_clear_pending_msg_events();
assert_eq!(msg_events.len(), 1);
match msg_events[0] {
MessageSendEvent::HandleError { action: ErrorAction::SendWarningMessage { ref msg, log_level: _ }, node_id } => {
assert_eq!(node_id, $recipient_node_id);
assert_eq!(msg.channel_id, $chan_id);
msg.data.clone()
},
_ => panic!("Unexpected event"),
}
}}
}

/// Check that a channel's closing channel update has been broadcasted, and optionally
/// check whether an error message event has occurred.
#[macro_export]
Expand Down
85 changes: 75 additions & 10 deletions lightning/src/ln/msgs.rs
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,7 @@ use bitcoin::hash_types::{Txid, BlockHash};
use ln::features::{ChannelFeatures, ChannelTypeFeatures, InitFeatures, NodeFeatures};

use prelude::*;
use core::{cmp, fmt};
use core::fmt;
use core::fmt::Debug;
use io::{self, Read};
use io_extras::read_to_end;
Expand Down Expand Up @@ -80,12 +80,29 @@ pub struct Init {
/// An error message to be sent or received from a peer
#[derive(Clone, Debug, PartialEq)]
pub struct ErrorMessage {
/// The channel ID involved in the error
/// The channel ID involved in the error.
///
/// All-0s indicates a general error unrelated to a specific channel, after which all channels
/// with the sending peer should be closed.
pub channel_id: [u8; 32],
/// A possibly human-readable error description.
/// The string should be sanitized before it is used (e.g. emitted to logs
/// or printed to stdout). Otherwise, a well crafted error message may trigger a security
/// vulnerability in the terminal emulator or the logging subsystem.
/// The string should be sanitized before it is used (e.g. emitted to logs or printed to
/// stdout). Otherwise, a well crafted error message may trigger a security vulnerability in
/// the terminal emulator or the logging subsystem.
pub data: String,
}

/// A warning message to be sent or received from a peer
#[derive(Clone, Debug, PartialEq)]
pub struct WarningMessage {
Copy link
Contributor

Choose a reason for hiding this comment

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

Did we name ErrorMessage with the trailing Message just to avoid conflicts with Rust's Error type? If so, is the suffix desired here? Maybe ok to parallel it here. No strong feelings.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Yea, I'm not sure if it was specifically to avoid conflicts or just because Error seems like something that would be used as an Error vs ErrorMessage is pretty clear. The same logic applies for Warning, IMO, but I also don't have particularly strong feelings.

/// The channel ID involved in the warning.
///
/// All-0s indicates a warning unrelated to a specific channel.
pub channel_id: [u8; 32],
/// A possibly human-readable warning description.
/// The string should be sanitized before it is used (e.g. emitted to logs or printed to
/// stdout). Otherwise, a well crafted error message may trigger a security vulnerability in
/// the terminal emulator or the logging subsystem.
TheBlueMatt marked this conversation as resolved.
Show resolved Hide resolved
pub data: String,
}

Expand Down Expand Up @@ -714,7 +731,16 @@ pub enum ErrorAction {
/// The peer did something incorrect. Tell them.
SendErrorMessage {
/// The message to send.
msg: ErrorMessage
msg: ErrorMessage,
},
/// The peer did something incorrect. Tell them without closing any channels.
SendWarningMessage {
/// The message to send.
msg: WarningMessage,
/// The peer may have done something harmless that we weren't able to meaningfully process,
/// though we should still tell them about it.
/// If this event is logged, log it at the given level.
log_level: logger::Level,
},
}

Expand Down Expand Up @@ -1503,10 +1529,38 @@ impl Readable for ErrorMessage {
Ok(Self {
channel_id: Readable::read(r)?,
data: {
let mut sz: usize = <u16 as Readable>::read(r)? as usize;
let data = read_to_end(r)?;
sz = cmp::min(data.len(), sz);
TheBlueMatt marked this conversation as resolved.
Show resolved Hide resolved
match String::from_utf8(data[..sz as usize].to_vec()) {
let sz: usize = <u16 as Readable>::read(r)? as usize;
let mut data = Vec::with_capacity(sz);
data.resize(sz, 0);
r.read_exact(&mut data)?;
match String::from_utf8(data) {
Ok(s) => s,
Err(_) => return Err(DecodeError::InvalidValue),
}
}
})
}
}

impl Writeable for WarningMessage {
fn write<W: Writer>(&self, w: &mut W) -> Result<(), io::Error> {
self.channel_id.write(w)?;
(self.data.len() as u16).write(w)?;
w.write_all(self.data.as_bytes())?;
Ok(())
}
}

impl Readable for WarningMessage {
fn read<R: Read>(r: &mut R) -> Result<Self, DecodeError> {
Ok(Self {
channel_id: Readable::read(r)?,
data: {
let sz: usize = <u16 as Readable>::read(r)? as usize;
let mut data = Vec::with_capacity(sz);
data.resize(sz, 0);
r.read_exact(&mut data)?;
match String::from_utf8(data) {
Ok(s) => s,
Err(_) => return Err(DecodeError::InvalidValue),
}
Expand Down Expand Up @@ -2405,6 +2459,17 @@ mod tests {
assert_eq!(encoded_value, target_value);
}

#[test]
fn encoding_warning() {
let error = msgs::WarningMessage {
channel_id: [2; 32],
data: String::from("rust-lightning"),
};
let encoded_value = error.encode();
let target_value = hex::decode("0202020202020202020202020202020202020202020202020202020202020202000e727573742d6c696768746e696e67").unwrap();
assert_eq!(encoded_value, target_value);
}

#[test]
fn encoding_ping() {
let ping = msgs::Ping {
Expand Down
52 changes: 42 additions & 10 deletions lightning/src/ln/peer_handler.rs
Original file line number Diff line number Diff line change
Expand Up @@ -821,6 +821,11 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
self.enqueue_message(peer, &msg);
continue;
},
msgs::ErrorAction::SendWarningMessage { msg, log_level } => {
log_given_level!(self.logger, log_level, "Error handling message{}; sending warning message with: {}", OptionalFromDebugger(&peer.their_node_id), e.err);
self.enqueue_message(peer, &msg);
continue;
},
}
}
}
Expand Down Expand Up @@ -897,25 +902,31 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
Ok(x) => x,
Err(e) => {
match e {
msgs::DecodeError::UnknownVersion => return Err(PeerHandleError { no_connection_possible: false }),
msgs::DecodeError::UnknownRequiredFeature => {
(msgs::DecodeError::UnknownRequiredFeature, _) => {
log_gossip!(self.logger, "Got a channel/node announcement with an unknown required feature flag, you may want to update!");
Copy link
Contributor

Choose a reason for hiding this comment

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

Not necessarily relevant to the PR, but could this happen for non-gossip messages?

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, yes, it could, I think there was a time where it couldn't but now it definitely can at least for TLVs. Lets fix that in a followup.

continue;
}
msgs::DecodeError::InvalidValue => {
(msgs::DecodeError::UnsupportedCompression, _) => {
log_gossip!(self.logger, "We don't support zlib-compressed message fields, sending a warning and ignoring message");
self.enqueue_message(peer, &msgs::WarningMessage { channel_id: [0; 32], data: "Unsupported message compression: zlib".to_owned() });
continue;
}
(_, Some(ty)) if is_gossip_msg(ty) => {
log_gossip!(self.logger, "Got an invalid value while deserializing a gossip message");
self.enqueue_message(peer, &msgs::WarningMessage { channel_id: [0; 32], data: "Unreadable/bogus gossip message".to_owned() });
continue;
}
(msgs::DecodeError::UnknownVersion, _) => return Err(PeerHandleError { no_connection_possible: false }),
(msgs::DecodeError::InvalidValue, _) => {
log_debug!(self.logger, "Got an invalid value while deserializing message");
return Err(PeerHandleError { no_connection_possible: false });
}
msgs::DecodeError::ShortRead => {
(msgs::DecodeError::ShortRead, _) => {
log_debug!(self.logger, "Deserialization failed due to shortness of message");
return Err(PeerHandleError { no_connection_possible: false });
}
msgs::DecodeError::BadLengthDescriptor => return Err(PeerHandleError { no_connection_possible: false }),
msgs::DecodeError::Io(_) => return Err(PeerHandleError { no_connection_possible: false }),
msgs::DecodeError::UnsupportedCompression => {
log_gossip!(self.logger, "We don't support zlib-compressed message fields, ignoring message");
continue;
}
(msgs::DecodeError::BadLengthDescriptor, _) => return Err(PeerHandleError { no_connection_possible: false }),
(msgs::DecodeError::Io(_), _) => return Err(PeerHandleError { no_connection_possible: false }),
Copy link
Contributor

Choose a reason for hiding this comment

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

An earlier commit handled this for gossip messages, too. I guess this way is more accurate, but just wanted to note the change in behavior.

Copy link
Collaborator Author

Choose a reason for hiding this comment

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

Yea, technically I don't think we should be able to hit this ever, but some of the other errors I'm not sure if we can hit them for gossip messages or not, and I'd just rather we return a warning for them anyway.

}
}
};
Expand Down Expand Up @@ -1022,6 +1033,21 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
return Err(PeerHandleError{ no_connection_possible: true }.into());
}
},
wire::Message::Warning(msg) => {
let mut data_is_printable = true;
for b in msg.data.bytes() {
if b < 32 || b > 126 {
data_is_printable = false;
break;
}
}
TheBlueMatt marked this conversation as resolved.
Show resolved Hide resolved

if data_is_printable {
log_debug!(self.logger, "Got warning message from {}: {}", log_pubkey!(peer.their_node_id.unwrap()), msg.data);
} else {
log_debug!(self.logger, "Got warning message from {} with non-ASCII error message", log_pubkey!(peer.their_node_id.unwrap()));
}
},

wire::Message::Ping(msg) => {
if msg.ponglen < 65532 {
Expand Down Expand Up @@ -1419,6 +1445,12 @@ impl<Descriptor: SocketDescriptor, CM: Deref, RM: Deref, L: Deref, CMH: Deref> P
msg.data);
self.enqueue_message(get_peer_for_forwarding!(node_id), msg);
},
msgs::ErrorAction::SendWarningMessage { ref msg, ref log_level } => {
log_given_level!(self.logger, *log_level, "Handling SendWarningMessage HandleError event in peer_handler for node {} with message {}",
log_pubkey!(node_id),
msg.data);
self.enqueue_message(get_peer_for_forwarding!(node_id), msg);
},
}
},
MessageSendEvent::SendChannelRangeQuery { ref node_id, ref msg } => {
Expand Down
46 changes: 15 additions & 31 deletions lightning/src/ln/shutdown_tests.rs
Original file line number Diff line number Diff line change
Expand Up @@ -415,13 +415,17 @@ fn test_upfront_shutdown_script() {
let flags = InitFeatures::known();
let chan = create_announced_chan_between_nodes_with_value(&nodes, 0, 2, 1000000, 1000000, flags.clone(), flags.clone());
nodes[0].node.close_channel(&OutPoint { txid: chan.3.txid(), index: 0 }.to_channel_id()).unwrap();
let mut node_0_shutdown = get_event_msg!(nodes[0], MessageSendEvent::SendShutdown, nodes[2].node.get_our_node_id());
let node_0_orig_shutdown = get_event_msg!(nodes[0], MessageSendEvent::SendShutdown, nodes[2].node.get_our_node_id());
let mut node_0_shutdown = node_0_orig_shutdown.clone();
node_0_shutdown.scriptpubkey = Builder::new().push_opcode(opcodes::all::OP_RETURN).into_script().to_p2sh();
// Test we enforce upfront_scriptpbukey if by providing a diffrent one at closing that we disconnect peer
// Test we enforce upfront_scriptpbukey if by providing a different one at closing that we warn
// the peer and ignore the message.
nodes[2].node.handle_shutdown(&nodes[0].node.get_our_node_id(), &InitFeatures::known(), &node_0_shutdown);
assert!(regex::Regex::new(r"Got shutdown request with a scriptpubkey \([A-Fa-f0-9]+\) which did not match their previous scriptpubkey.").unwrap().is_match(check_closed_broadcast!(nodes[2], true).unwrap().data.as_str()));
check_closed_event!(nodes[2], 1, ClosureReason::ProcessingError { err: "Got shutdown request with a scriptpubkey (a91441c98a140039816273e50db317422c11c2bfcc8887) which did not match their previous scriptpubkey.".to_string() });
check_added_monitors!(nodes[2], 1);
assert!(regex::Regex::new(r"Got shutdown request with a scriptpubkey \([A-Fa-f0-9]+\) which did not match their previous scriptpubkey.")
.unwrap().is_match(&check_warn_msg!(nodes[2], nodes[0].node.get_our_node_id(), chan.2)));
// This allows nodes[2] to retry the shutdown message, which should get a response:
nodes[2].node.handle_shutdown(&nodes[0].node.get_our_node_id(), &InitFeatures::known(), &node_0_orig_shutdown);
get_event_msg!(nodes[2], MessageSendEvent::SendShutdown, nodes[0].node.get_our_node_id());

// We test that in case of peer committing upfront to a script, if it doesn't change at closing, we sign
let chan = create_announced_chan_between_nodes_with_value(&nodes, 0, 2, 1000000, 1000000, flags.clone(), flags.clone());
Expand Down Expand Up @@ -668,17 +672,8 @@ fn test_unsupported_anysegwit_shutdown_script() {
node_0_shutdown.scriptpubkey = unsupported_shutdown_script.into_inner();
nodes[0].node.handle_shutdown(&nodes[1].node.get_our_node_id(), &node_cfgs[1].features, &node_0_shutdown);

let events = nodes[0].node.get_and_clear_pending_msg_events();
assert_eq!(events.len(), 2);
match events[1] {
MessageSendEvent::HandleError { action: ErrorAction::SendErrorMessage { ref msg }, node_id } => {
assert_eq!(node_id, nodes[1].node.get_our_node_id());
assert_eq!(msg.data, "Got a nonstandard scriptpubkey (60020028) from remote peer".to_owned());
},
_ => panic!("Unexpected event"),
}
check_added_monitors!(nodes[0], 1);
check_closed_event!(nodes[0], 1, ClosureReason::ProcessingError { err: "Got a nonstandard scriptpubkey (60020028) from remote peer".to_string() });
assert_eq!(&check_warn_msg!(nodes[0], nodes[1].node.get_our_node_id(), chan.2),
"Got a nonstandard scriptpubkey (60020028) from remote peer");
}

#[test]
Expand All @@ -704,17 +699,8 @@ fn test_invalid_shutdown_script() {
.into_script();
nodes[0].node.handle_shutdown(&nodes[1].node.get_our_node_id(), &InitFeatures::known(), &node_0_shutdown);

let events = nodes[0].node.get_and_clear_pending_msg_events();
assert_eq!(events.len(), 2);
match events[1] {
MessageSendEvent::HandleError { action: ErrorAction::SendErrorMessage { ref msg }, node_id } => {
assert_eq!(node_id, nodes[1].node.get_our_node_id());
assert_eq!(msg.data, "Got a nonstandard scriptpubkey (00020000) from remote peer".to_owned())
},
_ => panic!("Unexpected event"),
}
check_added_monitors!(nodes[0], 1);
check_closed_event!(nodes[0], 1, ClosureReason::ProcessingError { err: "Got a nonstandard scriptpubkey (00020000) from remote peer".to_string() });
assert_eq!(&check_warn_msg!(nodes[0], nodes[1].node.get_our_node_id(), chan.2),
"Got a nonstandard scriptpubkey (00020000) from remote peer");
}

#[derive(PartialEq)]
Expand Down Expand Up @@ -762,10 +748,8 @@ fn do_test_closing_signed_reinit_timeout(timeout_step: TimeoutStep) {

if timeout_step != TimeoutStep::AfterShutdown {
nodes[1].node.handle_closing_signed(&nodes[0].node.get_our_node_id(), &node_0_closing_signed);
// At this point nodes[1] should send back a warning message indicating it disagrees with the
// given channel-closing fee. Currently we do not implement warning messages so instead we
// remain silent here.
assert!(nodes[1].node.get_and_clear_pending_msg_events().is_empty());
assert!(check_warn_msg!(nodes[1], nodes[0].node.get_our_node_id(), chan_id)
.starts_with("Unable to come to consensus about closing feerate"));

// Now deliver a mutated closing_signed indicating a higher acceptable fee range, which
// nodes[1] should happily accept and respond to.
Expand Down
Loading