X-Git-Url: http://git.bitcoin.ninja/index.cgi?a=blobdiff_plain;f=lightning%2Fsrc%2Fln%2Foutbound_payment.rs;h=aa92043cf9124ba5c62778ebea0f4bd6dd9127e2;hb=7f4c473c88a0fd43de2b72bb368f244b63492dc6;hp=7e5df84a25311b2d9a148fe946714d6c37436378;hpb=8f024303e781be9c1379c8efdefdb669fadb6325;p=rust-lightning diff --git a/lightning/src/ln/outbound_payment.rs b/lightning/src/ln/outbound_payment.rs index 7e5df84a..aa92043c 100644 --- a/lightning/src/ln/outbound_payment.rs +++ b/lightning/src/ln/outbound_payment.rs @@ -16,8 +16,8 @@ use bitcoin::secp256k1::{self, Secp256k1, SecretKey}; use crate::sign::{EntropySource, NodeSigner, Recipient}; use crate::events::{self, PaymentFailureReason}; use crate::ln::{PaymentHash, PaymentPreimage, PaymentSecret}; -use crate::ln::channelmanager::{ChannelDetails, EventCompletionAction, HTLCSource, IDEMPOTENCY_TIMEOUT_TICKS, PaymentId}; -use crate::ln::onion_utils::HTLCFailReason; +use crate::ln::channelmanager::{ChannelDetails, EventCompletionAction, HTLCSource, PaymentId}; +use crate::ln::onion_utils::{DecodedOnionFailure, HTLCFailReason}; use crate::routing::router::{InFlightHtlcs, Path, PaymentParameters, Route, RouteParameters, Router}; use crate::util::errors::APIError; use crate::util::logger::Logger; @@ -32,12 +32,27 @@ use core::ops::Deref; use crate::prelude::*; use crate::sync::Mutex; +/// The number of ticks of [`ChannelManager::timer_tick_occurred`] until we time-out the idempotency +/// of payments by [`PaymentId`]. See [`OutboundPayments::remove_stale_payments`]. +/// +/// [`ChannelManager::timer_tick_occurred`]: crate::ln::channelmanager::ChannelManager::timer_tick_occurred +pub(crate) const IDEMPOTENCY_TIMEOUT_TICKS: u8 = 7; + +/// The number of ticks of [`ChannelManager::timer_tick_occurred`] until an invoice request without +/// a response is timed out. +/// +/// [`ChannelManager::timer_tick_occurred`]: crate::ln::channelmanager::ChannelManager::timer_tick_occurred +const INVOICE_REQUEST_TIMEOUT_TICKS: u8 = 3; + /// Stores the session_priv for each part of a payment that is still pending. For versions 0.0.102 /// and later, also stores information for retrying the payment. pub(crate) enum PendingOutboundPayment { Legacy { session_privs: HashSet<[u8; 32]>, }, + AwaitingInvoice { + timer_ticks_without_response: u8, + }, Retryable { retry_strategy: Option, attempts: PaymentAttempts, @@ -108,6 +123,12 @@ impl PendingOutboundPayment { params.previously_failed_channels.push(scid); } } + fn is_awaiting_invoice(&self) -> bool { + match self { + PendingOutboundPayment::AwaitingInvoice { .. } => true, + _ => false, + } + } pub(super) fn is_fulfilled(&self) -> bool { match self { PendingOutboundPayment::Fulfilled { .. } => true, @@ -130,6 +151,7 @@ impl PendingOutboundPayment { fn payment_hash(&self) -> Option { match self { PendingOutboundPayment::Legacy { .. } => None, + PendingOutboundPayment::AwaitingInvoice { .. } => None, PendingOutboundPayment::Retryable { payment_hash, .. } => Some(*payment_hash), PendingOutboundPayment::Fulfilled { payment_hash, .. } => *payment_hash, PendingOutboundPayment::Abandoned { payment_hash, .. } => Some(*payment_hash), @@ -142,8 +164,11 @@ impl PendingOutboundPayment { PendingOutboundPayment::Legacy { session_privs } | PendingOutboundPayment::Retryable { session_privs, .. } | PendingOutboundPayment::Fulfilled { session_privs, .. } | - PendingOutboundPayment::Abandoned { session_privs, .. } - => session_privs, + PendingOutboundPayment::Abandoned { session_privs, .. } => session_privs, + PendingOutboundPayment::AwaitingInvoice { .. } => { + debug_assert!(false); + return; + }, }); let payment_hash = self.payment_hash(); *self = PendingOutboundPayment::Fulfilled { session_privs, payment_hash, timer_ticks_without_htlcs: 0 }; @@ -169,7 +194,11 @@ impl PendingOutboundPayment { PendingOutboundPayment::Fulfilled { session_privs, .. } | PendingOutboundPayment::Abandoned { session_privs, .. } => { session_privs.remove(session_priv) - } + }, + PendingOutboundPayment::AwaitingInvoice { .. } => { + debug_assert!(false); + false + }, }; if remove_res { if let PendingOutboundPayment::Retryable { ref mut pending_amt_msat, ref mut pending_fee_msat, .. } = self { @@ -189,6 +218,10 @@ impl PendingOutboundPayment { PendingOutboundPayment::Retryable { session_privs, .. } => { session_privs.insert(session_priv) } + PendingOutboundPayment::AwaitingInvoice { .. } => { + debug_assert!(false); + false + }, PendingOutboundPayment::Fulfilled { .. } => false, PendingOutboundPayment::Abandoned { .. } => false, }; @@ -210,7 +243,8 @@ impl PendingOutboundPayment { PendingOutboundPayment::Fulfilled { session_privs, .. } | PendingOutboundPayment::Abandoned { session_privs, .. } => { session_privs.len() - } + }, + PendingOutboundPayment::AwaitingInvoice { .. } => 0, } } } @@ -679,7 +713,7 @@ impl OutboundPayments { let mut outbounds = self.pending_outbound_payments.lock().unwrap(); outbounds.retain(|pmt_id, pmt| { let mut retain = true; - if !pmt.is_auto_retryable_now() && pmt.remaining_parts() == 0 { + if !pmt.is_auto_retryable_now() && pmt.remaining_parts() == 0 && !pmt.is_awaiting_invoice() { pmt.mark_abandoned(PaymentFailureReason::RetriesExhausted); if let PendingOutboundPayment::Abandoned { payment_hash, reason, .. } = pmt { pending_events.lock().unwrap().push_back((events::Event::PaymentFailed { @@ -697,7 +731,8 @@ impl OutboundPayments { pub(super) fn needs_abandon(&self) -> bool { let outbounds = self.pending_outbound_payments.lock().unwrap(); outbounds.iter().any(|(_, pmt)| - !pmt.is_auto_retryable_now() && pmt.remaining_parts() == 0 && !pmt.is_fulfilled()) + !pmt.is_auto_retryable_now() && pmt.remaining_parts() == 0 && !pmt.is_fulfilled() && + !pmt.is_awaiting_invoice()) } /// Errors immediately on [`RetryableSendFailure`] error conditions. Otherwise, further errors may @@ -722,6 +757,8 @@ impl OutboundPayments { { #[cfg(feature = "std")] { if has_expired(&route_params) { + log_error!(logger, "Payment with id {} and hash {} had expired before we started paying", + payment_id, payment_hash); return Err(RetryableSendFailure::PaymentExpired) } } @@ -730,16 +767,25 @@ impl OutboundPayments { &node_signer.get_node_id(Recipient::Node).unwrap(), &route_params, Some(&first_hops.iter().collect::>()), inflight_htlcs(), payment_hash, payment_id, - ).map_err(|_| RetryableSendFailure::RouteNotFound)?; + ).map_err(|_| { + log_error!(logger, "Failed to find route for payment with id {} and hash {}", + payment_id, payment_hash); + RetryableSendFailure::RouteNotFound + })?; let onion_session_privs = self.add_new_pending_payment(payment_hash, recipient_onion.clone(), payment_id, keysend_preimage, &route, Some(retry_strategy), Some(route_params.payment_params.clone()), entropy_source, best_block_height) - .map_err(|_| RetryableSendFailure::DuplicatePayment)?; + .map_err(|_| { + log_error!(logger, "Payment with id {} is already pending. New payment had payment hash {}", + payment_id, payment_hash); + RetryableSendFailure::DuplicatePayment + })?; let res = self.pay_route_internal(&route, payment_hash, recipient_onion, keysend_preimage, payment_id, None, onion_session_privs, node_signer, best_block_height, &send_payment_along_path); - log_info!(logger, "Result sending payment with id {}: {:?}", log_bytes!(payment_id.0), res); + log_info!(logger, "Sending payment with id {} and hash {} returned {:?}", + payment_id, payment_hash, res); if let Err(e) = res { self.handle_pay_route_err(e, payment_id, payment_hash, route, route_params, router, first_hops, &inflight_htlcs, entropy_source, node_signer, best_block_height, logger, pending_events, &send_payment_along_path); } @@ -762,7 +808,7 @@ impl OutboundPayments { { #[cfg(feature = "std")] { if has_expired(&route_params) { - log_error!(logger, "Payment params expired on retry, abandoning payment {}", log_bytes!(payment_id.0)); + log_error!(logger, "Payment params expired on retry, abandoning payment {}", &payment_id); self.abandon_payment(payment_id, PaymentFailureReason::PaymentExpired, pending_events); return } @@ -775,7 +821,7 @@ impl OutboundPayments { ) { Ok(route) => route, Err(e) => { - log_error!(logger, "Failed to find a route on retry, abandoning payment {}: {:#?}", log_bytes!(payment_id.0), e); + log_error!(logger, "Failed to find a route on retry, abandoning payment {}: {:#?}", &payment_id, e); self.abandon_payment(payment_id, PaymentFailureReason::RouteNotFound, pending_events); return } @@ -834,6 +880,10 @@ impl OutboundPayments { log_error!(logger, "Unable to retry payments that were initially sent on LDK versions prior to 0.0.102"); return }, + PendingOutboundPayment::AwaitingInvoice { .. } => { + log_error!(logger, "Payment not yet sent"); + return + }, PendingOutboundPayment::Fulfilled { .. } => { log_error!(logger, "Payment already completed"); return @@ -844,7 +894,7 @@ impl OutboundPayments { }, }; if !payment.get().is_retryable_now() { - log_error!(logger, "Retries exhausted for payment id {}", log_bytes!(payment_id.0)); + log_error!(logger, "Retries exhausted for payment id {}", &payment_id); abandon_with_entry!(payment, PaymentFailureReason::RetriesExhausted); return } @@ -855,7 +905,7 @@ impl OutboundPayments { res }, hash_map::Entry::Vacant(_) => { - log_error!(logger, "Payment with ID {} not found", log_bytes!(payment_id.0)); + log_error!(logger, "Payment with ID {} not found", &payment_id); return } } @@ -863,7 +913,7 @@ impl OutboundPayments { let res = self.pay_route_internal(&route, payment_hash, recipient_onion, keysend_preimage, payment_id, Some(total_msat), onion_session_privs, node_signer, best_block_height, &send_payment_along_path); - log_info!(logger, "Result retrying payment id {}: {:?}", log_bytes!(payment_id.0), res); + log_info!(logger, "Result retrying payment id {}: {:?}", &payment_id, res); if let Err(e) = res { self.handle_pay_route_err(e, payment_id, payment_hash, route, route_params, router, first_hops, inflight_htlcs, entropy_source, node_signer, best_block_height, logger, pending_events, send_payment_along_path); } @@ -965,7 +1015,7 @@ impl OutboundPayments { })) } - let route = Route { paths: vec![path], payment_params: None }; + let route = Route { paths: vec![path], route_params: None }; let onion_session_privs = self.add_new_pending_payment(payment_hash, RecipientOnionFields::spontaneous_empty(), payment_id, None, &route, None, None, entropy_source, best_block_height)?; @@ -1040,6 +1090,21 @@ impl OutboundPayments { } } + #[allow(unused)] + pub(super) fn add_new_awaiting_invoice(&self, payment_id: PaymentId) -> Result<(), ()> { + let mut pending_outbounds = self.pending_outbound_payments.lock().unwrap(); + match pending_outbounds.entry(payment_id) { + hash_map::Entry::Occupied(_) => Err(()), + hash_map::Entry::Vacant(entry) => { + entry.insert(PendingOutboundPayment::AwaitingInvoice { + timer_ticks_without_response: 0, + }); + + Ok(()) + }, + } + } + fn pay_route_internal( &self, route: &Route, payment_hash: PaymentHash, recipient_onion: RecipientOnionFields, keysend_preimage: Option, payment_id: PaymentId, recv_value_msat: Option, @@ -1134,9 +1199,9 @@ impl OutboundPayments { results, payment_id, failed_paths_retry: if pending_amt_unsent != 0 { - if let Some(payment_params) = &route.payment_params { + if let Some(payment_params) = route.route_params.as_ref().map(|p| p.payment_params.clone()) { Some(RouteParameters { - payment_params: payment_params.clone(), + payment_params: payment_params, final_value_msat: pending_amt_unsent, }) } else { None } @@ -1188,6 +1253,7 @@ impl OutboundPayments { if let hash_map::Entry::Occupied(mut payment) = outbounds.entry(payment_id) { if !payment.get().is_fulfilled() { let payment_hash = PaymentHash(Sha256::hash(&payment_preimage.0).into_inner()); + log_info!(logger, "Payment with id {} and hash {} sent!", payment_id, payment_hash); let fee_paid_msat = payment.get().get_pending_fee_msat(); pending_events.push_back((events::Event::PaymentSent { payment_id: Some(payment_id), @@ -1215,7 +1281,7 @@ impl OutboundPayments { } } } else { - log_trace!(logger, "Received duplicative fulfill for HTLC with payment_preimage {}", log_bytes!(payment_preimage.0)); + log_trace!(logger, "Received duplicative fulfill for HTLC with payment_preimage {}", &payment_preimage); } } @@ -1244,19 +1310,19 @@ impl OutboundPayments { } } - pub(super) fn remove_stale_resolved_payments(&self, - pending_events: &Mutex)>>) + pub(super) fn remove_stale_payments( + &self, pending_events: &Mutex)>>) { - // If an outbound payment was completed, and no pending HTLCs remain, we should remove it - // from the map. However, if we did that immediately when the last payment HTLC is claimed, - // this could race the user making a duplicate send_payment call and our idempotency - // guarantees would be violated. Instead, we wait a few timer ticks to do the actual - // removal. This should be more than sufficient to ensure the idempotency of any - // `send_payment` calls that were made at the same time the `PaymentSent` event was being - // processed. let mut pending_outbound_payments = self.pending_outbound_payments.lock().unwrap(); - let pending_events = pending_events.lock().unwrap(); + let mut pending_events = pending_events.lock().unwrap(); pending_outbound_payments.retain(|payment_id, payment| { + // If an outbound payment was completed, and no pending HTLCs remain, we should remove it + // from the map. However, if we did that immediately when the last payment HTLC is claimed, + // this could race the user making a duplicate send_payment call and our idempotency + // guarantees would be violated. Instead, we wait a few timer ticks to do the actual + // removal. This should be more than sufficient to ensure the idempotency of any + // `send_payment` calls that were made at the same time the `PaymentSent` event was being + // processed. if let PendingOutboundPayment::Fulfilled { session_privs, timer_ticks_without_htlcs, .. } = payment { let mut no_remaining_entries = session_privs.is_empty(); if no_remaining_entries { @@ -1281,6 +1347,16 @@ impl OutboundPayments { *timer_ticks_without_htlcs = 0; true } + } else if let PendingOutboundPayment::AwaitingInvoice { timer_ticks_without_response, .. } = payment { + *timer_ticks_without_response += 1; + if *timer_ticks_without_response <= INVOICE_REQUEST_TIMEOUT_TICKS { + true + } else { + pending_events.push_back( + (events::Event::InvoiceRequestFailed { payment_id: *payment_id }, None) + ); + false + } } else { true } }); } @@ -1293,9 +1369,12 @@ impl OutboundPayments { pending_events: &Mutex)>>, logger: &L, ) -> bool where L::Target: Logger { #[cfg(test)] - let (network_update, short_channel_id, payment_retryable, onion_error_code, onion_error_data) = onion_error.decode_onion_failure(secp_ctx, logger, &source); + let DecodedOnionFailure { + network_update, short_channel_id, payment_retryable, onion_error_code, onion_error_data + } = onion_error.decode_onion_failure(secp_ctx, logger, &source); #[cfg(not(test))] - let (network_update, short_channel_id, payment_retryable, _, _) = onion_error.decode_onion_failure(secp_ctx, logger, &source); + let DecodedOnionFailure { network_update, short_channel_id, payment_retryable } = + onion_error.decode_onion_failure(secp_ctx, logger, &source); let payment_is_probe = payment_is_probe(payment_hash, &payment_id, probing_cookie_secret); let mut session_priv_bytes = [0; 32]; @@ -1320,11 +1399,11 @@ impl OutboundPayments { let mut pending_retry_ev = false; let attempts_remaining = if let hash_map::Entry::Occupied(mut payment) = outbounds.entry(*payment_id) { if !payment.get_mut().remove(&session_priv_bytes, Some(&path)) { - log_trace!(logger, "Received duplicative fail for HTLC with payment_hash {}", log_bytes!(payment_hash.0)); + log_trace!(logger, "Received duplicative fail for HTLC with payment_hash {}", &payment_hash); return false } if payment.get().is_fulfilled() { - log_trace!(logger, "Received failure of HTLC with payment_hash {} after payment completion", log_bytes!(payment_hash.0)); + log_trace!(logger, "Received failure of HTLC with payment_hash {} after payment completion", &payment_hash); return false } let mut is_retryable_now = payment.get().is_auto_retryable_now(); @@ -1358,11 +1437,11 @@ impl OutboundPayments { } is_retryable_now } else { - log_trace!(logger, "Received duplicative fail for HTLC with payment_hash {}", log_bytes!(payment_hash.0)); + log_trace!(logger, "Received duplicative fail for HTLC with payment_hash {}", &payment_hash); return false }; core::mem::drop(outbounds); - log_trace!(logger, "Failing outbound payment HTLC with payment_hash {}", log_bytes!(payment_hash.0)); + log_trace!(logger, "Failing outbound payment HTLC with payment_hash {}", &payment_hash); let path_failure = { if payment_is_probe { @@ -1423,6 +1502,11 @@ impl OutboundPayments { }, None)); payment.remove(); } + } else if let PendingOutboundPayment::AwaitingInvoice { .. } = payment.get() { + pending_events.lock().unwrap().push_back((events::Event::InvoiceRequestFailed { + payment_id, + }, None)); + payment.remove(); } } } @@ -1486,6 +1570,9 @@ impl_writeable_tlv_based_enum_upgradable!(PendingOutboundPayment, (1, reason, option), (2, payment_hash, required), }, + (5, AwaitingInvoice) => { + (0, timer_ticks_without_response, required), + }, ); #[cfg(test)] @@ -1501,7 +1588,7 @@ mod tests { use crate::ln::outbound_payment::{OutboundPayments, Retry, RetryableSendFailure}; use crate::routing::gossip::NetworkGraph; use crate::routing::router::{InFlightHtlcs, Path, PaymentParameters, Route, RouteHop, RouteParameters}; - use crate::sync::{Arc, Mutex}; + use crate::sync::{Arc, Mutex, RwLock}; use crate::util::errors::APIError; use crate::util::test_utils; @@ -1540,7 +1627,7 @@ mod tests { let outbound_payments = OutboundPayments::new(); let logger = test_utils::TestLogger::new(); let network_graph = Arc::new(NetworkGraph::new(Network::Testnet, &logger)); - let scorer = Mutex::new(test_utils::TestScorer::new()); + let scorer = RwLock::new(test_utils::TestScorer::new()); let router = test_utils::TestRouter::new(network_graph, &scorer); let secp_ctx = Secp256k1::new(); let keys_manager = test_utils::TestKeysInterface::new(&[0; 32], Network::Testnet); @@ -1550,14 +1637,11 @@ mod tests { PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[42; 32]).unwrap()), 0 ).with_expiry_time(past_expiry_time); - let expired_route_params = RouteParameters { - payment_params, - final_value_msat: 0, - }; + let expired_route_params = RouteParameters::from_payment_params_and_value(payment_params, 0); let pending_events = Mutex::new(VecDeque::new()); if on_retry { outbound_payments.add_new_pending_payment(PaymentHash([0; 32]), RecipientOnionFields::spontaneous_empty(), - PaymentId([0; 32]), None, &Route { paths: vec![], payment_params: None }, + PaymentId([0; 32]), None, &Route { paths: vec![], route_params: None }, Some(Retry::Attempts(1)), Some(expired_route_params.payment_params.clone()), &&keys_manager, 0).unwrap(); outbound_payments.retry_payment_internal( @@ -1587,24 +1671,21 @@ mod tests { let outbound_payments = OutboundPayments::new(); let logger = test_utils::TestLogger::new(); let network_graph = Arc::new(NetworkGraph::new(Network::Testnet, &logger)); - let scorer = Mutex::new(test_utils::TestScorer::new()); + let scorer = RwLock::new(test_utils::TestScorer::new()); let router = test_utils::TestRouter::new(network_graph, &scorer); let secp_ctx = Secp256k1::new(); let keys_manager = test_utils::TestKeysInterface::new(&[0; 32], Network::Testnet); let payment_params = PaymentParameters::from_node_id( PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[42; 32]).unwrap()), 0); - let route_params = RouteParameters { - payment_params, - final_value_msat: 0, - }; + let route_params = RouteParameters::from_payment_params_and_value(payment_params, 0); router.expect_find_route(route_params.clone(), Err(LightningError { err: String::new(), action: ErrorAction::IgnoreError })); let pending_events = Mutex::new(VecDeque::new()); if on_retry { outbound_payments.add_new_pending_payment(PaymentHash([0; 32]), RecipientOnionFields::spontaneous_empty(), - PaymentId([0; 32]), None, &Route { paths: vec![], payment_params: None }, + PaymentId([0; 32]), None, &Route { paths: vec![], route_params: None }, Some(Retry::Attempts(1)), Some(route_params.payment_params.clone()), &&keys_manager, 0).unwrap(); outbound_payments.retry_payment_internal( @@ -1629,7 +1710,7 @@ mod tests { let outbound_payments = OutboundPayments::new(); let logger = test_utils::TestLogger::new(); let network_graph = Arc::new(NetworkGraph::new(Network::Testnet, &logger)); - let scorer = Mutex::new(test_utils::TestScorer::new()); + let scorer = RwLock::new(test_utils::TestScorer::new()); let router = test_utils::TestRouter::new(network_graph, &scorer); let secp_ctx = Secp256k1::new(); let keys_manager = test_utils::TestKeysInterface::new(&[0; 32], Network::Testnet); @@ -1637,10 +1718,7 @@ mod tests { let sender_pk = PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[42; 32]).unwrap()); let receiver_pk = PublicKey::from_secret_key(&secp_ctx, &SecretKey::from_slice(&[43; 32]).unwrap()); let payment_params = PaymentParameters::from_node_id(sender_pk, 0); - let route_params = RouteParameters { - payment_params: payment_params.clone(), - final_value_msat: 0, - }; + let route_params = RouteParameters::from_payment_params_and_value(payment_params.clone(), 0); let failed_scid = 42; let route = Route { paths: vec![Path { hops: vec![RouteHop { @@ -1651,7 +1729,7 @@ mod tests { fee_msat: 0, cltv_expiry_delta: 0, }], blinded_tail: None }], - payment_params: Some(payment_params), + route_params: Some(route_params.clone()), }; router.expect_find_route(route_params.clone(), Ok(route.clone())); let mut route_params_w_failed_scid = route_params.clone();