Expose an event when a payment has failed and retries complete

When a payment fails, a payer needs to know when they can consider
a payment as fully-failed, and when only some of the HTLCs in the
payment have failed. This isn't possible with the current event
scheme, as discovered recently and as described in the previous
commit.

This adds a new event which describes when a payment is fully and
irrevocably failed, generating it only after the payment has
expired or been marked as expired with
`ChannelManager::mark_retries_exceeded` *and* all HTLCs for it
have failed. With this, a payer can more simply deduce when a
payment has failed and use that to remove payment state or
finalize a payment failure.

Author: TheBlueMatt

lightning/src/ln/channelmanager.rs

@@ -838,6 +838,10 @@ const CHECK_CLTV_EXPIRY_SANITY: u32 = MIN_CLTV_EXPIRY_DELTA as u32 - LATENCY_GRA
 #[allow(dead_code)]
 const CHECK_CLTV_EXPIRY_SANITY_2: u32 = MIN_CLTV_EXPIRY_DELTA as u32 - LATENCY_GRACE_PERIOD_BLOCKS - 2*CLTV_CLAIM_BUFFER;
 
+/// The number of blocks before we consider an outbound payment for expiry if it doesn't have any
+/// pending HTLCs in flight.
+pub(crate) const PAYMENT_EXPIRY_BLOCKS: u32 = 3;
+
 /// Information needed for constructing an invoice route hint for this channel.
 #[derive(Clone, Debug, PartialEq)]
 pub struct CounterpartyForwardingInfo {
@@ -2409,15 +2413,26 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 	/// Signals that no further retries for the given payment will occur.
 	///
 	/// After this method returns, any future calls to [`retry_payment`] for the given `payment_id`
-	/// will fail with [`PaymentSendFailure::ParameterError`].
+	/// will fail with [`PaymentSendFailure::ParameterError`]. If no such event has been generated,
+	/// an [`Event::PaymentFailed`] event will be generated as soon as there are no remaining
+	/// pending HTLCs for this payment.
 	///
 	/// [`retry_payment`]: Self::retry_payment
+	/// [`Event::PaymentFailed`]: events::Event::PaymentFailed
 	pub fn no_further_payment_retries(&self, payment_id: PaymentId) {
 		let _persistence_guard = PersistenceNotifierGuard::notify_on_drop(&self.total_consistency_lock, &self.persistence_notifier);
 
 		let mut outbounds = self.pending_outbound_payments.lock().unwrap();
 		if let hash_map::Entry::Occupied(mut payment) = outbounds.entry(payment_id) {
-			let _ = payment.get_mut().mark_retries_exceeded();
+			if let Ok(()) = payment.get_mut().mark_retries_exceeded() {
+				if payment.get().remaining_parts() == 0 {
+					self.pending_events.lock().unwrap().push(events::Event::PaymentFailed {
+						payment_id,
+						payment_hash: payment.get().payment_hash().expect("RetriesExceeded PendintOutboundPayments always have a payment hash set"),
+					});
+					payment.remove();
+				}
+			}
 		}
 	}
 
@@ -3248,22 +3263,28 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 									final_cltv_expiry_delta: path_last_hop.cltv_expiry_delta,
 								})
 							} else { None };
