Split LockableScore responsibilities between read & write operations
[rust-lightning] / lightning / src / ln / outbound_payment.rs
index 9c8d66458739d7e21f2982ea50e096a7013fb98f..f60bf565efa35ddadac28416f2a7da22233d4892 100644 (file)
@@ -17,7 +17,7 @@ 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::onion_utils::{DecodedOnionFailure, HTLCFailReason};
 use crate::routing::router::{InFlightHtlcs, Path, PaymentParameters, Route, RouteParameters, Router};
 use crate::util::errors::APIError;
 use crate::util::logger::Logger;
@@ -515,9 +515,9 @@ impl RecipientOnionFields {
                let tlvs = &mut self.custom_tlvs;
                let further_tlvs = &mut further_htlc_fields.custom_tlvs;
 
-               let even_tlvs: Vec<&(u64, Vec<u8>)> = tlvs.iter().filter(|(typ, _)| *typ % 2 == 0).collect();
-               let further_even_tlvs: Vec<&(u64, Vec<u8>)> = further_tlvs.iter().filter(|(typ, _)| *typ % 2 == 0).collect();
-               if even_tlvs != further_even_tlvs { return Err(()) }
+               let even_tlvs = tlvs.iter().filter(|(typ, _)| *typ % 2 == 0);
+               let further_even_tlvs = further_tlvs.iter().filter(|(typ, _)| *typ % 2 == 0);
+               if even_tlvs.ne(further_even_tlvs) { return Err(()) }
 
                tlvs.retain(|tlv| further_tlvs.iter().any(|further_tlv| tlv == further_tlv));
                further_tlvs.retain(|further_tlv| tlvs.iter().any(|tlv| tlv == further_tlv));
@@ -722,6 +722,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 +732,25 @@ impl OutboundPayments {
                        &node_signer.get_node_id(Recipient::Node).unwrap(), &route_params,
                        Some(&first_hops.iter().collect::<Vec<_>>()), 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 +773,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 +786,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
                        }
@@ -844,7 +855,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 +866,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 +874,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);
                }
@@ -1177,7 +1188,7 @@ impl OutboundPayments {
 
        pub(super) fn claim_htlc<L: Deref>(
                &self, payment_id: PaymentId, payment_preimage: PaymentPreimage, session_priv: SecretKey,
-               path: Path, from_onchain: bool,
+               path: Path, from_onchain: bool, ev_completion_action: EventCompletionAction,
                pending_events: &Mutex<VecDeque<(events::Event, Option<EventCompletionAction>)>>,
                logger: &L,
        ) where L::Target: Logger {
@@ -1188,13 +1199,14 @@ 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),
                                        payment_preimage,
                                        payment_hash,
                                        fee_paid_msat,
-                               }, None));
+                               }, Some(ev_completion_action.clone())));
                                payment.get_mut().mark_fulfilled();
                        }
 
@@ -1211,11 +1223,11 @@ impl OutboundPayments {
                                                payment_id,
                                                payment_hash,
                                                path,
-                                       }, None));
+                                       }, Some(ev_completion_action)));
                                }
                        }
                } 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);
                }
        }
 
@@ -1293,9 +1305,12 @@ impl OutboundPayments {
                pending_events: &Mutex<VecDeque<(events::Event, Option<EventCompletionAction>)>>, 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 +1335,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 +1373,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 {
@@ -1501,7 +1516,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 +1555,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);
@@ -1587,7 +1602,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);
@@ -1629,7 +1644,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);