Improve error message.

... for ChannelError and APIMisuseError
Before this commit, When rl returns error, we don't know
The actual parameter which caused the error.
By returning parameterised `String` instead of predefined `&'static str`,
We can give a caller improved error message.

TestLogger now has two additional methods
1. `assert_log_contains` which checks the logged messsage
  has entry which includes the specified string as a substring.
2. `aasert_log_regex` mostly same with above but it is more flexible
  that caller specifies regex which has to be satisfied instead of
  just a substring.
For regex, tests now includes `regex` as dev-dependency.

Author: joemphilips

lightning/Cargo.toml

@@ -28,3 +28,4 @@ features = ["bitcoinconsensus"]
 
 [dev-dependencies]
 hex = "0.3"
+regex = "0.1.80"

lightning/src/lib.rs

@@ -20,6 +20,7 @@
 
 extern crate bitcoin;
 #[cfg(test)] extern crate hex;
+#[cfg(test)] extern crate regex;
 
 #[macro_use]
 pub mod util;

lightning/src/ln/channel.rs

@@ -972,8 +972,8 @@ pub fn route_over_limit<'a, 'b, 'c>(origin_node: &Node<'a, 'b, 'c>, expected_rou
 	}
 
 	let (_, our_payment_hash) = get_payment_preimage_hash!(origin_node);
