Simplify and expand logging in is_resolving_htlc_output
[rust-lightning] / src / ln / channelmonitor.rs
index 9fed550982177f1d7433ddddd4e36cd98b8cd1c2..ea3e279213c88cca40a7e3fa5c800828fbc20f12 100644 (file)
@@ -568,6 +568,8 @@ impl ChannelMonitor {
                }
 
                let new_txid = unsigned_commitment_tx.txid();
+               log_trace!(self, "Tracking new remote commitment transaction with txid {} at commitment number {} with {} HTLC outputs", new_txid, commitment_number, htlc_outputs.len());
+               log_trace!(self, "New potential remote commitment transaction: {}", encode::serialize_hex(unsigned_commitment_tx));
                if let Storage::Local { ref mut current_remote_commitment_txid, ref mut prev_remote_commitment_txid, .. } = self.key_storage {
                        *prev_remote_commitment_txid = current_remote_commitment_txid.take();
                        *current_remote_commitment_txid = Some(new_txid);
@@ -987,9 +989,6 @@ impl ChannelMonitor {
                self.write(writer, false)
        }
 
-       //TODO: Functions to serialize/deserialize (with different forms depending on which information
-       //we want to leave out (eg funding_txo, etc).
-
        /// Can only fail if idx is < get_min_seen_secret
        pub(super) fn get_secret(&self, idx: u64) -> Option<[u8; 32]> {
                for i in 0..self.old_secrets.len() {
@@ -1180,11 +1179,34 @@ impl ChannelMonitor {
                                }
                        }
 
-                       if !inputs.is_empty() || !txn_to_broadcast.is_empty() { // ie we're confident this is actually ours
+                       if !inputs.is_empty() || !txn_to_broadcast.is_empty() || per_commitment_option.is_some() { // ie we're confident this is actually ours
                                // We're definitely a remote commitment transaction!
                                log_trace!(self, "Got broadcast of revoked remote commitment transaction, generating general spend tx with {} inputs and {} other txn to broadcast", inputs.len(), txn_to_broadcast.len());
                                watch_outputs.append(&mut tx.output.clone());
                                self.remote_commitment_txn_on_chain.insert(commitment_txid, (commitment_number, tx.output.iter().map(|output| { output.script_pubkey.clone() }).collect()));
+
+                               // TODO: We really should only fail backwards after our revocation claims have been
+                               // confirmed, but we also need to do more other tracking of in-flight pre-confirm
+                               // on-chain claims, so we can do that at the same time.
+                               macro_rules! check_htlc_fails {
+                                       ($txid: expr, $commitment_tx: expr) => {
+                                               if let Some(&(_, ref outpoints)) = self.remote_claimable_outpoints.get(&$txid) {
+                                                       for &(ref payment_hash, ref source, _) in outpoints.iter() {
+                                                               log_trace!(self, "Failing HTLC with payment_hash {} from {} remote commitment tx due to broadcast of revoked remote commitment transaction", log_bytes!(payment_hash.0), $commitment_tx);
+                                                               htlc_updated.push(((*source).clone(), None, payment_hash.clone()));
+                                                       }
+                                               }
+                                       }
+                               }
+                               if let Storage::Local { ref current_remote_commitment_txid, ref prev_remote_commitment_txid, .. } = self.key_storage {
+                                       if let &Some(ref txid) = current_remote_commitment_txid {
+                                               check_htlc_fails!(txid, "current");
+                                       }
+                                       if let &Some(ref txid) = prev_remote_commitment_txid {
+                                               check_htlc_fails!(txid, "remote");
+                                       }
+                               }
+                               // No need to check local commitment txn, symmetric HTLCSource must be present as per-htlc data on remote commitment tx
                        }
                        if inputs.is_empty() { return (txn_to_broadcast, (commitment_txid, watch_outputs), spendable_outputs, htlc_updated); } // Nothing to be done...probably a false positive/local tx
 
@@ -1212,39 +1234,54 @@ impl ChannelMonitor {
                                output: spend_tx.output[0].clone(),
                        });
                        txn_to_broadcast.push(spend_tx);
+               } else if let Some(per_commitment_data) = per_commitment_option {
+                       // While this isn't useful yet, there is a potential race where if a counterparty
+                       // revokes a state at the same time as the commitment transaction for that state is
+                       // confirmed, and the watchtower receives the block before the user, the user could
+                       // upload a new ChannelMonitor with the revocation secret but the watchtower has
+                       // already processed the block, resulting in the remote_commitment_txn_on_chain entry
+                       // not being generated by the above conditional. Thus, to be safe, we go ahead and
+                       // insert it here.
+                       watch_outputs.append(&mut tx.output.clone());
+                       self.remote_commitment_txn_on_chain.insert(commitment_txid, (commitment_number, tx.output.iter().map(|output| { output.script_pubkey.clone() }).collect()));
+
+                       log_trace!(self, "Got broadcast of non-revoked remote commitment transaction {}", commitment_txid);
 
                        // TODO: We really should only fail backwards after our revocation claims have been
                        // confirmed, but we also need to do more other tracking of in-flight pre-confirm
                        // on-chain claims, so we can do that at the same time.
-                       if let Storage::Local { ref current_remote_commitment_txid, ref prev_remote_commitment_txid, .. } = self.key_storage {
-                               if let &Some(ref txid) = current_remote_commitment_txid {
-                                       if let Some(&(_, ref latest_outpoints)) = self.remote_claimable_outpoints.get(&txid) {
-                                               for &(ref payment_hash, ref source, _) in latest_outpoints.iter() {
-                                                       log_trace!(self, "Failing HTLC with payment_hash {} from current remote commitment tx due to broadcast of revoked remote commitment transaction", log_bytes!(payment_hash.0));
+                       macro_rules! check_htlc_fails {
+                               ($txid: expr, $commitment_tx: expr, $id: tt) => {
+                                       if let Some(&(_, ref latest_outpoints)) = self.remote_claimable_outpoints.get(&$txid) {
+                                               $id: for &(ref payment_hash, ref source, _) in latest_outpoints.iter() {
+                                                       // Check if the HTLC is present in the commitment transaction that was
+                                                       // broadcast, but not if it was below the dust limit, which we should
+                                                       // fail backwards immediately as there is no way for us to learn the
+                                                       // payment_preimage.
+                                                       // Note that if the dust limit were allowed to change between
+                                                       // commitment transactions we'd want to be check whether *any*
+                                                       // broadcastable commitment transaction has the HTLC in it, but it
+                                                       // cannot currently change after channel initialization, so we don't
+                                                       // need to here.
+                                                       for &(_, ref broadcast_source, ref output_idx) in per_commitment_data.1.iter() {
+                                                               if output_idx.is_some() && source == broadcast_source {
+                                                                       continue $id;
+                                                               }
+                                                       }
+                                                       log_trace!(self, "Failing HTLC with payment_hash {} from {} remote commitment tx due to broadcast of remote commitment transaction", log_bytes!(payment_hash.0), $commitment_tx);
                                                        htlc_updated.push(((*source).clone(), None, payment_hash.clone()));
                                                }
                                        }
                                }
+                       }
+                       if let Storage::Local { ref current_remote_commitment_txid, ref prev_remote_commitment_txid, .. } = self.key_storage {
+                               if let &Some(ref txid) = current_remote_commitment_txid {
+                                       check_htlc_fails!(txid, "current", 'current_loop);
+                               }
                                if let &Some(ref txid) = prev_remote_commitment_txid {
-                                       if let Some(&(_, ref prev_outpoint)) = self.remote_claimable_outpoints.get(&txid) {
-                                               for &(ref payment_hash, ref source, _) in prev_outpoint.iter() {
-                                                       log_trace!(self, "Failing HTLC with payment_hash {} from previous remote commitment tx due to broadcast of revoked remote commitment transaction", log_bytes!(payment_hash.0));
-                                                       htlc_updated.push(((*source).clone(), None, payment_hash.clone()));
-                                               }
-                                       }
+                                       check_htlc_fails!(txid, "previous", 'prev_loop);
                                }
                        }
-                       // No need to check local commitment txn, symmetric HTLCSource must be present as per-htlc data on remote commitment tx
-               } else if let Some(per_commitment_data) = per_commitment_option {
-                       // While this isn't useful yet, there is a potential race where if a counterparty
-                       // revokes a state at the same time as the commitment transaction for that state is
-                       // confirmed, and the watchtower receives the block before the user, the user could
-                       // upload a new ChannelMonitor with the revocation secret but the watchtower has
-                       // already processed the block, resulting in the remote_commitment_txn_on_chain entry
-                       // not being generated by the above conditional. Thus, to be safe, we go ahead and
-                       // insert it here.
-                       watch_outputs.append(&mut tx.output.clone());
-                       self.remote_commitment_txn_on_chain.insert(commitment_txid, (commitment_number, tx.output.iter().map(|output| { output.script_pubkey.clone() }).collect()));
 
                        if let Some(revocation_points) = self.their_cur_revocation_points {
                                let revocation_point_option =
@@ -1406,10 +1443,6 @@ impl ChannelMonitor {
                                                output: spend_tx.output[0].clone(),
                                        });
                                        txn_to_broadcast.push(spend_tx);
-
-                                       // TODO: We need to fail back HTLCs that were't included in the broadcast
-                                       // commitment transaction, either because they didn't meet dust or because a
-                                       // stale (but not yet revoked) commitment transaction was broadcast!
                                }
                        }
                }
@@ -1714,10 +1747,13 @@ impl ChannelMonitor {
                                for tx in txn.iter() {
                                        broadcaster.broadcast_transaction(tx);
                                }
-                               let mut updated = self.is_resolving_htlc_output(tx);
-                               if updated.len() > 0 {
-                                       htlc_updated.append(&mut updated);
-                               }
+                       }
+                       // While all commitment/HTLC-Success/HTLC-Timeout transactions have one input, HTLCs
+                       // can also be resolved in a few other ways which can have more than one output. Thus,
+                       // we call is_resolving_htlc_output here outside of the tx.input.len() == 1 check.
+                       let mut updated = self.is_resolving_htlc_output(tx);
+                       if updated.len() > 0 {
+                               htlc_updated.append(&mut updated);
                        }
                }
                if let Some(ref cur_local_tx) = self.current_local_signed_commitment_tx {
@@ -1800,19 +1836,48 @@ impl ChannelMonitor {
 
                'outer_loop: for input in &tx.input {
                        let mut payment_data = None;
+                       let revocation_sig_claim = (input.witness.len() == 3 && input.witness[2].len() == OFFERED_HTLC_SCRIPT_WEIGHT && input.witness[1].len() == 33)
+                               || (input.witness.len() == 3 && input.witness[2].len() == ACCEPTED_HTLC_SCRIPT_WEIGHT && input.witness[1].len() == 33);
+                       let accepted_preimage_claim = input.witness.len() == 5 && input.witness[4].len() == ACCEPTED_HTLC_SCRIPT_WEIGHT;
+                       let offered_preimage_claim = input.witness.len() == 3 && input.witness[2].len() == OFFERED_HTLC_SCRIPT_WEIGHT;
+
+                       macro_rules! log_claim {
+                               ($source: expr, $local_tx: expr, $outbound_htlc: expr, $payment_hash: expr, $source_avail: expr) => {
+                                       // We found the output in question, but aren't failing it backwards
+                                       // as we have no corresponding source. This implies either it is an
+                                       // inbound HTLC or an outbound HTLC on a revoked transaction.
+                                       if ($local_tx && revocation_sig_claim) ||
+                                                       ($outbound_htlc && !$source_avail && (accepted_preimage_claim || offered_preimage_claim)) {
+                                               log_error!(self, "Input spending {} ({}:{}) in {} resolves {} HTLC with payment hash {} with {}!",
+                                                       $source, input.previous_output.txid, input.previous_output.vout, tx.txid(),
+                                                       if $outbound_htlc { "outbound" } else { "inbound" }, log_bytes!($payment_hash.0),
+                                                       if revocation_sig_claim { "revocation sig" } else { "preimage claim after we'd passed the HTLC resolution back" });
+                                       } else {
+                                               log_info!(self, "Input spending {} ({}:{}) in {} resolves {} HTLC with payment hash {} with {}",
+                                                       $source, input.previous_output.txid, input.previous_output.vout, tx.txid(),
+                                                       if $outbound_htlc { "outbound" } else { "inbound" }, log_bytes!($payment_hash.0),
+                                                       if revocation_sig_claim { "revocation sig" } else if accepted_preimage_claim || offered_preimage_claim { "preimage" } else { "timeout" });
+                                       }
+                               }
+                       }
 
                        macro_rules! scan_commitment {
-                               ($htlc_outputs: expr, $htlc_sources: expr, $source: expr) => {
+                               ($htlc_outputs: expr, $htlc_sources: expr, $source: expr, $local_tx: expr) => {
                                        for &(ref payment_hash, ref source, ref vout) in $htlc_sources.iter() {
                                                if &Some(input.previous_output.vout) == vout {
-                                                       log_trace!(self, "Input spending {}:{} resolves HTLC with payment hash {} from {}", input.previous_output.txid, input.previous_output.vout, log_bytes!(payment_hash.0), $source);
+                                                       log_claim!($source, $local_tx, true, payment_hash, true);
+                                                       // We have a resolution of an HTLC either from one of our latest
+                                                       // local commitment transactions or an unrevoked remote commitment
+                                                       // transaction. This implies we either learned a preimage, the HTLC
+                                                       // has timed out, or we screwed up. In any case, we should now
+                                                       // resolve the source HTLC with the original sender.
                                                        payment_data = Some((source.clone(), *payment_hash));
                                                }
                                        }
                                        if payment_data.is_none() {
                                                for htlc_output in $htlc_outputs {
                                                        if input.previous_output.vout == htlc_output.transaction_output_index {
-                                                               log_info!(self, "Input spending {}:{} in {} resolves inbound HTLC with timeout from {}", input.previous_output.txid, input.previous_output.vout, tx.txid(), $source);
+                                                               log_claim!($source, $local_tx, $local_tx == htlc_output.offered, htlc_output.payment_hash, false);
                                                                continue 'outer_loop;
                                                        }
                                                }
@@ -1824,32 +1889,29 @@ impl ChannelMonitor {
                                if input.previous_output.txid == current_local_signed_commitment_tx.txid {
                                        scan_commitment!(current_local_signed_commitment_tx.htlc_outputs.iter().map(|&(ref a, _, _)| a),
                                                current_local_signed_commitment_tx.htlc_sources,
-                                               "our latest local commitment tx");
+                                               "our latest local commitment tx", true);
                                }
                        }
                        if let Some(ref prev_local_signed_commitment_tx) = self.prev_local_signed_commitment_tx {
                                if input.previous_output.txid == prev_local_signed_commitment_tx.txid {
                                        scan_commitment!(prev_local_signed_commitment_tx.htlc_outputs.iter().map(|&(ref a, _, _)| a),
                                                prev_local_signed_commitment_tx.htlc_sources,
-                                               "our latest local commitment tx");
+                                               "our previous local commitment tx", true);
                                }
                        }
                        if let Some(&(ref htlc_outputs, ref htlc_sources)) = self.remote_claimable_outpoints.get(&input.previous_output.txid) {
-                               scan_commitment!(htlc_outputs, htlc_sources, "remote commitment tx");
+                               scan_commitment!(htlc_outputs, htlc_sources, "remote commitment tx", false);
                        }
 
-                       // If tx isn't solving htlc output from local/remote commitment tx and htlc isn't outbound we don't need
-                       // to broadcast solving backward
+                       // Check that scan_commitment, above, decided there is some source worth relaying an
+                       // HTLC resolution backwards to and figure out whether we learned a preimage from it.
                        if let Some((source, payment_hash)) = payment_data {
                                let mut payment_preimage = PaymentPreimage([0; 32]);
-                               if (input.witness.len() == 3 && input.witness[2].len() == OFFERED_HTLC_SCRIPT_WEIGHT && input.witness[1].len() == 33)
-                                       || (input.witness.len() == 3 && input.witness[2].len() == ACCEPTED_HTLC_SCRIPT_WEIGHT && input.witness[1].len() == 33) {
-                                       log_error!(self, "Remote used revocation sig to take a {} HTLC output at index {} from commitment_tx {}", if input.witness[2].len() == OFFERED_HTLC_SCRIPT_WEIGHT { "offered" } else { "accepted" }, input.previous_output.vout, input.previous_output.txid);
-                               } else if input.witness.len() == 5 && input.witness[4].len() == ACCEPTED_HTLC_SCRIPT_WEIGHT {
-                                       payment_preimage.0.copy_from_slice(&tx.input[0].witness[3]);
+                               if accepted_preimage_claim {
+                                       payment_preimage.0.copy_from_slice(&input.witness[3]);
                                        htlc_updated.push((source, Some(payment_preimage), payment_hash));
-                               } else if input.witness.len() == 3 && input.witness[2].len() == OFFERED_HTLC_SCRIPT_WEIGHT {
-                                       payment_preimage.0.copy_from_slice(&tx.input[0].witness[1]);
+                               } else if offered_preimage_claim {
+                                       payment_preimage.0.copy_from_slice(&input.witness[1]);
                                        htlc_updated.push((source, Some(payment_preimage), payment_hash));
                                } else {
                                        htlc_updated.push((source, None, payment_hash));