-							self.pending_events.lock().unwrap().push(
-								events::Event::PaymentPathFailed {
-									payment_id: Some(payment_id),
-									payment_hash,
-									rejected_by_dest: false,
-									network_update: None,
-									all_paths_failed: payment.get().remaining_parts() == 0,
-									path: path.clone(),
-									short_channel_id: None,
-									retry,
-									#[cfg(test)]
-									error_code: None,
-									#[cfg(test)]
-									error_data: None,
-								}
-							);
+							let mut pending_events = self.pending_events.lock().unwrap();
+							pending_events.push(events::Event::PaymentPathFailed {
+								payment_id: Some(payment_id),
+								payment_hash,
+								rejected_by_dest: false,
+								network_update: None,
+								all_paths_failed: payment.get().remaining_parts() == 0,
+								path: path.clone(),
+								short_channel_id: None,
+								retry,
+								#[cfg(test)]
+								error_code: None,
+								#[cfg(test)]
+								error_data: None,
+							});
+							if payment.get().retries_exceeded() && payment.get().remaining_parts() == 0 {
+								pending_events.push(events::Event::PaymentFailed {
+									payment_id,
+									payment_hash: payment.get().payment_hash().expect("RetriesExceeded PendintOutboundPayments always have a payment hash set"),
+								});
+								payment.remove();
+							}
 						}
 					} else {
 						log_trace!(self.logger, "Received duplicative fail for HTLC with payment_hash {}", log_bytes!(payment_hash.0));
@@ -3294,6 +3315,7 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 				session_priv_bytes.copy_from_slice(&session_priv[..]);
 				let mut outbounds = self.pending_outbound_payments.lock().unwrap();
 				let mut all_paths_failed = false;
+				let mut full_failure_ev = None;
 				if let hash_map::Entry::Occupied(mut payment) = outbounds.entry(payment_id) {
 					if !payment.get_mut().remove(&session_priv_bytes, Some(&path)) {
 						log_trace!(self.logger, "Received duplicative fail for HTLC with payment_hash {}", log_bytes!(payment_hash.0));
@@ -3305,6 +3327,13 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 					}
 					if payment.get().remaining_parts() == 0 {
 						all_paths_failed = true;
+						if payment.get().retries_exceeded() {
+							full_failure_ev = Some(events::Event::PaymentFailed {
+								payment_id,
+								payment_hash: payment.get().payment_hash().expect("RetriesExceeded PendintOutboundPayments always have a payment hash set"),
+							});
+							payment.remove();
+						}
 					}
 				} else {
 					log_trace!(self.logger, "Received duplicative fail for HTLC with payment_hash {}", log_bytes!(payment_hash.0));
@@ -3320,6 +3349,7 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 					})
 				} else { None };
 				log_trace!(self.logger, "Failing outbound payment HTLC with payment_hash {}", log_bytes!(payment_hash.0));
+
 				match &onion_error {
 					&HTLCFailReason::LightningError { ref err } => {
 #[cfg(test)]
@@ -3329,22 +3359,22 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 						// TODO: If we decided to blame ourselves (or one of our channels) in
 						// process_onion_failure we should close that channel as it implies our
 						// next-hop is needlessly blaming us!
-						self.pending_events.lock().unwrap().push(
-							events::Event::PaymentPathFailed {
-								payment_id: Some(payment_id),
-								payment_hash: payment_hash.clone(),
-								rejected_by_dest: !payment_retryable,
-								network_update,
-								all_paths_failed,
-								path: path.clone(),
-								short_channel_id,
-								retry,
+						let mut pending_events = self.pending_events.lock().unwrap();
+						pending_events.push(events::Event::PaymentPathFailed {
+							payment_id: Some(payment_id),
+							payment_hash: payment_hash.clone(),
+							rejected_by_dest: !payment_retryable,
+							network_update,
+							all_paths_failed,
+							path: path.clone(),
+							short_channel_id,
+							retry,
 #[cfg(test)]
-								error_code: onion_error_code,
+							error_code: onion_error_code,
 #[cfg(test)]
-								error_data: onion_error_data
-							}
-						);
+							error_data: onion_error_data
+						});
+						if let Some(ev) = full_failure_ev { pending_events.push(ev); }
 					},
 					&HTLCFailReason::Reason {
 #[cfg(test)]
@@ -3359,22 +3389,22 @@ impl<Signer: Sign, M: Deref, T: Deref, K: Deref, F: Deref, L: Deref> ChannelMana
 						// ChannelDetails.
 						// TODO: For non-temporary failures, we really should be closing the
 						// channel here as we apparently can't relay through them anyway.
-						self.pending_events.lock().unwrap().push(
-							events::Event::PaymentPathFailed {
-								payment_id: Some(payment_id),
-								payment_hash: payment_hash.clone(),
-								rejected_by_dest: path.len() == 1,
-								network_update: None,
-								all_paths_failed,
-								path: path.clone(),
-								short_channel_id: Some(path.first().unwrap().short_channel_id),
-								retry,
+						let mut pending_events = self.pending_events.lock().unwrap();
+						pending_events.push(events::Event::PaymentPathFailed {
+							payment_id: Some(payment_id),
+							payment_hash: payment_hash.clone(),
+							rejected_by_dest: path.len() == 1,
+							network_update: None,
+							all_paths_failed,
+							path: path.clone(),
+							short_channel_id: Some(path.first().unwrap().short_channel_id),
+							retry,
 #[cfg(test)]
-								error_code: Some(*failure_code),
+							error_code: Some(*failure_code),
 #[cfg(test)]
-								error_data: Some(data.clone()),
-							}
-						);
+							error_data: Some(data.clone()),
+						});
+						if let Some(ev) = full_failure_ev { pending_events.push(ev); }
 					}
 				}
 			},