-	unwrap_send_err!(origin_node.node.send_payment(&route, our_payment_hash, &None), true, APIError::ChannelUnavailable { err },
-		assert_eq!(err, "Cannot send value that would put us over the max HTLC value in flight our peer will accept"));
+	unwrap_send_err!(origin_node.node.send_payment(&route, our_payment_hash, &None), true, APIError::ChannelUnavailable { ref err },
+		assert!(err.contains("Cannot send value that would put us over the max HTLC value in flight our peer will accept")));
 }
 
 pub fn send_payment<'a, 'b, 'c>(origin: &Node<'a, 'b, 'c>, expected_route: &[&Node<'a, 'b, 'c>], recv_value: u64, expected_value: u64)  {

lightning/src/ln/channelmanager.rs

@@ -461,7 +461,7 @@ pub enum ErrorAction {
 /// An Err type for failure to process messages.
 pub struct LightningError {
 	/// A human-readable message describing the error
-	pub err: &'static str,
+	pub err: String,
 	/// The action which should be taken against the offending peer.
 	pub action: ErrorAction,
 }
@@ -701,7 +701,7 @@ impl fmt::Display for DecodeError {
 
 impl fmt::Debug for LightningError {
 	fn fmt(&self, f: &mut fmt::Formatter) -> fmt::Result {
-		f.write_str(self.err)
+		f.write_str(self.err.as_str())
 	}
 }
 

lightning/src/ln/functional_test_utils.rs

@@ -146,11 +146,11 @@ pub(super) fn build_onion_payloads(path: &Vec<RouteHop>, total_msat: u64, paymen
 		});
 		cur_value_msat += hop.fee_msat;
 		if cur_value_msat >= 21000000 * 100000000 * 1000 {
-			return Err(APIError::RouteError{err: "Channel fees overflowed?!"});
+			return Err(APIError::RouteError{err: "Channel fees overflowed?"});
 		}
 		cur_cltv += hop.cltv_expiry_delta as u32;
 		if cur_cltv >= 500000000 {
-			return Err(APIError::RouteError{err: "Channel CLTV overflowed?!"});
+			return Err(APIError::RouteError{err: "Channel CLTV overflowed?"});
 		}
 		last_short_channel_id = hop.short_channel_id;
 	}

lightning/src/ln/functional_tests.rs

@@ -11,6 +11,7 @@ use bitcoin::secp256k1;
 
 use util::chacha20poly1305rfc::ChaCha20Poly1305RFC;
 use util::byte_utils;
+use bitcoin::hashes::hex::ToHex;
 
 // Sha256("Noise_XK_secp256k1_ChaChaPoly_SHA256")
 const NOISE_CK: [u8; 32] = [0x26, 0x40, 0xf5, 0x2e, 0xeb, 0xcd, 0x9e, 0x88, 0x29, 0x58, 0x95, 0x1c, 0x79, 0x42, 0x50, 0xee, 0xdb, 0x28, 0x00, 0x2c, 0x05, 0xd7, 0xdc, 0x2e, 0xa0, 0xf1, 0x95, 0x40, 0x60, 0x42, 0xca, 0xf1];
@@ -139,7 +140,7 @@ impl PeerChannelEncryptor {
 
 		let mut chacha = ChaCha20Poly1305RFC::new(key, &nonce, h);
 		if !chacha.decrypt(&cyphertext[0..cyphertext.len() - 16], res, &cyphertext[cyphertext.len() - 16..]) {
-			return Err(LightningError{err: "Bad MAC", action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
+			return Err(LightningError{err: "Bad MAC".to_owned(), action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
 		}
 		Ok(())
 	}
@@ -193,11 +194,11 @@ impl PeerChannelEncryptor {
 		assert_eq!(act.len(), 50);
 
 		if act[0] != 0 {
-			return Err(LightningError{err: "Unknown handshake version number", action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
+			return Err(LightningError{err: format!("Unknown handshake version number {}", act[0]), action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
 		}
 
 		let their_pub = match PublicKey::from_slice(&act[1..34]) {
-			Err(_) => return Err(LightningError{err: "Invalid public key", action: msgs::ErrorAction::DisconnectPeer{ msg: None }}),
+			Err(_) => return Err(LightningError{err: format!("Invalid public key {}", &act[1..34].to_hex()), action: msgs::ErrorAction::DisconnectPeer{ msg: None }}),
 			Ok(key) => key,
 		};
 
@@ -330,14 +331,14 @@ impl PeerChannelEncryptor {
 							panic!("Requested act at wrong step");
 						}
 						if act_three[0] != 0 {
-							return Err(LightningError{err: "Unknown handshake version number", action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
+							return Err(LightningError{err: format!("Unknown handshake version number {}", act_three[0]), action: msgs::ErrorAction::DisconnectPeer{ msg: None }});
 						}
 
 						let mut their_node_id = [0; 33];
 						PeerChannelEncryptor::decrypt_with_ad(&mut their_node_id, 1, &temp_k2.unwrap(), &bidirectional_state.h, &act_three[1..50])?;
 						self.their_node_id = Some(match PublicKey::from_slice(&their_node_id) {
 							Ok(key) => key,
-							Err(_) => return Err(LightningError{err: "Bad node_id from peer", action: msgs::ErrorAction::DisconnectPeer{ msg: None }}),
+							Err(_) => return Err(LightningError{err: format!("Bad node_id from peer, {}", &their_node_id.to_hex()), action: msgs::ErrorAction::DisconnectPeer{ msg: None }}),
 						});
 
 						let mut sha = Sha256::engine();

lightning/src/ln/msgs.rs

@@ -22,6 +22,7 @@ use std::sync::atomic::{AtomicUsize, Ordering};
 use std::collections::BTreeMap;
 use std::collections::btree_map::Entry as BtreeEntry;
 use std::ops::Deref;
+use bitcoin::hashes::hex::ToHex;
 
 /// Receives and validates network updates from peers,
 /// stores authentic and relevant data as a network graph.
@@ -74,7 +75,7 @@ macro_rules! secp_verify_sig {
 	( $secp_ctx: expr, $msg: expr, $sig: expr, $pubkey: expr ) => {
 		match $secp_ctx.verify($msg, $sig, $pubkey) {
 			Ok(_) => {},
-			Err(_) => return Err(LightningError{err: "Invalid signature from remote node", action: ErrorAction::IgnoreError}),
+			Err(_) => return Err(LightningError{err: "Invalid signature from remote node".to_owned(), action: ErrorAction::IgnoreError}),
 		}
 	};
 }
@@ -86,7 +87,7 @@ impl<C: Deref + Sync + Send, L: Deref + Sync + Send> RoutingMessageHandler for N
 
 	fn handle_channel_announcement(&self, msg: &msgs::ChannelAnnouncement) -> Result<bool, LightningError> {
 		if msg.contents.node_id_1 == msg.contents.node_id_2 || msg.contents.bitcoin_key_1 == msg.contents.bitcoin_key_2 {
-			return Err(LightningError{err: "Channel announcement node had a channel with itself", action: ErrorAction::IgnoreError});
+			return Err(LightningError{err: "Channel announcement node had a channel with itself".to_owned(), action: ErrorAction::IgnoreError});
 		}
 
 		let checked_utxo = match self.chain_monitor.get_chain_utxo(msg.contents.chain_hash, msg.contents.short_channel_id) {
@@ -97,7 +98,7 @@ impl<C: Deref + Sync + Send, L: Deref + Sync + Send> RoutingMessageHandler for N
 				                                    .push_opcode(opcodes::all::OP_PUSHNUM_2)
 				                                    .push_opcode(opcodes::all::OP_CHECKMULTISIG).into_script().to_v0_p2wsh();
 				if script_pubkey != expected_script {
-					return Err(LightningError{err: "Channel announcement keys didn't match on-chain script", action: ErrorAction::IgnoreError});
+					return Err(LightningError{err: format!("Channel announcement key({}) didn't match on-chain script ({})", script_pubkey.to_hex(), expected_script.to_hex()), action: ErrorAction::IgnoreError});
 				}
 				//TODO: Check if value is worth storing, use it to inform routing, and compare it
 				//to the new HTLC max field in channel_update
@@ -108,10 +109,10 @@ impl<C: Deref + Sync + Send, L: Deref + Sync + Send> RoutingMessageHandler for N
 				false
 			},
 			Err(ChainError::NotWatched) => {
-				return Err(LightningError{err: "Channel announced on an unknown chain", action: ErrorAction::IgnoreError});
+				return Err(LightningError{err: format!("Channel announced on an unknown chain ({})", msg.contents.chain_hash.encode().to_hex()), action: ErrorAction::IgnoreError});
 			},
 			Err(ChainError::UnknownTx) => {
-				return Err(LightningError{err: "Channel announced without corresponding UTXO entry", action: ErrorAction::IgnoreError});
+				return Err(LightningError{err: "Channel announced without corresponding UTXO entry".to_owned(), action: ErrorAction::IgnoreError});
 			},
 		};
 		let result = self.network_graph.write().unwrap().update_channel_from_announcement(msg, checked_utxo, Some(&self.secp_ctx));
@@ -522,11 +523,11 @@ impl NetworkGraph {
 		}
 
 		match self.nodes.get_mut(&msg.contents.node_id) {
-			None => Err(LightningError{err: "No existing channels for node_announcement", action: ErrorAction::IgnoreError}),
+			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.contents.timestamp {
-						return Err(LightningError{err: "Update older than last processed update", action: ErrorAction::IgnoreError});
+						return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreError});
 					}
 				}
 
@@ -588,7 +589,7 @@ impl NetworkGraph {
 					Self::remove_channel_in_nodes(&mut self.nodes, &entry.get(), msg.contents.short_channel_id);
 					*entry.get_mut() = chan_info;
 				} else {
-					return Err(LightningError{err: "Already have knowledge of channel", action: ErrorAction::IgnoreError})
+					return Err(LightningError{err: "Already have knowledge of channel".to_owned(), action: ErrorAction::IgnoreError})
 				}
 			},
 			BtreeEntry::Vacant(entry) => {
@@ -656,13 +657,13 @@ impl NetworkGraph {
 		let chan_was_enabled;
 
 		match self.channels.get_mut(&msg.contents.short_channel_id) {
-			None => return Err(LightningError{err: "Couldn't find channel for update", action: ErrorAction::IgnoreError}),
+			None => return Err(LightningError{err: "Couldn't find channel for update".to_owned(), action: ErrorAction::IgnoreError}),
 			Some(channel) => {
 				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.contents.timestamp {
-								return Err(LightningError{err: "Update older than last processed update", action: ErrorAction::IgnoreError});
+								return Err(LightningError{err: "Update older than last processed update".to_owned(), action: ErrorAction::IgnoreError});
 							}
 							chan_was_enabled = existing_chan_info.enabled;
 						} else {

lightning/src/ln/onion_utils.rs

@@ -165,11 +165,11 @@ pub fn get_route<L: Deref>(our_node_id: &PublicKey, network: &NetworkGraph, targ
 	// TODO: Obviously *only* using total fee cost sucks. We should consider weighting by
 	// uptime/success in using a node in the past.
 	if *target == *our_node_id {
-		return Err(LightningError{err: "Cannot generate a route to ourselves", action: ErrorAction::IgnoreError});
+		return Err(LightningError{err: "Cannot generate a route to ourselves".to_owned(), action: ErrorAction::IgnoreError});
 	}
 
 	if final_value_msat > 21_000_000 * 1_0000_0000 * 1000 {
-		return Err(LightningError{err: "Cannot generate a route of more value than all existing satoshis", action: ErrorAction::IgnoreError});
+		return Err(LightningError{err: "Cannot generate a route of more value than all existing satoshis".to_owned(), action: ErrorAction::IgnoreError});
 	}
 
 	// We do a dest-to-source Dijkstra's sorting by each node's distance from the destination
@@ -209,7 +209,7 @@ pub fn get_route<L: Deref>(our_node_id: &PublicKey, network: &NetworkGraph, targ
 			first_hop_targets.insert(chan.remote_network_id, (short_channel_id, chan.counterparty_features.clone()));
 		}
 		if first_hop_targets.is_empty() {
-			return Err(LightningError{err: "Cannot route when there are no outbound routes away from us", action: ErrorAction::IgnoreError});
+			return Err(LightningError{err: "Cannot route when there are no outbound routes away from us".to_owned(), action: ErrorAction::IgnoreError});
 		}
 	}
 
@@ -374,7 +374,7 @@ pub fn get_route<L: Deref>(our_node_id: &PublicKey, network: &NetworkGraph, targ
 
 				let new_entry = match dist.remove(&res.last().unwrap().pubkey) {
 					Some(hop) => hop.3,
-					None => return Err(LightningError{err: "Failed to find a non-fee-overflowing path to the given destination", action: ErrorAction::IgnoreError}),
+					None => return Err(LightningError{err: "Failed to find a non-fee-overflowing path to the given destination".to_owned(), action: ErrorAction::IgnoreError}),
 				};
 				res.last_mut().unwrap().fee_msat = new_entry.fee_msat;
 				res.last_mut().unwrap().cltv_expiry_delta = new_entry.cltv_expiry_delta;
@@ -395,7 +395,7 @@ pub fn get_route<L: Deref>(our_node_id: &PublicKey, network: &NetworkGraph, targ
 		}
 	}
 
-	Err(LightningError{err: "Failed to find a path to the given destination", action: ErrorAction::IgnoreError})
+	Err(LightningError{err: "Failed to find a path to the given destination".to_owned(), action: ErrorAction::IgnoreError})
 }
 
 #[cfg(test)]
@@ -881,7 +881,7 @@ mod tests {
 		assert_eq!(route.paths[0][0].fee_msat, 200);
 		assert_eq!(route.paths[0][0].cltv_expiry_delta, (13 << 8) | 1);
 		assert_eq!(route.paths[0][0].node_features.le_flags(), &vec![0b11]); // it should also override our view of their features
-		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::new()); // No feature flags will meet the relevant-to-channel conversion
+		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::<u8>::new()); // No feature flags will meet the relevant-to-channel conversion
 
 		assert_eq!(route.paths[0][1].pubkey, node3);
 		assert_eq!(route.paths[0][1].short_channel_id, 13);
@@ -945,7 +945,7 @@ mod tests {
 		assert_eq!(route.paths[0][0].fee_msat, 200);
 		assert_eq!(route.paths[0][0].cltv_expiry_delta, (13 << 8) | 1);
 		assert_eq!(route.paths[0][0].node_features.le_flags(), &vec![0b11]); // it should also override our view of their features
-		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::new()); // No feature flags will meet the relevant-to-channel conversion
+		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::<u8>::new()); // No feature flags will meet the relevant-to-channel conversion
 
 		assert_eq!(route.paths[0][1].pubkey, node3);
 		assert_eq!(route.paths[0][1].short_channel_id, 13);
@@ -1008,7 +1008,7 @@ mod tests {
 		assert_eq!(route.paths[0][0].fee_msat, 200);
 		assert_eq!(route.paths[0][0].cltv_expiry_delta, (13 << 8) | 1);
 		assert_eq!(route.paths[0][0].node_features.le_flags(), &vec![0b11]);
-		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::new()); // No feature flags will meet the relevant-to-channel conversion
+		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::<u8>::new()); // No feature flags will meet the relevant-to-channel conversion
 
 		assert_eq!(route.paths[0][1].pubkey, node3);
 		assert_eq!(route.paths[0][1].short_channel_id, 13);
@@ -1082,8 +1082,8 @@ mod tests {
 		assert_eq!(route.paths[0][4].short_channel_id, 8);
 		assert_eq!(route.paths[0][4].fee_msat, 100);
 		assert_eq!(route.paths[0][4].cltv_expiry_delta, 42);
-		assert_eq!(route.paths[0][4].node_features.le_flags(), &Vec::new()); // We dont pass flags in from invoices yet
-		assert_eq!(route.paths[0][4].channel_features.le_flags(), &Vec::new()); // We can't learn any flags from invoices, sadly
+		assert_eq!(route.paths[0][4].node_features.le_flags(), &Vec::<u8>::new()); // We dont pass flags in from invoices yet
+		assert_eq!(route.paths[0][4].channel_features.le_flags(), &Vec::<u8>::new()); // We can't learn any flags from invoices, sadly
 
 		// Simple test with outbound channel to 4 to test that last_hops and first_hops connect
 		let our_chans = vec![channelmanager::ChannelDetails {
@@ -1105,14 +1105,14 @@ mod tests {
 		assert_eq!(route.paths[0][0].fee_msat, 0);
 		assert_eq!(route.paths[0][0].cltv_expiry_delta, (8 << 8) | 1);
 		assert_eq!(route.paths[0][0].node_features.le_flags(), &vec![0b11]);
-		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::new()); // No feature flags will meet the relevant-to-channel conversion
+		assert_eq!(route.paths[0][0].channel_features.le_flags(), &Vec::<u8>::new()); // No feature flags will meet the relevant-to-channel conversion
 
 		assert_eq!(route.paths[0][1].pubkey, node7);
 		assert_eq!(route.paths[0][1].short_channel_id, 8);
 		assert_eq!(route.paths[0][1].fee_msat, 100);
 		assert_eq!(route.paths[0][1].cltv_expiry_delta, 42);
-		assert_eq!(route.paths[0][1].node_features.le_flags(), &Vec::new()); // We dont pass flags in from invoices yet
-		assert_eq!(route.paths[0][1].channel_features.le_flags(), &Vec::new()); // We can't learn any flags from invoices, sadly
+		assert_eq!(route.paths[0][1].node_features.le_flags(), &Vec::<u8>::new()); // We dont pass flags in from invoices yet
+		assert_eq!(route.paths[0][1].channel_features.le_flags(), &Vec::<u8>::new()); // We can't learn any flags from invoices, sadly
 
 		last_hops[0].fees.base_msat = 1000;
 
@@ -1147,8 +1147,8 @@ mod tests {
 		assert_eq!(route.paths[0][3].short_channel_id, 10);
 		assert_eq!(route.paths[0][3].fee_msat, 100);
 		assert_eq!(route.paths[0][3].cltv_expiry_delta, 42);
-		assert_eq!(route.paths[0][3].node_features.le_flags(), &Vec::new()); // We dont pass flags in from invoices yet
-		assert_eq!(route.paths[0][3].channel_features.le_flags(), &Vec::new()); // We can't learn any flags from invoices, sadly
+		assert_eq!(route.paths[0][3].node_features.le_flags(), &Vec::<u8>::new()); // We dont pass flags in from invoices yet
+		assert_eq!(route.paths[0][3].channel_features.le_flags(), &Vec::<u8>::new()); // We can't learn any flags from invoices, sadly
 
 		// ...but still use 8 for larger payments as 6 has a variable feerate
 		let route = get_route(&our_id, &net_graph_msg_handler.network_graph.read().unwrap(), &node7, None, &last_hops, 2000, 42, Arc::clone(&logger)).unwrap();
@@ -1188,7 +1188,7 @@ mod tests {
 		assert_eq!(route.paths[0][4].short_channel_id, 8);
 		assert_eq!(route.paths[0][4].fee_msat, 2000);
 		assert_eq!(route.paths[0][4].cltv_expiry_delta, 42);
-		assert_eq!(route.paths[0][4].node_features.le_flags(), &Vec::new()); // We dont pass flags in from invoices yet
-		assert_eq!(route.paths[0][4].channel_features.le_flags(), &Vec::new()); // We can't learn any flags from invoices, sadly
+		assert_eq!(route.paths[0][4].node_features.le_flags(), &Vec::<u8>::new()); // We dont pass flags in from invoices yet
+		assert_eq!(route.paths[0][4].channel_features.le_flags(), &Vec::<u8>::new()); // We can't learn any flags from invoices, sadly
 	}
 }

lightning/src/ln/peer_channel_encryptor.rs

@@ -9,7 +9,7 @@ pub enum APIError {
 	/// are documented, but generally indicates some precondition of a function was violated.
 	APIMisuseError {
 		/// A human-readable error message
-		err: &'static str
+		err: String
 	},
 	/// Due to a high feerate, we were unable to complete the request.
 	/// For example, this may be returned if the feerate implies we cannot open a channel at the
@@ -31,7 +31,7 @@ pub enum APIError {
 	/// peer, channel at capacity, channel shutting down, etc.
 	ChannelUnavailable {
 		/// A human-readable error message
-		err: &'static str
+		err: String
 	},
 	/// An attempt to call add/update_monitor returned an Err (ie you did this!), causing the
 	/// attempted action to fail.