Merge pull request #954 from TheBlueMatt/2021-06-no-spurious-forward-fails
[rust-lightning] / lightning / src / ln / channel.rs
index 2672511115ef6fd9ae159e1572fa5e953d9a1308..1d3e264a3fcbf263eec75e3b85e8d0b65c81e024 100644 (file)
@@ -288,7 +288,7 @@ impl HTLCCandidate {
 }
 
 /// Information needed for constructing an invoice route hint for this channel.
-#[derive(Clone)]
+#[derive(Clone, Debug, PartialEq)]
 pub struct CounterpartyForwardingInfo {
        /// Base routing fee in millisatoshis.
        pub fee_base_msat: u32,
@@ -434,6 +434,15 @@ pub(super) struct Channel<Signer: Sign> {
        next_local_commitment_tx_fee_info_cached: Mutex<Option<CommitmentTxInfoCached>>,
        #[cfg(any(test, feature = "fuzztarget"))]
        next_remote_commitment_tx_fee_info_cached: Mutex<Option<CommitmentTxInfoCached>>,
+
+       /// lnd has a long-standing bug where, upon reconnection, if the channel is not yet confirmed
+       /// they will not send a channel_reestablish until the channel locks in. Then, they will send a
+       /// funding_locked *before* sending the channel_reestablish (which is clearly a violation of
+       /// the BOLT specs). We copy c-lightning's workaround here and simply store the funding_locked
+       /// message until we receive a channel_reestablish.
+       ///
+       /// See-also <https://github.com/lightningnetwork/lnd/issues/4006>
+       pub workaround_lnd_bug_4006: Option<msgs::FundingLocked>,
 }
 
 #[cfg(any(test, feature = "fuzztarget"))]
@@ -633,6 +642,8 @@ impl<Signer: Sign> Channel<Signer> {
                        next_local_commitment_tx_fee_info_cached: Mutex::new(None),
                        #[cfg(any(test, feature = "fuzztarget"))]
                        next_remote_commitment_tx_fee_info_cached: Mutex::new(None),
+
+                       workaround_lnd_bug_4006: None,
                })
        }
 
@@ -876,6 +887,8 @@ impl<Signer: Sign> Channel<Signer> {
                        next_local_commitment_tx_fee_info_cached: Mutex::new(None),
                        #[cfg(any(test, feature = "fuzztarget"))]
                        next_remote_commitment_tx_fee_info_cached: Mutex::new(None),
+
+                       workaround_lnd_bug_4006: None,
                };
 
                Ok(chan)
@@ -909,7 +922,10 @@ impl<Signer: Sign> Channel<Signer> {
                let mut local_htlc_total_msat = 0;
                let mut value_to_self_msat_offset = 0;
 
-               log_trace!(logger, "Building commitment transaction number {} (really {} xor {}) for {}, generated by {} with fee {}...", commitment_number, (INITIAL_COMMITMENT_NUMBER - commitment_number), get_commitment_transaction_number_obscure_factor(&self.get_holder_pubkeys().payment_point, &self.get_counterparty_pubkeys().payment_point, self.is_outbound()), if local { "us" } else { "remote" }, if generated_by_local { "us" } else { "remote" }, feerate_per_kw);
+               log_trace!(logger, "Building commitment transaction number {} (really {} xor {}) for channel {} for {}, generated by {} with fee {}...",
+                       commitment_number, (INITIAL_COMMITMENT_NUMBER - commitment_number),
+                       get_commitment_transaction_number_obscure_factor(&self.get_holder_pubkeys().payment_point, &self.get_counterparty_pubkeys().payment_point, self.is_outbound()),
+                       log_bytes!(self.channel_id), 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) => {
@@ -1291,7 +1307,7 @@ impl<Signer: Sign> Channel<Signer> {
                                        _ => {}
                                }
                        }
-                       log_trace!(logger, "Adding HTLC claim to holding_cell! Current state: {}", self.channel_state);
+                       log_trace!(logger, "Adding HTLC claim to holding_cell in channel {}! Current state: {}", log_bytes!(self.channel_id()), self.channel_state);
                        self.holding_cell_htlc_updates.push(HTLCUpdateAwaitingACK::ClaimHTLC {
                                payment_preimage: payment_preimage_arg, htlc_id: htlc_id_arg,
                        });
@@ -1305,7 +1321,7 @@ impl<Signer: Sign> Channel<Signer> {
                                debug_assert!(false, "Have an inbound HTLC we tried to claim before it was fully committed to");
                                return Ok((None, Some(monitor_update)));
                        }
-                       log_trace!(logger, "Upgrading HTLC {} to LocalRemoved with a Fulfill!", log_bytes!(htlc.payment_hash.0));
+                       log_trace!(logger, "Upgrading HTLC {} to LocalRemoved with a Fulfill in channel {}!", log_bytes!(htlc.payment_hash.0), log_bytes!(self.channel_id));
                        htlc.state = InboundHTLCState::LocalRemoved(InboundHTLCRemovalReason::Fulfill(payment_preimage_arg.clone()));
                }
 