@@ -4905,14 +4935,19 @@ where
 			inbound_payment.expiry_time > header.time as u64
 		});
 
+		let mut pending_events = self.pending_events.lock().unwrap();
 		let mut outbounds = self.pending_outbound_payments.lock().unwrap();
-		outbounds.retain(|_, payment| {
-			const PAYMENT_EXPIRY_BLOCKS: u32 = 3;
+		outbounds.retain(|payment_id, payment| {
 			if payment.remaining_parts() != 0 { return true }
-			if let PendingOutboundPayment::Retryable { starting_block_height, .. } = payment {
-				return *starting_block_height + PAYMENT_EXPIRY_BLOCKS > height
-			}
-			true
+			if let PendingOutboundPayment::Retryable { starting_block_height, payment_hash, .. } = payment {
+				if *starting_block_height + PAYMENT_EXPIRY_BLOCKS <= height {
+					log_info!(self.logger, "Timing out payment with id {} and hash {}", log_bytes!(payment_id.0), log_bytes!(payment_hash.0));
+					pending_events.push(events::Event::PaymentFailed {
+						payment_id: *payment_id, payment_hash: *payment_hash,
+					});
+					false
+				} else { true }
+			} else { true }
 		});
 	}
 

lightning/src/ln/functional_test_utils.rs

@@ -1212,8 +1212,9 @@ macro_rules! expect_payment_failed_with_update {
 	($node: expr, $expected_payment_hash: expr, $rejected_by_dest: expr, $scid: expr, $chan_closed: expr) => {
 		let events = $node.node.get_and_clear_pending_events();
 		assert_eq!(events.len(), 1);
+		let our_payment_id;
 		match events[0] {
-			Event::PaymentPathFailed { ref payment_hash, rejected_by_dest, ref network_update, ref error_code, ref error_data, ref path, ref retry, .. } => {
+			Event::PaymentPathFailed { ref payment_hash, rejected_by_dest, ref network_update, ref error_code, ref error_data, ref path, ref retry, ref payment_id, .. } => {
 				assert_eq!(*payment_hash, $expected_payment_hash, "unexpected payment_hash");
 				assert_eq!(rejected_by_dest, $rejected_by_dest, "unexpected rejected_by_dest value");
 				assert!(retry.is_some(), "expected retry.is_some()");
@@ -1233,19 +1234,34 @@ macro_rules! expect_payment_failed_with_update {
 					Some(_) => panic!("Unexpected update type"),
 					None => panic!("Expected update"),
 				}
+				our_payment_id = payment_id.unwrap();
 			},
 			_ => panic!("Unexpected event"),
 		}
+		$node.node.no_further_payment_retries(our_payment_id);
+		let events = $node.node.get_and_clear_pending_events();
+		assert_eq!(events.len(), 1);
+		match events[0] {
+			Event::PaymentFailed { ref payment_hash, ref payment_id } => {
+				assert_eq!(*payment_hash, $expected_payment_hash, "unexpected second payment_hash");
+				assert_eq!(*payment_id, our_payment_id);
+			}
+			_ => panic!("Unexpected second event"),
+		}
 	}
 }
 
 #[cfg(test)]
 macro_rules! expect_payment_failed {
 	($node: expr, $expected_payment_hash: expr, $rejected_by_dest: expr $(, $expected_error_code: expr, $expected_error_data: expr)*) => {
+		expect_payment_failed!($node, $expected_payment_hash, $rejected_by_dest, false $(, $expected_error_code, $expected_error_data)*);
+	};
+	($node: expr, $expected_payment_hash: expr, $rejected_by_dest: expr, $mpp_parts_remain: expr $(, $expected_error_code: expr, $expected_error_data: expr)*) => {
 		let events = $node.node.get_and_clear_pending_events();
 		assert_eq!(events.len(), 1);
+		let our_payment_id;
 		match events[0] {
-			Event::PaymentPathFailed { ref payment_hash, rejected_by_dest, network_update: _, ref error_code, ref error_data, ref path, ref retry, .. } => {
+			Event::PaymentPathFailed { ref payment_hash, rejected_by_dest, ref error_code, ref error_data, ref path, ref retry, ref payment_id, .. } => {
 				assert_eq!(*payment_hash, $expected_payment_hash, "unexpected payment_hash");
 				assert_eq!(rejected_by_dest, $rejected_by_dest, "unexpected rejected_by_dest value");
 				assert!(retry.is_some(), "expected retry.is_some()");
@@ -1257,9 +1273,22 @@ macro_rules! expect_payment_failed {
 					assert_eq!(error_code.unwrap(), $expected_error_code, "unexpected error code");
 					assert_eq!(&error_data.as_ref().unwrap()[..], $expected_error_data, "unexpected error data");
 				)*
+				our_payment_id = payment_id.unwrap();
 			},
 			_ => panic!("Unexpected event"),
 		}
+		if !$mpp_parts_remain {
+			$node.node.no_further_payment_retries(our_payment_id);
+			let events = $node.node.get_and_clear_pending_events();
+			assert_eq!(events.len(), 1);
+			match events[0] {
+				Event::PaymentFailed { ref payment_hash, ref payment_id } => {
+					assert_eq!(*payment_hash, $expected_payment_hash, "unexpected second payment_hash");
+					assert_eq!(*payment_id, our_payment_id);
+				}
+				_ => panic!("Unexpected second event"),
+			}
+		}
 	}
 }
 
@@ -1563,17 +1592,31 @@ pub fn fail_payment_along_route<'a, 'b, 'c>(origin_node: &Node<'a, 'b, 'c>, expe
 			commitment_signed_dance!(origin_node, prev_node, next_msgs.as_ref().unwrap().1, false);
 			let events = origin_node.node.get_and_clear_pending_events();
 			assert_eq!(events.len(), 1);
+			let our_payment_id;
 			match events[0] {
-				Event::PaymentPathFailed { payment_hash, rejected_by_dest, all_paths_failed, ref path, .. } => {
+				Event::PaymentPathFailed { payment_hash, rejected_by_dest, all_paths_failed, ref path, ref payment_id, .. } => {
 					assert_eq!(payment_hash, our_payment_hash);
 					assert!(rejected_by_dest);
 					assert_eq!(all_paths_failed, i == expected_paths.len() - 1);
 					for (idx, hop) in expected_route.iter().enumerate() {
 						assert_eq!(hop.node.get_our_node_id(), path[idx].pubkey);
 					}
+					our_payment_id = payment_id.unwrap();
 				},
 				_ => panic!("Unexpected event"),
 			}
+			if i == expected_paths.len() - 1 {
+				origin_node.node.no_further_payment_retries(our_payment_id);
+				let events = origin_node.node.get_and_clear_pending_events();
+				assert_eq!(events.len(), 1);
+				match events[0] {
+					Event::PaymentFailed { ref payment_hash, ref payment_id } => {
+						assert_eq!(*payment_hash, our_payment_hash, "unexpected second payment_hash");
+						assert_eq!(*payment_id, our_payment_id);
+					}
+					_ => panic!("Unexpected second event"),
+				}
+			}
 		}
 	}
 

lightning/src/ln/functional_tests.rs

@@ -19,7 +19,7 @@ use chain::transaction::OutPoint;
 use chain::keysinterface::BaseSign;
 use ln::{PaymentPreimage, PaymentSecret, PaymentHash};
 use ln::channel::{COMMITMENT_TX_BASE_WEIGHT, COMMITMENT_TX_WEIGHT_PER_HTLC, CONCURRENT_INBOUND_HTLC_FEE_BUFFER, FEE_SPIKE_BUFFER_FEE_INCREASE_MULTIPLE, MIN_AFFORDABLE_HTLC_COUNT};
-use ln::channelmanager::{ChannelManager, ChannelManagerReadArgs, PaymentId, RAACommitmentOrder, PaymentSendFailure, BREAKDOWN_TIMEOUT, MIN_CLTV_EXPIRY_DELTA};
+use ln::channelmanager::{ChannelManager, ChannelManagerReadArgs, PaymentId, RAACommitmentOrder, PaymentSendFailure, BREAKDOWN_TIMEOUT, MIN_CLTV_EXPIRY_DELTA, PAYMENT_EXPIRY_BLOCKS };
 use ln::channel::{Channel, ChannelError};
 use ln::{chan_utils, onion_utils};
 use ln::chan_utils::{HTLC_SUCCESS_TX_WEIGHT, HTLC_TIMEOUT_TX_WEIGHT, HTLCOutputInCommitment};
@@ -3149,9 +3149,10 @@ fn do_test_commitment_revoked_fail_backward_exhaustive(deliver_bs_raa: bool, use
 	mine_transaction(&nodes[1], &revoked_local_txn[0]);
 	check_added_monitors!(nodes[1], 1);
 	connect_blocks(&nodes[1], ANTI_REORG_DELAY - 1);
+	assert!(ANTI_REORG_DELAY > PAYMENT_EXPIRY_BLOCKS); // We assume payments will also expire
 
 	let events = nodes[1].node.get_and_clear_pending_events();
-	assert_eq!(events.len(), if deliver_bs_raa { 2 } else { 3 });
+	assert_eq!(events.len(), if deliver_bs_raa { 2 } else { 4 });
 	match events[0] {
 		Event::ChannelClosed { reason: ClosureReason::CommitmentTxConfirmed, .. } => { },
 		_ => panic!("Unexepected event"),
@@ -3164,6 +3165,12 @@ fn do_test_commitment_revoked_fail_backward_exhaustive(deliver_bs_raa: bool, use
 	}
 	if !deliver_bs_raa {
 		match events[2] {
+			Event::PaymentFailed { ref payment_hash, .. } => {
+				assert_eq!(*payment_hash, fourth_payment_hash);
+			},
+			_ => panic!("Unexpected event"),
+		}
+		match events[3] {
 			Event::PendingHTLCsForwardable { .. } => { },
 			_ => panic!("Unexpected event"),
 		};
@@ -4181,7 +4188,14 @@ fn do_test_holding_cell_htlc_add_timeouts(forwarded_htlc: bool) {
 		}
 		expect_payment_failed_with_update!(nodes[0], second_payment_hash, false, chan_2.0.contents.short_channel_id, false);
 	} else {
-		expect_payment_failed!(nodes[1], second_payment_hash, true);
+		let events = nodes[1].node.get_and_clear_pending_events();
+		assert_eq!(events.len(), 2);
+		if let Event::PaymentPathFailed { ref payment_hash, .. } = events[0] {
+			assert_eq!(*payment_hash, second_payment_hash);
+		} else { panic!("Unexpected event"); }
+		if let Event::PaymentFailed { ref payment_hash, .. } = events[1] {
+			assert_eq!(*payment_hash, second_payment_hash);
+		} else { panic!("Unexpected event"); }
 	}
 }
 
@@ -5837,7 +5851,14 @@ fn do_htlc_claim_previous_remote_commitment_only(use_dust: bool, check_revoke_no
 		check_added_monitors!(nodes[0], 1);
 		check_closed_event!(nodes[0], 1, ClosureReason::CommitmentTxConfirmed);
 	} else {
-		expect_payment_failed!(nodes[0], our_payment_hash, true);
+		let events = nodes[0].node.get_and_clear_pending_events();
+		assert_eq!(events.len(), 2);
+		if let Event::PaymentPathFailed { ref payment_hash, .. } = events[0] {
+			assert_eq!(*payment_hash, our_payment_hash);
+		} else { panic!("Unexpected event"); }
+		if let Event::PaymentFailed { ref payment_hash, .. } = events[1] {
+			assert_eq!(*payment_hash, our_payment_hash);
+		} else { panic!("Unexpected event"); }
 	}
 }