Merge pull request #1013 from TheBlueMatt/2021-07-warning-msgs

Author: TheBlueMatt

fuzz/src/msg_targets/gen_target.sh

@@ -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"

fuzz/src/msg_targets/mod.rs

@@ -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;

fuzz/src/msg_targets/msg_warning_message.rs

@@ -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);
+}

lightning/src/ln/channel.rs

@@ -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());

lightning/src/ln/channelmanager.rs

@@ -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,
@@ -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()))

lightning/src/ln/functional_test_utils.rs

@@ -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]

lightning/src/ln/msgs.rs

@@ -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;
@@ -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 {
+	/// 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.
 	pub data: String,
 }
 
@@ -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,
 	},
 }
 
@@ -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);
-				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),
 				}
@@ -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 {

lightning/src/ln/peer_handler.rs

@@ -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;
+												},
 											}
 										}
 									}
@@ -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!");
 														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 }),
 												}
 											}
 										};
@@ -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;
+					}
+				}
+
+				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 {
@@ -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 } => {

lightning/src/ln/shutdown_tests.rs

@@ -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());
@@ -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]
@@ -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)]
@@ -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.