@@ -1391,7 +1407,7 @@ impl<Signer: Sign> Channel<Signer> {
                                        _ => {}
                                }
                        }
-                       log_trace!(logger, "Placing failure for HTLC ID {} in holding cell", htlc_id_arg);
+                       log_trace!(logger, "Placing failure for HTLC ID {} in holding cell in channel {}.", htlc_id_arg, log_bytes!(self.channel_id()));
                        self.holding_cell_htlc_updates.push(HTLCUpdateAwaitingACK::FailHTLC {
                                htlc_id: htlc_id_arg,
                                err_packet,
@@ -1399,7 +1415,7 @@ impl<Signer: Sign> Channel<Signer> {
                        return Ok(None);
                }
 
-               log_trace!(logger, "Failing HTLC ID {} back with a update_fail_htlc message", htlc_id_arg);
+               log_trace!(logger, "Failing HTLC ID {} back with a update_fail_htlc message in channel {}.", htlc_id_arg, log_bytes!(self.channel_id()));
                {
                        let htlc = &mut self.pending_inbound_htlcs[pending_idx];
                        htlc.state = InboundHTLCState::LocalRemoved(InboundHTLCRemovalReason::FailRelay(err_packet.clone()));
@@ -1531,7 +1547,10 @@ impl<Signer: Sign> Channel<Signer> {
                        let initial_commitment_bitcoin_tx = trusted_tx.built_transaction();
                        let sighash = initial_commitment_bitcoin_tx.get_sighash_all(&funding_script, self.channel_value_satoshis);
                        // They sign the holder commitment transaction...
-                       log_trace!(logger, "Checking funding_created tx signature {} by key {} against tx {} (sighash {}) with redeemscript {}", log_bytes!(sig.serialize_compact()[..]), log_bytes!(self.counterparty_funding_pubkey().serialize()), encode::serialize_hex(&initial_commitment_bitcoin_tx.transaction), log_bytes!(sighash[..]), encode::serialize_hex(&funding_script));
+                       log_trace!(logger, "Checking funding_created tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} for channel {}.",
+                               log_bytes!(sig.serialize_compact()[..]), log_bytes!(self.counterparty_funding_pubkey().serialize()),
+                               encode::serialize_hex(&initial_commitment_bitcoin_tx.transaction), log_bytes!(sighash[..]),
+                               encode::serialize_hex(&funding_script), log_bytes!(self.channel_id()));
                        secp_check!(self.secp_ctx.verify(&sighash, &sig, self.counterparty_funding_pubkey()), "Invalid funding_created signature from peer".to_owned());
                }
 
@@ -1540,7 +1559,8 @@ impl<Signer: Sign> Channel<Signer> {
 
                let counterparty_trusted_tx = counterparty_initial_commitment_tx.trust();
                let counterparty_initial_bitcoin_tx = counterparty_trusted_tx.built_transaction();
-               log_trace!(logger, "Initial counterparty ID {} tx {}", counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction));
+               log_trace!(logger, "Initial counterparty tx for channel {} is: txid {} tx {}",
+                       log_bytes!(self.channel_id()), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction));
 
                let counterparty_signature = self.holder_signer.sign_counterparty_commitment(&counterparty_initial_commitment_tx, &self.secp_ctx)
                                .map_err(|_| ChannelError::Close("Failed to get signatures for new commitment_signed".to_owned()))?.0;
@@ -1616,6 +1636,8 @@ impl<Signer: Sign> Channel<Signer> {
                self.cur_counterparty_commitment_transaction_number -= 1;
                self.cur_holder_commitment_transaction_number -= 1;
 
+               log_info!(logger, "Generated funding_signed for peer for channel {}", log_bytes!(self.channel_id()));
+
                Ok((msgs::FundingSigned {
                        channel_id: self.channel_id,
                        signature
@@ -1644,7 +1666,8 @@ impl<Signer: Sign> Channel<Signer> {
                let counterparty_trusted_tx = counterparty_initial_commitment_tx.trust();
                let counterparty_initial_bitcoin_tx = counterparty_trusted_tx.built_transaction();
 
-               log_trace!(logger, "Initial counterparty ID {} tx {}", counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction));
+               log_trace!(logger, "Initial counterparty tx for channel {} is: txid {} tx {}",
+                       log_bytes!(self.channel_id()), counterparty_initial_bitcoin_tx.txid, encode::serialize_hex(&counterparty_initial_bitcoin_tx.transaction));
 
                let holder_signer = self.build_holder_transaction_keys(self.cur_holder_commitment_transaction_number)?;
                let initial_commitment_tx = self.build_commitment_transaction(self.cur_holder_commitment_transaction_number, &holder_signer, true, false, self.feerate_per_kw, logger).0;
@@ -1686,12 +1709,15 @@ impl<Signer: Sign> Channel<Signer> {
                self.cur_holder_commitment_transaction_number -= 1;
                self.cur_counterparty_commitment_transaction_number -= 1;
 
+               log_info!(logger, "Received funding_signed from peer for channel {}", log_bytes!(self.channel_id()));
+
                Ok((channel_monitor, self.funding_transaction.as_ref().cloned().unwrap()))
        }
 
-       pub fn funding_locked(&mut self, msg: &msgs::FundingLocked) -> Result<(), ChannelError> {
+       pub fn funding_locked<L: Deref>(&mut self, msg: &msgs::FundingLocked, logger: &L) -> Result<(), ChannelError> where L::Target: Logger {
                if self.channel_state & (ChannelState::PeerDisconnected as u32) == ChannelState::PeerDisconnected as u32 {
-                       return Err(ChannelError::Close("Peer sent funding_locked when we needed a channel_reestablish".to_owned()));
+                       self.workaround_lnd_bug_4006 = Some(msg.clone());
+                       return Err(ChannelError::Ignore("Peer sent funding_locked when we needed a channel_reestablish. The peer is likely lnd, see https://github.com/lightningnetwork/lnd/issues/4006".to_owned()));
                }
 
                let non_shutdown_state = self.channel_state & (!MULTI_STATE_FLAGS);
@@ -1719,6 +1745,9 @@ impl<Signer: Sign> Channel<Signer> {
 
                self.counterparty_prev_commitment_point = self.counterparty_cur_commitment_point;
                self.counterparty_cur_commitment_point = Some(msg.next_per_commitment_point);
+
+               log_info!(logger, "Received funding_locked from peer for channel {}", log_bytes!(self.channel_id()));
+
                Ok(())
        }
 
@@ -2028,7 +2057,7 @@ impl<Signer: Sign> Channel<Signer> {
                        if pending_remote_value_msat - msg.amount_msat - chan_reserve_msat < remote_fee_cost_incl_stuck_buffer_msat {
                                // Note that if the pending_forward_status is not updated here, then it's because we're already failing
                                // the HTLC, i.e. its status is already set to failing.
-                               log_info!(logger, "Attempting to fail HTLC due to fee spike buffer violation");
+                               log_info!(logger, "Attempting to fail HTLC due to fee spike buffer violation in channel {}. Rebalancing is required.", log_bytes!(self.channel_id()));
                                pending_forward_status = create_pending_htlc_status(self, pending_forward_status, 0x1000|7);
                        }
                } else {
@@ -2160,7 +2189,10 @@ impl<Signer: Sign> Channel<Signer> {
                                let bitcoin_tx = trusted_tx.built_transaction();
                                let sighash = bitcoin_tx.get_sighash_all(&funding_script, self.channel_value_satoshis);
 
-                               log_trace!(logger, "Checking commitment tx signature {} by key {} against tx {} (sighash {}) with redeemscript {}", log_bytes!(msg.signature.serialize_compact()[..]), log_bytes!(self.counterparty_funding_pubkey().serialize()), encode::serialize_hex(&bitcoin_tx.transaction), log_bytes!(sighash[..]), encode::serialize_hex(&funding_script));
+                               log_trace!(logger, "Checking commitment tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} in channel {}",
+                                       log_bytes!(msg.signature.serialize_compact()[..]),
+                                       log_bytes!(self.counterparty_funding_pubkey().serialize()), encode::serialize_hex(&bitcoin_tx.transaction),
+                                       log_bytes!(sighash[..]), encode::serialize_hex(&funding_script), log_bytes!(self.channel_id()));
                                if let Err(_) = self.secp_ctx.verify(&sighash, &msg.signature, &self.counterparty_funding_pubkey()) {
                                        return Err((None, ChannelError::Close("Invalid commitment tx signature from peer".to_owned())));
                                }
@@ -2207,7 +2239,9 @@ impl<Signer: Sign> Channel<Signer> {
                                let htlc_tx = self.build_htlc_transaction(&commitment_txid, &htlc, true, &keys, feerate_per_kw);
                                let htlc_redeemscript = chan_utils::get_htlc_redeemscript(&htlc, &keys);
                                let htlc_sighash = hash_to_message!(&bip143::SigHashCache::new(&htlc_tx).signature_hash(0, &htlc_redeemscript, htlc.amount_msat / 1000, SigHashType::All)[..]);
-                               log_trace!(logger, "Checking HTLC tx signature {} by key {} against tx {} (sighash {}) with redeemscript {}", log_bytes!(msg.htlc_signatures[idx].serialize_compact()[..]), log_bytes!(keys.countersignatory_htlc_key.serialize()), encode::serialize_hex(&htlc_tx), log_bytes!(htlc_sighash[..]), encode::serialize_hex(&htlc_redeemscript));
+                               log_trace!(logger, "Checking HTLC tx signature {} by key {} against tx {} (sighash {}) with redeemscript {} in channel {}.",
+                                       log_bytes!(msg.htlc_signatures[idx].serialize_compact()[..]), log_bytes!(keys.countersignatory_htlc_key.serialize()),
+                                       encode::serialize_hex(&htlc_tx), log_bytes!(htlc_sighash[..]), encode::serialize_hex(&htlc_redeemscript), log_bytes!(self.channel_id()));
                                if let Err(_) = self.secp_ctx.verify(&htlc_sighash, &msg.htlc_signatures[idx], &keys.countersignatory_htlc_key) {
                                        return Err((None, ChannelError::Close("Invalid HTLC tx signature from peer".to_owned())));
                                }
@@ -2257,6 +2291,8 @@ impl<Signer: Sign> Channel<Signer> {
                                Some(forward_info.clone())
                        } else { None };
                        if let Some(forward_info) = new_forward {
+                               log_trace!(logger, "Updating HTLC {} to AwaitingRemoteRevokeToAnnounce due to commitment_signed in channel {}.",
+                                       log_bytes!(htlc.payment_hash.0), log_bytes!(self.channel_id));
                                htlc.state = InboundHTLCState::AwaitingRemoteRevokeToAnnounce(forward_info);
                                need_commitment = true;
                        }
@@ -2265,6 +2301,8 @@ impl<Signer: Sign> Channel<Signer> {
                        if let Some(fail_reason) = if let &mut OutboundHTLCState::RemoteRemoved(ref mut fail_reason) = &mut htlc.state {
                                Some(fail_reason.take())
                        } else { None } {
+                               log_trace!(logger, "Updating HTLC {} to AwaitingRemoteRevokeToRemove due to commitment_signed in channel {}.",
+                                       log_bytes!(htlc.payment_hash.0), log_bytes!(self.channel_id));
                                htlc.state = OutboundHTLCState::AwaitingRemoteRevokeToRemove(fail_reason);
                                need_commitment = true;
                        }
@@ -2290,6 +2328,8 @@ impl<Signer: Sign> Channel<Signer> {
                                self.latest_monitor_update_id = monitor_update.update_id;
                                monitor_update.updates.append(&mut additional_update.updates);
                        }
+                       log_debug!(logger, "Received valid commitment_signed from peer in channel {}, updated HTLC state but awaiting a monitor update resolution to reply.",
+                               log_bytes!(self.channel_id));
                        // TODO: Call maybe_propose_first_closing_signed on restoration (or call it here and
                        // re-send the message on restoration)
                        return Err((Some(monitor_update), ChannelError::Ignore("Previous monitor update failure prevented generation of RAA".to_owned())));
@@ -2309,6 +2349,9 @@ impl<Signer: Sign> Channel<Signer> {
                        (None, self.maybe_propose_first_closing_signed(fee_estimator))
                } else { (None, None) };
 
+               log_debug!(logger, "Received valid commitment_signed from peer in channel {}, updating HTLC state and responding with{} a revoke_and_ack.",
+                       log_bytes!(self.channel_id()), if commitment_signed.is_some() { " our own commitment_signed and" } else { "" });
+
                Ok((msgs::RevokeAndACK {
                        channel_id: self.channel_id,
                        per_commitment_secret,
@@ -2331,7 +2374,8 @@ impl<Signer: Sign> Channel<Signer> {
        fn free_holding_cell_htlcs<L: Deref>(&mut self, logger: &L) -> Result<(Option<(msgs::CommitmentUpdate, ChannelMonitorUpdate)>, Vec<(HTLCSource, PaymentHash)>), ChannelError> where L::Target: Logger {
                assert_eq!(self.channel_state & ChannelState::MonitorUpdateFailed as u32, 0);
                if self.holding_cell_htlc_updates.len() != 0 || self.holding_cell_update_fee.is_some() {
-                       log_trace!(logger, "Freeing holding cell with {} HTLC updates{}", self.holding_cell_htlc_updates.len(), if self.holding_cell_update_fee.is_some() { " and a fee update" } else { "" });
+                       log_trace!(logger, "Freeing holding cell with {} HTLC updates{} in channel {}", self.holding_cell_htlc_updates.len(),
+                               if self.holding_cell_update_fee.is_some() { " and a fee update" } else { "" }, log_bytes!(self.channel_id()));
 
                        let mut monitor_update = ChannelMonitorUpdate {
                                update_id: self.latest_monitor_update_id + 1, // We don't increment this yet!
@@ -2357,7 +2401,8 @@ impl<Signer: Sign> Channel<Signer> {
                                                        Err(e) => {
                                                                match e {
                                                                        ChannelError::Ignore(ref msg) => {
-                                                                               log_info!(logger, "Failed to send HTLC with payment_hash {} due to {}", log_bytes!(payment_hash.0), msg);
+                                                                               log_info!(logger, "Failed to send HTLC with payment_hash {} due to {} in channel {}",
+                                                                                       log_bytes!(payment_hash.0), msg, log_bytes!(self.channel_id()));
                                                                                // If we fail to send here, then this HTLC should
                                                                                // be failed backwards. Failing to send here
                                                                                // indicates that this HTLC may keep being put back
@@ -2421,6 +2466,10 @@ impl<Signer: Sign> Channel<Signer> {
                        self.latest_monitor_update_id = monitor_update.update_id;
                        monitor_update.updates.append(&mut additional_update.updates);
 
+                       log_debug!(logger, "Freeing holding cell in channel {} resulted in {}{} HTLCs added, {} HTLCs fulfilled, and {} HTLCs failed.",
+                               log_bytes!(self.channel_id()), if update_fee.is_some() { "a fee update, " } else { "" },
+                               update_add_htlcs.len(), update_fulfill_htlcs.len(), update_fail_htlcs.len());
+
                        Ok((Some((msgs::CommitmentUpdate {
                                update_add_htlcs,
                                update_fulfill_htlcs,
@@ -2496,7 +2545,7 @@ impl<Signer: Sign> Channel<Signer> {
                self.counterparty_cur_commitment_point = Some(msg.next_per_commitment_point);
                self.cur_counterparty_commitment_transaction_number -= 1;
 
-               log_trace!(logger, "Updating HTLCs on receipt of RAA...");
+               log_trace!(logger, "Updating HTLCs on receipt of RAA in channel {}...", log_bytes!(self.channel_id()));
                let mut to_forward_infos = Vec::new();
                let mut revoked_htlcs = Vec::new();
                let mut update_fail_htlcs = Vec::new();
@@ -2533,10 +2582,8 @@ impl<Signer: Sign> Channel<Signer> {
                        });
                        for htlc in pending_inbound_htlcs.iter_mut() {
                                let swap = if let &InboundHTLCState::AwaitingRemoteRevokeToAnnounce(_) = &htlc.state {
-                                       log_trace!(logger, " ...promoting inbound AwaitingRemoteRevokeToAnnounce {} to Committed", log_bytes!(htlc.payment_hash.0));
                                        true
                                } else if let &InboundHTLCState::AwaitingAnnouncedRemoteRevoke(_) = &htlc.state {
-                                       log_trace!(logger, " ...promoting inbound AwaitingAnnouncedRemoteRevoke {} to Committed", log_bytes!(htlc.payment_hash.0));
                                        true
                                } else { false };
                                if swap {
@@ -2544,11 +2591,13 @@ impl<Signer: Sign> Channel<Signer> {
                                        mem::swap(&mut state, &mut htlc.state);
 
                                        if let InboundHTLCState::AwaitingRemoteRevokeToAnnounce(forward_info) = state {
+                                               log_trace!(logger, " ...promoting inbound AwaitingRemoteRevokeToAnnounce {} to AwaitingAnnouncedRemoteRevoke", log_bytes!(htlc.payment_hash.0));
                                                htlc.state = InboundHTLCState::AwaitingAnnouncedRemoteRevoke(forward_info);
                                                require_commitment = true;
                                        } else if let InboundHTLCState::AwaitingAnnouncedRemoteRevoke(forward_info) = state {
                                                match forward_info {
                                                        PendingHTLCStatus::Fail(fail_msg) => {
+                                                               log_trace!(logger, " ...promoting inbound AwaitingAnnouncedRemoteRevoke {} to LocalRemoved due to PendingHTLCStatus indicating failure", log_bytes!(htlc.payment_hash.0));
                                                                require_commitment = true;
                                                                match fail_msg {
                                                                        HTLCFailureMsg::Relay(msg) => {
@@ -2562,6 +2611,7 @@ impl<Signer: Sign> Channel<Signer> {
                                                                }
                                                        },
                                                        PendingHTLCStatus::Forward(forward_info) => {
+                                                               log_trace!(logger, " ...promoting inbound AwaitingAnnouncedRemoteRevoke {} to Committed", log_bytes!(htlc.payment_hash.0));
                                                                to_forward_infos.push((forward_info, htlc.htlc_id));
                                                                htlc.state = InboundHTLCState::Committed;
                                                        }
@@ -2619,6 +2669,7 @@ impl<Signer: Sign> Channel<Signer> {
                        }
                        self.monitor_pending_forwards.append(&mut to_forward_infos);
                        self.monitor_pending_failures.append(&mut revoked_htlcs);
+                       log_debug!(logger, "Received a valid revoke_and_ack for channel {} but awaiting a monitor update resolution to reply.", log_bytes!(self.channel_id()));
                        return Ok((None, Vec::new(), Vec::new(), None, monitor_update, Vec::new()))
                }
 
@@ -2649,6 +2700,8 @@ impl<Signer: Sign> Channel<Signer> {
                                        self.latest_monitor_update_id = monitor_update.update_id;
                                        monitor_update.updates.append(&mut additional_update.updates);
 
+                                       log_debug!(logger, "Received a valid revoke_and_ack for channel {}. Responding with a commitment update with {} HTLCs failed.",
+                                               log_bytes!(self.channel_id()), update_fail_htlcs.len() + update_fail_malformed_htlcs.len());
                                        Ok((Some(msgs::CommitmentUpdate {
                                                update_add_htlcs: Vec::new(),
                                                update_fulfill_htlcs: Vec::new(),
@@ -2658,6 +2711,7 @@ impl<Signer: Sign> Channel<Signer> {
                                                commitment_signed
                                        }), to_forward_infos, revoked_htlcs, None, monitor_update, htlcs_to_fail))
                                } else {
+                                       log_debug!(logger, "Received a valid revoke_and_ack for channel {} with no reply necessary.", log_bytes!(self.channel_id()));
                                        Ok((None, to_forward_infos, revoked_htlcs, self.maybe_propose_first_closing_signed(fee_estimator), monitor_update, htlcs_to_fail))
                                }
                        }
@@ -2756,7 +2810,7 @@ impl<Signer: Sign> Channel<Signer> {
                }
 
                self.channel_state |= ChannelState::PeerDisconnected as u32;
-               log_debug!(logger, "Peer disconnection resulted in {} remote-announced HTLC drops on channel {}", inbound_drop_count, log_bytes!(self.channel_id()));
+               log_trace!(logger, "Peer disconnection resulted in {} remote-announced HTLC drops on channel {}", inbound_drop_count, log_bytes!(self.channel_id()));
        }
 
        /// Indicates that a ChannelMonitor update failed to be stored by the client and further
@@ -2823,10 +2877,9 @@ impl<Signer: Sign> Channel<Signer> {
                self.monitor_pending_revoke_and_ack = false;
                self.monitor_pending_commitment_signed = false;
                let order = self.resend_order.clone();
-               log_trace!(logger, "Restored monitor updating resulting in {}{} commitment update and {} RAA, with {} first",
-                       if funding_broadcastable.is_some() { "a funding broadcastable, " } else { "" },
-                       if commitment_update.is_some() { "a" } else { "no" },
-                       if raa.is_some() { "an" } else { "no" },
+               log_debug!(logger, "Restored monitor updating in channel {} resulting in {}{} commitment update and {} RAA, with {} first",
+                       log_bytes!(self.channel_id()), if funding_broadcastable.is_some() { "a funding broadcastable, " } else { "" },
+                       if commitment_update.is_some() { "a" } else { "no" }, if raa.is_some() { "an" } else { "no" },
                        match order { RAACommitmentOrder::CommitmentFirst => "commitment", RAACommitmentOrder::RevokeAndACKFirst => "RAA"});
                (raa, commitment_update, order, forwards, failures, funding_broadcastable, funding_locked)
        }
@@ -2904,8 +2957,8 @@ impl<Signer: Sign> Channel<Signer> {
                        }
                }
 
-               log_trace!(logger, "Regenerated latest commitment update with {} update_adds, {} update_fulfills, {} update_fails, and {} update_fail_malformeds",
-                               update_add_htlcs.len(), update_fulfill_htlcs.len(), update_fail_htlcs.len(), update_fail_malformed_htlcs.len());
+               log_trace!(logger, "Regenerated latest commitment update in channel {} with {} update_adds, {} update_fulfills, {} update_fails, and {} update_fail_malformeds",
+                               log_bytes!(self.channel_id()), update_add_htlcs.len(), update_fulfill_htlcs.len(), update_fail_htlcs.len(), update_fail_malformed_htlcs.len());
                msgs::CommitmentUpdate {
                        update_add_htlcs, update_fulfill_htlcs, update_fail_htlcs, update_fail_malformed_htlcs,
                        update_fee: None,
@@ -3590,12 +3643,13 @@ impl<Signer: Sign> Channel<Signer> {
                                        // send it immediately instead of waiting for a best_block_updated call (which
                                        // may have already happened for this block).
                                        if let Some(funding_locked) = self.check_get_funding_locked(height) {
+                                               log_info!(logger, "Sending a funding_locked to our peer for channel {}", log_bytes!(self.channel_id));
                                                return Ok(Some(funding_locked));
                                        }
                                }
                                for inp in tx.input.iter() {
                                        if inp.previous_output == funding_txo.into_bitcoin_outpoint() {
-                                               log_trace!(logger, "Detected channel-closing tx {} spending {}:{}, closing channel {}", tx.txid(), inp.previous_output.txid, inp.previous_output.vout, log_bytes!(self.channel_id()));
+                                               log_info!(logger, "Detected channel-closing tx {} spending {}:{}, closing channel {}", tx.txid(), inp.previous_output.txid, inp.previous_output.vout, log_bytes!(self.channel_id()));
                                                return Err(msgs::ErrorMessage {
                                                        channel_id: self.channel_id(),
                                                        data: "Commitment or closing transaction was confirmed on chain.".to_owned()
@@ -3618,7 +3672,8 @@ impl<Signer: Sign> Channel<Signer> {
        ///
        /// May return some HTLCs (and their payment_hash) which have timed out and should be failed
        /// back.
-       pub fn best_block_updated(&mut self, height: u32, highest_header_time: u32) -> Result<(Option<msgs::FundingLocked>, Vec<(HTLCSource, PaymentHash)>), msgs::ErrorMessage> {
+       pub fn best_block_updated<L: Deref>(&mut self, height: u32, highest_header_time: u32, logger: &L)
+                       -> Result<(Option<msgs::FundingLocked>, Vec<(HTLCSource, PaymentHash)>), msgs::ErrorMessage> where L::Target: Logger {
                let mut timed_out_htlcs = Vec::new();
                let unforwarded_htlc_cltv_limit = height + HTLC_FAIL_BACK_BUFFER;
                self.holding_cell_htlc_updates.retain(|htlc_update| {
@@ -3636,6 +3691,7 @@ impl<Signer: Sign> Channel<Signer> {
                self.update_time_counter = cmp::max(self.update_time_counter, highest_header_time);
 
                if let Some(funding_locked) = self.check_get_funding_locked(height) {
+                       log_info!(logger, "Sending a funding_locked to our peer for channel {}", log_bytes!(self.channel_id));
                        return Ok((Some(funding_locked), timed_out_htlcs));
                }
 
@@ -3668,7 +3724,7 @@ impl<Signer: Sign> Channel<Signer> {
        /// Indicates the funding transaction is no longer confirmed in the main chain. This may
        /// force-close the channel, but may also indicate a harmless reorganization of a block or two
        /// before the channel has reached funding_locked and we can just wait for more blocks.
-       pub fn funding_transaction_unconfirmed(&mut self) -> Result<(), msgs::ErrorMessage> {
+       pub fn funding_transaction_unconfirmed<L: Deref>(&mut self, logger: &L) -> Result<(), msgs::ErrorMessage> where L::Target: Logger {
                if self.funding_tx_confirmation_height != 0 {
                        // We handle the funding disconnection by calling best_block_updated with a height one
                        // below where our funding was connected, implying a reorg back to conf_height - 1.
@@ -3677,7 +3733,7 @@ impl<Signer: Sign> Channel<Signer> {
                        // larger. If we don't know that time has moved forward, we can just set it to the last
                        // time we saw and it will be ignored.
                        let best_time = self.update_time_counter;
-                       match self.best_block_updated(reorg_height, best_time) {
+                       match self.best_block_updated(reorg_height, best_time, logger) {
                                Ok((funding_locked, timed_out_htlcs)) => {
                                        assert!(funding_locked.is_none(), "We can't generate a funding with 0 confirmations?");
                                        assert!(timed_out_htlcs.is_empty(), "We can't have accepted HTLCs with a timeout before our funding confirmation?");
@@ -3933,13 +3989,13 @@ impl<Signer: Sign> Channel<Signer> {
                let dummy_pubkey = PublicKey::from_slice(&pk).unwrap();
                let data_loss_protect = if self.cur_counterparty_commitment_transaction_number + 1 < INITIAL_COMMITMENT_NUMBER {
                        let remote_last_secret = self.commitment_secrets.get_secret(self.cur_counterparty_commitment_transaction_number + 2).unwrap();
-                       log_trace!(logger, "Enough info to generate a Data Loss Protect with per_commitment_secret {}", log_bytes!(remote_last_secret));
+                       log_trace!(logger, "Enough info to generate a Data Loss Protect with per_commitment_secret {} for channel {}", log_bytes!(remote_last_secret), log_bytes!(self.channel_id()));
                        OptionalField::Present(DataLossProtect {
                                your_last_per_commitment_secret: remote_last_secret,
                                my_current_per_commitment_point: dummy_pubkey
                        })
                } else {
-                       log_info!(logger, "Sending a data_loss_protect with no previous remote per_commitment_secret");
+                       log_info!(logger, "Sending a data_loss_protect with no previous remote per_commitment_secret for channel {}", log_bytes!(self.channel_id()));
                        OptionalField::Present(DataLossProtect {
                                your_last_per_commitment_secret: [0;32],
                                my_current_per_commitment_point: dummy_pubkey,
@@ -4214,18 +4270,17 @@ impl<Signer: Sign> Channel<Signer> {
                        signature = res.0;
                        htlc_signatures = res.1;
 
-                       log_trace!(logger, "Signed remote commitment tx {} (txid {}) with redeemscript {} -> {}",
+                       log_trace!(logger, "Signed remote commitment tx {} (txid {}) with redeemscript {} -> {} in channel {}",
                                encode::serialize_hex(&counterparty_commitment_tx.0.trust().built_transaction().transaction),
-                               &counterparty_commitment_txid,
-                               encode::serialize_hex(&self.get_funding_redeemscript()),
-                               log_bytes!(signature.serialize_compact()[..]));
+                               &counterparty_commitment_txid, encode::serialize_hex(&self.get_funding_redeemscript()),
+                               log_bytes!(signature.serialize_compact()[..]), log_bytes!(self.channel_id()));
 
                        for (ref htlc_sig, ref htlc) in htlc_signatures.iter().zip(htlcs) {
-                               log_trace!(logger, "Signed remote HTLC tx {} with redeemscript {} with pubkey {} -> {}",
+                               log_trace!(logger, "Signed remote HTLC tx {} with redeemscript {} with pubkey {} -> {} in channel {}",
                                        encode::serialize_hex(&chan_utils::build_htlc_transaction(&counterparty_commitment_txid, feerate_per_kw, self.get_holder_selected_contest_delay(), htlc, &counterparty_keys.broadcaster_delayed_payment_key, &counterparty_keys.revocation_key)),
                                        encode::serialize_hex(&chan_utils::get_htlc_redeemscript(&htlc, &counterparty_keys)),
                                        log_bytes!(counterparty_keys.broadcaster_htlc_key.serialize()),
-                                       log_bytes!(htlc_sig.serialize_compact()[..]));
+                                       log_bytes!(htlc_sig.serialize_compact()[..]), log_bytes!(self.channel_id()));
                        }
                }
 
@@ -4614,7 +4669,7 @@ impl<Signer: Sign> Writeable for Channel<Signer> {
 
                self.channel_update_status.write(writer)?;
 
-               write_tlv_fields!(writer, {}, {(0, self.announcement_sigs)});
+               write_tlv_fields!(writer, {(0, self.announcement_sigs, option)});
 
                Ok(())
        }
@@ -4787,7 +4842,7 @@ impl<'a, Signer: Sign, K: Deref> ReadableArgs<&'a K> for Channel<Signer>
                let channel_update_status = Readable::read(reader)?;
 
                let mut announcement_sigs = None;
-               read_tlv_fields!(reader, {}, {(0, announcement_sigs)});
+               read_tlv_fields!(reader, {(0, announcement_sigs, option)});
 
                let mut secp_ctx = Secp256k1::new();
                secp_ctx.seeded_randomize(&keys_source.get_secure_random_bytes());
@@ -4871,6 +4926,8 @@ impl<'a, Signer: Sign, K: Deref> ReadableArgs<&'a K> for Channel<Signer>
                        next_local_commitment_tx_fee_info_cached: Mutex::new(None),
                        #[cfg(any(test, feature = "fuzztarget"))]
                        next_remote_commitment_tx_fee_info_cached: Mutex::new(None),
+
+                       workaround_lnd_bug_4006: None,
                })
        }
 }