X-Git-Url: http://git.bitcoin.ninja/index.cgi?a=blobdiff_plain;f=lightning%2Fsrc%2Fln%2Fchannel.rs;h=a39e453c1731da79ca55fde0f3c1397840efd05c;hb=fbb36a07696317362cfdb46aa4c6f67eb279afef;hp=51872337801559f5d5630ddada69d3952b3952e0;hpb=8e7b5905fd84999318bdcf9cbcb9cfecbf58f532;p=rust-lightning diff --git a/lightning/src/ln/channel.rs b/lightning/src/ln/channel.rs index 51872337..a39e453c 100644 --- a/lightning/src/ln/channel.rs +++ b/lightning/src/ln/channel.rs @@ -40,6 +40,7 @@ use util::errors::APIError; use util::config::{UserConfig,ChannelConfig}; use util::scid_utils::scid_from_parts; +use prelude::*; use core::{cmp,mem,fmt}; use core::ops::Deref; #[cfg(any(test, feature = "fuzztarget"))] @@ -113,8 +114,8 @@ enum InboundHTLCState { /// commitment transaction without it as otherwise we'll have to force-close the channel to /// claim it before the timeout (obviously doesn't apply to revoked HTLCs that we can't claim /// anyway). That said, ChannelMonitor does this for us (see - /// ChannelMonitor::would_broadcast_at_height) so we actually remove the HTLC from our own - /// local state before then, once we're sure that the next commitment_signed and + /// ChannelMonitor::should_broadcast_holder_commitment_txn) so we actually remove the HTLC from + /// our own local state before then, once we're sure that the next commitment_signed and /// ChannelMonitor::provide_latest_local_commitment_tx will not include this HTLC. LocalRemoved(InboundHTLCRemovalReason), } @@ -287,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, @@ -433,6 +434,15 @@ pub(super) struct Channel { next_local_commitment_tx_fee_info_cached: Mutex>, #[cfg(any(test, feature = "fuzztarget"))] next_remote_commitment_tx_fee_info_cached: Mutex>, + + /// 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 + pub workaround_lnd_bug_4006: Option, } #[cfg(any(test, feature = "fuzztarget"))] @@ -632,6 +642,8 @@ impl Channel { 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, }) } @@ -875,6 +887,8 @@ impl Channel { 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) @@ -908,7 +922,10 @@ impl Channel { 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) => { @@ -1290,7 +1307,7 @@ impl Channel { _ => {} } } - 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, }); @@ -1304,7 +1321,7 @@ impl Channel { 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())); } @@ -1390,7 +1407,7 @@ impl Channel { _ => {} } } - 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, @@ -1398,7 +1415,7 @@ impl Channel { 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())); @@ -1427,9 +1444,6 @@ impl Channel { if msg.channel_reserve_satoshis > self.channel_value_satoshis { return Err(ChannelError::Close(format!("Bogus channel_reserve_satoshis ({}). Must not be greater than ({})", msg.channel_reserve_satoshis, self.channel_value_satoshis))); } - if msg.dust_limit_satoshis > msg.channel_reserve_satoshis { - return Err(ChannelError::Close(format!("Bogus channel_reserve ({}) and dust_limit ({})", msg.channel_reserve_satoshis, msg.dust_limit_satoshis))); - } if msg.channel_reserve_satoshis < self.holder_dust_limit_satoshis { return Err(ChannelError::Close(format!("Peer never wants payout outputs? channel_reserve_satoshis was ({}). dust_limit is ({})", msg.channel_reserve_satoshis, self.holder_dust_limit_satoshis))); } @@ -1474,6 +1488,12 @@ impl Channel { if msg.minimum_depth > config.peer_channel_config_limits.max_minimum_depth { return Err(ChannelError::Close(format!("We consider the minimum depth to be unreasonably large. Expected minimum: ({}). Actual: ({})", config.peer_channel_config_limits.max_minimum_depth, msg.minimum_depth))); } + if msg.minimum_depth == 0 { + // Note that if this changes we should update the serialization minimum version to + // indicate to older clients that they don't understand some features of the current + // channel. + return Err(ChannelError::Close("Minimum confirmation depth must be at least 1".to_owned())); + } let counterparty_shutdown_scriptpubkey = if their_features.supports_upfront_shutdown_script() { match &msg.shutdown_scriptpubkey { @@ -1533,7 +1553,10 @@ impl Channel { 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()); } @@ -1542,7 +1565,8 @@ impl Channel { 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; @@ -1618,6 +1642,8 @@ impl Channel { 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 @@ -1646,7 +1672,8 @@ impl Channel { 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; @@ -1688,12 +1715,15 @@ impl Channel { 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(&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); @@ -1721,6 +1751,9 @@ impl Channel { 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(()) } @@ -2030,7 +2063,7 @@ impl Channel { 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 { @@ -2162,7 +2195,10 @@ impl Channel { 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()))); } @@ -2209,7 +2245,9 @@ impl Channel { 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()))); } @@ -2259,6 +2297,8 @@ impl Channel { 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; } @@ -2267,6 +2307,8 @@ impl Channel { 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; } @@ -2292,6 +2334,8 @@ impl Channel { 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()))); @@ -2311,6 +2355,9 @@ impl Channel { (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, @@ -2333,7 +2380,8 @@ impl Channel { fn free_holding_cell_htlcs(&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! @@ -2359,7 +2407,8 @@ impl Channel { 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 @@ -2423,6 +2472,10 @@ impl Channel { 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, @@ -2498,7 +2551,7 @@ impl Channel { 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(); @@ -2535,10 +2588,8 @@ impl Channel { }); 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 { @@ -2546,11 +2597,13 @@ impl Channel { 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) => { @@ -2564,6 +2617,7 @@ impl Channel { } }, 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; } @@ -2621,6 +2675,7 @@ impl Channel { } 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())) } @@ -2651,6 +2706,8 @@ impl Channel { 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(), @@ -2660,6 +2717,7 @@ impl Channel { 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)) } } @@ -2758,7 +2816,7 @@ impl Channel { } 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 @@ -2825,10 +2883,9 @@ impl Channel { 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) } @@ -2906,8 +2963,8 @@ impl Channel { } } - 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, @@ -3462,7 +3519,7 @@ impl Channel { /// is_usable() and considers things like the channel being temporarily disabled. /// Allowed in any state (including after shutdown) pub fn is_live(&self) -> bool { - self.is_usable() && (self.channel_state & (ChannelState::PeerDisconnected as u32 | ChannelState::MonitorUpdateFailed as u32) == 0) + self.is_usable() && (self.channel_state & (ChannelState::PeerDisconnected as u32) == 0) } /// Returns true if this channel has been marked as awaiting a monitor update to move forward. @@ -3592,12 +3649,13 @@ impl Channel { // 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() @@ -3620,7 +3678,8 @@ impl Channel { /// /// 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, Vec<(HTLCSource, PaymentHash)>), msgs::ErrorMessage> { + pub fn best_block_updated(&mut self, height: u32, highest_header_time: u32, logger: &L) + -> Result<(Option, 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| { @@ -3638,6 +3697,7 @@ impl Channel { 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)); } @@ -3670,7 +3730,7 @@ impl Channel { /// 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(&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. @@ -3679,7 +3739,7 @@ impl Channel { // 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?"); @@ -3935,13 +3995,13 @@ impl Channel { 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, @@ -3976,10 +4036,18 @@ impl Channel { /// Adds a pending outbound HTLC to this channel, note that you probably want /// send_htlc_and_commit instead cause you'll want both messages at once. - /// This returns an option instead of a pure UpdateAddHTLC as we may be in a state where we are - /// waiting on the remote peer to send us a revoke_and_ack during which time we cannot add new - /// HTLCs on the wire or we wouldn't be able to determine what they actually ACK'ed. - /// You MUST call send_commitment prior to any other calls on this Channel + /// + /// This returns an optional UpdateAddHTLC as we may be in a state where we cannot add HTLCs on + /// the wire: + /// * In cases where we're waiting on the remote peer to send us a revoke_and_ack, we + /// wouldn't be able to determine what they actually ACK'ed if we have two sets of updates + /// awaiting ACK. + /// * In cases where we're marked MonitorUpdateFailed, we cannot commit to a new state as we + /// may not yet have sent the previous commitment update messages and will need to regenerate + /// them. + /// + /// You MUST call send_commitment prior to calling any other methods on this Channel! + /// /// If an Err is returned, it's a ChannelError::Ignore! pub fn send_htlc(&mut self, amount_msat: u64, payment_hash: PaymentHash, cltv_expiry: u32, source: HTLCSource, onion_routing_packet: msgs::OnionPacket) -> Result, ChannelError> { if (self.channel_state & (ChannelState::ChannelFunded as u32 | BOTH_SIDES_SHUTDOWN_MASK)) != (ChannelState::ChannelFunded as u32) { @@ -3998,14 +4066,14 @@ impl Channel { return Err(ChannelError::Ignore(format!("Cannot send less than their minimum HTLC value ({})", self.counterparty_htlc_minimum_msat))); } - if (self.channel_state & (ChannelState::PeerDisconnected as u32 | ChannelState::MonitorUpdateFailed as u32)) != 0 { + if (self.channel_state & (ChannelState::PeerDisconnected as u32)) != 0 { // Note that this should never really happen, if we're !is_live() on receipt of an // incoming HTLC for relay will result in us rejecting the HTLC and we won't allow // the user to send directly into a !is_live() channel. However, if we // disconnected during the time the previous hop was doing the commitment dance we may // end up getting here after the forwarding delay. In any case, returning an // IgnoreError will get ChannelManager to do the right thing and fail backwards now. - return Err(ChannelError::Ignore("Cannot send an HTLC while disconnected/frozen for channel monitor update".to_owned())); + return Err(ChannelError::Ignore("Cannot send an HTLC while disconnected from channel counterparty".to_owned())); } let (outbound_htlc_count, htlc_outbound_value_msat) = self.get_outbound_pending_htlc_stats(); @@ -4050,7 +4118,7 @@ impl Channel { } // Now update local state: - if (self.channel_state & (ChannelState::AwaitingRemoteRevoke as u32)) == (ChannelState::AwaitingRemoteRevoke as u32) { + if (self.channel_state & (ChannelState::AwaitingRemoteRevoke as u32 | ChannelState::MonitorUpdateFailed as u32)) != 0 { self.holding_cell_htlc_updates.push(HTLCUpdateAwaitingACK::AddHTLC { amount_msat, payment_hash, @@ -4208,18 +4276,17 @@ impl Channel { 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())); } } @@ -4381,37 +4448,11 @@ fn is_unsupported_shutdown_script(their_features: &InitFeatures, script: &Script const SERIALIZATION_VERSION: u8 = 1; const MIN_SERIALIZATION_VERSION: u8 = 1; -impl Writeable for InboundHTLCRemovalReason { - fn write(&self, writer: &mut W) -> Result<(), ::std::io::Error> { - match self { - &InboundHTLCRemovalReason::FailRelay(ref error_packet) => { - 0u8.write(writer)?; - error_packet.write(writer)?; - }, - &InboundHTLCRemovalReason::FailMalformed((ref onion_hash, ref err_code)) => { - 1u8.write(writer)?; - onion_hash.write(writer)?; - err_code.write(writer)?; - }, - &InboundHTLCRemovalReason::Fulfill(ref payment_preimage) => { - 2u8.write(writer)?; - payment_preimage.write(writer)?; - }, - } - Ok(()) - } -} - -impl Readable for InboundHTLCRemovalReason { - fn read(reader: &mut R) -> Result { - Ok(match ::read(reader)? { - 0 => InboundHTLCRemovalReason::FailRelay(Readable::read(reader)?), - 1 => InboundHTLCRemovalReason::FailMalformed((Readable::read(reader)?, Readable::read(reader)?)), - 2 => InboundHTLCRemovalReason::Fulfill(Readable::read(reader)?), - _ => return Err(DecodeError::InvalidValue), - }) - } -} +impl_writeable_tlv_based_enum!(InboundHTLCRemovalReason,; + (0, FailRelay), + (1, FailMalformed), + (2, Fulfill), +); impl Writeable for ChannelUpdateStatus { fn write(&self, writer: &mut W) -> Result<(), ::std::io::Error> { @@ -4518,9 +4559,10 @@ impl Writeable for Channel { &OutboundHTLCState::Committed => { 1u8.write(writer)?; }, - &OutboundHTLCState::RemoteRemoved(ref fail_reason) => { - 2u8.write(writer)?; - fail_reason.write(writer)?; + &OutboundHTLCState::RemoteRemoved(_) => { + // Treat this as a Committed because we haven't received the CS - they'll + // resend the claim/fail on reconnect as we all (hopefully) the missing CS. + 1u8.write(writer)?; }, &OutboundHTLCState::AwaitingRemoteRevokeToRemove(ref fail_reason) => { 3u8.write(writer)?; @@ -4633,7 +4675,7 @@ impl Writeable for Channel { self.channel_update_status.write(writer)?; - write_tlv_fields!(writer, {}, {(0, self.announcement_sigs)}); + write_tlv_fields!(writer, {(0, self.announcement_sigs, option)}); Ok(()) } @@ -4806,7 +4848,7 @@ impl<'a, Signer: Sign, K: Deref> ReadableArgs<&'a K> for Channel 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()); @@ -4890,6 +4932,8 @@ impl<'a, Signer: Sign, K: Deref> ReadableArgs<&'a K> for Channel 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, }) } } @@ -4928,6 +4972,7 @@ mod tests { use bitcoin::hashes::Hash; use bitcoin::hash_types::{Txid, WPubkeyHash}; use std::sync::Arc; + use prelude::*; struct TestFeeEstimator { fee_est: u32