log_trace information about commitment txn as they're being built

Author: TheBlueMatt

src/ln/channel.rs

@@ -774,6 +774,8 @@ impl Channel {
 		let mut local_htlc_total_msat = 0;
 		let mut value_to_self_msat_offset = 0;
 
+		log_trace!(self, "Building commitment transaction number {} for {}, generated by {} with fee {}...", commitment_number, if local { "us" } else { "remote" }, if generated_by_local { "us" } else { "remote" }, feerate_per_kw);
+
 		macro_rules! get_htlc_in_commitment {
 			($htlc: expr, $offered: expr) => {
 				HTLCOutputInCommitment {
@@ -791,21 +793,25 @@ impl Channel {
 				if $outbound == local { // "offered HTLC output"
 					let htlc_in_tx = get_htlc_in_commitment!($htlc, true);
 					if $htlc.amount_msat / 1000 >= dust_limit_satoshis + (feerate_per_kw * HTLC_TIMEOUT_TX_WEIGHT / 1000) {
+						log_trace!(self, "   ...including {} HTLC {} with value {}", if $outbound { "outbound" } else { "inbound" }, log_bytes!($htlc.payment_hash.0), $htlc.amount_msat);
 						txouts.push((TxOut {
 							script_pubkey: chan_utils::get_htlc_redeemscript(&htlc_in_tx, &keys).to_v0_p2wsh(),
 							value: $htlc.amount_msat / 1000
 						}, Some((htlc_in_tx, $source))));
 					} else {
+						log_trace!(self, "   ...not including {} HTLC {} with value {} due to dust limit", if $outbound { "outbound" } else { "inbound" }, log_bytes!($htlc.payment_hash.0), $htlc.amount_msat);
 						included_dust_htlcs.push((htlc_in_tx, $source));
 					}
 				} else {
 					let htlc_in_tx = get_htlc_in_commitment!($htlc, false);
 					if $htlc.amount_msat / 1000 >= dust_limit_satoshis + (feerate_per_kw * HTLC_SUCCESS_TX_WEIGHT / 1000) {
+						log_trace!(self, "   ...including {} HTLC {} with value {}", if $outbound { "outbound" } else { "inbound" }, log_bytes!($htlc.payment_hash.0), $htlc.amount_msat);
 						txouts.push((TxOut { // "received HTLC output"
 							script_pubkey: chan_utils::get_htlc_redeemscript(&htlc_in_tx, &keys).to_v0_p2wsh(),
 							value: $htlc.amount_msat / 1000
 						}, Some((htlc_in_tx, $source))));
 					} else {
+						log_trace!(self, "   ...not including {} HTLC {} with value {} due to dust limit", if $outbound { "outbound" } else { "inbound" }, log_bytes!($htlc.payment_hash.0), $htlc.amount_msat);
 						included_dust_htlcs.push((htlc_in_tx, $source));
 					}
 				}
@@ -825,6 +831,13 @@ impl Channel {
 				add_htlc_output!(htlc, false, None);
 				remote_htlc_total_msat += htlc.amount_msat;
 			} else {
+				log_trace!(self, "   ...not including inbound HTLC {} with value {} due to state ({})", log_bytes!(htlc.payment_hash.0), htlc.amount_msat, match htlc.state {
+						InboundHTLCState::RemoteAnnounced(_) => "RemoteAnnounced",
+						InboundHTLCState::AwaitingRemoteRevokeToAnnounce(_) => "AwaitingRemoteRevokeToAnnounce",
+						InboundHTLCState::AwaitingAnnouncedRemoteRevoke(_) => "AwaitingAnnouncedRemoteRevoke",
+						InboundHTLCState::Committed => "Committed",
+						InboundHTLCState::LocalRemoved(_) => "LocalRemoved",
+					});
 				match &htlc.state {
 					&InboundHTLCState::LocalRemoved(ref reason) => {
 						if generated_by_local {
@@ -851,6 +864,13 @@ impl Channel {
 				add_htlc_output!(htlc, true, Some(&htlc.source));
 				local_htlc_total_msat += htlc.amount_msat;
 			} else {
+				log_trace!(self, "   ...not including outbound HTLC {} with value {} due to state ({})", log_bytes!(htlc.payment_hash.0), htlc.amount_msat, match htlc.state {
+						OutboundHTLCState::LocalAnnounced(_) => "LocalAnnounced",
+						OutboundHTLCState::Committed => "Committed",
+						OutboundHTLCState::RemoteRemoved => "RemoteRemoved",
+						OutboundHTLCState::AwaitingRemoteRevokeToRemove => "AwaitingRemoteRevokeToRemove",
+						OutboundHTLCState::AwaitingRemovedRemoteRevoke => "AwaitingRemovedRemoteRevoke",
+					});
 				match htlc.state {
 					OutboundHTLCState::AwaitingRemoteRevokeToRemove|OutboundHTLCState::AwaitingRemovedRemoteRevoke => {
 						if htlc.fail_reason.is_none() {
@@ -1695,6 +1715,7 @@ impl Channel {
 		};
 		let local_commitment_txid = local_commitment_tx.0.txid();
 		let local_sighash = Message::from_slice(&bip143::SighashComponents::new(&local_commitment_tx.0).sighash_all(&local_commitment_tx.0.input[0], &funding_script, self.channel_value_satoshis)[..]).unwrap();
+		log_trace!(self, "Checking commitment tx signature {} by key {} against tx {} with redeemscript {}", log_bytes!(msg.signature[..]), log_bytes!(self.their_funding_pubkey.unwrap().serialize()), encode::serialize_hex(&local_commitment_tx.0), encode::serialize_hex(&funding_script));
 		secp_check!(self.secp_ctx.verify(&local_sighash, &msg.signature, &self.their_funding_pubkey.unwrap()), "Invalid commitment tx signature from peer");
 
 		//If channel fee was updated by funder confirm funder can afford the new fee rate when applied to the current local commitment transaction
@@ -1720,6 +1741,7 @@ impl Channel {
 			if let Some(_) = htlc.transaction_output_index {
 				let mut htlc_tx = self.build_htlc_transaction(&local_commitment_txid, &htlc, true, &local_keys, feerate_per_kw);
 				let htlc_redeemscript = chan_utils::get_htlc_redeemscript(&htlc, &local_keys);
+				log_trace!(self, "Checking HTLC tx signature {} by key {} against tx {} with redeemscript {}", log_bytes!(msg.htlc_signatures[idx][..]), log_bytes!(local_keys.b_htlc_key.serialize()), encode::serialize_hex(&htlc_tx), encode::serialize_hex(&htlc_redeemscript));
 				let htlc_sighash = Message::from_slice(&bip143::SighashComponents::new(&htlc_tx).sighash_all(&htlc_tx.input[0], &htlc_redeemscript, htlc.amount_msat / 1000)[..]).unwrap();
 				secp_check!(self.secp_ctx.verify(&htlc_sighash, &msg.htlc_signatures[idx], &local_keys.b_htlc_key), "Invalid HTLC tx signature from peer");
 				let htlc_sig = if htlc.offered {
@@ -3285,6 +3307,7 @@ impl Channel {
 		let remote_commitment_txid = remote_commitment_tx.0.txid();
 		let remote_sighash = Message::from_slice(&bip143::SighashComponents::new(&remote_commitment_tx.0).sighash_all(&remote_commitment_tx.0.input[0], &funding_script, self.channel_value_satoshis)[..]).unwrap();
 		let our_sig = self.secp_ctx.sign(&remote_sighash, &self.local_keys.funding_key);
+		log_trace!(self, "Signing commitment tx {} with redeemscript {} with pubkey {} -> {}", encode::serialize_hex(&remote_commitment_tx.0), encode::serialize_hex(&funding_script), log_bytes!(PublicKey::from_secret_key(&self.secp_ctx, &self.local_keys.funding_key).serialize()), log_bytes!(our_sig[..]));
 
 		let mut htlc_sigs = Vec::with_capacity(remote_commitment_tx.1);
 		for &(ref htlc, _) in remote_commitment_tx.2.iter() {
@@ -3294,6 +3317,7 @@ impl Channel {
 				let htlc_sighash = Message::from_slice(&bip143::SighashComponents::new(&htlc_tx).sighash_all(&htlc_tx.input[0], &htlc_redeemscript, htlc.amount_msat / 1000)[..]).unwrap();
 				let our_htlc_key = secp_check!(chan_utils::derive_private_key(&self.secp_ctx, &remote_keys.per_commitment_point, &self.local_keys.htlc_base_key), "Derived invalid key, peer is maliciously selecting parameters");
 				htlc_sigs.push(self.secp_ctx.sign(&htlc_sighash, &our_htlc_key));
+				log_trace!(self, "Signing HTLC tx {} with redeemscript {} with pubkey {} -> {}", encode::serialize_hex(&htlc_tx), encode::serialize_hex(&htlc_redeemscript), log_bytes!(PublicKey::from_secret_key(&self.secp_ctx, &our_htlc_key).serialize()), log_bytes!(htlc_sigs.last().unwrap()[..]));
 			}
 		}