Merge pull request #401 from ariard/2019-11-log-tx-broadcast

Add log for every tx broadcast

Author: TheBlueMatt

lightning/src/ln/channelmanager.rs

@@ -772,6 +772,7 @@ impl<'a> ChannelManager<'a> {
 			self.fail_htlc_backwards_internal(self.channel_state.lock().unwrap(), htlc_source.0, &htlc_source.1, HTLCFailReason::Reason { failure_code: 0x4000 | 8, data: Vec::new() });
 		}
 		for tx in local_txn {
+			log_trace!(self, "Broadcast onchain {}", log_tx!(tx));
 			self.tx_broadcaster.broadcast_transaction(&tx);
 		}
 	}
@@ -2077,6 +2078,7 @@ impl<'a> ChannelManager<'a> {
 			}
 		};
 		if let Some(broadcast_tx) = tx {
+			log_trace!(self, "Broadcast onchain {}", log_tx!(broadcast_tx));
 			self.tx_broadcaster.broadcast_transaction(&broadcast_tx);
 		}
 		if let Some(chan) = chan_option {

lightning/src/ln/channelmonitor.rs

@@ -2176,6 +2176,7 @@ impl ChannelMonitor {
 					}
 				}
 				for tx in txn.iter() {
+					log_trace!(self, "Broadcast onchain {}", log_tx!(tx));
 					broadcaster.broadcast_transaction(tx);
 				}
 			}
@@ -2211,6 +2212,7 @@ impl ChannelMonitor {
 		let mut pending_claims = Vec::new();
 		if let Some(ref cur_local_tx) = self.current_local_signed_commitment_tx {
 			if self.would_broadcast_at_height(height) {
+				log_trace!(self, "Broadcast onchain {}", log_tx!(cur_local_tx.tx));
 				broadcaster.broadcast_transaction(&cur_local_tx.tx);
 				match self.key_storage {
 					Storage::Local { ref delayed_payment_base_key, ref latest_per_commitment_point, .. } => {
@@ -2221,6 +2223,7 @@ impl ChannelMonitor {
 							watch_outputs.push((cur_local_tx.txid.clone(), new_outputs));
 						}
 						for tx in txs {
+							log_trace!(self, "Broadcast onchain {}", log_tx!(tx));
 							broadcaster.broadcast_transaction(&tx);
 						}
 					},
@@ -2232,6 +2235,7 @@ impl ChannelMonitor {
 							watch_outputs.push((cur_local_tx.txid.clone(), new_outputs));
 						}
 						for tx in txs {
+							log_trace!(self, "Broadcast onchain {}", log_tx!(tx));
 							broadcaster.broadcast_transaction(&tx);
 						}
 					}

lightning/src/util/macro_logger.rs

@@ -1,6 +1,7 @@
 use chain::transaction::OutPoint;
 
 use bitcoin_hashes::sha256d::Hash as Sha256dHash;
+use bitcoin::blockdata::transaction::Transaction;
 use secp256k1::key::PublicKey;
 
 use ln::router::Route;
@@ -89,6 +90,29 @@ macro_rules! log_route {
 	}
 }
 
+pub(crate) struct DebugTx<'a>(pub &'a Transaction);
+impl<'a> std::fmt::Display for DebugTx<'a> {
+	fn fmt(&self, f: &mut std::fmt::Formatter) -> Result<(), std::fmt::Error> {
+		if self.0.input.len() == 1 && self.0.input[0].witness.last().unwrap().len() == 71 && (self.0.input[0].sequence >> 8*3) as u8 == 0x80 { write!(f, "commitment tx")?; }
+		else if self.0.input.len() == 1 && self.0.input[0].witness.last().unwrap().len() == 71 { write!(f, "closing tx")?; }
+		else if self.0.input.len() == 1 && self.0.input[0].witness.last().unwrap().len() == 133 && self.0.input[0].witness.len() == 5 { write!(f, "HTLC-timeout tx")?; }
+		else if self.0.input.len() == 1 && (self.0.input[0].witness.last().unwrap().len() == 138 || self.0.input[0].witness.last().unwrap().len() == 139) && self.0.input[0].witness.len() == 5 { write!(f, "HTLC-success tx")?; }
+		else {
+			for inp in &self.0.input {
+				if inp.witness.last().unwrap().len() == 133 { write!(f, "preimage tx")?; break }
+				else if inp.witness.last().unwrap().len() == 138 { write!(f, "timeout tx")?; break }
+			}
+		}
+		Ok(())
+	}
+}
+
+macro_rules! log_tx {
+	($obj: expr) => {
+		::util::macro_logger::DebugTx(&$obj)
+	}
+}
+
 macro_rules! log_internal {
 	($self: ident, $lvl:expr, $($arg:tt)+) => (
 		&$self.logger.log(&::util::logger::Record::new($lvl, format_args!($($arg)+), module_path!(), file!(), line!()));