From c4a1452ed663129ea8f2f1376f18dfc100440dce Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 16 Jan 2025 15:53:03 +0800 Subject: [PATCH 01/35] add testcase to reproduce issue --- src/fiber/tests/payment.rs | 68 +++++++++++++++++++++++++++++++++++ src/fiber/tests/test_utils.rs | 19 ++++++++++ 2 files changed, 87 insertions(+) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 5cf5c22e..91073334 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1,6 +1,7 @@ use std::collections::HashSet; use super::test_utils::init_tracing; +use crate::fiber::channel::UpdateCommand; use crate::fiber::graph::PaymentSessionStatus; use crate::fiber::network::HopHint; use crate::fiber::network::SendPaymentCommand; @@ -1751,3 +1752,70 @@ async fn test_send_payment_middle_hop_balance_is_not_enough() { .expect("got error") .contains("Failed to build route")); } + +#[tokio::test] +async fn test_send_payment_middle_hop_update_fee() { + // https://github.com/nervosnetwork/fiber/issues/480 + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ], + 4, + true, + ) + .await; + let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + + let mut all_sent = HashSet::new(); + + for _i in 0..10 { + let res = node_0 + .send_payment_keysend(&node_3, 1000, false) + .await + .unwrap(); + eprintln!("res: {:?}", res); + all_sent.insert(res.payment_hash); + tokio::time::sleep(tokio::time::Duration::from_millis(50)).await; + } + + node_2 + .update_channel_with_command( + channels[1], + UpdateCommand { + enabled: None, + tlc_expiry_delta: None, + tlc_minimum_value: None, + tlc_fee_proportional_millionths: Some(10), + }, + ) + .await; + + tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + + loop { + for payment_hash in all_sent.clone().iter() { + let status = node_0.get_payment_status(*payment_hash).await; + eprintln!("got payment: {:?} status: {:?}", payment_hash, status); + if status == PaymentSessionStatus::Success { + eprintln!("payment_hash: {:?} success", payment_hash); + all_sent.remove(payment_hash); + } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; + } + let res = node_0.node_info().await; + eprintln!("node0 node_info: {:?}", res); + let res = node_1.node_info().await; + eprintln!("node1 node_info: {:?}", res); + let res = node_2.node_info().await; + eprintln!("node2 node_info: {:?}", res); + let res = node_3.node_info().await; + eprintln!("node3 node_info: {:?}", res); + if all_sent.is_empty() { + break; + } + } +} diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index 8645d8e0..2b32411c 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -3,6 +3,7 @@ use crate::fiber::channel::ChannelActorStateStore; use crate::fiber::channel::ChannelCommand; use crate::fiber::channel::ChannelCommandWithId; use crate::fiber::channel::ReloadParams; +use crate::fiber::channel::UpdateCommand; use crate::fiber::graph::NetworkGraphStateStore; use crate::fiber::graph::PaymentSession; use crate::fiber::graph::PaymentSessionStatus; @@ -762,6 +763,24 @@ impl NetworkNode { .await; } + pub async fn update_channel_with_command( + &mut self, + channel_id: Hash256, + command: UpdateCommand, + ) { + let message = |rpc_reply| -> NetworkActorMessage { + NetworkActorMessage::Command(NetworkActorCommand::ControlFiberChannel( + ChannelCommandWithId { + channel_id, + command: ChannelCommand::Update(command, rpc_reply), + }, + )) + }; + call!(self.network_actor, message) + .expect("node_a alive") + .expect("update channel success"); + } + pub fn get_payment_session(&self, payment_hash: Hash256) -> Option { self.store.get_payment_session(payment_hash) } From a8e99a87c4508db0c80923c645ff659d35c3d1b5 Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 16 Jan 2025 15:58:20 +0800 Subject: [PATCH 02/35] fix test --- src/fiber/tests/payment.rs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 91073334..ff45d955 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1789,7 +1789,7 @@ async fn test_send_payment_middle_hop_update_fee() { enabled: None, tlc_expiry_delta: None, tlc_minimum_value: None, - tlc_fee_proportional_millionths: Some(10), + tlc_fee_proportional_millionths: Some(100000), }, ) .await; From df3f3be10a512d9db3841a0a5fb7cb20d66acd94 Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 16 Jan 2025 21:44:34 +0800 Subject: [PATCH 03/35] add more log --- src/fiber/channel.rs | 84 ++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 84 insertions(+) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 8b52cfe9..40d97bef 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -1098,6 +1098,7 @@ where ProcessingChannelError::InternalError("insert preimage failed".to_string()) })?; } + eprintln!("handled remove_tlc peer message: {:?}", &remove_tlc.tlc_id); Ok(()) } @@ -1200,6 +1201,10 @@ where }; let (funding_tx_partial_signature, commitment_tx_partial_signature) = state.build_and_sign_commitment_tx()?; + eprintln!( + "sign funding_tx_partial_signature: {:?}", + &funding_tx_partial_signature + ); let commitment_signed = CommitmentSigned { channel_id: state.get_id(), funding_tx_partial_signature, @@ -1290,11 +1295,13 @@ where reason: command.reason, }), ); + eprintln!("begin to send remove tlc peer message"); self.network .send_message(NetworkActorMessage::new_command( NetworkActorCommand::SendFiberMessage(msg), )) .expect(ASSUME_NETWORK_ACTOR_ALIVE); + eprintln!("end send remove tlc peer message"); state.maybe_transition_to_shutdown(&self.network)?; self.handle_commitment_signed_command(state)?; @@ -4338,12 +4345,22 @@ impl ChannelActorState { [to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data], ) = self.build_settlement_transaction_outputs(false); + eprintln!("remote false"); + eprintln!( + "to_local_output: {:?} to_remote_output: {:?}", + to_local_output, to_remote_output + ); + eprintln!( + "to_local_output_data: {:?} to_remote_output_data: {:?}", + to_local_output_data, to_remote_output_data + ); let commitment_lock_script_args = [ &blake2b_256(x_only_aggregated_pubkey)[0..20], self.get_delay_epoch_as_lock_args_bytes().as_slice(), self.get_remote_commitment_number().to_be_bytes().as_slice(), ] .concat(); + let message = blake2b_256( [ to_local_output.as_slice(), @@ -4354,9 +4371,14 @@ impl ChannelActorState { ] .concat(), ); + eprintln!("sign commitment_tx_partial_signature: {:?}", message); sign_ctx.sign(message.as_slice())? }; + eprintln!( + "sign commitment_tx_partial_signature: {:?}", + commitment_tx_partial_signature + ); // Note that we must update channel state here to update commitment number, // so that next step will obtain the correct commitment point. @@ -4851,6 +4873,7 @@ impl ChannelActorState { } else { let mut result = vec![tlcs.len() as u8]; for (tlc, local, remote) in tlcs { + eprintln!("tlc: {:?} for_remote: {:?}", tlc, for_remote); result.extend_from_slice(&tlc.get_htlc_type().to_le_bytes()); result.extend_from_slice(&tlc.amount.to_le_bytes()); result.extend_from_slice(&tlc.get_hash()); @@ -4862,6 +4885,7 @@ impl ChannelActorState { .to_le_bytes(), ); } + eprintln!("htlc result: {:?}", result); result } } @@ -5162,6 +5186,11 @@ impl ChannelActorState { ] .concat(), ); + eprintln!("signing message: {:?}", message); + eprintln!( + "sign psct.commitment_tx_partial_signature: {:?}", + psct.commitment_tx_partial_signature + ); let aggregated_signature = sign_ctx .sign_and_aggregate(message.as_slice(), psct.commitment_tx_partial_signature)?; @@ -5805,8 +5834,14 @@ impl ChannelActorState { ] .concat(), ); + eprintln!("handle revoke message: {:?}", message); + eprintln!( + "handle revoke message revocation_partial_signature: {:?}", + revocation_partial_signature + ); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), revocation_partial_signature)?; + eprintln!("successfully sign_and_aggregate ..."); RevocationData { commitment_number, x_only_aggregated_pubkey, @@ -5821,6 +5856,15 @@ impl ChannelActorState { [to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data], ) = self.build_settlement_transaction_outputs(true); + eprintln!("remote true ..........."); + eprintln!( + "to_local_output: {:?} to_remote_output: {:?}", + to_local_output, to_remote_output + ); + eprintln!( + "to_local_output_data: {:?} to_remote_output_data: {:?}", + to_local_output_data, to_remote_output_data + ); let commitment_lock_script_args = [ &blake2b_256(x_only_aggregated_pubkey)[0..20], self.get_delay_epoch_as_lock_args_bytes().as_slice(), @@ -5837,8 +5881,15 @@ impl ChannelActorState { ] .concat(), ); + + eprintln!("handle revoke message settlement_data: {:?}", message); + eprintln!( + "handle revoke message revocation_partial_signature settlement_data: {:?}", + commitment_tx_partial_signature + ); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), commitment_tx_partial_signature)?; + eprintln!("successfully sign_and_aggregate settlement data..."); SettlementData { x_only_aggregated_pubkey, @@ -6172,6 +6223,8 @@ impl ChannelActorState { ); let settlement_data = { + eprintln!("check_init_commitment_tx_signature message: {:?}", message); + let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), signature)?; @@ -6562,6 +6615,7 @@ impl ChannelActorState { .capacity(capacity.pack()) .build(); let output_data = Bytes::default(); + eprintln!("output_data: {:?}", output_data); (output, output_data) } } @@ -6636,6 +6690,7 @@ impl ChannelActorState { let mut received_pending = 0; let mut received_fullfilled = 0; for info in pending_tlcs { + eprintln!("tlc info: {:?}", info); if info.is_offered() { offered_pending += info.amount; if (info.outbound_status() == OutboundTlcStatus::RemoveWaitAck @@ -6646,6 +6701,7 @@ impl ChannelActorState { .map(|r| matches!(r, RemoveTlcReason::RemoveTlcFulfill(_))) .unwrap_or_default() { + eprintln!("offered_fullfilled + : {:?}", info.amount); offered_fullfilled += info.amount; } } else { @@ -6657,10 +6713,18 @@ impl ChannelActorState { .map(|r| matches!(r, RemoveTlcReason::RemoveTlcFulfill(_))) .unwrap_or_default() { + eprintln!("received_fullfilled + : {:?}", info.amount); received_fullfilled += info.amount; } } } + eprintln!( + "self.to_local_amount: {:?}, self.to_remote_amount: {:?}", + self.to_local_amount, self.to_remote_amount + ); + eprintln!("received_fullfilled: {:?}, offered_pending: {:?}, offered_fullfilled: {:?}, received_pending: {:?}", + received_fullfilled, offered_pending, offered_fullfilled, received_pending + ); let to_local_value = self.to_local_amount + received_fullfilled - offered_pending; let to_remote_value = self.to_remote_amount + offered_fullfilled - received_pending; @@ -6704,6 +6768,9 @@ impl ChannelActorState { .pack(), ) .build(); + eprintln!("to_local_value: {:?}, local_reserved_ckb_amount: {:?}, commitment_tx_fee: {:?}, for_remote: {:?}", + to_local_value, self.local_reserved_ckb_amount, commitment_tx_fee, for_remote + ); let to_local_output_data = Bytes::default(); let to_remote_output = CellOutput::new_builder() @@ -6713,6 +6780,10 @@ impl ChannelActorState { .pack(), ) .build(); + eprintln!( + "to_remote_value: {:?}, remote_reserved_ckb_amount: {:?}, commitment_tx_fee: {:?}, for_remote: {:?}", + to_remote_value, self.remote_reserved_ckb_amount, commitment_tx_fee, for_remote + ); let to_remote_output_data = Bytes::default(); if for_remote { ( @@ -6736,10 +6807,16 @@ impl ChannelActorState { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(false); let deterministic_verify_ctx = self.get_deterministic_verify_context(); + eprintln!( + "verify funding_tx_partial_signature: {:?} deterministic_verify_ctx: {:?}", + funding_tx_partial_signature, deterministic_verify_ctx + ); + eprintln!("commitment_tx hash: {:?}", commitment_tx.hash().as_slice()); deterministic_verify_ctx.verify( funding_tx_partial_signature, commitment_tx.hash().as_slice(), )?; + eprintln!("verify successfully ....."); let to_local_output = settlement_tx .outputs() @@ -6792,6 +6869,11 @@ impl ChannelActorState { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); let deterministic_sign_ctx = self.get_deterministic_sign_context(); + eprintln!("sign deterministic_sign_ctx: {:?}", deterministic_sign_ctx); + eprintln!( + "sign commitment_tx hash: {:?}", + commitment_tx.hash().as_slice() + ); let funding_tx_partial_signature = deterministic_sign_ctx.sign(commitment_tx.hash().as_slice())?; @@ -6975,6 +7057,7 @@ impl Musig2CommonContext { } } +#[derive(Debug)] struct Musig2VerifyContext { common_ctx: Musig2CommonContext, pubkey: Pubkey, @@ -6994,6 +7077,7 @@ impl Musig2VerifyContext { } } +#[derive(Debug)] struct Musig2SignContext { common_ctx: Musig2CommonContext, seckey: Privkey, From 88d3d3ba2cefbb9714f0727d79cf4db6cc29b253 Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 17 Jan 2025 10:35:52 +0800 Subject: [PATCH 04/35] add testcase to reproduce issue 480 --- src/fiber/tests/payment.rs | 92 ++++++++++++++++++++++++++++++++++- src/fiber/tests/test_utils.rs | 68 +++++++++++++++++++++++++- 2 files changed, 157 insertions(+), 3 deletions(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 5cf5c22e..15f20359 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1,6 +1,5 @@ -use std::collections::HashSet; - use super::test_utils::init_tracing; +use crate::fiber::channel::UpdateCommand; use crate::fiber::graph::PaymentSessionStatus; use crate::fiber::network::HopHint; use crate::fiber::network::SendPaymentCommand; @@ -9,6 +8,7 @@ use crate::fiber::types::Hash256; use crate::fiber::NetworkActorCommand; use crate::fiber::NetworkActorMessage; use ractor::call; +use std::collections::HashSet; // This test will send two payments from node_0 to node_1, the first payment will run // with dry_run, the second payment will run without dry_run. Both payments will be successful. @@ -1751,3 +1751,91 @@ async fn test_send_payment_middle_hop_balance_is_not_enough() { .expect("got error") .contains("Failed to build route")); } + +#[tokio::test] +async fn test_send_payment_middle_hop_update_fee() { + // https://github.com/nervosnetwork/fiber/issues/480 + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ], + 4, + true, + ) + .await; + let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + + let mut all_sent = HashSet::new(); + + for _i in 0..10 { + let res = node_0 + .send_payment_keysend(&node_3, 1000, false) + .await + .unwrap(); + eprintln!("res: {:?}", res); + all_sent.insert(res.payment_hash); + tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; + } + + node_2 + .update_channel_with_command( + channels[1], + UpdateCommand { + enabled: None, + tlc_expiry_delta: None, + tlc_minimum_value: None, + tlc_fee_proportional_millionths: Some(100000), + }, + ) + .await; + + tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + node_1 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + node_2 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + loop { + let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!(false, "unexpected event: {:?}", triggered_unexpected_events); + } + + let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!(false, "unexpected event: {:?}", triggered_unexpected_events); + } + + for payment_hash in all_sent.clone().iter() { + let status = node_0.get_payment_status(*payment_hash).await; + //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); + if status == PaymentSessionStatus::Failed || status == PaymentSessionStatus::Success { + //eprintln!("payment_hash: {:?} success", payment_hash); + all_sent.remove(payment_hash); + } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; + } + // let res = node_0.node_info().await; + // eprintln!("node0 node_info: {:?}", res); + // let res = node_1.node_info().await; + // eprintln!("node1 node_info: {:?}", res); + // let res = node_2.node_info().await; + // eprintln!("node2 node_info: {:?}", res); + // let res = node_3.node_info().await; + // eprintln!("node3 node_info: {:?}", res); + if all_sent.is_empty() { + break; + } + } +} diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index 8645d8e0..3f8712e6 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -3,6 +3,7 @@ use crate::fiber::channel::ChannelActorStateStore; use crate::fiber::channel::ChannelCommand; use crate::fiber::channel::ChannelCommandWithId; use crate::fiber::channel::ReloadParams; +use crate::fiber::channel::UpdateCommand; use crate::fiber::graph::NetworkGraphStateStore; use crate::fiber::graph::PaymentSession; use crate::fiber::graph::PaymentSessionStatus; @@ -21,6 +22,7 @@ use ractor::{call, Actor, ActorRef}; use rand::rngs::OsRng; use secp256k1::{Message, Secp256k1}; use std::collections::HashMap; +use std::collections::HashSet; use std::{ env, ffi::OsStr, @@ -186,6 +188,8 @@ pub struct NetworkNode { pub peer_id: PeerId, pub event_emitter: mpsc::Receiver, pub pubkey: Pubkey, + pub unexpected_events: Arc>>, + pub triggered_unexpected_events: Arc>>, } pub struct NetworkNodeConfig { @@ -762,6 +766,24 @@ impl NetworkNode { .await; } + pub async fn update_channel_with_command( + &mut self, + channel_id: Hash256, + command: UpdateCommand, + ) { + let message = |rpc_reply| -> NetworkActorMessage { + NetworkActorMessage::Command(NetworkActorCommand::ControlFiberChannel( + ChannelCommandWithId { + channel_id, + command: ChannelCommand::Update(command, rpc_reply), + }, + )) + }; + call!(self.network_actor, message) + .expect("node_a alive") + .expect("update channel success"); + } + pub fn get_payment_session(&self, payment_hash: Hash256) -> Option { self.store.get_payment_session(payment_hash) } @@ -840,6 +862,31 @@ impl NetworkNode { } }; + let unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); + let triggered_unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); + let (self_event_sender, self_event_receiver) = mpsc::channel(10000); + let unexpected_events_clone = unexpected_events.clone(); + let triggered_unexpected_events_clone = triggered_unexpected_events.clone(); + // spwan a new thread to collect all the events from event_receiver + tokio::spawn(async move { + while let Some(event) = event_receiver.recv().await { + self_event_sender + .send(event.clone()) + .await + .expect("send event"); + let unexpected_events = unexpected_events_clone.read().await; + let event_content = format!("{:?}", event); + for unexpected_event in unexpected_events.iter() { + if event_content.contains(unexpected_event) { + triggered_unexpected_events_clone + .write() + .await + .insert(unexpected_event.clone()); + } + } + } + }); + println!( "Network node started for peer_id {:?} in directory {:?}", &peer_id, @@ -858,8 +905,10 @@ impl NetworkNode { chain_actor, private_key: secret_key.into(), peer_id, - event_emitter: event_receiver, + event_emitter: self_event_receiver, pubkey: public_key.into(), + unexpected_events, + triggered_unexpected_events, } } @@ -872,6 +921,23 @@ impl NetworkNode { } } + pub async fn set_unexpected_events(&self, events: Vec) { + let mut unexpected_events = self.unexpected_events.write().await; + unexpected_events.clear(); + for event in events { + unexpected_events.insert(event); + } + } + + pub async fn get_triggered_unexpected_events(&self) -> Vec { + self.triggered_unexpected_events + .read() + .await + .iter() + .cloned() + .collect() + } + pub async fn get_network_channels(&self) -> Vec { self.network_graph .read() From 566aff024585b329920dc98dc1c5dd1448c5fb2b Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 17 Jan 2025 18:21:57 +0800 Subject: [PATCH 05/35] simply assertion --- src/fiber/tests/payment.rs | 8 ++------ 1 file changed, 2 insertions(+), 6 deletions(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 15f20359..68d0aa82 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1808,14 +1808,10 @@ async fn test_send_payment_middle_hop_update_fee() { .await; loop { let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!(false, "unexpected event: {:?}", triggered_unexpected_events); - } + assert!(triggered_unexpected_events.is_empty()); let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!(false, "unexpected event: {:?}", triggered_unexpected_events); - } + assert!(triggered_unexpected_events.is_empty()); for payment_hash in all_sent.clone().iter() { let status = node_0.get_payment_status(*payment_hash).await; From 5353710ca08958c45e9dc6f24ea47a7707ed528d Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 17 Jan 2025 18:48:52 +0800 Subject: [PATCH 06/35] add testcase middle hop set higher fee rate to make payment fail --- src/fiber/tests/payment.rs | 41 +++++++++++++++++++++++++++++++++++++- 1 file changed, 40 insertions(+), 1 deletion(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 68d0aa82..bc8adcb4 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1753,7 +1753,46 @@ async fn test_send_payment_middle_hop_balance_is_not_enough() { } #[tokio::test] -async fn test_send_payment_middle_hop_update_fee() { +async fn test_send_payment_middle_hop_update_fee_send_payment_failed() { + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ], + 4, + true, + ) + .await; + let [mut node_0, _node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + + // node_2 update fee rate to a higher one, so the payment will fail + let res = node_0 + .send_payment_keysend(&node_3, 1000, false) + .await + .unwrap(); + eprintln!("res: {:?}", res); + let payment_hash = res.payment_hash; + + node_2 + .update_channel_with_command( + channels[1], + UpdateCommand { + enabled: None, + tlc_expiry_delta: None, + tlc_minimum_value: None, + tlc_fee_proportional_millionths: Some(100000), + }, + ) + .await; + + node_0.wait_until_failed(payment_hash).await; +} + +#[tokio::test] +async fn test_send_payment_middle_hop_update_fee_multiple_payments() { // https://github.com/nervosnetwork/fiber/issues/480 init_tracing(); let _span = tracing::info_span!("node", node = "test").entered(); From d434e02ec8e2eb64c6694157d91c101c9afdc95d Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 19 Jan 2025 00:14:45 +0800 Subject: [PATCH 07/35] keep fail tcl in tlc state --- src/fiber/channel.rs | 74 ++++++++++++++++++++++++----------- src/fiber/tests/payment.rs | 28 +++++++------ src/fiber/tests/test_utils.rs | 39 ++++++++++-------- 3 files changed, 90 insertions(+), 51 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 40d97bef..a4c3502c 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -1098,7 +1098,6 @@ where ProcessingChannelError::InternalError("insert preimage failed".to_string()) })?; } - eprintln!("handled remove_tlc peer message: {:?}", &remove_tlc.tlc_id); Ok(()) } @@ -1295,13 +1294,13 @@ where reason: command.reason, }), ); - eprintln!("begin to send remove tlc peer message"); + //eprintln!("begin to send remove tlc peer message"); self.network .send_message(NetworkActorMessage::new_command( NetworkActorCommand::SendFiberMessage(msg), )) .expect(ASSUME_NETWORK_ACTOR_ALIVE); - eprintln!("end send remove tlc peer message"); + //eprintln!("end send remove tlc peer message"); state.maybe_transition_to_shutdown(&self.network)?; self.handle_commitment_signed_command(state)?; @@ -2521,6 +2520,7 @@ impl Debug for TlcInfo { .field("status", &self.status) .field("amount", &self.amount) .field("removed_reason", &self.removed_reason) + .field("payment_hash", &self.payment_hash) .finish() } } @@ -2557,6 +2557,14 @@ impl TlcInfo { self.status.as_inbound_status() } + pub fn is_remove_comfirmed(&self) -> bool { + match self.status { + TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, + _ => false, + } + } + fn get_hash(&self) -> ShortHash { self.payment_hash.as_ref()[..20] .try_into() @@ -4337,6 +4345,7 @@ impl ChannelActorState { .concat(), ); let our_signature = sign_ctx.sign(message.as_slice()).expect("valid signature"); + eprintln!("sign revocation_partial_signature: {:?}", our_signature); our_signature }; @@ -4545,15 +4554,20 @@ impl ChannelActorState { ))); } let payment_hash = tlc.payment_hash; - if let Some(tlc) = self + let tlc_info = self .tlc_state .all_tlcs() .find(|tlc| tlc.payment_hash == payment_hash) - { - return Err(ProcessingChannelError::RepeatedProcessing(format!( - "Trying to insert tlc with duplicate payment hash {:?} with tlc {:?}", - payment_hash, tlc - ))); + .cloned(); + if let Some(tlc) = tlc_info { + if tlc.is_remove_comfirmed() { + self.tlc_state.apply_remove_tlc(tlc.tlc_id); + } else { + return Err(ProcessingChannelError::RepeatedProcessing(format!( + "Trying to insert tlc with duplicate payment hash {:?} with tlc {:?}", + payment_hash, tlc + ))); + } } if tlc.is_offered() { let sent_tlc_value = self.get_offered_tlc_balance(); @@ -4585,6 +4599,10 @@ impl ChannelActorState { tlc_id: TLCId, ) -> Result<(TlcInfo, RemoveTlcReason), ProcessingChannelError> { let current = self.tlc_state.get_mut(&tlc_id).expect("TLC exists").clone(); + eprintln!( + "node: {:?} remove_tlc_with_reason: {:?}", + self.local_pubkey, current + ); let reason = current .removed_reason .clone() @@ -4618,8 +4636,8 @@ impl ChannelActorState { debug!("Updated local balance to {} and remote balance to {} by removing tlc {:?} with reason {:?}", to_local_amount, to_remote_amount, tlc_id, reason); + self.tlc_state.apply_remove_tlc(tlc_id); } - self.tlc_state.apply_remove_tlc(tlc_id); debug!( "Removed tlc payment_hash {:?} with reason {:?}", current.payment_hash, reason @@ -4873,7 +4891,6 @@ impl ChannelActorState { } else { let mut result = vec![tlcs.len() as u8]; for (tlc, local, remote) in tlcs { - eprintln!("tlc: {:?} for_remote: {:?}", tlc, for_remote); result.extend_from_slice(&tlc.get_htlc_type().to_le_bytes()); result.extend_from_slice(&tlc.amount.to_le_bytes()); result.extend_from_slice(&tlc.get_hash()); @@ -4885,7 +4902,6 @@ impl ChannelActorState { .to_le_bytes(), ); } - eprintln!("htlc result: {:?}", result); result } } @@ -5835,13 +5851,9 @@ impl ChannelActorState { .concat(), ); eprintln!("handle revoke message: {:?}", message); - eprintln!( - "handle revoke message revocation_partial_signature: {:?}", - revocation_partial_signature - ); + let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), revocation_partial_signature)?; - eprintln!("successfully sign_and_aggregate ..."); RevocationData { commitment_number, x_only_aggregated_pubkey, @@ -5904,6 +5916,10 @@ impl ChannelActorState { self.increment_local_commitment_number(); self.append_remote_commitment_point(next_per_commitment_point); + eprintln!( + "node: {:?} handle_revoke_and_ack_peer_message", + self.local_pubkey + ); let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); network .send_message(NetworkActorMessage::new_notification( @@ -6615,7 +6631,7 @@ impl ChannelActorState { .capacity(capacity.pack()) .build(); let output_data = Bytes::default(); - eprintln!("output_data: {:?}", output_data); + eprintln!("output: {:?}", output); (output, output_data) } } @@ -6681,6 +6697,7 @@ impl ChannelActorState { InboundTlcStatus::AnnounceWaitAck => true, InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => true, + //InboundTlcStatus::RemoveAckPending => true, InboundTlcStatus::RemoveAckConfirmed => true, } })); @@ -6689,6 +6706,10 @@ impl ChannelActorState { let mut offered_fullfilled = 0; let mut received_pending = 0; let mut received_fullfilled = 0; + eprintln!( + "node: {:?} build_settlement_transaction_outputs: {:?}", + self.local_pubkey, for_remote + ); for info in pending_tlcs { eprintln!("tlc info: {:?}", info); if info.is_offered() { @@ -6808,8 +6829,8 @@ impl ChannelActorState { let deterministic_verify_ctx = self.get_deterministic_verify_context(); eprintln!( - "verify funding_tx_partial_signature: {:?} deterministic_verify_ctx: {:?}", - funding_tx_partial_signature, deterministic_verify_ctx + "verify funding_tx_partial_signature: {:?}", + funding_tx_partial_signature ); eprintln!("commitment_tx hash: {:?}", commitment_tx.hash().as_slice()); deterministic_verify_ctx.verify( @@ -6852,7 +6873,12 @@ impl ChannelActorState { .concat(), ); let verify_ctx = self.get_verify_context(); + eprintln!( + "node: {:?} begin to verify commitment_tx_partial_signature: {:?} with message: {:?}", + self.local_pubkey, commitment_tx_partial_signature, message + ); verify_ctx.verify(commitment_tx_partial_signature, message.as_slice())?; + eprintln!("verify commitment_tx_partial_signature successfully ....."); Ok(PartiallySignedCommitmentTransaction { version: self.get_current_commitment_number(false), @@ -6869,7 +6895,7 @@ impl ChannelActorState { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); let deterministic_sign_ctx = self.get_deterministic_sign_context(); - eprintln!("sign deterministic_sign_ctx: {:?}", deterministic_sign_ctx); + //eprintln!("sign deterministic_sign_ctx: {:?}", deterministic_sign_ctx); eprintln!( "sign commitment_tx hash: {:?}", commitment_tx.hash().as_slice() @@ -6912,8 +6938,12 @@ impl ChannelActorState { ); let sign_ctx = self.get_sign_context(true); - let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; + let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; + eprintln!( + "node: {:?} sign commitment_tx_partial_signature: {:?}, with message: {:?}", + self.local_pubkey, commitment_tx_partial_signature, message + ); Ok(( funding_tx_partial_signature, commitment_tx_partial_signature, diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index bc8adcb4..5edb132c 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1810,7 +1810,7 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { let mut all_sent = HashSet::new(); - for _i in 0..10 { + for _i in 0..5 { let res = node_0 .send_payment_keysend(&node_3, 1000, false) .await @@ -1847,28 +1847,32 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { .await; loop { let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; - assert!(triggered_unexpected_events.is_empty()); + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_1 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; - assert!(triggered_unexpected_events.is_empty()); + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_2 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } for payment_hash in all_sent.clone().iter() { let status = node_0.get_payment_status(*payment_hash).await; //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); if status == PaymentSessionStatus::Failed || status == PaymentSessionStatus::Success { - //eprintln!("payment_hash: {:?} success", payment_hash); + eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); all_sent.remove(payment_hash); } tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; } - // let res = node_0.node_info().await; - // eprintln!("node0 node_info: {:?}", res); - // let res = node_1.node_info().await; - // eprintln!("node1 node_info: {:?}", res); - // let res = node_2.node_info().await; - // eprintln!("node2 node_info: {:?}", res); - // let res = node_3.node_info().await; - // eprintln!("node3 node_info: {:?}", res); if all_sent.is_empty() { break; } diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index 3f8712e6..e0bf3fd2 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -189,7 +189,7 @@ pub struct NetworkNode { pub event_emitter: mpsc::Receiver, pub pubkey: Pubkey, pub unexpected_events: Arc>>, - pub triggered_unexpected_events: Arc>>, + pub triggered_unexpected_events: Arc>>, } pub struct NetworkNodeConfig { @@ -863,9 +863,9 @@ impl NetworkNode { }; let unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); - let triggered_unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); + let triggered_unexpected_events = Arc::new(TokioRwLock::new(Vec::::new())); let (self_event_sender, self_event_receiver) = mpsc::channel(10000); - let unexpected_events_clone = unexpected_events.clone(); + let _unexpected_events_clone = unexpected_events.clone(); let triggered_unexpected_events_clone = triggered_unexpected_events.clone(); // spwan a new thread to collect all the events from event_receiver tokio::spawn(async move { @@ -874,16 +874,26 @@ impl NetworkNode { .send(event.clone()) .await .expect("send event"); - let unexpected_events = unexpected_events_clone.read().await; + //let unexpected_events = unexpected_events_clone.read().await; let event_content = format!("{:?}", event); - for unexpected_event in unexpected_events.iter() { - if event_content.contains(unexpected_event) { - triggered_unexpected_events_clone - .write() - .await - .insert(unexpected_event.clone()); - } + if !event_content.contains("WaitingTlcAck") + && !event_content.contains("AddTlcFailed") + && event_content.contains("DebugEvent") + { + triggered_unexpected_events_clone + .write() + .await + .push(event_content.clone()); } + + // for unexpected_event in unexpected_events.iter() { + // if !event_content.contains("WaitingTlcAck") { + // triggered_unexpected_events_clone + // .write() + // .await + // .push(unexpected_event.clone()); + // } + // } } }); @@ -930,12 +940,7 @@ impl NetworkNode { } pub async fn get_triggered_unexpected_events(&self) -> Vec { - self.triggered_unexpected_events - .read() - .await - .iter() - .cloned() - .collect() + self.triggered_unexpected_events.read().await.clone() } pub async fn get_network_channels(&self) -> Vec { From 3ffd0196c6b1847f9880538810a76bfacf2d0766 Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 19 Jan 2025 00:36:37 +0800 Subject: [PATCH 08/35] add tlc status RemoveApplyConfirmed? --- src/fiber/channel.rs | 48 ++++++++++++++++++++++++++++++++++++++++---- 1 file changed, 44 insertions(+), 4 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index a4c3502c..6ee84806 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -737,6 +737,27 @@ where .await .expect("expect remove tlc success"); } + + // let pending_tlcs = if inbound { + // state.tlc_state.received_tlcs.tlcs.iter_mut() + // } else { + // state.tlc_state.offered_tlcs.tlcs.iter_mut() + // }; + // let apply_removed_tlcs: Vec<_> = pending_tlcs + // .filter(|tlc| { + // tlc.removed_reason.is_some() + // && matches!( + // tlc.status, + // TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) + // | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) + // ) + // }) + // .map(|tlc| tlc.tlc_id) + // .collect(); + // for tlc_id in apply_removed_tlcs { + // state.tlc_state.apply_remove_tlc(tlc_id); + // } + if state.get_local_balance() != previous_balance { state.update_graph_for_local_channel_change(&self.network); state.update_graph_for_remote_channel_change(&self.network); @@ -2438,8 +2459,10 @@ pub enum OutboundTlcStatus { RemoveWaitPrevAck, // We have sent commitment signed to peer and waiting ACK for confirming this RemoveTlc RemoveWaitAck, - // We have received the ACK for the RemoveTlc, it's safe to remove this tlc + // We have received the ACK for the RemoveTlc RemoveAckConfirmed, + // We have waited another ACK for the RemoveTlc, it's safe to remove this tlc + RemoveApplyConfirmed, } #[derive(Debug, Clone, Serialize, Deserialize, Eq, PartialEq)] @@ -2457,6 +2480,8 @@ pub enum InboundTlcStatus { LocalRemoved, // We have received the ACK for the RemoveTlc, it's safe to remove this tlc RemoveAckConfirmed, + // We have waited another ACK for the RemoveTlc, it's safe to remove this tlc + RemoveApplyConfirmed, } #[derive(Debug, Clone, Serialize, Deserialize, Eq, PartialEq)] @@ -2559,8 +2584,10 @@ impl TlcInfo { pub fn is_remove_comfirmed(&self) -> bool { match self.status { - TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, - TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, + TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) => true, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) => true, _ => false, } } @@ -2837,6 +2864,7 @@ impl TlcState { OutboundTlcStatus::RemoveWaitPrevAck => for_remote, OutboundTlcStatus::RemoveWaitAck => false, OutboundTlcStatus::RemoveAckConfirmed => false, + OutboundTlcStatus::RemoveApplyConfirmed => false, }) .chain( self.received_tlcs @@ -2849,6 +2877,7 @@ impl TlcState { InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => !for_remote, InboundTlcStatus::RemoveAckConfirmed => false, + InboundTlcStatus::RemoveApplyConfirmed => false, }), ) } @@ -2896,6 +2925,11 @@ impl TlcState { OutboundTlcStatus::RemoveWaitAck => { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); } + // OutboundTlcStatus::RemoveAckConfirmed + // if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => + // { + // tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed); + // } _ => {} } } @@ -2911,6 +2945,11 @@ impl TlcState { InboundTlcStatus::LocalRemoved => { tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); } + // InboundTlcStatus::RemoveAckConfirmed + // if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => + // { + // tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed); + // } _ => {} } } @@ -6689,6 +6728,7 @@ impl ChannelActorState { OutboundTlcStatus::RemoveWaitPrevAck => true, OutboundTlcStatus::RemoveWaitAck => true, OutboundTlcStatus::RemoveAckConfirmed => true, + OutboundTlcStatus::RemoveApplyConfirmed => false, }) .chain(self.tlc_state.received_tlcs.tlcs.iter().filter(move |tlc| { match tlc.inbound_status() { @@ -6697,8 +6737,8 @@ impl ChannelActorState { InboundTlcStatus::AnnounceWaitAck => true, InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => true, - //InboundTlcStatus::RemoveAckPending => true, InboundTlcStatus::RemoveAckConfirmed => true, + InboundTlcStatus::RemoveApplyConfirmed => false, } })); From e3750e2af52d162266a933d6c9e78d1f750ec3e4 Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 19 Jan 2025 22:37:25 +0800 Subject: [PATCH 09/35] clean up failed tlcs --- src/fiber/channel.rs | 221 ++++++++++++++++++++++++++++++++++--------- src/fiber/types.rs | 24 +++++ 2 files changed, 201 insertions(+), 44 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 6ee84806..67133988 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -70,7 +70,7 @@ use tokio::sync::oneshot; use super::{graph::ChannelUpdateInfo, types::ForwardTlcResult}; use std::{ collections::HashSet, - fmt::{self, Debug}, + fmt::{self, Debug, Display}, sync::Arc, time::{SystemTime, UNIX_EPOCH}, u128, @@ -144,6 +144,22 @@ pub enum ChannelCommand { ReloadState(ReloadParams), } +impl Display for ChannelCommand { + fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result { + match self { + ChannelCommand::TxCollaborationCommand(_) => write!(f, "TxCollaborationCommand"), + ChannelCommand::CommitmentSigned() => write!(f, "CommitmentSigned"), + ChannelCommand::AddTlc(_, _) => write!(f, "AddTlc"), + ChannelCommand::RemoveTlc(_, _) => write!(f, "RemoveTlc"), + ChannelCommand::Shutdown(_, _) => write!(f, "Shutdown"), + ChannelCommand::Update(_, _) => write!(f, "Update"), + ChannelCommand::ForwardTlcResult(_) => write!(f, "ForwardTlcResult"), + #[cfg(test)] + ChannelCommand::ReloadState(_) => write!(f, "ReloadState"), + } + } +} + #[cfg(test)] #[derive(Debug)] pub struct ReloadParams { @@ -716,9 +732,9 @@ where ) { let previous_balance = state.get_local_balance(); let pending_tlcs = if inbound { - state.tlc_state.received_tlcs.tlcs.iter_mut() + state.tlc_state.received_tlcs.tlcs.iter() } else { - state.tlc_state.offered_tlcs.tlcs.iter_mut() + state.tlc_state.offered_tlcs.tlcs.iter() }; let settled_tlcs: Vec<_> = pending_tlcs .filter(|tlc| { @@ -738,31 +754,46 @@ where .expect("expect remove tlc success"); } - // let pending_tlcs = if inbound { - // state.tlc_state.received_tlcs.tlcs.iter_mut() - // } else { - // state.tlc_state.offered_tlcs.tlcs.iter_mut() - // }; - // let apply_removed_tlcs: Vec<_> = pending_tlcs - // .filter(|tlc| { - // tlc.removed_reason.is_some() - // && matches!( - // tlc.status, - // TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) - // | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) - // ) - // }) - // .map(|tlc| tlc.tlc_id) - // .collect(); - // for tlc_id in apply_removed_tlcs { - // state.tlc_state.apply_remove_tlc(tlc_id); - // } - if state.get_local_balance() != previous_balance { state.update_graph_for_local_channel_change(&self.network); state.update_graph_for_remote_channel_change(&self.network); } - } + //self.clean_up_failed_tlcs(state, inbound); + } + + // fn clean_up_failed_tlcs(&self, state: &mut ChannelActorState, inbound: bool) { + // let pending_tlcs = if inbound { + // state.tlc_state.received_tlcs.tlcs.iter() + // } else { + // state.tlc_state.offered_tlcs.tlcs.iter() + // }; + + // let apply_removed_tlcs: Vec<_> = pending_tlcs + // .filter(|tlc| { + // matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + // && matches!( + // tlc.status, + // TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + // | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + // ) + // }) + // .map(|tlc| tlc.tlc_id) + // .collect(); + // for tlc_id in apply_removed_tlcs { + // eprintln!( + // "node: {:?} clean up failed tlc: {:?}", + // state.get_local_peer_id(), + // state.tlc_state.get_mut(&tlc_id).unwrap() + // ); + // let tlc_info = state.tlc_state.get_mut(&tlc_id).unwrap(); + // tlc_info.status = match tlc_info.status { + // TlcStatus::Inbound(_) => TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed), + // TlcStatus::Outbound(_) => { + // TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) + // } + // }; + // } + // } async fn process_add_tlc_error( &self, @@ -796,6 +827,11 @@ where // There's no shared secret stored in the received TLC, use the one found in the peeled onion packet. &error.shared_secret, ); + eprintln!( + "register remove tlc: {:?} reason: {:?}", + tlc_id, + RemoveTlcReason::RemoveTlcFail(error_packet.clone()), + ); self.register_retryable_tlc_remove( myself, state, @@ -1544,6 +1580,7 @@ where pending_tlc_ops.retain_mut(|retryable_operation| { match retryable_operation { RetryableTlcOperation::RemoveTlc(tlc_id, ref reason) => { + eprintln!("remove tlc: {:?} reason: {:?}", tlc_id, reason); match self.handle_remove_tlc_command( state, RemoveTlcCommand { @@ -2297,14 +2334,19 @@ where state: &mut Self::State, ) -> Result<(), ActorProcessingErr> { trace!( - "Channel actor processing message: id: {:?}, state: {:?}, message: {:?}", - &state.get_id(), + "\n\nChannel actor processing message: id: {:?}, state: {:?}, message: {:?}", + &state.local_pubkey, &state.state, message, ); match message { ChannelActorMessage::PeerMessage(message) => { + eprintln!( + "\n\n -- yukang_handle_peer_message: {} node: {:?}", + message, + state.get_local_peer_id() + ); if let Err(error) = self .handle_peer_message(&myself, state, message.clone()) .await @@ -2317,8 +2359,15 @@ where } } ChannelActorMessage::Command(command) => { + eprintln!( + "\n\n ++ yukang_handle_command: {} node: {:?}", + command, + state.get_local_peer_id() + ); if let Err(err) = self.handle_command(&myself, state, command).await { - error!("Error while processing channel command: {:?}", err); + if !matches!(err, ProcessingChannelError::WaitingTlcAck) { + error!("Error while processing channel command: {:?}", err); + } } } ChannelActorMessage::Event(e) => { @@ -2592,6 +2641,10 @@ impl TlcInfo { } } + pub fn is_fail_remove_confirmed(&self) -> bool { + matches!(self.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + } + fn get_hash(&self) -> ShortHash { self.payment_hash.as_ref()[..20] .try_into() @@ -2830,10 +2883,36 @@ impl TlcState { } pub fn add_offered_tlc(&mut self, tlc: TlcInfo) { + let failed_tlcs = self + .offered_tlcs + .tlcs + .iter() + .filter(|info| info.outbound_status() == OutboundTlcStatus::RemoveApplyConfirmed) + .map(|info| info.tlc_id) + .collect::>(); + + if failed_tlcs.len() >= 3 { + self.offered_tlcs + .tlcs + .retain(|info| info.tlc_id != failed_tlcs[0]); + } self.offered_tlcs.add_tlc(tlc); } pub fn add_received_tlc(&mut self, tlc: TlcInfo) { + let failed_tlcs = self + .received_tlcs + .tlcs + .iter() + .filter(|info| info.inbound_status() == InboundTlcStatus::RemoveApplyConfirmed) + .map(|info| info.tlc_id) + .collect::>(); + + if failed_tlcs.len() >= 3 { + self.received_tlcs + .tlcs + .retain(|info| info.tlc_id != failed_tlcs[0]); + } self.received_tlcs.add_tlc(tlc); } @@ -2923,13 +3002,18 @@ impl TlcState { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck); } OutboundTlcStatus::RemoveWaitAck => { + eprintln!( + "set remove outbound to {:?}", + OutboundTlcStatus::RemoveAckConfirmed + ); tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); } - // OutboundTlcStatus::RemoveAckConfirmed - // if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => - // { - // tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed); - // } + OutboundTlcStatus::RemoveAckConfirmed + if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => + { + eprintln!("set remove apply confirmed outbound: {:?}", tlc); + tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed); + } _ => {} } } @@ -2940,16 +3024,22 @@ impl TlcState { tlc.status = TlcStatus::Inbound(InboundTlcStatus::AnnounceWaitAck); } InboundTlcStatus::AnnounceWaitAck => { + eprintln!("set inbound to committed : {:?}", tlc); tlc.status = TlcStatus::Inbound(InboundTlcStatus::Committed); } InboundTlcStatus::LocalRemoved => { + eprintln!( + "set remove inbound to {:?}", + OutboundTlcStatus::RemoveAckConfirmed + ); tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); } - // InboundTlcStatus::RemoveAckConfirmed - // if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => - // { - // tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed); - // } + InboundTlcStatus::RemoveAckConfirmed + if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => + { + eprintln!("set remove apply confirmed inbound: {:?}", tlc); + tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed); + } _ => {} } } @@ -4640,7 +4730,8 @@ impl ChannelActorState { let current = self.tlc_state.get_mut(&tlc_id).expect("TLC exists").clone(); eprintln!( "node: {:?} remove_tlc_with_reason: {:?}", - self.local_pubkey, current + self.get_local_peer_id(), + current ); let reason = current .removed_reason @@ -5957,8 +6048,10 @@ impl ChannelActorState { eprintln!( "node: {:?} handle_revoke_and_ack_peer_message", - self.local_pubkey + self.get_local_peer_id() ); + + //self.clean_up_failed_tlcs(); let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); network .send_message(NetworkActorMessage::new_notification( @@ -5973,6 +6066,41 @@ impl ChannelActorState { Ok(need_commitment_signed) } + fn clean_up_failed_tlcs(&mut self) { + let pending_tlcs = self + .tlc_state + .received_tlcs + .tlcs + .iter() + .chain(self.tlc_state.offered_tlcs.tlcs.iter()); + + // let pending_tlcs = if inbound { + // state.tlc_state.offered_tlcs.tlcs.iter() + // } else { + // state.tlc_state.received_tlcs.tlcs.iter() + // }; + + let apply_removed_tlcs: Vec<_> = pending_tlcs + .filter(|tlc| { + matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + && matches!( + tlc.status, + TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) + ) + }) + .map(|tlc| tlc.tlc_id) + .collect(); + for tlc_id in apply_removed_tlcs { + eprintln!( + "node: {:?} clean up failed tlc: {:?}", + self.get_local_peer_id(), + self.tlc_state.get_mut(&tlc_id).unwrap() + ); + self.tlc_state.apply_remove_tlc(tlc_id); + } + } + async fn handle_reestablish_channel_message( &mut self, reestablish_channel: &ReestablishChannel, @@ -6728,7 +6856,7 @@ impl ChannelActorState { OutboundTlcStatus::RemoveWaitPrevAck => true, OutboundTlcStatus::RemoveWaitAck => true, OutboundTlcStatus::RemoveAckConfirmed => true, - OutboundTlcStatus::RemoveApplyConfirmed => false, + OutboundTlcStatus::RemoveApplyConfirmed => true, }) .chain(self.tlc_state.received_tlcs.tlcs.iter().filter(move |tlc| { match tlc.inbound_status() { @@ -6738,7 +6866,7 @@ impl ChannelActorState { InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => true, InboundTlcStatus::RemoveAckConfirmed => true, - InboundTlcStatus::RemoveApplyConfirmed => false, + InboundTlcStatus::RemoveApplyConfirmed => true, } })); @@ -6748,7 +6876,8 @@ impl ChannelActorState { let mut received_fullfilled = 0; eprintln!( "node: {:?} build_settlement_transaction_outputs: {:?}", - self.local_pubkey, for_remote + self.get_local_peer_id(), + for_remote ); for info in pending_tlcs { eprintln!("tlc info: {:?}", info); @@ -6915,7 +7044,9 @@ impl ChannelActorState { let verify_ctx = self.get_verify_context(); eprintln!( "node: {:?} begin to verify commitment_tx_partial_signature: {:?} with message: {:?}", - self.local_pubkey, commitment_tx_partial_signature, message + self.get_local_peer_id(), + commitment_tx_partial_signature, + message ); verify_ctx.verify(commitment_tx_partial_signature, message.as_slice())?; eprintln!("verify commitment_tx_partial_signature successfully ....."); @@ -6982,7 +7113,9 @@ impl ChannelActorState { let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; eprintln!( "node: {:?} sign commitment_tx_partial_signature: {:?}, with message: {:?}", - self.local_pubkey, commitment_tx_partial_signature, message + self.get_local_peer_id(), + commitment_tx_partial_signature, + message ); Ok(( funding_tx_partial_signature, diff --git a/src/fiber/types.rs b/src/fiber/types.rs index 517cb311..23afcc1b 100644 --- a/src/fiber/types.rs +++ b/src/fiber/types.rs @@ -2377,6 +2377,30 @@ pub enum FiberChannelMessage { AnnouncementSignatures(AnnouncementSignatures), } +impl Display for FiberChannelMessage { + fn fmt(&self, f: &mut Formatter<'_>) -> fmt::Result { + match self { + FiberChannelMessage::AcceptChannel(_) => write!(f, "AcceptChannel"), + FiberChannelMessage::CommitmentSigned(_) => write!(f, "CommitmentSigned"), + FiberChannelMessage::TxSignatures(_) => write!(f, "TxSignatures"), + FiberChannelMessage::ChannelReady(_) => write!(f, "ChannelReady"), + FiberChannelMessage::TxUpdate(_) => write!(f, "TxUpdate"), + FiberChannelMessage::TxComplete(_) => write!(f, "TxComplete"), + FiberChannelMessage::TxAbort(_) => write!(f, "TxAbort"), + FiberChannelMessage::TxInitRBF(_) => write!(f, "TxInitRBF"), + FiberChannelMessage::TxAckRBF(_) => write!(f, "TxAckRBF"), + FiberChannelMessage::Shutdown(_) => write!(f, "Shutdown"), + FiberChannelMessage::ClosingSigned(_) => write!(f, "ClosingSigned"), + FiberChannelMessage::UpdateTlcInfo(_) => write!(f, "UpdateTlcInfo"), + FiberChannelMessage::AddTlc(_) => write!(f, "AddTlc"), + FiberChannelMessage::RevokeAndAck(_) => write!(f, "RevokeAndAck"), + FiberChannelMessage::RemoveTlc(_) => write!(f, "RemoveTlc"), + FiberChannelMessage::ReestablishChannel(_) => write!(f, "ReestablishChannel"), + FiberChannelMessage::AnnouncementSignatures(_) => write!(f, "AnnouncementSignatures"), + } + } +} + impl FiberChannelMessage { pub fn get_channel_id(&self) -> Hash256 { match self { From 6f19693034c8a27db226959685111cc5111f90f9 Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 19 Jan 2025 22:42:11 +0800 Subject: [PATCH 10/35] cleanup --- src/fiber/channel.rs | 274 +++------------------------------- src/fiber/tests/payment.rs | 1 - src/fiber/tests/test_utils.rs | 28 ++-- 3 files changed, 29 insertions(+), 274 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 67133988..8713dc84 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -758,42 +758,7 @@ where state.update_graph_for_local_channel_change(&self.network); state.update_graph_for_remote_channel_change(&self.network); } - //self.clean_up_failed_tlcs(state, inbound); - } - - // fn clean_up_failed_tlcs(&self, state: &mut ChannelActorState, inbound: bool) { - // let pending_tlcs = if inbound { - // state.tlc_state.received_tlcs.tlcs.iter() - // } else { - // state.tlc_state.offered_tlcs.tlcs.iter() - // }; - - // let apply_removed_tlcs: Vec<_> = pending_tlcs - // .filter(|tlc| { - // matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - // && matches!( - // tlc.status, - // TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - // | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - // ) - // }) - // .map(|tlc| tlc.tlc_id) - // .collect(); - // for tlc_id in apply_removed_tlcs { - // eprintln!( - // "node: {:?} clean up failed tlc: {:?}", - // state.get_local_peer_id(), - // state.tlc_state.get_mut(&tlc_id).unwrap() - // ); - // let tlc_info = state.tlc_state.get_mut(&tlc_id).unwrap(); - // tlc_info.status = match tlc_info.status { - // TlcStatus::Inbound(_) => TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed), - // TlcStatus::Outbound(_) => { - // TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) - // } - // }; - // } - // } + } async fn process_add_tlc_error( &self, @@ -827,11 +792,6 @@ where // There's no shared secret stored in the received TLC, use the one found in the peeled onion packet. &error.shared_secret, ); - eprintln!( - "register remove tlc: {:?} reason: {:?}", - tlc_id, - RemoveTlcReason::RemoveTlcFail(error_packet.clone()), - ); self.register_retryable_tlc_remove( myself, state, @@ -1257,10 +1217,6 @@ where }; let (funding_tx_partial_signature, commitment_tx_partial_signature) = state.build_and_sign_commitment_tx()?; - eprintln!( - "sign funding_tx_partial_signature: {:?}", - &funding_tx_partial_signature - ); let commitment_signed = CommitmentSigned { channel_id: state.get_id(), funding_tx_partial_signature, @@ -1351,13 +1307,11 @@ where reason: command.reason, }), ); - //eprintln!("begin to send remove tlc peer message"); self.network .send_message(NetworkActorMessage::new_command( NetworkActorCommand::SendFiberMessage(msg), )) .expect(ASSUME_NETWORK_ACTOR_ALIVE); - //eprintln!("end send remove tlc peer message"); state.maybe_transition_to_shutdown(&self.network)?; self.handle_commitment_signed_command(state)?; @@ -1580,7 +1534,6 @@ where pending_tlc_ops.retain_mut(|retryable_operation| { match retryable_operation { RetryableTlcOperation::RemoveTlc(tlc_id, ref reason) => { - eprintln!("remove tlc: {:?} reason: {:?}", tlc_id, reason); match self.handle_remove_tlc_command( state, RemoveTlcCommand { @@ -2334,19 +2287,14 @@ where state: &mut Self::State, ) -> Result<(), ActorProcessingErr> { trace!( - "\n\nChannel actor processing message: id: {:?}, state: {:?}, message: {:?}", - &state.local_pubkey, + "Channel actor processing message: id: {:?}, state: {:?}, message: {:?}", + &state.get_id(), &state.state, message, ); match message { ChannelActorMessage::PeerMessage(message) => { - eprintln!( - "\n\n -- yukang_handle_peer_message: {} node: {:?}", - message, - state.get_local_peer_id() - ); if let Err(error) = self .handle_peer_message(&myself, state, message.clone()) .await @@ -2359,15 +2307,8 @@ where } } ChannelActorMessage::Command(command) => { - eprintln!( - "\n\n ++ yukang_handle_command: {} node: {:?}", - command, - state.get_local_peer_id() - ); if let Err(err) = self.handle_command(&myself, state, command).await { - if !matches!(err, ProcessingChannelError::WaitingTlcAck) { - error!("Error while processing channel command: {:?}", err); - } + error!("Error while processing channel command: {:?}", err); } } ChannelActorMessage::Event(e) => { @@ -2508,10 +2449,8 @@ pub enum OutboundTlcStatus { RemoveWaitPrevAck, // We have sent commitment signed to peer and waiting ACK for confirming this RemoveTlc RemoveWaitAck, - // We have received the ACK for the RemoveTlc + // We have received the ACK for the RemoveTlc, it's safe to remove this tlc RemoveAckConfirmed, - // We have waited another ACK for the RemoveTlc, it's safe to remove this tlc - RemoveApplyConfirmed, } #[derive(Debug, Clone, Serialize, Deserialize, Eq, PartialEq)] @@ -2529,8 +2468,6 @@ pub enum InboundTlcStatus { LocalRemoved, // We have received the ACK for the RemoveTlc, it's safe to remove this tlc RemoveAckConfirmed, - // We have waited another ACK for the RemoveTlc, it's safe to remove this tlc - RemoveApplyConfirmed, } #[derive(Debug, Clone, Serialize, Deserialize, Eq, PartialEq)] @@ -2633,16 +2570,15 @@ impl TlcInfo { pub fn is_remove_comfirmed(&self) -> bool { match self.status { - TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) => true, - TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) => true, + TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, _ => false, } } pub fn is_fail_remove_confirmed(&self) -> bool { matches!(self.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + && self.is_remove_comfirmed() } fn get_hash(&self) -> ShortHash { @@ -2882,38 +2818,25 @@ impl TlcState { } } - pub fn add_offered_tlc(&mut self, tlc: TlcInfo) { - let failed_tlcs = self - .offered_tlcs - .tlcs + fn check_and_add_tlc(tlcs: &mut Vec, tlc: TlcInfo) { + let failed_tlcs = tlcs .iter() - .filter(|info| info.outbound_status() == OutboundTlcStatus::RemoveApplyConfirmed) + .filter(|info| info.is_fail_remove_confirmed()) .map(|info| info.tlc_id) .collect::>(); if failed_tlcs.len() >= 3 { - self.offered_tlcs - .tlcs - .retain(|info| info.tlc_id != failed_tlcs[0]); + tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); } - self.offered_tlcs.add_tlc(tlc); + tlcs.push(tlc); } - pub fn add_received_tlc(&mut self, tlc: TlcInfo) { - let failed_tlcs = self - .received_tlcs - .tlcs - .iter() - .filter(|info| info.inbound_status() == InboundTlcStatus::RemoveApplyConfirmed) - .map(|info| info.tlc_id) - .collect::>(); + pub fn add_offered_tlc(&mut self, tlc: TlcInfo) { + Self::check_and_add_tlc(&mut self.offered_tlcs.tlcs, tlc); + } - if failed_tlcs.len() >= 3 { - self.received_tlcs - .tlcs - .retain(|info| info.tlc_id != failed_tlcs[0]); - } - self.received_tlcs.add_tlc(tlc); + pub fn add_received_tlc(&mut self, tlc: TlcInfo) { + Self::check_and_add_tlc(&mut self.received_tlcs.tlcs, tlc); } pub fn set_received_tlc_removed(&mut self, tlc_id: u64, reason: RemoveTlcReason) { @@ -2943,7 +2866,6 @@ impl TlcState { OutboundTlcStatus::RemoveWaitPrevAck => for_remote, OutboundTlcStatus::RemoveWaitAck => false, OutboundTlcStatus::RemoveAckConfirmed => false, - OutboundTlcStatus::RemoveApplyConfirmed => false, }) .chain( self.received_tlcs @@ -2956,7 +2878,6 @@ impl TlcState { InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => !for_remote, InboundTlcStatus::RemoveAckConfirmed => false, - InboundTlcStatus::RemoveApplyConfirmed => false, }), ) } @@ -3002,18 +2923,8 @@ impl TlcState { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck); } OutboundTlcStatus::RemoveWaitAck => { - eprintln!( - "set remove outbound to {:?}", - OutboundTlcStatus::RemoveAckConfirmed - ); tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); } - OutboundTlcStatus::RemoveAckConfirmed - if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => - { - eprintln!("set remove apply confirmed outbound: {:?}", tlc); - tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed); - } _ => {} } } @@ -3024,22 +2935,11 @@ impl TlcState { tlc.status = TlcStatus::Inbound(InboundTlcStatus::AnnounceWaitAck); } InboundTlcStatus::AnnounceWaitAck => { - eprintln!("set inbound to committed : {:?}", tlc); tlc.status = TlcStatus::Inbound(InboundTlcStatus::Committed); } InboundTlcStatus::LocalRemoved => { - eprintln!( - "set remove inbound to {:?}", - OutboundTlcStatus::RemoveAckConfirmed - ); tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); } - InboundTlcStatus::RemoveAckConfirmed - if matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) => - { - eprintln!("set remove apply confirmed inbound: {:?}", tlc); - tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed); - } _ => {} } } @@ -4474,7 +4374,6 @@ impl ChannelActorState { .concat(), ); let our_signature = sign_ctx.sign(message.as_slice()).expect("valid signature"); - eprintln!("sign revocation_partial_signature: {:?}", our_signature); our_signature }; @@ -4483,15 +4382,6 @@ impl ChannelActorState { [to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data], ) = self.build_settlement_transaction_outputs(false); - eprintln!("remote false"); - eprintln!( - "to_local_output: {:?} to_remote_output: {:?}", - to_local_output, to_remote_output - ); - eprintln!( - "to_local_output_data: {:?} to_remote_output_data: {:?}", - to_local_output_data, to_remote_output_data - ); let commitment_lock_script_args = [ &blake2b_256(x_only_aggregated_pubkey)[0..20], self.get_delay_epoch_as_lock_args_bytes().as_slice(), @@ -4509,14 +4399,8 @@ impl ChannelActorState { ] .concat(), ); - eprintln!("sign commitment_tx_partial_signature: {:?}", message); - sign_ctx.sign(message.as_slice())? }; - eprintln!( - "sign commitment_tx_partial_signature: {:?}", - commitment_tx_partial_signature - ); // Note that we must update channel state here to update commitment number, // so that next step will obtain the correct commitment point. @@ -4728,11 +4612,6 @@ impl ChannelActorState { tlc_id: TLCId, ) -> Result<(TlcInfo, RemoveTlcReason), ProcessingChannelError> { let current = self.tlc_state.get_mut(&tlc_id).expect("TLC exists").clone(); - eprintln!( - "node: {:?} remove_tlc_with_reason: {:?}", - self.get_local_peer_id(), - current - ); let reason = current .removed_reason .clone() @@ -5332,11 +5211,6 @@ impl ChannelActorState { ] .concat(), ); - eprintln!("signing message: {:?}", message); - eprintln!( - "sign psct.commitment_tx_partial_signature: {:?}", - psct.commitment_tx_partial_signature - ); let aggregated_signature = sign_ctx .sign_and_aggregate(message.as_slice(), psct.commitment_tx_partial_signature)?; @@ -5980,7 +5854,6 @@ impl ChannelActorState { ] .concat(), ); - eprintln!("handle revoke message: {:?}", message); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), revocation_partial_signature)?; @@ -5998,15 +5871,6 @@ impl ChannelActorState { [to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data], ) = self.build_settlement_transaction_outputs(true); - eprintln!("remote true ..........."); - eprintln!( - "to_local_output: {:?} to_remote_output: {:?}", - to_local_output, to_remote_output - ); - eprintln!( - "to_local_output_data: {:?} to_remote_output_data: {:?}", - to_local_output_data, to_remote_output_data - ); let commitment_lock_script_args = [ &blake2b_256(x_only_aggregated_pubkey)[0..20], self.get_delay_epoch_as_lock_args_bytes().as_slice(), @@ -6024,14 +5888,8 @@ impl ChannelActorState { .concat(), ); - eprintln!("handle revoke message settlement_data: {:?}", message); - eprintln!( - "handle revoke message revocation_partial_signature settlement_data: {:?}", - commitment_tx_partial_signature - ); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), commitment_tx_partial_signature)?; - eprintln!("successfully sign_and_aggregate settlement data..."); SettlementData { x_only_aggregated_pubkey, @@ -6046,12 +5904,6 @@ impl ChannelActorState { self.increment_local_commitment_number(); self.append_remote_commitment_point(next_per_commitment_point); - eprintln!( - "node: {:?} handle_revoke_and_ack_peer_message", - self.get_local_peer_id() - ); - - //self.clean_up_failed_tlcs(); let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); network .send_message(NetworkActorMessage::new_notification( @@ -6066,41 +5918,6 @@ impl ChannelActorState { Ok(need_commitment_signed) } - fn clean_up_failed_tlcs(&mut self) { - let pending_tlcs = self - .tlc_state - .received_tlcs - .tlcs - .iter() - .chain(self.tlc_state.offered_tlcs.tlcs.iter()); - - // let pending_tlcs = if inbound { - // state.tlc_state.offered_tlcs.tlcs.iter() - // } else { - // state.tlc_state.received_tlcs.tlcs.iter() - // }; - - let apply_removed_tlcs: Vec<_> = pending_tlcs - .filter(|tlc| { - matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - && matches!( - tlc.status, - TlcStatus::Inbound(InboundTlcStatus::RemoveApplyConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveApplyConfirmed) - ) - }) - .map(|tlc| tlc.tlc_id) - .collect(); - for tlc_id in apply_removed_tlcs { - eprintln!( - "node: {:?} clean up failed tlc: {:?}", - self.get_local_peer_id(), - self.tlc_state.get_mut(&tlc_id).unwrap() - ); - self.tlc_state.apply_remove_tlc(tlc_id); - } - } - async fn handle_reestablish_channel_message( &mut self, reestablish_channel: &ReestablishChannel, @@ -6406,8 +6223,6 @@ impl ChannelActorState { ); let settlement_data = { - eprintln!("check_init_commitment_tx_signature message: {:?}", message); - let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), signature)?; @@ -6798,7 +6613,6 @@ impl ChannelActorState { .capacity(capacity.pack()) .build(); let output_data = Bytes::default(); - eprintln!("output: {:?}", output); (output, output_data) } } @@ -6856,7 +6670,6 @@ impl ChannelActorState { OutboundTlcStatus::RemoveWaitPrevAck => true, OutboundTlcStatus::RemoveWaitAck => true, OutboundTlcStatus::RemoveAckConfirmed => true, - OutboundTlcStatus::RemoveApplyConfirmed => true, }) .chain(self.tlc_state.received_tlcs.tlcs.iter().filter(move |tlc| { match tlc.inbound_status() { @@ -6866,7 +6679,6 @@ impl ChannelActorState { InboundTlcStatus::Committed => true, InboundTlcStatus::LocalRemoved => true, InboundTlcStatus::RemoveAckConfirmed => true, - InboundTlcStatus::RemoveApplyConfirmed => true, } })); @@ -6874,13 +6686,7 @@ impl ChannelActorState { let mut offered_fullfilled = 0; let mut received_pending = 0; let mut received_fullfilled = 0; - eprintln!( - "node: {:?} build_settlement_transaction_outputs: {:?}", - self.get_local_peer_id(), - for_remote - ); for info in pending_tlcs { - eprintln!("tlc info: {:?}", info); if info.is_offered() { offered_pending += info.amount; if (info.outbound_status() == OutboundTlcStatus::RemoveWaitAck @@ -6891,7 +6697,6 @@ impl ChannelActorState { .map(|r| matches!(r, RemoveTlcReason::RemoveTlcFulfill(_))) .unwrap_or_default() { - eprintln!("offered_fullfilled + : {:?}", info.amount); offered_fullfilled += info.amount; } } else { @@ -6903,18 +6708,11 @@ impl ChannelActorState { .map(|r| matches!(r, RemoveTlcReason::RemoveTlcFulfill(_))) .unwrap_or_default() { - eprintln!("received_fullfilled + : {:?}", info.amount); received_fullfilled += info.amount; } } } - eprintln!( - "self.to_local_amount: {:?}, self.to_remote_amount: {:?}", - self.to_local_amount, self.to_remote_amount - ); - eprintln!("received_fullfilled: {:?}, offered_pending: {:?}, offered_fullfilled: {:?}, received_pending: {:?}", - received_fullfilled, offered_pending, offered_fullfilled, received_pending - ); + let to_local_value = self.to_local_amount + received_fullfilled - offered_pending; let to_remote_value = self.to_remote_amount + offered_fullfilled - received_pending; @@ -6958,9 +6756,6 @@ impl ChannelActorState { .pack(), ) .build(); - eprintln!("to_local_value: {:?}, local_reserved_ckb_amount: {:?}, commitment_tx_fee: {:?}, for_remote: {:?}", - to_local_value, self.local_reserved_ckb_amount, commitment_tx_fee, for_remote - ); let to_local_output_data = Bytes::default(); let to_remote_output = CellOutput::new_builder() @@ -6970,10 +6765,7 @@ impl ChannelActorState { .pack(), ) .build(); - eprintln!( - "to_remote_value: {:?}, remote_reserved_ckb_amount: {:?}, commitment_tx_fee: {:?}, for_remote: {:?}", - to_remote_value, self.remote_reserved_ckb_amount, commitment_tx_fee, for_remote - ); + let to_remote_output_data = Bytes::default(); if for_remote { ( @@ -6997,16 +6789,10 @@ impl ChannelActorState { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(false); let deterministic_verify_ctx = self.get_deterministic_verify_context(); - eprintln!( - "verify funding_tx_partial_signature: {:?}", - funding_tx_partial_signature - ); - eprintln!("commitment_tx hash: {:?}", commitment_tx.hash().as_slice()); deterministic_verify_ctx.verify( funding_tx_partial_signature, commitment_tx.hash().as_slice(), )?; - eprintln!("verify successfully ....."); let to_local_output = settlement_tx .outputs() @@ -7042,14 +6828,7 @@ impl ChannelActorState { .concat(), ); let verify_ctx = self.get_verify_context(); - eprintln!( - "node: {:?} begin to verify commitment_tx_partial_signature: {:?} with message: {:?}", - self.get_local_peer_id(), - commitment_tx_partial_signature, - message - ); verify_ctx.verify(commitment_tx_partial_signature, message.as_slice())?; - eprintln!("verify commitment_tx_partial_signature successfully ....."); Ok(PartiallySignedCommitmentTransaction { version: self.get_current_commitment_number(false), @@ -7066,11 +6845,6 @@ impl ChannelActorState { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); let deterministic_sign_ctx = self.get_deterministic_sign_context(); - //eprintln!("sign deterministic_sign_ctx: {:?}", deterministic_sign_ctx); - eprintln!( - "sign commitment_tx hash: {:?}", - commitment_tx.hash().as_slice() - ); let funding_tx_partial_signature = deterministic_sign_ctx.sign(commitment_tx.hash().as_slice())?; @@ -7111,12 +6885,6 @@ impl ChannelActorState { let sign_ctx = self.get_sign_context(true); let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; - eprintln!( - "node: {:?} sign commitment_tx_partial_signature: {:?}, with message: {:?}", - self.get_local_peer_id(), - commitment_tx_partial_signature, - message - ); Ok(( funding_tx_partial_signature, commitment_tx_partial_signature, @@ -7260,7 +7028,6 @@ impl Musig2CommonContext { } } -#[derive(Debug)] struct Musig2VerifyContext { common_ctx: Musig2CommonContext, pubkey: Pubkey, @@ -7280,7 +7047,6 @@ impl Musig2VerifyContext { } } -#[derive(Debug)] struct Musig2SignContext { common_ctx: Musig2CommonContext, seckey: Privkey, diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 5edb132c..b09756fc 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1815,7 +1815,6 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { .send_payment_keysend(&node_3, 1000, false) .await .unwrap(); - eprintln!("res: {:?}", res); all_sent.insert(res.payment_hash); tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; } diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index e0bf3fd2..618d5467 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -865,7 +865,7 @@ impl NetworkNode { let unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); let triggered_unexpected_events = Arc::new(TokioRwLock::new(Vec::::new())); let (self_event_sender, self_event_receiver) = mpsc::channel(10000); - let _unexpected_events_clone = unexpected_events.clone(); + let unexpected_events_clone = unexpected_events.clone(); let triggered_unexpected_events_clone = triggered_unexpected_events.clone(); // spwan a new thread to collect all the events from event_receiver tokio::spawn(async move { @@ -874,26 +874,16 @@ impl NetworkNode { .send(event.clone()) .await .expect("send event"); - //let unexpected_events = unexpected_events_clone.read().await; + let unexpected_events = unexpected_events_clone.read().await; let event_content = format!("{:?}", event); - if !event_content.contains("WaitingTlcAck") - && !event_content.contains("AddTlcFailed") - && event_content.contains("DebugEvent") - { - triggered_unexpected_events_clone - .write() - .await - .push(event_content.clone()); + for unexpected_event in unexpected_events.iter() { + if event_content.contains(unexpected_event) { + triggered_unexpected_events_clone + .write() + .await + .push(unexpected_event.clone()); + } } - - // for unexpected_event in unexpected_events.iter() { - // if !event_content.contains("WaitingTlcAck") { - // triggered_unexpected_events_clone - // .write() - // .await - // .push(unexpected_event.clone()); - // } - // } } }); From 2afd7b54e4735c11f6400476dbe194caae0d3d14 Mon Sep 17 00:00:00 2001 From: yukang Date: Mon, 20 Jan 2025 11:17:17 +0800 Subject: [PATCH 11/35] continue after fee error --- src/fiber/channel.rs | 48 +++++++++++++++++-- src/fiber/history.rs | 23 ++++++++- src/fiber/network.rs | 23 ++++++++- src/fiber/tests/payment.rs | 95 ++++++++++++++++++++++++++++++++++++++ 4 files changed, 182 insertions(+), 7 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 8713dc84..2e63427f 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -1052,6 +1052,7 @@ where ); return Err(ProcessingChannelError::TlcForwardFeeIsTooLow); } + eprintln!("ok fee: {}, expected_fee: {:?}", forward_fee, expected_fee); // if this is not the last hop, forward TLC to next hop self.register_retryable_forward_tlc( myself, @@ -2308,7 +2309,10 @@ where } ChannelActorMessage::Command(command) => { if let Err(err) = self.handle_command(&myself, state, command).await { - error!("Error while processing channel command: {:?}", err); + if !matches!(err, ProcessingChannelError::WaitingTlcAck) { + error!("Error while processing channel command: {:?}", err); + } + //error!("Error while processing channel command: {:?}", err); } } ChannelActorMessage::Event(e) => { @@ -2818,7 +2822,11 @@ impl TlcState { } } - fn check_and_add_tlc(tlcs: &mut Vec, tlc: TlcInfo) { + fn check_and_add_tlc( + tlcs: &mut Vec, + tlc: TlcInfo, + retryable_tlc_operations: &mut Vec, + ) { let failed_tlcs = tlcs .iter() .filter(|info| info.is_fail_remove_confirmed()) @@ -2827,16 +2835,31 @@ impl TlcState { if failed_tlcs.len() >= 3 { tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); + retryable_tlc_operations.retain(|op| match op { + RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], + // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + // id != &u64::try_from(failed_tlcs[0]).unwrap() + // } + _ => true, + }); } tlcs.push(tlc); } pub fn add_offered_tlc(&mut self, tlc: TlcInfo) { - Self::check_and_add_tlc(&mut self.offered_tlcs.tlcs, tlc); + Self::check_and_add_tlc( + &mut self.offered_tlcs.tlcs, + tlc, + &mut self.retryable_tlc_operations, + ); } pub fn add_received_tlc(&mut self, tlc: TlcInfo) { - Self::check_and_add_tlc(&mut self.received_tlcs.tlcs, tlc); + Self::check_and_add_tlc( + &mut self.received_tlcs.tlcs, + tlc, + &mut self.retryable_tlc_operations, + ); } pub fn set_received_tlc_removed(&mut self, tlc_id: u64, reason: RemoveTlcReason) { @@ -4575,6 +4598,19 @@ impl ChannelActorState { if let Some(tlc) = tlc_info { if tlc.is_remove_comfirmed() { self.tlc_state.apply_remove_tlc(tlc.tlc_id); + eprintln!( + "Remove tlc with payment hash {:?} with tlc {:?}", + payment_hash, tlc + ); + self.tlc_state + .retryable_tlc_operations + .retain(|op| match op { + RetryableTlcOperation::RemoveTlc(id, _) => id != &tlc.tlc_id, + RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + id != &u64::try_from(tlc.tlc_id).unwrap() + } + _ => true, + }); } else { return Err(ProcessingChannelError::RepeatedProcessing(format!( "Trying to insert tlc with duplicate payment hash {:?} with tlc {:?}", @@ -4988,6 +5024,10 @@ impl ChannelActorState { ) -> ProcessingChannelResult { if let Some(tlc) = self.tlc_state.get(&tlc_id) { if tlc.removed_reason.is_some() { + eprintln!( + "TLC is already removed: {:?} reason: {:?}", + tlc_id, tlc.removed_reason + ); return Err(ProcessingChannelError::RepeatedProcessing( "TLC is already removed".to_string(), )); diff --git a/src/fiber/history.rs b/src/fiber/history.rs index bc11c9aa..82f3ed17 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -254,17 +254,36 @@ impl InternalResult { TlcErrorCode::PermanentChannelFailure => { self.fail_pair(nodes, index + 1); } - TlcErrorCode::FeeInsufficient | TlcErrorCode::IncorrectTlcExpiry => { + TlcErrorCode::FeeInsufficient => { + need_to_retry = true; + eprintln!("need_to_retry: {:?}, index: {:?}", need_to_retry, index); + self.fail_pair_balanced(nodes, index); + if index > 1 { + self.succeed_range_pairs(nodes, 0, index - 1); + } + } + TlcErrorCode::IncorrectTlcExpiry => { need_to_retry = false; if index == 1 { self.fail_node(nodes, 1); } else { - self.fail_pair(nodes, index - 1); + self.fail_pair(nodes, index + 1); if index > 1 { self.succeed_range_pairs(nodes, 0, index - 2); } } } + // TlcErrorCode::FeeInsufficient | TlcErrorCode::IncorrectTlcExpiry => { + // need_to_retry = false; + // if index == 1 { + // self.fail_node(nodes, 1); + // } else { + // self.fail_pair(nodes, index - 1); + // if index > 1 { + // self.succeed_range_pairs(nodes, 0, index - 2); + // } + // } + // } TlcErrorCode::TemporaryChannelFailure => { self.fail_pair_balanced(nodes, index + 1); self.succeed_range_pairs(nodes, 0, index); diff --git a/src/fiber/network.rs b/src/fiber/network.rs index c3aad001..572c6965 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1520,6 +1520,11 @@ where payment_session.hops_public_keys(), ) .unwrap_or(TlcErr::new(TlcErrorCode::InvalidOnionError)); + eprintln!( + "got on_remove_tlc_event: {:?} {:?} detail: {:?}", + payment_hash, reason, error_detail + ); + self.update_graph_with_tlc_fail(&state.network, &error_detail) .await; let need_to_retry = self @@ -1527,12 +1532,18 @@ where .write() .await .record_payment_fail(&payment_session, error_detail.clone()); + eprintln!("need_to_retry: {:?}", need_to_retry); if need_to_retry { // If this is the first hop error, like the WaitingTlcAck error, // we will just retry later, return Ok here for letting endpoint user // know payment session is created successfully self.register_payment_retry(myself, payment_hash); } else { + eprintln!( + "set_payment_fail_with_error: {:?} with error code: {:?}", + payment_hash, + error_detail.error_code.as_ref() + ); self.set_payment_fail_with_error( &mut payment_session, error_detail.error_code.as_ref(), @@ -1606,6 +1617,10 @@ where match graph.build_route(payment_data.clone()) { Err(e) => { let error = format!("Failed to build route, {}", e); + eprintln!( + "Failed to build route: {:?} for payment hash: {:?}", + e, payment_data.payment_hash + ); self.set_payment_fail_with_error(payment_session, &error); return Err(Error::SendPaymentError(error)); } @@ -1764,7 +1779,13 @@ where let Some(mut payment_session) = self.store.get_payment_session(payment_hash) else { return Err(Error::InvalidParameter(payment_hash.to_string())); }; - assert!(payment_session.status != PaymentSessionStatus::Failed); + eprintln!("try_payment_session: {:?}", payment_session); + if payment_session.status == PaymentSessionStatus::Failed { + return Err(Error::SendPaymentError(format!( + "Payment session failed: {:?}", + payment_hash + ))); + } let payment_data = payment_session.request.clone(); if payment_session.can_retry() { diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index b09756fc..431a8b17 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1877,3 +1877,98 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { } } } + +// #[tokio::test] +// async fn test_send_payment_middle_hop_update_fee_should_recovery() { +// // a variant test from +// // https://github.com/nervosnetwork/fiber/issues/480 +// // in this test, we will make sure the payment should recovery after the fee is updated by the middle hop +// // there are two channels between node_1 and node_2, they are with the same fee rate +// // path finding will pick the channel with latest time, so channels[2] will be picked +// // but we will update the fee rate of channels[1] to a higher one +// // so the payment will fail, but after the payment failed, the path finding should pick the channels[1] in the next try +// // in the end, all the payments should success +// init_tracing(); +// let _span = tracing::info_span!("node", node = "test").entered(); +// let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( +// &[ +// ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), +// ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), +// ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), +// ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), +// ], +// 4, +// true, +// ) +// .await; +// let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + +// let mut all_sent = HashSet::new(); + +// for _i in 0..5 { +// let res = node_0 +// .send_payment_keysend(&node_3, 1000, false) +// .await +// .unwrap(); +// all_sent.insert(res.payment_hash); +// tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; +// } + +// node_2 +// .update_channel_with_command( +// channels[2], +// UpdateCommand { +// enabled: None, +// tlc_expiry_delta: None, +// tlc_minimum_value: None, +// tlc_fee_proportional_millionths: Some(100000), +// }, +// ) +// .await; + +// tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; +// node_1 +// .set_unexpected_events(vec![ +// "Musig2VerifyError".to_string(), +// "Musig2RoundFinalizeError".to_string(), +// ]) +// .await; +// node_2 +// .set_unexpected_events(vec![ +// "Musig2VerifyError".to_string(), +// "Musig2RoundFinalizeError".to_string(), +// ]) +// .await; +// loop { +// let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; +// if !triggered_unexpected_events.is_empty() { +// assert!( +// false, +// "node_1 triggered_unexpected_events: {:?}", +// triggered_unexpected_events +// ); +// } + +// let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; +// if !triggered_unexpected_events.is_empty() { +// assert!( +// false, +// "node_2 triggered_unexpected_events: {:?}", +// triggered_unexpected_events +// ); +// } + +// for payment_hash in all_sent.clone().iter() { +// let status = node_0.get_payment_status(*payment_hash).await; +// //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); +// if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { +// eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); +// all_sent.remove(payment_hash); +// } +// tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; +// } +// if all_sent.is_empty() { +// break; +// } +// } +// } From f102d0d79cfc0946bcf1bf4c965536d8310803b5 Mon Sep 17 00:00:00 2001 From: yukang Date: Mon, 20 Jan 2025 22:02:42 +0800 Subject: [PATCH 12/35] debug now --- src/fiber/channel.rs | 200 +++++++++++++++++++++++++++------- src/fiber/network.rs | 14 ++- src/fiber/tests/payment.rs | 218 +++++++++++++++++++++---------------- 3 files changed, 294 insertions(+), 138 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 2e63427f..e221d707 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -749,6 +749,14 @@ where .collect(); for tlc_id in settled_tlcs { + let local_peer_id = state.get_local_peer_id(); + let tlc_info = state.tlc_state.get_mut(&tlc_id).expect("expect tlc"); + eprintln!( + "node: {:?} apply_settled_remove_tlcs: tlc_id: {:?} with tlc_info payment_hash: {:?}", + local_peer_id, + tlc_id, + tlc_info.payment_hash + ); self.apply_remove_tlc_operation(myself, state, tlc_id) .await .expect("expect remove tlc success"); @@ -1153,6 +1161,11 @@ where if tlc_info.previous_tlc.is_none() { // only the original sender of the TLC should send `TlcRemoveReceived` event // because only the original sender cares about the TLC event to settle the payment + eprintln!( + "{:?} send TlcRemoveReceived event: {:?}", + state.get_local_peer_id(), + tlc_info.payment_hash + ); if tlc_info.is_offered() { self.network .send_message(NetworkActorMessage::new_event( @@ -1477,6 +1490,7 @@ where reason: RemoveTlcReason, ) { let remove_tlc = RetryableTlcOperation::RelayRemoveTlc(channel_id, tlc_id, reason); + eprintln!("register retryable relay remove tlc: {:?}", remove_tlc); self.register_retryable_tlc_operation(myself, state, remove_tlc) .await; } @@ -1535,6 +1549,12 @@ where pending_tlc_ops.retain_mut(|retryable_operation| { match retryable_operation { RetryableTlcOperation::RemoveTlc(tlc_id, ref reason) => { + eprintln!( + "node {:?} call retryable remove tlc: {:?} with reason: {:?}", + state.get_local_peer_id(), + tlc_id, + reason + ); match self.handle_remove_tlc_command( state, RemoveTlcCommand { @@ -1551,6 +1571,7 @@ where // send relay remove tlc with network actor to previous hop let (send, _recv) = oneshot::channel::>(); let port = RpcReplyPort::from(send); + eprintln!("relay remove tlc: {:?} with reason: {:?}", tlc_id, reason); self.network .send_message(NetworkActorMessage::new_command( NetworkActorCommand::ControlFiberChannel(ChannelCommandWithId { @@ -2296,21 +2317,39 @@ where match message { ChannelActorMessage::PeerMessage(message) => { + eprintln!( + "\n\n --yukang_handle peer message node {:?} -- {} channel: {:?}", + state.get_local_peer_id(), + message, + message.get_channel_id() + ); if let Err(error) = self .handle_peer_message(&myself, state, message.clone()) .await { error!( - "Error while processing channel message: {:?} with message: {:?}", - error, message + "{:?} Error while processing channel message: {:?} with message: {:?}", + state.get_local_peer_id(), + error, + message ); debug_event!(&self.network, &format!("{:?}", error)); } } ChannelActorMessage::Command(command) => { + eprintln!( + "\n\n --yukang_handle command node {:?} -- {} channel: {:?}", + state.get_local_peer_id(), + command, + state.get_id() + ); if let Err(err) = self.handle_command(&myself, state, command).await { if !matches!(err, ProcessingChannelError::WaitingTlcAck) { - error!("Error while processing channel command: {:?}", err); + error!( + "{:?} Error while processing channel command: {:?}", + state.get_local_peer_id(), + err + ); } //error!("Error while processing channel command: {:?}", err); } @@ -2827,22 +2866,22 @@ impl TlcState { tlc: TlcInfo, retryable_tlc_operations: &mut Vec, ) { - let failed_tlcs = tlcs - .iter() - .filter(|info| info.is_fail_remove_confirmed()) - .map(|info| info.tlc_id) - .collect::>(); - - if failed_tlcs.len() >= 3 { - tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); - retryable_tlc_operations.retain(|op| match op { - RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], - // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - // id != &u64::try_from(failed_tlcs[0]).unwrap() - // } - _ => true, - }); - } + // let failed_tlcs = tlcs + // .iter() + // .filter(|info| info.is_fail_remove_confirmed()) + // .map(|info| info.tlc_id) + // .collect::>(); + + // if failed_tlcs.len() >= 3 { + // tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); + // retryable_tlc_operations.retain(|op| match op { + // RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], + // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + // id != &u64::try_from(failed_tlcs[0]).unwrap() + // } + // _ => true, + // }); + // } tlcs.push(tlc); } @@ -2852,6 +2891,12 @@ impl TlcState { tlc, &mut self.retryable_tlc_operations, ); + // let all_payment_hash = self.all_tlcs().map(|x| x.payment_hash).collect::>(); + // // assert no duplicate payment hash + // assert_eq!( + // all_payment_hash.len(), + // all_payment_hash.iter().collect::>().len() + // ); } pub fn add_received_tlc(&mut self, tlc: TlcInfo) { @@ -2860,6 +2905,12 @@ impl TlcState { tlc, &mut self.retryable_tlc_operations, ); + // let all_payment_hash = self.all_tlcs().map(|x| x.payment_hash).collect::>(); + // // assert no duplicate payment hash + // assert_eq!( + // all_payment_hash.len(), + // all_payment_hash.iter().collect::>().len() + // ); } pub fn set_received_tlc_removed(&mut self, tlc_id: u64, reason: RemoveTlcReason) { @@ -4424,6 +4475,11 @@ impl ChannelActorState { ); sign_ctx.sign(message.as_slice())? }; + eprintln!( + "node: {:?} sign commitment_tx_partial_signature: {:?}", + self.get_local_peer_id(), + commitment_tx_partial_signature + ); // Note that we must update channel state here to update commitment number, // so that next step will obtain the correct commitment point. @@ -4590,31 +4646,36 @@ impl ChannelActorState { ))); } let payment_hash = tlc.payment_hash; - let tlc_info = self + let tlc_infos: Vec<_> = self .tlc_state .all_tlcs() - .find(|tlc| tlc.payment_hash == payment_hash) - .cloned(); - if let Some(tlc) = tlc_info { - if tlc.is_remove_comfirmed() { - self.tlc_state.apply_remove_tlc(tlc.tlc_id); - eprintln!( - "Remove tlc with payment hash {:?} with tlc {:?}", - payment_hash, tlc - ); - self.tlc_state - .retryable_tlc_operations - .retain(|op| match op { - RetryableTlcOperation::RemoveTlc(id, _) => id != &tlc.tlc_id, - RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - id != &u64::try_from(tlc.tlc_id).unwrap() - } - _ => true, - }); + .filter(|tlc| tlc.payment_hash == payment_hash) + .map(|info| info.clone()) + .collect(); + if !tlc_infos.is_empty() { + if tlc_infos.iter().all(|t| t.is_fail_remove_confirmed()) { + // for t in tlc_infos { + // eprintln!( + // "Node {:?} Remove tlc with payment hash {:?} with tlc {:?}", + // self.get_local_peer_id(), + // payment_hash, + // t + // ); + // self.tlc_state.apply_remove_tlc(t.tlc_id); + // self.tlc_state + // .retryable_tlc_operations + // .retain(|op| match op { + // RetryableTlcOperation::RemoveTlc(id, _) => id != &t.tlc_id, + // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + // id != &u64::try_from(t.tlc_id).unwrap() + // } + // _ => true, + // }); + // } } else { return Err(ProcessingChannelError::RepeatedProcessing(format!( - "Trying to insert tlc with duplicate payment hash {:?} with tlc {:?}", - payment_hash, tlc + "Trying to insert tlc with duplicate payment hash {:?} with tlcs {:?}", + payment_hash, tlc_infos ))); } } @@ -5059,7 +5120,7 @@ impl ChannelActorState { } fn check_for_tlc_update( - &self, + &mut self, add_tlc_amount: Option, is_tlc_command_message: bool, is_sent: bool, @@ -5086,6 +5147,34 @@ impl ChannelActorState { if let Some(add_amount) = add_tlc_amount { self.check_tlc_limits(add_amount, is_sent)?; } + + let failed_tlcs = self + .tlc_state + .all_tlcs() + .filter(|info| info.is_fail_remove_confirmed()) + .map(|info| info.tlc_id) + .collect::>(); + + if failed_tlcs.len() >= 3 { + self.tlc_state + .offered_tlcs + .tlcs + .retain(|info| info.tlc_id != failed_tlcs[0]); + self.tlc_state + .offered_tlcs + .tlcs + .retain(|info| info.tlc_id != failed_tlcs[0]); + self.tlc_state + .retryable_tlc_operations + .retain(|op| match op { + RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], + // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + // id != &u64::try_from(failed_tlcs[0]).unwrap() + // } + _ => true, + }); + } + Ok(()) } @@ -5928,8 +6017,14 @@ impl ChannelActorState { .concat(), ); + eprintln!( + "node {:?} verify : {:?}", + self.get_local_peer_id(), + commitment_tx_partial_signature + ); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), commitment_tx_partial_signature)?; + eprintln!("verify success ..........."); SettlementData { x_only_aggregated_pubkey, @@ -6726,7 +6821,9 @@ impl ChannelActorState { let mut offered_fullfilled = 0; let mut received_pending = 0; let mut received_fullfilled = 0; + eprintln!("\n----------------------------- {}", for_remote); for info in pending_tlcs { + eprintln!("info: {:?}", info); if info.is_offered() { offered_pending += info.amount; if (info.outbound_status() == OutboundTlcStatus::RemoveWaitAck @@ -6753,8 +6850,20 @@ impl ChannelActorState { } } + eprintln!( + "offered_pending: {}, offered_fullfilled: {}, received_pending: {}, received_fullfilled: {}", + offered_pending, offered_fullfilled, received_pending, received_fullfilled + ); + eprintln!( + "old to_local_amount: {}, old to_remote_amount: {}", + self.to_local_amount, self.to_remote_amount + ); let to_local_value = self.to_local_amount + received_fullfilled - offered_pending; let to_remote_value = self.to_remote_amount + offered_fullfilled - received_pending; + eprintln!( + "to_local_value: {}, to_remote_value: {}", + to_local_value, to_remote_value + ); let commitment_tx_fee = calculate_commitment_tx_fee(self.commitment_fee_rate, &self.funding_udt_type_script); @@ -6868,7 +6977,12 @@ impl ChannelActorState { .concat(), ); let verify_ctx = self.get_verify_context(); + eprintln!( + "begin to verify commitment_tx_partial_signature: {:?}", + commitment_tx_partial_signature + ); verify_ctx.verify(commitment_tx_partial_signature, message.as_slice())?; + eprintln!("verify successfully......"); Ok(PartiallySignedCommitmentTransaction { version: self.get_current_commitment_number(false), @@ -6925,6 +7039,10 @@ impl ChannelActorState { let sign_ctx = self.get_sign_context(true); let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; + eprintln!( + "begin to sign commitment_tx_partial_signature: {:?}", + commitment_tx_partial_signature + ); Ok(( funding_tx_partial_signature, commitment_tx_partial_signature, diff --git a/src/fiber/network.rs b/src/fiber/network.rs index 572c6965..33bb599f 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1521,8 +1521,8 @@ where ) .unwrap_or(TlcErr::new(TlcErrorCode::InvalidOnionError)); eprintln!( - "got on_remove_tlc_event: {:?} {:?} detail: {:?}", - payment_hash, reason, error_detail + "node {:?} got on_remove_tlc_event: {:?} {:?} detail: {:?}", + state.peer_id, payment_hash, reason, error_detail ); self.update_graph_with_tlc_fail(&state.network, &error_detail) @@ -1779,7 +1779,7 @@ where let Some(mut payment_session) = self.store.get_payment_session(payment_hash) else { return Err(Error::InvalidParameter(payment_hash.to_string())); }; - eprintln!("try_payment_session: {:?}", payment_session); + if payment_session.status == PaymentSessionStatus::Failed { return Err(Error::SendPaymentError(format!( "Payment session failed: {:?}", @@ -1787,6 +1787,12 @@ where ))); } + eprintln!( + "try_payment_session: {:?} times: {:?}", + payment_session.payment_hash(), + payment_session.retried_times + ); + let payment_data = payment_session.request.clone(); if payment_session.can_retry() { if payment_session.last_error != Some("WaitingTlcAck".to_string()) { @@ -1796,6 +1802,8 @@ where let hops_info = self .build_payment_route(&mut payment_session, &payment_data) .await?; + let funding_txs: Vec<_> = hops_info.iter().map(|hop| hop.funding_tx_hash).collect(); + eprintln!("payment funding_txs: {:?}", funding_txs); match self .send_payment_onion_packet(state, &mut payment_session, &payment_data, hops_info) .await diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 431a8b17..2aa9dce6 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1878,97 +1878,127 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { } } -// #[tokio::test] -// async fn test_send_payment_middle_hop_update_fee_should_recovery() { -// // a variant test from -// // https://github.com/nervosnetwork/fiber/issues/480 -// // in this test, we will make sure the payment should recovery after the fee is updated by the middle hop -// // there are two channels between node_1 and node_2, they are with the same fee rate -// // path finding will pick the channel with latest time, so channels[2] will be picked -// // but we will update the fee rate of channels[1] to a higher one -// // so the payment will fail, but after the payment failed, the path finding should pick the channels[1] in the next try -// // in the end, all the payments should success -// init_tracing(); -// let _span = tracing::info_span!("node", node = "test").entered(); -// let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( -// &[ -// ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), -// ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), -// ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), -// ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), -// ], -// 4, -// true, -// ) -// .await; -// let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); - -// let mut all_sent = HashSet::new(); - -// for _i in 0..5 { -// let res = node_0 -// .send_payment_keysend(&node_3, 1000, false) -// .await -// .unwrap(); -// all_sent.insert(res.payment_hash); -// tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; -// } - -// node_2 -// .update_channel_with_command( -// channels[2], -// UpdateCommand { -// enabled: None, -// tlc_expiry_delta: None, -// tlc_minimum_value: None, -// tlc_fee_proportional_millionths: Some(100000), -// }, -// ) -// .await; - -// tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; -// node_1 -// .set_unexpected_events(vec![ -// "Musig2VerifyError".to_string(), -// "Musig2RoundFinalizeError".to_string(), -// ]) -// .await; -// node_2 -// .set_unexpected_events(vec![ -// "Musig2VerifyError".to_string(), -// "Musig2RoundFinalizeError".to_string(), -// ]) -// .await; -// loop { -// let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; -// if !triggered_unexpected_events.is_empty() { -// assert!( -// false, -// "node_1 triggered_unexpected_events: {:?}", -// triggered_unexpected_events -// ); -// } - -// let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; -// if !triggered_unexpected_events.is_empty() { -// assert!( -// false, -// "node_2 triggered_unexpected_events: {:?}", -// triggered_unexpected_events -// ); -// } - -// for payment_hash in all_sent.clone().iter() { -// let status = node_0.get_payment_status(*payment_hash).await; -// //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); -// if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { -// eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); -// all_sent.remove(payment_hash); -// } -// tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; -// } -// if all_sent.is_empty() { -// break; -// } -// } -// } +#[tokio::test] +async fn test_send_payment_middle_hop_update_fee_should_recovery() { + // a variant test from + // https://github.com/nervosnetwork/fiber/issues/480 + // in this test, we will make sure the payment should recovery after the fee is updated by the middle hop + // there are two channels between node_1 and node_2, they are with the same fee rate + // path finding will pick the channel with latest time, so channels[2] will be picked + // but we will update the fee rate of channels[1] to a higher one + // so the payment will fail, but after the payment failed, the path finding should pick the channels[1] in the next try + // in the end, all the payments should success + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((2, 3), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ], + 4, + true, + ) + .await; + let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + + let mut all_sent = HashSet::new(); + + for _i in 0..3 { + let res = node_0 + .send_payment_keysend(&node_3, 1000, false) + .await + .unwrap(); + all_sent.insert(res.payment_hash); + tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; + } + + node_2 + .update_channel_with_command( + channels[2], + UpdateCommand { + enabled: None, + tlc_expiry_delta: None, + tlc_minimum_value: None, + tlc_fee_proportional_millionths: Some(100000), + }, + ) + .await; + + tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + node_0 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + node_1 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + node_2 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + node_3 + .set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + loop { + let triggered_unexpected_events = node_0.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_0 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } + + let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_1 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } + + let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_2 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } + + let triggered_unexpected_events = node_3.get_triggered_unexpected_events().await; + if !triggered_unexpected_events.is_empty() { + assert!( + false, + "node_3 triggered_unexpected_events: {:?}", + triggered_unexpected_events + ); + } + + for payment_hash in all_sent.clone().iter() { + let status = node_0.get_payment_status(*payment_hash).await; + //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); + if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { + eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); + all_sent.remove(payment_hash); + } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; + } + if all_sent.is_empty() { + break; + } + } +} From 19fc720f9b483ac85043b82569561c6b6585f91e Mon Sep 17 00:00:00 2001 From: yukang Date: Tue, 21 Jan 2025 08:56:01 +0800 Subject: [PATCH 13/35] debug mut and avoid duplicate remove relay --- src/fiber/channel.rs | 144 +++++++++++++++++++++++-------------- src/fiber/history.rs | 3 +- src/fiber/tests/channel.rs | 2 +- src/fiber/tests/tlc_op.rs | 5 +- 4 files changed, 98 insertions(+), 56 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index e221d707..92f2125d 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -854,7 +854,18 @@ where assert!(previous_tlc.is_received()); assert!(previous_channel_id != state.get_id()); + if state + .tlc_state + .applied_relay_remove_tlcs + .contains(&tlc_info.tlc_id) + { + return; + } let remove_reason = remove_reason.clone().backward(&tlc_info.shared_secret); + state + .tlc_state + .applied_relay_remove_tlcs + .insert(tlc_info.tlc_id); self.register_retryable_relay_tlc_remove( myself, state, @@ -2565,6 +2576,7 @@ pub struct TlcInfo { /// ^^^^ ^^^^ /// pub previous_tlc: Option<(Hash256, TLCId)>, + pub removed_confirmed_at: Option, } impl Debug for TlcInfo { @@ -2614,6 +2626,7 @@ impl TlcInfo { pub fn is_remove_comfirmed(&self) -> bool { match self.status { TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, + TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) => true, TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, _ => false, } @@ -2733,6 +2746,7 @@ pub struct TlcState { pub received_tlcs: PendingTlcs, pub retryable_tlc_operations: Vec, pub applied_add_tlcs: HashSet, + pub applied_relay_remove_tlcs: HashSet, pub waiting_ack: bool, } @@ -2864,7 +2878,7 @@ impl TlcState { fn check_and_add_tlc( tlcs: &mut Vec, tlc: TlcInfo, - retryable_tlc_operations: &mut Vec, + _retryable_tlc_operations: &mut Vec, ) { // let failed_tlcs = tlcs // .iter() @@ -2986,7 +3000,7 @@ impl TlcState { self.need_another_commitment_signed() } - pub fn update_for_revoke_and_ack(&mut self) -> bool { + pub fn update_for_revoke_and_ack(&mut self, local_commitment_number: u64) -> bool { self.set_waiting_ack(false); for tlc in self.offered_tlcs.tlcs.iter_mut() { match tlc.outbound_status() { @@ -2998,6 +3012,7 @@ impl TlcState { } OutboundTlcStatus::RemoveWaitAck => { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); + tlc.removed_confirmed_at = Some(local_commitment_number); } _ => {} } @@ -3013,6 +3028,7 @@ impl TlcState { } InboundTlcStatus::LocalRemoved => { tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); + tlc.removed_confirmed_at = Some(local_commitment_number); } _ => {} } @@ -4654,24 +4670,8 @@ impl ChannelActorState { .collect(); if !tlc_infos.is_empty() { if tlc_infos.iter().all(|t| t.is_fail_remove_confirmed()) { - // for t in tlc_infos { - // eprintln!( - // "Node {:?} Remove tlc with payment hash {:?} with tlc {:?}", - // self.get_local_peer_id(), - // payment_hash, - // t - // ); - // self.tlc_state.apply_remove_tlc(t.tlc_id); - // self.tlc_state - // .retryable_tlc_operations - // .retain(|op| match op { - // RetryableTlcOperation::RemoveTlc(id, _) => id != &t.tlc_id, - // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - // id != &u64::try_from(t.tlc_id).unwrap() - // } - // _ => true, - // }); - // } + // If all the tlcs with the same payment hash are failed and removed + // then we can insert the new tlc. } else { return Err(ProcessingChannelError::RepeatedProcessing(format!( "Trying to insert tlc with duplicate payment hash {:?} with tlcs {:?}", @@ -4743,6 +4743,23 @@ impl ChannelActorState { debug!("Updated local balance to {} and remote balance to {} by removing tlc {:?} with reason {:?}", to_local_amount, to_remote_amount, tlc_id, reason); self.tlc_state.apply_remove_tlc(tlc_id); + } else { + // if let Some(remove_confirmed_at) = current.removed_confirmed_at { + // let current_local_commitment_number = self.get_local_commitment_number(); + // eprintln!( + // "removed_confirmed_at: {:?} current_local_commitment_number: {:?}", + // remove_confirmed_at, current_local_commitment_number + // ); + // if remove_confirmed_at + 3 < current_local_commitment_number { + // eprintln!( + // "remove tlc: {:?} with reason {:?} is too old, remove it, payment_hash: {:?}", + // current, reason, current.payment_hash + // ); + // self.tlc_state.apply_remove_tlc(tlc_id); + // } else { + // eprintln!("keep tlc: {:?}", tlc_id); + // } + // } } debug!( "Removed tlc payment_hash {:?} with reason {:?}", @@ -5148,32 +5165,32 @@ impl ChannelActorState { self.check_tlc_limits(add_amount, is_sent)?; } - let failed_tlcs = self - .tlc_state - .all_tlcs() - .filter(|info| info.is_fail_remove_confirmed()) - .map(|info| info.tlc_id) - .collect::>(); + // let failed_tlcs = self + // .tlc_state + // .all_tlcs() + // .filter(|info| info.is_fail_remove_confirmed()) + // .map(|info| info.tlc_id) + // .collect::>(); - if failed_tlcs.len() >= 3 { - self.tlc_state - .offered_tlcs - .tlcs - .retain(|info| info.tlc_id != failed_tlcs[0]); - self.tlc_state - .offered_tlcs - .tlcs - .retain(|info| info.tlc_id != failed_tlcs[0]); - self.tlc_state - .retryable_tlc_operations - .retain(|op| match op { - RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], - // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - // id != &u64::try_from(failed_tlcs[0]).unwrap() - // } - _ => true, - }); - } + // if failed_tlcs.len() >= 3 { + // self.tlc_state + // .offered_tlcs + // .tlcs + // .retain(|info| info.tlc_id != failed_tlcs[0]); + // self.tlc_state + // .offered_tlcs + // .tlcs + // .retain(|info| info.tlc_id != failed_tlcs[0]); + // self.tlc_state + // .retryable_tlc_operations + // .retain(|op| match op { + // RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], + // // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { + // // id != &u64::try_from(failed_tlcs[0]).unwrap() + // // } + // _ => true, + // }); + // } Ok(()) } @@ -5239,6 +5256,7 @@ impl ChannelActorState { previous_tlc: command .previous_tlc .map(|(channel_id, tlc_id)| (channel_id, TLCId::Received(tlc_id))), + removed_confirmed_at: None, } } @@ -5258,6 +5276,7 @@ impl ChannelActorState { created_at: self.get_current_commitment_numbers(), removed_reason: None, previous_tlc: None, + removed_confirmed_at: None, }; Ok(tlc_info) } @@ -6039,7 +6058,9 @@ impl ChannelActorState { self.increment_local_commitment_number(); self.append_remote_commitment_point(next_per_commitment_point); - let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); + let need_commitment_signed = self + .tlc_state + .update_for_revoke_and_ack(self.get_local_commitment_number()); network .send_message(NetworkActorMessage::new_notification( NetworkServiceEvent::RevokeAndAckReceived( @@ -6303,7 +6324,7 @@ impl ChannelActorState { Ok(()) } - fn build_init_commitment_tx_signature(&self) -> Result { + fn build_init_commitment_tx_signature(&mut self) -> Result { let sign_ctx = self.get_sign_context(true); let x_only_aggregated_pubkey = sign_ctx.common_ctx.x_only_aggregated_pubkey(); let ([to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data]) = @@ -6331,7 +6352,7 @@ impl ChannelActorState { } fn check_init_commitment_tx_signature( - &self, + &mut self, signature: PartialSignature, ) -> Result { let sign_ctx = self.get_sign_context(false); @@ -6665,7 +6686,7 @@ impl ChannelActorState { // so as to consume the funding cell. The last element is the witnesses for the // commitment transaction. fn build_commitment_and_settlement_tx( - &self, + &mut self, for_remote: bool, ) -> (TransactionView, TransactionView) { let commitment_tx = { @@ -6790,9 +6811,26 @@ impl ChannelActorState { } fn build_settlement_transaction_outputs( - &self, + &mut self, for_remote: bool, ) -> ([CellOutput; 2], [Bytes; 2]) { + let tlcs = if for_remote { + &mut self.tlc_state.offered_tlcs.tlcs + } else { + &mut self.tlc_state.received_tlcs.tlcs + }; + + let failed_tlcs = tlcs + .iter() + .filter(|info| info.is_fail_remove_confirmed()) + .map(|info| info.tlc_id) + .collect::>(); + + if failed_tlcs.len() >= 3 { + eprintln!("remove failed_tlcs: {:?}", failed_tlcs[0]); + tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); + } + let pending_tlcs = self .tlc_state .offered_tlcs @@ -6931,7 +6969,7 @@ impl ChannelActorState { } pub fn build_and_verify_commitment_tx( - &self, + &mut self, funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result { @@ -6994,7 +7032,7 @@ impl ChannelActorState { } fn build_and_sign_commitment_tx( - &self, + &mut self, ) -> Result<(PartialSignature, PartialSignature), ProcessingChannelError> { let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); @@ -7052,7 +7090,7 @@ impl ChannelActorState { /// Verify the partial signature from the peer and create a complete transaction /// with valid witnesses. fn verify_and_complete_tx( - &self, + &mut self, funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result<(TransactionView, SettlementData), ProcessingChannelError> { diff --git a/src/fiber/history.rs b/src/fiber/history.rs index 82f3ed17..1fcd0c92 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -181,7 +181,8 @@ impl InternalResult { let Some(index) = error_index else { error!("Error index not found in the route: {:?}", tlc_err); - return need_to_retry; + // FIXME: what happended here? + return false; }; let len = nodes.len(); diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index 65a53c26..c4c44e50 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -5318,7 +5318,7 @@ async fn test_send_payment_with_final_all_failed_middle_hops() { source_node.wait_until_failed(payment_hash).await; source_node - .assert_payment_status(payment_hash, PaymentSessionStatus::Failed, Some(3)) + .assert_payment_status(payment_hash, PaymentSessionStatus::Failed, Some(2)) .await; } diff --git a/src/fiber/tests/tlc_op.rs b/src/fiber/tests/tlc_op.rs index 4bfa9b7c..8b5dab72 100644 --- a/src/fiber/tests/tlc_op.rs +++ b/src/fiber/tests/tlc_op.rs @@ -213,6 +213,7 @@ impl Actor for TlcActor { shared_secret: command.shared_secret, previous_tlc: None, status: TlcStatus::Outbound(OutboundTlcStatus::LocalAnnounced), + removed_confirmed_at: None, }; state.tlc_state.add_offered_tlc(add_tlc.clone()); state.tlc_state.increment_offering(); @@ -327,7 +328,7 @@ impl Actor for TlcActor { let hash = sign_tlcs(tlcs); assert_eq!(hash, peer_hash); - state.tlc_state.update_for_revoke_and_ack(); + state.tlc_state.update_for_revoke_and_ack(0); } } Ok(()) @@ -467,6 +468,7 @@ fn test_tlc_state_v2() { created_at: CommitmentNumbers::default(), removed_reason: None, previous_tlc: None, + removed_confirmed_at: None, }; let mut add_tlc2 = TlcInfo { amount: 20000, @@ -481,6 +483,7 @@ fn test_tlc_state_v2() { created_at: CommitmentNumbers::default(), removed_reason: None, previous_tlc: None, + removed_confirmed_at: None, }; tlc_state.add_offered_tlc(add_tlc1.clone()); tlc_state.add_offered_tlc(add_tlc2.clone()); From d6b47c18e5a85ed06ce8506d5426c34c34634005 Mon Sep 17 00:00:00 2001 From: yukang Date: Tue, 21 Jan 2025 11:48:33 +0800 Subject: [PATCH 14/35] debug remove tail tlc --- src/fiber/channel.rs | 95 +++++++++++++++++++++++---------------- src/fiber/tests/tlc_op.rs | 4 +- 2 files changed, 60 insertions(+), 39 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 92f2125d..75eaaa05 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -738,7 +738,7 @@ where }; let settled_tlcs: Vec<_> = pending_tlcs .filter(|tlc| { - tlc.removed_reason.is_some() + matches!(tlc.removed_reason, Some(_)) && matches!( tlc.status, TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) @@ -762,6 +762,37 @@ where .expect("expect remove tlc success"); } + // let pending_tlcs = if inbound { + // state.tlc_state.received_tlcs.tlcs.iter() + // } else { + // state.tlc_state.offered_tlcs.tlcs.iter() + // }; + // let settled_tlcs: Vec<_> = pending_tlcs + // .filter(|tlc| { + // matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + // && matches!( + // tlc.status, + // TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + // | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + // ) + // }) + // .map(|tlc| tlc.tlc_id) + // .collect(); + + // for tlc_id in settled_tlcs { + // let local_peer_id = state.get_local_peer_id(); + // let tlc_info = state.tlc_state.get_mut(&tlc_id).expect("expect tlc"); + // eprintln!( + // "node: {:?} apply_settled_remove_tlcs: tlc_id: {:?} with tlc_info payment_hash: {:?}", + // local_peer_id, + // tlc_id, + // tlc_info.payment_hash + // ); + // self.apply_remove_tlc_operation(myself, state, tlc_id) + // .await + // .expect("expect remove tlc success"); + // } + if state.get_local_balance() != previous_balance { state.update_graph_for_local_channel_change(&self.network); state.update_graph_for_remote_channel_change(&self.network); @@ -3000,7 +3031,7 @@ impl TlcState { self.need_another_commitment_signed() } - pub fn update_for_revoke_and_ack(&mut self, local_commitment_number: u64) -> bool { + pub fn update_for_revoke_and_ack(&mut self, commitment_numbers: CommitmentNumbers) -> bool { self.set_waiting_ack(false); for tlc in self.offered_tlcs.tlcs.iter_mut() { match tlc.outbound_status() { @@ -3012,7 +3043,7 @@ impl TlcState { } OutboundTlcStatus::RemoveWaitAck => { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(local_commitment_number); + tlc.removed_confirmed_at = Some(commitment_numbers.get_local()); } _ => {} } @@ -3028,7 +3059,7 @@ impl TlcState { } InboundTlcStatus::LocalRemoved => { tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(local_commitment_number); + tlc.removed_confirmed_at = Some(commitment_numbers.get_remote()); } _ => {} } @@ -4744,22 +4775,27 @@ impl ChannelActorState { to_local_amount, to_remote_amount, tlc_id, reason); self.tlc_state.apply_remove_tlc(tlc_id); } else { - // if let Some(remove_confirmed_at) = current.removed_confirmed_at { - // let current_local_commitment_number = self.get_local_commitment_number(); - // eprintln!( - // "removed_confirmed_at: {:?} current_local_commitment_number: {:?}", - // remove_confirmed_at, current_local_commitment_number - // ); - // if remove_confirmed_at + 3 < current_local_commitment_number { - // eprintln!( - // "remove tlc: {:?} with reason {:?} is too old, remove it, payment_hash: {:?}", - // current, reason, current.payment_hash - // ); - // self.tlc_state.apply_remove_tlc(tlc_id); - // } else { - // eprintln!("keep tlc: {:?}", tlc_id); - // } - // } + if let Some(remove_confirmed_at) = current.removed_confirmed_at { + //let current_local_commitment_number = self.get_remote_commitment_number(); + let current_local_commitment_number = if current.is_offered() { + self.get_local_commitment_number() + } else { + self.get_remote_commitment_number() + }; + eprintln!( + "removed_confirmed_at: {:?} current_local_commitment_number: {:?}", + remove_confirmed_at, current_local_commitment_number + ); + if remove_confirmed_at + 3 < current_local_commitment_number { + eprintln!( + "remove tlc: {:?} with reason {:?} is too old, remove it, payment_hash: {:?}", + current, reason, current.payment_hash + ); + self.tlc_state.apply_remove_tlc(tlc_id); + } else { + eprintln!("keep tlc: {:?}", tlc_id); + } + } } debug!( "Removed tlc payment_hash {:?} with reason {:?}", @@ -6060,7 +6096,7 @@ impl ChannelActorState { let need_commitment_signed = self .tlc_state - .update_for_revoke_and_ack(self.get_local_commitment_number()); + .update_for_revoke_and_ack(self.get_current_commitment_numbers()); network .send_message(NetworkActorMessage::new_notification( NetworkServiceEvent::RevokeAndAckReceived( @@ -6814,23 +6850,6 @@ impl ChannelActorState { &mut self, for_remote: bool, ) -> ([CellOutput; 2], [Bytes; 2]) { - let tlcs = if for_remote { - &mut self.tlc_state.offered_tlcs.tlcs - } else { - &mut self.tlc_state.received_tlcs.tlcs - }; - - let failed_tlcs = tlcs - .iter() - .filter(|info| info.is_fail_remove_confirmed()) - .map(|info| info.tlc_id) - .collect::>(); - - if failed_tlcs.len() >= 3 { - eprintln!("remove failed_tlcs: {:?}", failed_tlcs[0]); - tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); - } - let pending_tlcs = self .tlc_state .offered_tlcs diff --git a/src/fiber/tests/tlc_op.rs b/src/fiber/tests/tlc_op.rs index 8b5dab72..f321344b 100644 --- a/src/fiber/tests/tlc_op.rs +++ b/src/fiber/tests/tlc_op.rs @@ -328,7 +328,9 @@ impl Actor for TlcActor { let hash = sign_tlcs(tlcs); assert_eq!(hash, peer_hash); - state.tlc_state.update_for_revoke_and_ack(0); + state + .tlc_state + .update_for_revoke_and_ack(CommitmentNumbers::default()); } } Ok(()) From ff081dbd9e61674d7af754898309b48c08c43961 Mon Sep 17 00:00:00 2001 From: yukang Date: Tue, 21 Jan 2025 16:50:54 +0800 Subject: [PATCH 15/35] add clean_up_failed_tcls --- src/fiber/channel.rs | 95 ++++++++++++++++---------------------- src/fiber/tests/payment.rs | 2 +- 2 files changed, 42 insertions(+), 55 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 75eaaa05..0d1efeec 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -73,7 +73,7 @@ use std::{ fmt::{self, Debug, Display}, sync::Arc, time::{SystemTime, UNIX_EPOCH}, - u128, + u128, u64, }; use super::types::{ChannelUpdateChannelFlags, ChannelUpdateMessageFlags, UpdateTlcInfo}; @@ -762,37 +762,6 @@ where .expect("expect remove tlc success"); } - // let pending_tlcs = if inbound { - // state.tlc_state.received_tlcs.tlcs.iter() - // } else { - // state.tlc_state.offered_tlcs.tlcs.iter() - // }; - // let settled_tlcs: Vec<_> = pending_tlcs - // .filter(|tlc| { - // matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - // && matches!( - // tlc.status, - // TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - // | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - // ) - // }) - // .map(|tlc| tlc.tlc_id) - // .collect(); - - // for tlc_id in settled_tlcs { - // let local_peer_id = state.get_local_peer_id(); - // let tlc_info = state.tlc_state.get_mut(&tlc_id).expect("expect tlc"); - // eprintln!( - // "node: {:?} apply_settled_remove_tlcs: tlc_id: {:?} with tlc_info payment_hash: {:?}", - // local_peer_id, - // tlc_id, - // tlc_info.payment_hash - // ); - // self.apply_remove_tlc_operation(myself, state, tlc_id) - // .await - // .expect("expect remove tlc success"); - // } - if state.get_local_balance() != previous_balance { state.update_graph_for_local_channel_change(&self.network); state.update_graph_for_remote_channel_change(&self.network); @@ -2618,6 +2587,7 @@ impl Debug for TlcInfo { .field("amount", &self.amount) .field("removed_reason", &self.removed_reason) .field("payment_hash", &self.payment_hash) + .field("removed_confirmed_at", &self.removed_confirmed_at) .finish() } } @@ -4448,6 +4418,7 @@ impl ChannelActorState { &mut self, network: &ActorRef, ) -> ProcessingChannelResult { + self.clean_up_failed_tlcs(); let sign_ctx = self.get_sign_context(false); let x_only_aggregated_pubkey = sign_ctx.common_ctx.x_only_aggregated_pubkey(); @@ -4774,28 +4745,6 @@ impl ChannelActorState { debug!("Updated local balance to {} and remote balance to {} by removing tlc {:?} with reason {:?}", to_local_amount, to_remote_amount, tlc_id, reason); self.tlc_state.apply_remove_tlc(tlc_id); - } else { - if let Some(remove_confirmed_at) = current.removed_confirmed_at { - //let current_local_commitment_number = self.get_remote_commitment_number(); - let current_local_commitment_number = if current.is_offered() { - self.get_local_commitment_number() - } else { - self.get_remote_commitment_number() - }; - eprintln!( - "removed_confirmed_at: {:?} current_local_commitment_number: {:?}", - remove_confirmed_at, current_local_commitment_number - ); - if remove_confirmed_at + 3 < current_local_commitment_number { - eprintln!( - "remove tlc: {:?} with reason {:?} is too old, remove it, payment_hash: {:?}", - current, reason, current.payment_hash - ); - self.tlc_state.apply_remove_tlc(tlc_id); - } else { - eprintln!("keep tlc: {:?}", tlc_id); - } - } } debug!( "Removed tlc payment_hash {:?} with reason {:?}", @@ -4805,6 +4754,40 @@ impl ChannelActorState { Ok((current.clone(), reason)) } + pub fn clean_up_failed_tlcs(&mut self) { + eprintln!( + "node : {:?} begin to clean up failed tlcs", + self.get_local_peer_id(), + ); + let mut failed_tlcs: Vec<_> = self + .tlc_state + .received_tlcs + .tlcs + .iter() + .chain(self.tlc_state.offered_tlcs.tlcs.iter()) + .filter(|tlc| { + matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + && matches!( + tlc.status, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) + ) + }) + .map(|tlc| (tlc.tlc_id, tlc.removed_confirmed_at.unwrap_or(u64::MAX))) + .collect(); + + if failed_tlcs.len() >= 3 { + failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); + eprintln!( + "node: {:?} remove failed tlc: {:?}", + self.get_local_peer_id(), + failed_tlcs + ); + self.tlc_state.apply_remove_tlc(failed_tlcs[0].0); + } + } + pub fn get_local_channel_public_keys(&self) -> &ChannelBasePublicKeys { &self.local_channel_public_keys } @@ -5985,6 +5968,7 @@ impl ChannelActorState { "unexpected RevokeAndAck message".to_string(), )); } + self.clean_up_failed_tlcs(); let RevokeAndAck { channel_id: _, revocation_partial_signature, @@ -6915,6 +6899,7 @@ impl ChannelActorState { "old to_local_amount: {}, old to_remote_amount: {}", self.to_local_amount, self.to_remote_amount ); + let to_local_value = self.to_local_amount + received_fullfilled - offered_pending; let to_remote_value = self.to_remote_amount + offered_fullfilled - received_pending; eprintln!( @@ -6992,6 +6977,7 @@ impl ChannelActorState { funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result { + self.clean_up_failed_tlcs(); let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(false); let deterministic_verify_ctx = self.get_deterministic_verify_context(); @@ -7053,6 +7039,7 @@ impl ChannelActorState { fn build_and_sign_commitment_tx( &mut self, ) -> Result<(PartialSignature, PartialSignature), ProcessingChannelError> { + self.clean_up_failed_tlcs(); let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); let deterministic_sign_ctx = self.get_deterministic_sign_context(); diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 2aa9dce6..a1b0ab7d 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1905,7 +1905,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { let mut all_sent = HashSet::new(); - for _i in 0..3 { + for _i in 0..5 { let res = node_0 .send_payment_keysend(&node_3, 1000, false) .await From bc3ad2eeabf7d359ae133a0cf146e738d7bb8878 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 10:09:02 +0800 Subject: [PATCH 16/35] debug invalid onion packet issue --- src/fiber/channel.rs | 25 +++++++++++++++++++++++++ src/fiber/network.rs | 5 ++++- src/fiber/tests/channel.rs | 9 +++++++-- 3 files changed, 36 insertions(+), 3 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 0d1efeec..058d7812 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -800,6 +800,12 @@ where // There's no shared secret stored in the received TLC, use the one found in the peeled onion packet. &error.shared_secret, ); + eprintln!( + "node: {:?} process_add_tlc_error: tlc_id: {:?} with payment_hash: {:?}", + state.get_local_peer_id(), + tlc_id, + payment_hash + ); self.register_retryable_tlc_remove( myself, state, @@ -862,6 +868,12 @@ where return; } let remove_reason = remove_reason.clone().backward(&tlc_info.shared_secret); + eprintln!( + "node: {:?} try_to_relay_remove_tlc: tlc_id: {:?} with payment_hash: {:?}", + state.get_local_peer_id(), + tlc_info.tlc_id, + tlc_info.payment_hash + ); state .tlc_state .applied_relay_remove_tlcs @@ -1146,6 +1158,13 @@ where ) -> Result<(), ProcessingChannelError> { let channel_id = state.get_id(); let (tlc_info, remove_reason) = state.remove_tlc_with_reason(tlc_id)?; + eprintln!( + "node {:?} apply_remove_tlc_operation: tlc_id: {:?} with payment_hash: {:?} with reason: {:?}", + state.get_local_peer_id(), + tlc_id, + tlc_info.payment_hash, + tlc_info.removed_reason, + ); if matches!(remove_reason, RemoveTlcReason::RemoveTlcFulfill(_)) && self.store.get_invoice(&tlc_info.payment_hash).is_some() { @@ -1676,6 +1695,12 @@ where state.tlc_state.remove_pending_tlc_operation(tlc_op); } _ => { + eprintln!( + "node: {:?} got forward result : {:?} tlc_err: {:?}", + state.get_local_peer_id(), + channel_err, + tlc_err + ); let error = ProcessingChannelError::TlcForwardingError(tlc_err) .with_shared_secret(peeled_onion.shared_secret.clone()); self.process_add_tlc_error( diff --git a/src/fiber/network.rs b/src/fiber/network.rs index 33bb599f..0011a8a5 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1519,7 +1519,10 @@ where &payment_session.session_key, payment_session.hops_public_keys(), ) - .unwrap_or(TlcErr::new(TlcErrorCode::InvalidOnionError)); + .unwrap_or_else(|| { + debug_event!(myself, "InvalidOnionError"); + TlcErr::new(TlcErrorCode::InvalidOnionError) + }); eprintln!( "node {:?} got on_remove_tlc_event: {:?} {:?} detail: {:?}", state.peer_id, payment_hash, reason, error_detail diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index c4c44e50..582233cf 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -5104,7 +5104,7 @@ async fn test_send_payment_with_all_failed_middle_hops() { let _span = tracing::info_span!("node", node = "test").entered(); // we have two chaneels between node_1 and node_2 // they liquid capacity is enough for send payment, but actual balance are both not enough - // path finding will all try them but all failed, so we assert the payment retry times is 3 + // path finding will all try them but all failed, so we assert the payment retry times is 2 let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( &[ ((0, 1), (100000000000, 100000000000)), @@ -5120,6 +5120,10 @@ async fn test_send_payment_with_all_failed_middle_hops() { let source_node = &node_0; let target_pubkey = node_3.pubkey.clone(); + node_0 + .set_unexpected_events(vec!["InvalidOnionError".to_string()]) + .await; + let message = |rpc_reply| -> NetworkActorMessage { NetworkActorMessage::Command(NetworkActorCommand::SendPayment( SendPaymentCommand { @@ -5150,8 +5154,9 @@ async fn test_send_payment_with_all_failed_middle_hops() { // because there is only one path for the payment, the payment will fail in the second try // this assertion make sure we didn't do meaningless retry + assert!(node_0.get_triggered_unexpected_events().await.is_empty()); let payment_session = source_node.get_payment_session(payment_hash).unwrap(); - assert_eq!(payment_session.retried_times, 3); + assert_eq!(payment_session.retried_times, 2); } #[tokio::test] From 3a0f8a4e5bedd15dc9656015475200a3fb785283 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 10:43:52 +0800 Subject: [PATCH 17/35] fix invalid onion packet issue --- src/fiber/channel.rs | 23 +++----- src/fiber/network.rs | 4 +- src/fiber/tests/channel.rs | 4 +- src/fiber/tests/payment.rs | 116 ++++++++----------------------------- src/fiber/types.rs | 4 +- 5 files changed, 41 insertions(+), 110 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 058d7812..4190d841 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -860,13 +860,6 @@ where assert!(previous_tlc.is_received()); assert!(previous_channel_id != state.get_id()); - if state - .tlc_state - .applied_relay_remove_tlcs - .contains(&tlc_info.tlc_id) - { - return; - } let remove_reason = remove_reason.clone().backward(&tlc_info.shared_secret); eprintln!( "node: {:?} try_to_relay_remove_tlc: tlc_id: {:?} with payment_hash: {:?}", @@ -874,10 +867,6 @@ where tlc_info.tlc_id, tlc_info.payment_hash ); - state - .tlc_state - .applied_relay_remove_tlcs - .insert(tlc_info.tlc_id); self.register_retryable_relay_tlc_remove( myself, state, @@ -1157,6 +1146,10 @@ where tlc_id: TLCId, ) -> Result<(), ProcessingChannelError> { let channel_id = state.get_id(); + if state.tlc_state.applied_remove_tlcs.contains(&tlc_id) { + return Ok(()); + } + state.tlc_state.applied_remove_tlcs.insert(tlc_id); let (tlc_info, remove_reason) = state.remove_tlc_with_reason(tlc_id)?; eprintln!( "node {:?} apply_remove_tlc_operation: tlc_id: {:?} with payment_hash: {:?} with reason: {:?}", @@ -1192,9 +1185,10 @@ where // only the original sender of the TLC should send `TlcRemoveReceived` event // because only the original sender cares about the TLC event to settle the payment eprintln!( - "{:?} send TlcRemoveReceived event: {:?}", + "{:?} send TlcRemoveReceived event: {:?} remove_reason: {:?}", state.get_local_peer_id(), - tlc_info.payment_hash + tlc_info.payment_hash, + remove_reason, ); if tlc_info.is_offered() { self.network @@ -2772,7 +2766,7 @@ pub struct TlcState { pub received_tlcs: PendingTlcs, pub retryable_tlc_operations: Vec, pub applied_add_tlcs: HashSet, - pub applied_relay_remove_tlcs: HashSet, + pub applied_remove_tlcs: HashSet, pub waiting_ack: bool, } @@ -2869,6 +2863,7 @@ impl TlcState { pub fn apply_remove_tlc(&mut self, tlc_id: TLCId) { self.applied_add_tlcs.remove(&tlc_id); + self.applied_remove_tlcs.remove(&tlc_id); if tlc_id.is_offered() { self.offered_tlcs.tlcs.retain(|tlc| tlc.tlc_id != tlc_id); } else { diff --git a/src/fiber/network.rs b/src/fiber/network.rs index 0011a8a5..db15d737 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1524,8 +1524,8 @@ where TlcErr::new(TlcErrorCode::InvalidOnionError) }); eprintln!( - "node {:?} got on_remove_tlc_event: {:?} {:?} detail: {:?}", - state.peer_id, payment_hash, reason, error_detail + "node {:?} got on_remove_tlc_event: {:?} {:?} detail: {:?} session_key: {:?}", + state.peer_id, payment_hash, reason, error_detail, payment_session.session_key ); self.update_graph_with_tlc_fail(&state.network, &error_detail) diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index 582233cf..84c907f3 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -5156,7 +5156,7 @@ async fn test_send_payment_with_all_failed_middle_hops() { // this assertion make sure we didn't do meaningless retry assert!(node_0.get_triggered_unexpected_events().await.is_empty()); let payment_session = source_node.get_payment_session(payment_hash).unwrap(); - assert_eq!(payment_session.retried_times, 2); + assert_eq!(payment_session.retried_times, 3); } #[tokio::test] @@ -5323,7 +5323,7 @@ async fn test_send_payment_with_final_all_failed_middle_hops() { source_node.wait_until_failed(payment_hash).await; source_node - .assert_payment_status(payment_hash, PaymentSessionStatus::Failed, Some(2)) + .assert_payment_status(payment_hash, PaymentSessionStatus::Failed, Some(3)) .await; } diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index a1b0ab7d..3a2991a3 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1806,6 +1806,13 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { true, ) .await; + for node in nodes.iter() { + node.set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + } let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); @@ -1832,36 +1839,12 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { .await; tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; - node_1 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - node_2 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - loop { - let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_1 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } - let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_2 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } + loop { + assert!(node_0.get_triggered_unexpected_events().await.is_empty()); + assert!(node_1.get_triggered_unexpected_events().await.is_empty()); + assert!(node_2.get_triggered_unexpected_events().await.is_empty()); + assert!(node_3.get_triggered_unexpected_events().await.is_empty()); for payment_hash in all_sent.clone().iter() { let status = node_0.get_payment_status(*payment_hash).await; @@ -1901,8 +1884,14 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { true, ) .await; + for node in nodes.iter() { + node.set_unexpected_events(vec![ + "Musig2VerifyError".to_string(), + "Musig2RoundFinalizeError".to_string(), + ]) + .await; + } let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); - let mut all_sent = HashSet::new(); for _i in 0..5 { @@ -1927,71 +1916,16 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { .await; tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; - node_0 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - node_1 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - node_2 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - node_3 - .set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - loop { - let triggered_unexpected_events = node_0.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_0 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } - - let triggered_unexpected_events = node_1.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_1 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } - - let triggered_unexpected_events = node_2.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_2 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } - let triggered_unexpected_events = node_3.get_triggered_unexpected_events().await; - if !triggered_unexpected_events.is_empty() { - assert!( - false, - "node_3 triggered_unexpected_events: {:?}", - triggered_unexpected_events - ); - } + loop { + assert!(node_0.get_triggered_unexpected_events().await.is_empty()); + assert!(node_1.get_triggered_unexpected_events().await.is_empty()); + assert!(node_2.get_triggered_unexpected_events().await.is_empty()); + assert!(node_3.get_triggered_unexpected_events().await.is_empty()); for payment_hash in all_sent.clone().iter() { let status = node_0.get_payment_status(*payment_hash).await; - //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); - if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { + if status == PaymentSessionStatus::Success { eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); all_sent.remove(payment_hash); } diff --git a/src/fiber/types.rs b/src/fiber/types.rs index 23afcc1b..082b4fb5 100644 --- a/src/fiber/types.rs +++ b/src/fiber/types.rs @@ -1568,7 +1568,9 @@ impl Debug for RemoveTlcReason { RemoveTlcReason::RemoveTlcFulfill(_fulfill) => { write!(f, "RemoveTlcFulfill") } - RemoveTlcReason::RemoveTlcFail(_fail) => write!(f, "RemoveTlcFail"), + RemoveTlcReason::RemoveTlcFail(fail) => { + write!(f, "RemoveTlcFail with packet ({:?})", fail) + } } } } From d255901eb5c5b2d4f55d83d3efc87d7c2efd119b Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 11:22:33 +0800 Subject: [PATCH 18/35] code refactor for testing --- src/fiber/tests/channel.rs | 4 ---- src/fiber/tests/payment.rs | 14 -------------- src/fiber/tests/test_utils.rs | 20 +++++++++++++++++--- 3 files changed, 17 insertions(+), 21 deletions(-) diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index 84c907f3..28b30f97 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -5120,10 +5120,6 @@ async fn test_send_payment_with_all_failed_middle_hops() { let source_node = &node_0; let target_pubkey = node_3.pubkey.clone(); - node_0 - .set_unexpected_events(vec!["InvalidOnionError".to_string()]) - .await; - let message = |rpc_reply| -> NetworkActorMessage { NetworkActorMessage::Command(NetworkActorCommand::SendPayment( SendPaymentCommand { diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 3a2991a3..abe6ce72 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1806,13 +1806,6 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { true, ) .await; - for node in nodes.iter() { - node.set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - } let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); @@ -1884,13 +1877,6 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { true, ) .await; - for node in nodes.iter() { - node.set_unexpected_events(vec![ - "Musig2VerifyError".to_string(), - "Musig2RoundFinalizeError".to_string(), - ]) - .await; - } let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index 618d5467..33b8f30a 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -669,6 +669,7 @@ impl NetworkNode { pub async fn wait_until_success(&self, payment_hash: Hash256) { loop { + assert!(self.get_triggered_unexpected_events().await.is_empty()); let status = self.get_payment_status(payment_hash).await; if status == PaymentSessionStatus::Success { eprintln!("Payment success: {:?}\n\n", payment_hash); @@ -684,6 +685,7 @@ impl NetworkNode { pub async fn wait_until_failed(&self, payment_hash: Hash256) { loop { + assert!(self.get_triggered_unexpected_events().await.is_empty()); let status = self.get_payment_status(payment_hash).await; if status == PaymentSessionStatus::Failed { eprintln!("Payment failed: {:?}\n\n", payment_hash); @@ -862,7 +864,20 @@ impl NetworkNode { } }; - let unexpected_events = Arc::new(TokioRwLock::new(HashSet::::new())); + let mut unexpected_events: HashSet = HashSet::new(); + + // Some usual unexpected events that we want to not happended + // use `assert!(node.get_triggered_unexpected_events().await.is_empty())` to check it + let default_unexpected_events = vec![ + "Musig2VerifyError", + "Musig2RoundFinalizeError", + "InvalidOnionError", + ]; + for event in default_unexpected_events { + unexpected_events.insert(event.to_string()); + } + + let unexpected_events = Arc::new(TokioRwLock::new(unexpected_events)); let triggered_unexpected_events = Arc::new(TokioRwLock::new(Vec::::new())); let (self_event_sender, self_event_receiver) = mpsc::channel(10000); let unexpected_events_clone = unexpected_events.clone(); @@ -921,9 +936,8 @@ impl NetworkNode { } } - pub async fn set_unexpected_events(&self, events: Vec) { + pub async fn add_unexpected_events(&self, events: Vec) { let mut unexpected_events = self.unexpected_events.write().await; - unexpected_events.clear(); for event in events { unexpected_events.insert(event); } From 9cbe6f93d088bdfc42d35d0e121c5f7e0131b582 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 11:28:59 +0800 Subject: [PATCH 19/35] clean up --- src/fiber/channel.rs | 84 +++----------------------------------- src/fiber/history.rs | 15 ++----- src/fiber/network.rs | 17 ++++---- src/fiber/tests/channel.rs | 2 +- 4 files changed, 19 insertions(+), 99 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 4190d841..80090c50 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -2896,56 +2896,12 @@ impl TlcState { } } - fn check_and_add_tlc( - tlcs: &mut Vec, - tlc: TlcInfo, - _retryable_tlc_operations: &mut Vec, - ) { - // let failed_tlcs = tlcs - // .iter() - // .filter(|info| info.is_fail_remove_confirmed()) - // .map(|info| info.tlc_id) - // .collect::>(); - - // if failed_tlcs.len() >= 3 { - // tlcs.retain(|info| info.tlc_id != failed_tlcs[0]); - // retryable_tlc_operations.retain(|op| match op { - // RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], - // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - // id != &u64::try_from(failed_tlcs[0]).unwrap() - // } - // _ => true, - // }); - // } - tlcs.push(tlc); - } - pub fn add_offered_tlc(&mut self, tlc: TlcInfo) { - Self::check_and_add_tlc( - &mut self.offered_tlcs.tlcs, - tlc, - &mut self.retryable_tlc_operations, - ); - // let all_payment_hash = self.all_tlcs().map(|x| x.payment_hash).collect::>(); - // // assert no duplicate payment hash - // assert_eq!( - // all_payment_hash.len(), - // all_payment_hash.iter().collect::>().len() - // ); + self.offered_tlcs.add_tlc(tlc); } pub fn add_received_tlc(&mut self, tlc: TlcInfo) { - Self::check_and_add_tlc( - &mut self.received_tlcs.tlcs, - tlc, - &mut self.retryable_tlc_operations, - ); - // let all_payment_hash = self.all_tlcs().map(|x| x.payment_hash).collect::>(); - // // assert no duplicate payment hash - // assert_eq!( - // all_payment_hash.len(), - // all_payment_hash.iter().collect::>().len() - // ); + self.received_tlcs.add_tlc(tlc); } pub fn set_received_tlc_removed(&mut self, tlc_id: u64, reason: RemoveTlcReason) { @@ -5203,34 +5159,6 @@ impl ChannelActorState { if let Some(add_amount) = add_tlc_amount { self.check_tlc_limits(add_amount, is_sent)?; } - - // let failed_tlcs = self - // .tlc_state - // .all_tlcs() - // .filter(|info| info.is_fail_remove_confirmed()) - // .map(|info| info.tlc_id) - // .collect::>(); - - // if failed_tlcs.len() >= 3 { - // self.tlc_state - // .offered_tlcs - // .tlcs - // .retain(|info| info.tlc_id != failed_tlcs[0]); - // self.tlc_state - // .offered_tlcs - // .tlcs - // .retain(|info| info.tlc_id != failed_tlcs[0]); - // self.tlc_state - // .retryable_tlc_operations - // .retain(|op| match op { - // RetryableTlcOperation::RemoveTlc(id, _) => id != &failed_tlcs[0], - // // RetryableTlcOperation::RelayRemoveTlc(_, id, _) => { - // // id != &u64::try_from(failed_tlcs[0]).unwrap() - // // } - // _ => true, - // }); - // } - Ok(()) } @@ -6364,7 +6292,7 @@ impl ChannelActorState { Ok(()) } - fn build_init_commitment_tx_signature(&mut self) -> Result { + fn build_init_commitment_tx_signature(&self) -> Result { let sign_ctx = self.get_sign_context(true); let x_only_aggregated_pubkey = sign_ctx.common_ctx.x_only_aggregated_pubkey(); let ([to_local_output, to_remote_output], [to_local_output_data, to_remote_output_data]) = @@ -6392,7 +6320,7 @@ impl ChannelActorState { } fn check_init_commitment_tx_signature( - &mut self, + &self, signature: PartialSignature, ) -> Result { let sign_ctx = self.get_sign_context(false); @@ -6851,7 +6779,7 @@ impl ChannelActorState { } fn build_settlement_transaction_outputs( - &mut self, + &self, for_remote: bool, ) -> ([CellOutput; 2], [Bytes; 2]) { let pending_tlcs = self @@ -6997,7 +6925,7 @@ impl ChannelActorState { funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result { - self.clean_up_failed_tlcs(); + //self.clean_up_failed_tlcs(); let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(false); let deterministic_verify_ctx = self.get_deterministic_verify_context(); diff --git a/src/fiber/history.rs b/src/fiber/history.rs index 1fcd0c92..f653750b 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -181,7 +181,9 @@ impl InternalResult { let Some(index) = error_index else { error!("Error index not found in the route: {:?}", tlc_err); - // FIXME: what happended here? + // if the error node is not in the route, + // and we can not penalize the source node (which is ourself) + // it's better to stop the payment session return false; }; @@ -274,17 +276,6 @@ impl InternalResult { } } } - // TlcErrorCode::FeeInsufficient | TlcErrorCode::IncorrectTlcExpiry => { - // need_to_retry = false; - // if index == 1 { - // self.fail_node(nodes, 1); - // } else { - // self.fail_pair(nodes, index - 1); - // if index > 1 { - // self.succeed_range_pairs(nodes, 0, index - 2); - // } - // } - // } TlcErrorCode::TemporaryChannelFailure => { self.fail_pair_balanced(nodes, index + 1); self.succeed_range_pairs(nodes, 0, index); diff --git a/src/fiber/network.rs b/src/fiber/network.rs index db15d737..d1fb47a5 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1783,12 +1783,14 @@ where return Err(Error::InvalidParameter(payment_hash.to_string())); }; - if payment_session.status == PaymentSessionStatus::Failed { - return Err(Error::SendPaymentError(format!( - "Payment session failed: {:?}", - payment_hash - ))); - } + assert!(payment_session.status != PaymentSessionStatus::Failed); + + // if payment_session.status == PaymentSessionStatus::Failed { + // return Err(Error::SendPaymentError(format!( + // "Payment session failed: {:?}", + // payment_hash + // ))); + // } eprintln!( "try_payment_session: {:?} times: {:?}", @@ -1805,8 +1807,7 @@ where let hops_info = self .build_payment_route(&mut payment_session, &payment_data) .await?; - let funding_txs: Vec<_> = hops_info.iter().map(|hop| hop.funding_tx_hash).collect(); - eprintln!("payment funding_txs: {:?}", funding_txs); + match self .send_payment_onion_packet(state, &mut payment_session, &payment_data, hops_info) .await diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index 28b30f97..cc953437 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -5104,7 +5104,7 @@ async fn test_send_payment_with_all_failed_middle_hops() { let _span = tracing::info_span!("node", node = "test").entered(); // we have two chaneels between node_1 and node_2 // they liquid capacity is enough for send payment, but actual balance are both not enough - // path finding will all try them but all failed, so we assert the payment retry times is 2 + // path finding will all try them but all failed, so we assert the payment retry times is 3 let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( &[ ((0, 1), (100000000000, 100000000000)), From b08b65e49474c7427a29d690b775908371ae19d4 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 12:04:09 +0800 Subject: [PATCH 20/35] code refactor for cleanup tlcs --- src/fiber/channel.rs | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 80090c50..58d74bc1 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -1253,6 +1253,7 @@ where ))); } }; + state.clean_up_failed_tlcs(); let (funding_tx_partial_signature, commitment_tx_partial_signature) = state.build_and_sign_commitment_tx()?; let commitment_signed = CommitmentSigned { @@ -4394,7 +4395,6 @@ impl ChannelActorState { &mut self, network: &ActorRef, ) -> ProcessingChannelResult { - self.clean_up_failed_tlcs(); let sign_ctx = self.get_sign_context(false); let x_only_aggregated_pubkey = sign_ctx.common_ctx.x_only_aggregated_pubkey(); @@ -5132,7 +5132,7 @@ impl ChannelActorState { } fn check_for_tlc_update( - &mut self, + &self, add_tlc_amount: Option, is_tlc_command_message: bool, is_sent: bool, @@ -5646,6 +5646,7 @@ impl ChannelActorState { } }; + self.clean_up_failed_tlcs(); let (commitment_tx, settlement_data) = self.verify_and_complete_tx( commitment_signed.funding_tx_partial_signature, commitment_signed.commitment_tx_partial_signature, @@ -5916,7 +5917,6 @@ impl ChannelActorState { "unexpected RevokeAndAck message".to_string(), )); } - self.clean_up_failed_tlcs(); let RevokeAndAck { channel_id: _, revocation_partial_signature, @@ -6654,7 +6654,7 @@ impl ChannelActorState { // so as to consume the funding cell. The last element is the witnesses for the // commitment transaction. fn build_commitment_and_settlement_tx( - &mut self, + &self, for_remote: bool, ) -> (TransactionView, TransactionView) { let commitment_tx = { @@ -6921,11 +6921,10 @@ impl ChannelActorState { } pub fn build_and_verify_commitment_tx( - &mut self, + &self, funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result { - //self.clean_up_failed_tlcs(); let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(false); let deterministic_verify_ctx = self.get_deterministic_verify_context(); @@ -6985,9 +6984,8 @@ impl ChannelActorState { } fn build_and_sign_commitment_tx( - &mut self, + &self, ) -> Result<(PartialSignature, PartialSignature), ProcessingChannelError> { - self.clean_up_failed_tlcs(); let (commitment_tx, settlement_tx) = self.build_commitment_and_settlement_tx(true); let deterministic_sign_ctx = self.get_deterministic_sign_context(); @@ -7044,7 +7042,7 @@ impl ChannelActorState { /// Verify the partial signature from the peer and create a complete transaction /// with valid witnesses. fn verify_and_complete_tx( - &mut self, + &self, funding_tx_partial_signature: PartialSignature, commitment_tx_partial_signature: PartialSignature, ) -> Result<(TransactionView, SettlementData), ProcessingChannelError> { From e21cfda900e8e959e27144a907d1b8aef1ef89e1 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 14:52:24 +0800 Subject: [PATCH 21/35] cleanup logs --- src/fiber/channel.rs | 130 ++++--------------------------------------- src/fiber/history.rs | 2 +- src/fiber/network.rs | 23 +------- 3 files changed, 13 insertions(+), 142 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index cd3902b8..5b33892c 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -738,7 +738,7 @@ where }; let settled_tlcs: Vec<_> = pending_tlcs .filter(|tlc| { - matches!(tlc.removed_reason, Some(_)) + tlc.removed_reason.is_some() && matches!( tlc.status, TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) @@ -749,14 +749,6 @@ where .collect(); for tlc_id in settled_tlcs { - let local_peer_id = state.get_local_peer_id(); - let tlc_info = state.tlc_state.get_mut(&tlc_id).expect("expect tlc"); - eprintln!( - "node: {:?} apply_settled_remove_tlcs: tlc_id: {:?} with tlc_info payment_hash: {:?}", - local_peer_id, - tlc_id, - tlc_info.payment_hash - ); self.apply_remove_tlc_operation(myself, state, tlc_id) .await .expect("expect remove tlc success"); @@ -800,12 +792,7 @@ where // There's no shared secret stored in the received TLC, use the one found in the peeled onion packet. &error.shared_secret, ); - eprintln!( - "node: {:?} process_add_tlc_error: tlc_id: {:?} with payment_hash: {:?}", - state.get_local_peer_id(), - tlc_id, - payment_hash - ); + self.register_retryable_tlc_remove( myself, state, @@ -861,12 +848,7 @@ where assert!(previous_channel_id != state.get_id()); let remove_reason = remove_reason.clone().backward(&tlc_info.shared_secret); - eprintln!( - "node: {:?} try_to_relay_remove_tlc: tlc_id: {:?} with payment_hash: {:?}", - state.get_local_peer_id(), - tlc_info.tlc_id, - tlc_info.payment_hash - ); + self.register_retryable_relay_tlc_remove( myself, state, @@ -1140,13 +1122,6 @@ where } state.tlc_state.applied_remove_tlcs.insert(tlc_id); let (tlc_info, remove_reason) = state.remove_tlc_with_reason(tlc_id)?; - eprintln!( - "node {:?} apply_remove_tlc_operation: tlc_id: {:?} with payment_hash: {:?} with reason: {:?}", - state.get_local_peer_id(), - tlc_id, - tlc_info.payment_hash, - tlc_info.removed_reason, - ); if matches!(remove_reason, RemoveTlcReason::RemoveTlcFulfill(_)) && self.store.get_invoice(&tlc_info.payment_hash).is_some() { @@ -1173,12 +1148,6 @@ where if tlc_info.previous_tlc.is_none() { // only the original sender of the TLC should send `TlcRemoveReceived` event // because only the original sender cares about the TLC event to settle the payment - eprintln!( - "{:?} send TlcRemoveReceived event: {:?} remove_reason: {:?}", - state.get_local_peer_id(), - tlc_info.payment_hash, - remove_reason, - ); if tlc_info.is_offered() { self.network .send_message(NetworkActorMessage::new_event( @@ -1515,7 +1484,6 @@ where reason: RemoveTlcReason, ) { let remove_tlc = RetryableTlcOperation::RelayRemoveTlc(channel_id, tlc_id, reason); - eprintln!("register retryable relay remove tlc: {:?}", remove_tlc); self.register_retryable_tlc_operation(myself, state, remove_tlc) .await; } @@ -1579,12 +1547,6 @@ where pending_tlc_ops.retain_mut(|retryable_operation| { match retryable_operation { RetryableTlcOperation::RemoveTlc(tlc_id, ref reason) => { - eprintln!( - "node {:?} call retryable remove tlc: {:?} with reason: {:?}", - state.get_local_peer_id(), - tlc_id, - reason - ); match self.handle_remove_tlc_command( state, RemoveTlcCommand { @@ -1601,7 +1563,6 @@ where // send relay remove tlc with network actor to previous hop let (send, _recv) = oneshot::channel::>(); let port = RpcReplyPort::from(send); - eprintln!("relay remove tlc: {:?} with reason: {:?}", tlc_id, reason); self.network .send_message(NetworkActorMessage::new_command( NetworkActorCommand::ControlFiberChannel(ChannelCommandWithId { @@ -1700,12 +1661,6 @@ where state.tlc_state.remove_pending_tlc_operation(tlc_op); } _ => { - eprintln!( - "node: {:?} got forward result : {:?} tlc_err: {:?}", - state.get_local_peer_id(), - channel_err, - tlc_err - ); let error = ProcessingChannelError::TlcForwardingError(tlc_err) .with_shared_secret(peeled_onion.shared_secret.clone()); self.process_add_tlc_error( @@ -2358,12 +2313,6 @@ where match message { ChannelActorMessage::PeerMessage(message) => { - eprintln!( - "\n\n --yukang_handle peer message node {:?} -- {} channel: {:?}", - state.get_local_peer_id(), - message, - message.get_channel_id() - ); if let Err(error) = self .handle_peer_message(&myself, state, message.clone()) .await @@ -2378,21 +2327,12 @@ where } } ChannelActorMessage::Command(command) => { - eprintln!( - "\n\n --yukang_handle command node {:?} -- {} channel: {:?}", - state.get_local_peer_id(), - command, - state.get_id() - ); if let Err(err) = self.handle_command(&myself, state, command).await { - if !matches!(err, ProcessingChannelError::WaitingTlcAck) { - error!( - "{:?} Error while processing channel command: {:?}", - state.get_local_peer_id(), - err - ); - } - //error!("Error while processing channel command: {:?}", err); + error!( + "{:?} Error while processing channel command: {:?}", + state.get_local_peer_id(), + err + ); } } ChannelActorMessage::Event(e) => { @@ -4500,11 +4440,6 @@ impl ChannelActorState { ); sign_ctx.sign(message.as_slice())? }; - eprintln!( - "node: {:?} sign commitment_tx_partial_signature: {:?}", - self.get_local_peer_id(), - commitment_tx_partial_signature - ); // Note that we must update channel state here to update commitment number, // so that next step will obtain the correct commitment point. @@ -4679,8 +4614,8 @@ impl ChannelActorState { .collect(); if !tlc_infos.is_empty() { if tlc_infos.iter().all(|t| t.is_fail_remove_confirmed()) { - // If all the tlcs with the same payment hash are failed and removed - // then we can insert the new tlc. + // If all the tlcs with the same payment hash are confirmed to be failed, + // then it's safe to insert the new tlc, the old tlcs will be removed later. } else { return Err(ProcessingChannelError::RepeatedProcessing(format!( "Trying to insert tlc with duplicate payment hash {:?} with tlcs {:?}", @@ -4762,10 +4697,6 @@ impl ChannelActorState { } pub fn clean_up_failed_tlcs(&mut self) { - eprintln!( - "node : {:?} begin to clean up failed tlcs", - self.get_local_peer_id(), - ); let mut failed_tlcs: Vec<_> = self .tlc_state .received_tlcs @@ -4786,11 +4717,6 @@ impl ChannelActorState { if failed_tlcs.len() >= 3 { failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); - eprintln!( - "node: {:?} remove failed tlc: {:?}", - self.get_local_peer_id(), - failed_tlcs - ); self.tlc_state.apply_remove_tlc(failed_tlcs[0].0); } } @@ -5168,10 +5094,6 @@ impl ChannelActorState { ) -> ProcessingChannelResult { if let Some(tlc) = self.tlc_state.get(&tlc_id) { if tlc.removed_reason.is_some() { - eprintln!( - "TLC is already removed: {:?} reason: {:?}", - tlc_id, tlc.removed_reason - ); return Err(ProcessingChannelError::RepeatedProcessing( "TLC is already removed".to_string(), )); @@ -6078,14 +6000,8 @@ impl ChannelActorState { .concat(), ); - eprintln!( - "node {:?} verify : {:?}", - self.get_local_peer_id(), - commitment_tx_partial_signature - ); let aggregated_signature = sign_ctx.sign_and_aggregate(message.as_slice(), commitment_tx_partial_signature)?; - eprintln!("verify success ..........."); SettlementData { x_only_aggregated_pubkey, @@ -6884,9 +6800,7 @@ impl ChannelActorState { let mut offered_fullfilled = 0; let mut received_pending = 0; let mut received_fullfilled = 0; - eprintln!("\n----------------------------- {}", for_remote); for info in pending_tlcs { - eprintln!("info: {:?}", info); if info.is_offered() { offered_pending += info.amount; if (info.outbound_status() == OutboundTlcStatus::RemoveWaitAck @@ -6913,21 +6827,8 @@ impl ChannelActorState { } } - eprintln!( - "offered_pending: {}, offered_fullfilled: {}, received_pending: {}, received_fullfilled: {}", - offered_pending, offered_fullfilled, received_pending, received_fullfilled - ); - eprintln!( - "old to_local_amount: {}, old to_remote_amount: {}", - self.to_local_amount, self.to_remote_amount - ); - let to_local_value = self.to_local_amount + received_fullfilled - offered_pending; let to_remote_value = self.to_remote_amount + offered_fullfilled - received_pending; - eprintln!( - "to_local_value: {}, to_remote_value: {}", - to_local_value, to_remote_value - ); let commitment_tx_fee = calculate_commitment_tx_fee(self.commitment_fee_rate, &self.funding_udt_type_script); @@ -7041,12 +6942,7 @@ impl ChannelActorState { .concat(), ); let verify_ctx = self.get_verify_context(); - eprintln!( - "begin to verify commitment_tx_partial_signature: {:?}", - commitment_tx_partial_signature - ); verify_ctx.verify(commitment_tx_partial_signature, message.as_slice())?; - eprintln!("verify successfully......"); Ok(PartiallySignedCommitmentTransaction { version: self.get_current_commitment_number(false), @@ -7101,12 +6997,8 @@ impl ChannelActorState { ); let sign_ctx = self.get_sign_context(true); - let commitment_tx_partial_signature = sign_ctx.sign(message.as_slice())?; - eprintln!( - "begin to sign commitment_tx_partial_signature: {:?}", - commitment_tx_partial_signature - ); + Ok(( funding_tx_partial_signature, commitment_tx_partial_signature, diff --git a/src/fiber/history.rs b/src/fiber/history.rs index f653750b..8a5b1bb4 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -270,7 +270,7 @@ impl InternalResult { if index == 1 { self.fail_node(nodes, 1); } else { - self.fail_pair(nodes, index + 1); + self.fail_pair(nodes, index - 1); if index > 1 { self.succeed_range_pairs(nodes, 0, index - 2); } diff --git a/src/fiber/network.rs b/src/fiber/network.rs index 2d022647..3220e1ad 100644 --- a/src/fiber/network.rs +++ b/src/fiber/network.rs @@ -1526,10 +1526,6 @@ where debug_event!(myself, "InvalidOnionError"); TlcErr::new(TlcErrorCode::InvalidOnionError) }); - eprintln!( - "node {:?} got on_remove_tlc_event: {:?} {:?} detail: {:?} session_key: {:?}", - state.peer_id, payment_hash, reason, error_detail, payment_session.session_key - ); self.update_graph_with_tlc_fail(&state.network, &error_detail) .await; @@ -1538,18 +1534,12 @@ where .write() .await .record_payment_fail(&payment_session, error_detail.clone()); - eprintln!("need_to_retry: {:?}", need_to_retry); if need_to_retry { // If this is the first hop error, like the WaitingTlcAck error, // we will just retry later, return Ok here for letting endpoint user // know payment session is created successfully self.register_payment_retry(myself, payment_hash); } else { - eprintln!( - "set_payment_fail_with_error: {:?} with error code: {:?}", - payment_hash, - error_detail.error_code.as_ref() - ); self.set_payment_fail_with_error( &mut payment_session, error_detail.error_code.as_ref(), @@ -1623,10 +1613,6 @@ where match graph.build_route(payment_data.clone()) { Err(e) => { let error = format!("Failed to build route, {}", e); - eprintln!( - "Failed to build route: {:?} for payment hash: {:?}", - e, payment_data.payment_hash - ); self.set_payment_fail_with_error(payment_session, &error); return Err(Error::SendPaymentError(error)); } @@ -1793,14 +1779,7 @@ where assert!(payment_session.status != PaymentSessionStatus::Failed); - // if payment_session.status == PaymentSessionStatus::Failed { - // return Err(Error::SendPaymentError(format!( - // "Payment session failed: {:?}", - // payment_hash - // ))); - // } - - eprintln!( + debug!( "try_payment_session: {:?} times: {:?}", payment_session.payment_hash(), payment_session.retried_times From 51feda5cc0b2d393bc66d77bc180304ea4a19764 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 17:01:53 +0800 Subject: [PATCH 22/35] add testcase for issue 475 --- src/fiber/tests/payment.rs | 92 +++++++++++++++++++++++++++-------- src/fiber/tests/test_utils.rs | 6 +-- 2 files changed, 75 insertions(+), 23 deletions(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 53f7b143..a07b48d5 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -25,9 +25,9 @@ async fn test_send_payment_for_direct_channel_and_dry_run() { true, ) .await; - let [mut node_0, node_1] = nodes.try_into().expect("2 nodes"); + let [node_0, node_1] = nodes.try_into().expect("2 nodes"); let channel = channels[0]; - let source_node = &mut node_0; + let source_node = &node_0; let res = source_node .send_payment_keysend(&node_1, 10000000000, true) @@ -328,7 +328,7 @@ async fn test_send_payment_for_pay_self() { true, ) .await; - let [mut node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); let node_1_channel0_balance = node_1.get_local_balance_from_channel(channels[0]); let node_1_channel1_balance = node_1.get_local_balance_from_channel(channels[1]); @@ -402,7 +402,7 @@ async fn test_send_payment_for_pay_self_with_two_nodes() { true, ) .await; - let [mut node_0, node_1] = nodes.try_into().expect("2 nodes"); + let [node_0, node_1] = nodes.try_into().expect("2 nodes"); let node_1_channel0_balance = node_1.get_local_balance_from_channel(channels[0]); let node_1_channel1_balance = node_1.get_local_balance_from_channel(channels[1]); @@ -469,7 +469,7 @@ async fn test_send_payment_with_more_capacity_for_payself() { true, ) .await; - let [mut node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); let node_1_channel0_balance = node_1.get_local_balance_from_channel(channels[0]); let node_1_channel1_balance = node_1.get_local_balance_from_channel(channels[1]); @@ -564,7 +564,7 @@ async fn test_send_payment_with_route_to_self_with_hop_hints() { true, ) .await; - let [mut node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); eprintln!("node_0: {:?}", node_0.pubkey); eprintln!("node_1: {:?}", node_1.pubkey); eprintln!("node_2: {:?}", node_2.pubkey); @@ -676,7 +676,7 @@ async fn test_send_payment_with_route_to_self_with_outbound_hop_hints() { true, ) .await; - let [mut node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); eprintln!("node_0: {:?}", node_0.pubkey); eprintln!("node_1: {:?}", node_1.pubkey); eprintln!("node_2: {:?}", node_2.pubkey); @@ -773,7 +773,7 @@ async fn test_send_payment_select_channel_with_hop_hints() { true, ) .await; - let [mut node_0, node_1, node_2, node_3] = nodes.try_into().expect("4 nodes"); + let [node_0, node_1, node_2, node_3] = nodes.try_into().expect("4 nodes"); eprintln!("node_0: {:?}", node_0.pubkey); eprintln!("node_1: {:?}", node_1.pubkey); eprintln!("node_2: {:?}", node_2.pubkey); @@ -918,7 +918,7 @@ async fn test_send_payment_two_nodes_with_hop_hints_and_multiple_channels() { true, ) .await; - let [mut node_0, node_1] = nodes.try_into().expect("2 nodes"); + let [node_0, node_1] = nodes.try_into().expect("2 nodes"); eprintln!("node_0: {:?}", node_0.pubkey); eprintln!("node_1: {:?}", node_1.pubkey); @@ -1129,7 +1129,7 @@ async fn test_network_three_nodes_two_channels_send_each_other() { true, ) .await; - let [mut node_a, node_b, mut node_c] = nodes.try_into().expect("3 nodes"); + let [node_a, node_b, node_c] = nodes.try_into().expect("3 nodes"); // Wait for the channel announcement to be broadcasted tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; @@ -1301,7 +1301,7 @@ async fn test_send_payment_bench_test() { true, ) .await; - let [mut node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, node_1, node_2] = nodes.try_into().expect("3 nodes"); tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; @@ -1355,7 +1355,7 @@ async fn test_send_payment_three_nodes_wait_succ_bench_test() { true, ) .await; - let [mut node_0, _node_1, node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, _node_1, node_2] = nodes.try_into().expect("3 nodes"); tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; @@ -1391,7 +1391,7 @@ async fn test_send_payment_three_nodes_send_each_other_bench_test() { true, ) .await; - let [mut node_0, _node_1, mut node_2] = nodes.try_into().expect("3 nodes"); + let [node_0, _node_1, node_2] = nodes.try_into().expect("3 nodes"); tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; @@ -1569,7 +1569,7 @@ async fn test_send_payment_middle_hop_stopped() { true, ) .await; - let [mut node_0, _node_1, _node_2, node_3, mut node_4] = nodes.try_into().expect("5 nodes"); + let [node_0, _node_1, _node_2, node_3, mut node_4] = nodes.try_into().expect("5 nodes"); // dry run node_0 -> node_3 will select 0 -> 4 -> 3 let res = node_0 @@ -1613,7 +1613,7 @@ async fn test_send_payment_middle_hop_stopped_retry_longer_path() { true, ) .await; - let [mut node_0, _node_1, mut node_2, mut node_3, _node_4, _node_5, _node_6] = + let [node_0, _node_1, mut node_2, mut node_3, _node_4, _node_5, _node_6] = nodes.try_into().expect("7 nodes"); // dry run node_0 -> node_3 will select 0 -> 1 -> 2 -> 3 @@ -1770,7 +1770,7 @@ async fn test_send_payment_target_hop_stopped() { true, ) .await; - let [mut node_0, _node_1, _node_2, _node_3, mut node_4] = nodes.try_into().expect("5 nodes"); + let [node_0, _node_1, _node_2, _node_3, mut node_4] = nodes.try_into().expect("5 nodes"); // dry run node_0 -> node_4 will select 0 -> 1 -> 2 -> 3 -> 4 let res = node_0 @@ -1811,7 +1811,7 @@ async fn test_send_payment_middle_hop_balance_is_not_enough() { true, ) .await; - let [mut node_0, _node_1, _node_2, node_3] = nodes.try_into().expect("3 nodes"); + let [node_0, _node_1, _node_2, node_3] = nodes.try_into().expect("3 nodes"); let res = node_0 .send_payment_keysend(&node_3, 1000, false) @@ -1844,7 +1844,7 @@ async fn test_send_payment_middle_hop_update_fee_send_payment_failed() { true, ) .await; - let [mut node_0, _node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + let [node_0, _node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); // node_2 update fee rate to a higher one, so the payment will fail let res = node_0 @@ -1884,7 +1884,7 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { true, ) .await; - let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + let [node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); @@ -1955,7 +1955,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { true, ) .await; - let [mut node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + let [node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); for _i in 0..5 { @@ -2000,3 +2000,55 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { } } } + +#[tokio::test] +async fn test_send_payment_complex_network_payself() { + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let funding_amount = MIN_RESERVED_CKB + 100000000; + let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (funding_amount, funding_amount)), + ((1, 2), (funding_amount, funding_amount)), + ((3, 4), (funding_amount, funding_amount)), + ((4, 5), (funding_amount, funding_amount)), + ((0, 3), (funding_amount, funding_amount)), + ((1, 4), (funding_amount, funding_amount)), + ((2, 5), (funding_amount, funding_amount)), + ], + 6, + true, + ) + .await; + + let mut all_sent = HashSet::new(); + for _k in 0..3 { + for i in 0..6 { + let res = nodes[i] + .send_payment_keysend_to_self(1000, false) + .await + .unwrap(); + eprintln!("res: {:?}", res); + let payment_hash = res.payment_hash; + all_sent.insert((i, payment_hash)); + } + } + + loop { + for i in 0..6 { + assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); + } + + for (i, payment_hash) in all_sent.clone().into_iter() { + let status = nodes[i].get_payment_status(payment_hash).await; + if status == PaymentSessionStatus::Success { + eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); + all_sent.remove(&(i, payment_hash)); + } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; + } + if all_sent.is_empty() { + break; + } + } +} diff --git a/src/fiber/tests/test_utils.rs b/src/fiber/tests/test_utils.rs index ba1bfcac..1ec6403b 100644 --- a/src/fiber/tests/test_utils.rs +++ b/src/fiber/tests/test_utils.rs @@ -553,7 +553,7 @@ impl NetworkNode { } pub async fn send_payment( - &mut self, + &self, command: SendPaymentCommand, ) -> std::result::Result { let message = |rpc_reply| -> NetworkActorMessage { @@ -566,7 +566,7 @@ impl NetworkNode { } pub async fn send_payment_keysend( - &mut self, + &self, recipient: &NetworkNode, amount: u128, dry_run: bool, @@ -591,7 +591,7 @@ impl NetworkNode { } pub async fn send_payment_keysend_to_self( - &mut self, + &self, amount: u128, dry_run: bool, ) -> std::result::Result { From 682eb3887d45caaaac8850b839608c95a47a0a40 Mon Sep 17 00:00:00 2001 From: yukang Date: Wed, 22 Jan 2025 17:16:24 +0800 Subject: [PATCH 23/35] add more tests for 475 --- src/fiber/tests/payment.rs | 61 ++++++++++++++++++++++++++++++++++++++ 1 file changed, 61 insertions(+) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index a07b48d5..308693d4 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2052,3 +2052,64 @@ async fn test_send_payment_complex_network_payself() { } } } + +#[tokio::test] +async fn test_send_payment_complex_network_payself_amount_exceeded() { + // variant from issue 475 + // the channel amount is not enough, so payments will be failed + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let ckb_unit = 100_000_000; + let funding_amount = MIN_RESERVED_CKB + 1000 * ckb_unit; + let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (funding_amount, funding_amount)), + ((1, 2), (funding_amount, funding_amount)), + ((3, 4), (funding_amount, funding_amount)), + ((4, 5), (funding_amount, funding_amount)), + ((0, 3), (funding_amount, funding_amount)), + ((1, 4), (funding_amount, funding_amount)), + ((2, 5), (funding_amount, funding_amount)), + ], + 6, + true, + ) + .await; + + let mut all_sent = HashSet::new(); + for _k in 0..2 { + for i in 0..6 { + let res = nodes[i] + .send_payment_keysend_to_self(500 * ckb_unit, false) + .await + .unwrap(); + eprintln!("res: {:?}", res); + let payment_hash = res.payment_hash; + all_sent.insert((i, payment_hash)); + } + } + + let mut result = vec![]; + loop { + for i in 0..6 { + assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); + } + + for (i, payment_hash) in all_sent.clone().into_iter() { + let status = nodes[i].get_payment_status(payment_hash).await; + if matches!( + status, + PaymentSessionStatus::Success | PaymentSessionStatus::Failed + ) { + eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); + result.push((i, payment_hash, status)); + all_sent.remove(&(i, payment_hash)); + } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; + } + if all_sent.is_empty() { + break; + } + } + eprintln!("result:\n {:?}", result); +} From 6f436fb5ec1ea4718c42cc008f36279033605957 Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 23 Jan 2025 00:20:57 +0800 Subject: [PATCH 24/35] fix #475, musig error caused by failed tlcs --- src/fiber/channel.rs | 71 +++++++++++++++--------- src/fiber/tests/payment.rs | 108 +++++++++++++++---------------------- src/fiber/types.rs | 4 +- 3 files changed, 92 insertions(+), 91 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 5b33892c..0f0244d4 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -2730,6 +2730,34 @@ impl PendingTlcs { .cloned() .collect() } + + pub fn get_oldest_failed_tlcs(&self) -> Vec { + let mut failed_tlcs = self + .tlcs + .iter() + .filter(|tlc| { + matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) + && matches!( + tlc.status, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) + ) + }) + .map(|tlc| (tlc.tlc_id, tlc.removed_confirmed_at.unwrap_or(u64::MAX))) + .collect::>(); + + let keep_failed_num = 2; + if failed_tlcs.len() >= keep_failed_num { + failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); + failed_tlcs[0..failed_tlcs.len() - keep_failed_num] + .iter() + .map(|(tlc_id, _)| *tlc_id) + .collect() + } else { + return Vec::new(); + } + } } #[derive(Default, Clone, Debug, Serialize, Deserialize)] @@ -2949,7 +2977,7 @@ impl TlcState { self.need_another_commitment_signed() } - pub fn update_for_revoke_and_ack(&mut self, commitment_numbers: CommitmentNumbers) -> bool { + pub fn update_for_revoke_and_ack(&mut self, _commitment_numbers: CommitmentNumbers) -> bool { self.set_waiting_ack(false); for tlc in self.offered_tlcs.tlcs.iter_mut() { match tlc.outbound_status() { @@ -2961,7 +2989,7 @@ impl TlcState { } OutboundTlcStatus::RemoveWaitAck => { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(commitment_numbers.get_local()); + tlc.removed_confirmed_at = Some(now_timestamp_as_millis_u64()); } _ => {} } @@ -2977,7 +3005,7 @@ impl TlcState { } InboundTlcStatus::LocalRemoved => { tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(commitment_numbers.get_remote()); + tlc.removed_confirmed_at = Some(now_timestamp_as_millis_u64()); } _ => {} } @@ -4697,27 +4725,22 @@ impl ChannelActorState { } pub fn clean_up_failed_tlcs(&mut self) { - let mut failed_tlcs: Vec<_> = self - .tlc_state - .received_tlcs - .tlcs + // Remove the oldest failed tlcs from the channel state turns out to be very tricky + // Because the different parties may have different views on the failed tlcs, + // so we need to be very careful here. + + // The basic idea is to remove the oldest failed tlcs that are confirmed by both parties. + // And we need to calculate the oldest failed tlcs independently from two directions, + // Because we may have tlc operations from both directions at the same time, order matters. + // see #475 for more details. + let failed_offered_tlcs = self.tlc_state.offered_tlcs.get_oldest_failed_tlcs(); + let failed_received_tlcs = self.tlc_state.received_tlcs.get_oldest_failed_tlcs(); + + for tlc_id in failed_offered_tlcs .iter() - .chain(self.tlc_state.offered_tlcs.tlcs.iter()) - .filter(|tlc| { - matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - && matches!( - tlc.status, - TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) - ) - }) - .map(|tlc| (tlc.tlc_id, tlc.removed_confirmed_at.unwrap_or(u64::MAX))) - .collect(); - - if failed_tlcs.len() >= 3 { - failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); - self.tlc_state.apply_remove_tlc(failed_tlcs[0].0); + .chain(failed_received_tlcs.iter()) + { + self.tlc_state.apply_remove_tlc(*tlc_id); } } @@ -6879,8 +6902,8 @@ impl ChannelActorState { .pack(), ) .build(); - let to_remote_output_data = Bytes::default(); + if for_remote { ( [to_local_output, to_remote_output], diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 308693d4..96e7d3ba 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1958,7 +1958,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { let [node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); - for _i in 0..5 { + for _i in 0..6 { let res = node_0 .send_payment_keysend(&node_3, 1000, false) .await @@ -2001,11 +2001,12 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { } } -#[tokio::test] -async fn test_send_payment_complex_network_payself() { +async fn run_complex_network_with_params( + funding_amount: u128, + payment_amount_gen: impl Fn() -> u128, +) -> Vec<(Hash256, PaymentSessionStatus)> { init_tracing(); let _span = tracing::info_span!("node", node = "test").entered(); - let funding_amount = MIN_RESERVED_CKB + 100000000; let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( &[ ((0, 1), (funding_amount, funding_amount)), @@ -2024,74 +2025,22 @@ async fn test_send_payment_complex_network_payself() { let mut all_sent = HashSet::new(); for _k in 0..3 { for i in 0..6 { + let payment_amount = payment_amount_gen(); let res = nodes[i] - .send_payment_keysend_to_self(1000, false) - .await - .unwrap(); - eprintln!("res: {:?}", res); - let payment_hash = res.payment_hash; - all_sent.insert((i, payment_hash)); - } - } - - loop { - for i in 0..6 { - assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); - } - - for (i, payment_hash) in all_sent.clone().into_iter() { - let status = nodes[i].get_payment_status(payment_hash).await; - if status == PaymentSessionStatus::Success { - eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); - all_sent.remove(&(i, payment_hash)); + .send_payment_keysend_to_self(payment_amount, false) + .await; + if let Ok(res) = res { + eprintln!("res: {:?}", res); + let payment_hash = res.payment_hash; + all_sent.insert((i, payment_hash)); } - tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; - } - if all_sent.is_empty() { - break; - } - } -} - -#[tokio::test] -async fn test_send_payment_complex_network_payself_amount_exceeded() { - // variant from issue 475 - // the channel amount is not enough, so payments will be failed - init_tracing(); - let _span = tracing::info_span!("node", node = "test").entered(); - let ckb_unit = 100_000_000; - let funding_amount = MIN_RESERVED_CKB + 1000 * ckb_unit; - let (nodes, _channels) = create_n_nodes_with_index_and_amounts_with_established_channel( - &[ - ((0, 1), (funding_amount, funding_amount)), - ((1, 2), (funding_amount, funding_amount)), - ((3, 4), (funding_amount, funding_amount)), - ((4, 5), (funding_amount, funding_amount)), - ((0, 3), (funding_amount, funding_amount)), - ((1, 4), (funding_amount, funding_amount)), - ((2, 5), (funding_amount, funding_amount)), - ], - 6, - true, - ) - .await; - - let mut all_sent = HashSet::new(); - for _k in 0..2 { - for i in 0..6 { - let res = nodes[i] - .send_payment_keysend_to_self(500 * ckb_unit, false) - .await - .unwrap(); - eprintln!("res: {:?}", res); - let payment_hash = res.payment_hash; - all_sent.insert((i, payment_hash)); } } let mut result = vec![]; loop { for i in 0..6 { + eprintln!("assert node: {:?}", i); assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); } @@ -2102,7 +2051,7 @@ async fn test_send_payment_complex_network_payself_amount_exceeded() { PaymentSessionStatus::Success | PaymentSessionStatus::Failed ) { eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); - result.push((i, payment_hash, status)); + result.push((payment_hash, status)); all_sent.remove(&(i, payment_hash)); } tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; @@ -2112,4 +2061,33 @@ async fn test_send_payment_complex_network_payself_amount_exceeded() { } } eprintln!("result:\n {:?}", result); + result +} + +#[tokio::test] +async fn test_send_payment_complex_network_payself() { + // from issue 475 + // channel amount is enough, so all payments should success + let res = run_complex_network_with_params(MIN_RESERVED_CKB + 100000000, || 1000).await; + let failed_count = res + .iter() + .filter(|(_, status)| *status == PaymentSessionStatus::Failed) + .count(); + assert_eq!(failed_count, 0); +} + +#[tokio::test] +async fn test_send_payment_complex_network_payself_amount_exceeded() { + // variant from issue 475 + // the channel amount is not enough, so payments maybe be failed + let ckb_unit = 100_000_000; + let res = run_complex_network_with_params(MIN_RESERVED_CKB + 1000 * ckb_unit, || { + (450 as u128 + (rand::random::() % 100) as u128) * ckb_unit + }) + .await; + let failed_count = res + .iter() + .filter(|(_, status)| *status == PaymentSessionStatus::Failed) + .count(); + assert!(failed_count > 0); } diff --git a/src/fiber/types.rs b/src/fiber/types.rs index 753d5115..48f058ce 100644 --- a/src/fiber/types.rs +++ b/src/fiber/types.rs @@ -1568,8 +1568,8 @@ impl Debug for RemoveTlcReason { RemoveTlcReason::RemoveTlcFulfill(_fulfill) => { write!(f, "RemoveTlcFulfill") } - RemoveTlcReason::RemoveTlcFail(fail) => { - write!(f, "RemoveTlcFail with packet ({:?})", fail) + RemoveTlcReason::RemoveTlcFail(_fail) => { + write!(f, "RemoveTlcFail") } } } From 1649af16caec185bc6e746e095efdfcab6472986 Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 23 Jan 2025 00:47:10 +0800 Subject: [PATCH 25/35] cleanup --- src/fiber/channel.rs | 6 ++---- src/fiber/tests/tlc_op.rs | 4 +--- 2 files changed, 3 insertions(+), 7 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 0f0244d4..e499c52a 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -2977,7 +2977,7 @@ impl TlcState { self.need_another_commitment_signed() } - pub fn update_for_revoke_and_ack(&mut self, _commitment_numbers: CommitmentNumbers) -> bool { + pub fn update_for_revoke_and_ack(&mut self) -> bool { self.set_waiting_ack(false); for tlc in self.offered_tlcs.tlcs.iter_mut() { match tlc.outbound_status() { @@ -6039,9 +6039,7 @@ impl ChannelActorState { self.increment_local_commitment_number(); self.append_remote_commitment_point(next_per_commitment_point); - let need_commitment_signed = self - .tlc_state - .update_for_revoke_and_ack(self.get_current_commitment_numbers()); + let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); network .send_message(NetworkActorMessage::new_notification( NetworkServiceEvent::RevokeAndAckReceived( diff --git a/src/fiber/tests/tlc_op.rs b/src/fiber/tests/tlc_op.rs index f321344b..177e4c6a 100644 --- a/src/fiber/tests/tlc_op.rs +++ b/src/fiber/tests/tlc_op.rs @@ -328,9 +328,7 @@ impl Actor for TlcActor { let hash = sign_tlcs(tlcs); assert_eq!(hash, peer_hash); - state - .tlc_state - .update_for_revoke_and_ack(CommitmentNumbers::default()); + state.tlc_state.update_for_revoke_and_ack(); } } Ok(()) From edff4f0751766573829c55ac007a55a747f7a42b Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 23 Jan 2025 16:02:13 +0800 Subject: [PATCH 26/35] code refactor and cleanup --- .github/workflows/ci.yml | 2 +- src/fiber/channel.rs | 27 ++++++++++++--------------- src/fiber/history.rs | 1 - src/fiber/tests/payment.rs | 6 ++---- 4 files changed, 15 insertions(+), 21 deletions(-) diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index 9f82c4ec..8d4bd156 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -36,7 +36,7 @@ jobs: with: tool: nextest - run: | - RUST_BACKTRACE=full RUST_LOG=trace cargo nextest run --no-fail-fast + TEST_TEMP_RETAIN=1 RUST_BACKTRACE=full RUST_LOG=trace cargo nextest run --no-fail-fast fmt: name: Rustfmt diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index e499c52a..181d19a6 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -744,6 +744,7 @@ where TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) ) + && !state.tlc_state.applied_remove_tlcs.contains(&tlc.tlc_id) }) .map(|tlc| tlc.tlc_id) .collect(); @@ -1117,10 +1118,9 @@ where tlc_id: TLCId, ) -> Result<(), ProcessingChannelError> { let channel_id = state.get_id(); - if state.tlc_state.applied_remove_tlcs.contains(&tlc_id) { - return Ok(()); - } + assert!(!state.tlc_state.applied_remove_tlcs.contains(&tlc_id)); state.tlc_state.applied_remove_tlcs.insert(tlc_id); + let (tlc_info, remove_reason) = state.remove_tlc_with_reason(tlc_id)?; if matches!(remove_reason, RemoveTlcReason::RemoveTlcFulfill(_)) && self.store.get_invoice(&tlc_info.payment_hash).is_some() @@ -2735,22 +2735,19 @@ impl PendingTlcs { let mut failed_tlcs = self .tlcs .iter() - .filter(|tlc| { - matches!(tlc.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - && matches!( - tlc.status, - TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) - ) + .filter_map(|tlc| { + if tlc.is_fail_remove_confirmed() { + Some((tlc.tlc_id, tlc.removed_confirmed_at.unwrap_or(u64::MAX))) + } else { + None + } }) - .map(|tlc| (tlc.tlc_id, tlc.removed_confirmed_at.unwrap_or(u64::MAX))) .collect::>(); - let keep_failed_num = 2; - if failed_tlcs.len() >= keep_failed_num { + let failed_tlc_num_limit = 2; + if failed_tlcs.len() >= failed_tlc_num_limit { failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); - failed_tlcs[0..failed_tlcs.len() - keep_failed_num] + failed_tlcs[0..failed_tlcs.len() - failed_tlc_num_limit] .iter() .map(|(tlc_id, _)| *tlc_id) .collect() diff --git a/src/fiber/history.rs b/src/fiber/history.rs index 8a5b1bb4..9f034bf0 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -259,7 +259,6 @@ impl InternalResult { } TlcErrorCode::FeeInsufficient => { need_to_retry = true; - eprintln!("need_to_retry: {:?}, index: {:?}", need_to_retry, index); self.fail_pair_balanced(nodes, index); if index > 1 { self.succeed_range_pairs(nodes, 0, index - 1); diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 96e7d3ba..3e78a394 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2030,7 +2030,6 @@ async fn run_complex_network_with_params( .send_payment_keysend_to_self(payment_amount, false) .await; if let Ok(res) = res { - eprintln!("res: {:?}", res); let payment_hash = res.payment_hash; all_sent.insert((i, payment_hash)); } @@ -2040,7 +2039,6 @@ async fn run_complex_network_with_params( let mut result = vec![]; loop { for i in 0..6 { - eprintln!("assert node: {:?}", i); assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); } @@ -2060,12 +2058,11 @@ async fn run_complex_network_with_params( break; } } - eprintln!("result:\n {:?}", result); result } #[tokio::test] -async fn test_send_payment_complex_network_payself() { +async fn test_send_payment_complex_network_payself_all_succeed() { // from issue 475 // channel amount is enough, so all payments should success let res = run_complex_network_with_params(MIN_RESERVED_CKB + 100000000, || 1000).await; @@ -2073,6 +2070,7 @@ async fn test_send_payment_complex_network_payself() { .iter() .filter(|(_, status)| *status == PaymentSessionStatus::Failed) .count(); + assert_eq!(failed_count, 0); } From 07d054da4a2e9769eb12da35558183dcfb48bb8c Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 23 Jan 2025 17:15:23 +0800 Subject: [PATCH 27/35] fix possible fail test with optimization enabled --- Makefile | 1 + src/fiber/tests/channel.rs | 6 ++++++ 2 files changed, 7 insertions(+) diff --git a/Makefile b/Makefile index 2613c462..41247bc8 100644 --- a/Makefile +++ b/Makefile @@ -34,6 +34,7 @@ coverage-run-unittests: RUSTFLAGS="${RUSTFLAGS} -Cinstrument-coverage" \ RUST_LOG=off \ LLVM_PROFILE_FILE="${COVERAGE_PROFRAW_DIR}/unittests-%p-%m.profraw" \ + TEST_TEMP_RETAIN=1 \ cargo test --all coverage-collect-data: diff --git a/src/fiber/tests/channel.rs b/src/fiber/tests/channel.rs index 14d96092..94673e2b 100644 --- a/src/fiber/tests/channel.rs +++ b/src/fiber/tests/channel.rs @@ -4514,6 +4514,9 @@ async fn test_connect_to_peers_with_mutual_channel_on_restart_1() { ) .await; + // sleep for a while to make sure this test works both for release mode + tokio::time::sleep(tokio::time::Duration::from_secs(2)).await; + node_a.restart().await; node_a.expect_event( @@ -4554,6 +4557,9 @@ async fn test_connect_to_peers_with_mutual_channel_on_restart_2() { ) .await; + // sleep for a while to make sure this test works both for release mode + tokio::time::sleep(tokio::time::Duration::from_secs(2)).await; + node_a.stop().await; node_b.expect_event( From d8d420d2f680adbee13579d8f5fdfa7bec7427ec Mon Sep 17 00:00:00 2001 From: yukang Date: Thu, 23 Jan 2025 18:00:43 +0800 Subject: [PATCH 28/35] add migration for tlc state change --- migrate/Cargo.lock | 110 ++++++++++++++++++ migrate/Cargo.toml | 2 + migrate/src/migrations/mig_20250123.rs | 151 +++++++++++++++++++++++++ migrate/src/migrations/mod.rs | 1 + 4 files changed, 264 insertions(+) create mode 100644 migrate/src/migrations/mig_20250123.rs diff --git a/migrate/Cargo.lock b/migrate/Cargo.lock index 879e5354..da391216 100644 --- a/migrate/Cargo.lock +++ b/migrate/Cargo.lock @@ -1761,6 +1761,114 @@ dependencies = [ "tracing-subscriber", ] +[[package]] +name = "fnn" +version = "0.3.1" +source = "git+https://github.com/nervosnetwork/fiber.git?tag=v0.3.1#d0f0ebd74b5fda3c329b3b89530dcc368cdaf10a" +dependencies = [ + "anyhow", + "arcode", + "bech32 0.8.1", + "bincode", + "bitcoin", + "bitflags 2.7.0", + "ckb-chain-spec", + "ckb-gen-types", + "ckb-hash 0.115.0", + "ckb-jsonrpc-types", + "ckb-resource", + "ckb-rocksdb", + "ckb-sdk", + "ckb-types", + "clap", + "clap-serde-derive", + "console", + "fiber-sphinx", + "futures", + "git-version", + "hex", + "home", + "indicatif", + "jsonrpsee", + "lightning-invoice", + "lnd-grpc-tonic-client", + "molecule", + "musig2", + "nom", + "num_enum", + "once_cell", + "ractor 0.14.2", + "rand 0.8.5", + "regex", + "secp256k1 0.28.2", + "serde", + "serde_json", + "serde_with", + "serde_yaml", + "socket2", + "strum", + "tentacle", + "thiserror 1.0.69", + "tokio", + "tokio-util", + "tracing", + "tracing-subscriber", +] + +[[package]] +name = "fnn" +version = "0.3.1" +source = "git+https://github.com/chenyukang/fiber.git?branch=yukang-fix-480-keep-fail-tlc#07d054da4a2e9769eb12da35558183dcfb48bb8c" +dependencies = [ + "anyhow", + "arcode", + "bech32 0.8.1", + "bincode", + "bitcoin", + "bitflags 2.7.0", + "ckb-chain-spec", + "ckb-gen-types", + "ckb-hash 0.115.0", + "ckb-jsonrpc-types", + "ckb-resource", + "ckb-rocksdb", + "ckb-sdk", + "ckb-types", + "clap", + "clap-serde-derive", + "console", + "fiber-sphinx", + "futures", + "git-version", + "hex", + "home", + "indicatif", + "jsonrpsee", + "lightning-invoice", + "lnd-grpc-tonic-client", + "molecule", + "musig2", + "nom", + "num_enum", + "once_cell", + "ractor 0.14.2", + "rand 0.8.5", + "regex", + "secp256k1 0.28.2", + "serde", + "serde_json", + "serde_with", + "serde_yaml", + "socket2", + "strum", + "tentacle", + "thiserror 1.0.69", + "tokio", + "tokio-util", + "tracing", + "tracing-subscriber", +] + [[package]] name = "fnn-migrate" version = "0.3.0" @@ -1773,6 +1881,8 @@ dependencies = [ "fnn 0.2.1 (git+https://github.com/nervosnetwork/fiber.git?tag=v0.2.1)", "fnn 0.2.1 (git+https://github.com/nervosnetwork/fiber.git?tag=v0.3.0-rc1)", "fnn 0.3.1", + "fnn 0.3.1 (git+https://github.com/nervosnetwork/fiber.git?tag=v0.3.1)", + "fnn 0.3.1 (git+https://github.com/chenyukang/fiber.git?branch=yukang-fix-480-keep-fail-tlc)", "hex", "indicatif", "serde", diff --git a/migrate/Cargo.toml b/migrate/Cargo.toml index badfb352..0fb00c4a 100644 --- a/migrate/Cargo.toml +++ b/migrate/Cargo.toml @@ -24,6 +24,8 @@ serde_json = "1.0.135" fiber_v020 = { package = "fnn", git = "https://github.com/nervosnetwork/fiber.git", tag = "v0.2.0" } fiber_v021 = { package = "fnn", git = "https://github.com/nervosnetwork/fiber.git", tag = "v0.2.1" } fiber_v030 = { package = "fnn", git = "https://github.com/nervosnetwork/fiber.git", tag = "v0.3.0-rc1" } +fiber_v031 = { package = "fnn", git = "https://github.com/nervosnetwork/fiber.git", tag = "v0.3.1" } +fiber_v032 = { package = "fnn", git = "https://github.com/chenyukang/fiber.git", branch = "yukang-fix-480-keep-fail-tlc"} [features] default = [] diff --git a/migrate/src/migrations/mig_20250123.rs b/migrate/src/migrations/mig_20250123.rs new file mode 100644 index 00000000..48d49180 --- /dev/null +++ b/migrate/src/migrations/mig_20250123.rs @@ -0,0 +1,151 @@ +use fiber::{store::migration::Migration, Error}; +use indicatif::ProgressBar; +use rocksdb::ops::Iterate; +use rocksdb::ops::Put; +use rocksdb::DB; +use std::{collections::HashSet, sync::Arc}; +use tracing::info; + +const MIGRATION_DB_VERSION: &str = "20250123051223"; + +pub use fiber_v031::fiber::channel::ChannelActorState as ChannelActorStateV031; +pub use fiber_v031::fiber::channel::{ + ChannelTlcInfo as ChannelTlcInfoV031, PendingTlcs as PendingTlcsV031, TlcInfo as TlcInfoV031, + TlcState as TlcStateV031, +}; + +use crate::util::convert; +pub use fiber_v032::fiber::channel::ChannelActorState as ChannelActorStateV032; +pub use fiber_v032::fiber::channel::{ + ChannelTlcInfo as ChannelTlcInfoV032, PendingTlcs as PendingTlcsV032, + PublicChannelInfo as PublicChannelInfoV032, TlcInfo as TlcInfoV032, TlcState as TlcStateV032, +}; + +pub struct MigrationObj { + version: String, +} + +impl MigrationObj { + pub fn new() -> Self { + Self { + version: MIGRATION_DB_VERSION.to_string(), + } + } +} + +fn convert_tlc_info(old: TlcInfoV031) -> TlcInfoV032 { + TlcInfoV032 { + channel_id: convert(old.channel_id), + status: convert(old.status), + tlc_id: convert(old.tlc_id), + amount: convert(old.amount), + payment_hash: convert(old.payment_hash), + expiry: convert(old.expiry), + hash_algorithm: convert(old.hash_algorithm), + onion_packet: convert(old.onion_packet), + shared_secret: convert(old.shared_secret), + created_at: convert(old.created_at), + removed_reason: convert(old.removed_reason), + previous_tlc: convert(old.previous_tlc), + // new field in v032 + removed_confirmed_at: None, + } +} + +fn convert_pending_tlcs(old: PendingTlcsV031) -> PendingTlcsV032 { + PendingTlcsV032 { + tlcs: old + .tlcs + .into_iter() + .map(|tlc| (convert_tlc_info(tlc))) + .collect(), + next_tlc_id: convert(old.next_tlc_id), + } +} + +impl Migration for MigrationObj { + fn migrate( + &self, + db: Arc, + _pb: Arc ProgressBar + Send + Sync>, + ) -> Result, Error> { + info!( + "MigrationObj::migrate to {} ...........", + MIGRATION_DB_VERSION + ); + + const CHANNEL_ACTOR_STATE_PREFIX: u8 = 0; + let prefix = vec![CHANNEL_ACTOR_STATE_PREFIX]; + + for (k, v) in db + .prefix_iterator(prefix.as_slice()) + .take_while(move |(col_key, _)| col_key.starts_with(prefix.as_slice())) + { + let old_channel_state: ChannelActorStateV031 = + bincode::deserialize(&v).expect("deserialize to old channel state"); + + let old_tlc_state = old_channel_state.tlc_state.clone(); + let new_tlc_state = TlcStateV032 { + offered_tlcs: convert_pending_tlcs(old_tlc_state.offered_tlcs), + received_tlcs: convert_pending_tlcs(old_tlc_state.received_tlcs), + retryable_tlc_operations: convert(old_tlc_state.retryable_tlc_operations), + applied_add_tlcs: convert(old_tlc_state.applied_add_tlcs), + // new field in v032 + applied_remove_tlcs: HashSet::new(), + waiting_ack: old_tlc_state.waiting_ack, + }; + + let new_channel_state = ChannelActorStateV032 { + state: convert(old_channel_state.state), + local_pubkey: convert(old_channel_state.local_pubkey), + remote_pubkey: convert(old_channel_state.remote_pubkey), + id: convert(old_channel_state.id), + funding_tx: old_channel_state.funding_tx, + funding_tx_confirmed_at: old_channel_state.funding_tx_confirmed_at, + funding_udt_type_script: old_channel_state.funding_udt_type_script, + is_acceptor: old_channel_state.is_acceptor, + to_local_amount: old_channel_state.to_local_amount, + to_remote_amount: old_channel_state.to_remote_amount, + local_reserved_ckb_amount: old_channel_state.local_reserved_ckb_amount, + remote_reserved_ckb_amount: old_channel_state.remote_reserved_ckb_amount, + commitment_fee_rate: old_channel_state.commitment_fee_rate, + commitment_delay_epoch: old_channel_state.commitment_delay_epoch, + funding_fee_rate: old_channel_state.funding_fee_rate, + signer: convert(old_channel_state.signer), + local_channel_public_keys: convert(old_channel_state.local_channel_public_keys), + commitment_numbers: convert(old_channel_state.commitment_numbers), + local_constraints: convert(old_channel_state.local_constraints), + remote_constraints: convert(old_channel_state.remote_constraints), + tlc_state: new_tlc_state, + remote_shutdown_script: old_channel_state.remote_shutdown_script, + local_shutdown_script: old_channel_state.local_shutdown_script, + last_commitment_signed_remote_nonce: old_channel_state + .last_commitment_signed_remote_nonce, + last_revoke_and_ack_remote_nonce: old_channel_state + .last_revoke_and_ack_remote_nonce, + last_committed_remote_nonce: old_channel_state.last_committed_remote_nonce, + latest_commitment_transaction: old_channel_state.latest_commitment_transaction, + remote_commitment_points: convert(old_channel_state.remote_commitment_points), + remote_channel_public_keys: convert(old_channel_state.remote_channel_public_keys), + local_shutdown_info: convert(old_channel_state.local_shutdown_info), + remote_shutdown_info: convert(old_channel_state.remote_shutdown_info), + reestablishing: old_channel_state.reestablishing, + created_at: old_channel_state.created_at, + public_channel_info: convert(old_channel_state.public_channel_info), + local_tlc_info: convert(old_channel_state.local_tlc_info), + remote_tlc_info: convert(old_channel_state.remote_tlc_info), + }; + + let new_channel_state_bytes = + bincode::serialize(&new_channel_state).expect("serialize to new channel state"); + + db.put(k, new_channel_state_bytes) + .expect("save new channel state"); + } + Ok(db) + } + + fn version(&self) -> &str { + &self.version + } +} diff --git a/migrate/src/migrations/mod.rs b/migrate/src/migrations/mod.rs index f6b0f1d5..8e4c259d 100644 --- a/migrate/src/migrations/mod.rs +++ b/migrate/src/migrations/mod.rs @@ -3,3 +3,4 @@ pub mod mig_20250114; pub mod mig_20250115; +pub mod mig_20250123; From 1dc65e0ba69cf11c0eb6436fc30fb7e3eb026558 Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 24 Jan 2025 10:29:07 +0800 Subject: [PATCH 29/35] add more test for send each other --- src/fiber/tests/payment.rs | 140 +++++++++++++++++++++++++++---------- 1 file changed, 105 insertions(+), 35 deletions(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 3e78a394..97c04b4f 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1418,6 +1418,87 @@ async fn test_send_payment_three_nodes_send_each_other_bench_test() { } } +#[tokio::test] +async fn test_send_payment_three_nodes_send_each_other_no_wait() { + init_tracing(); + let _span = tracing::info_span!("node", node = "test").entered(); + let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + &[ + ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), + ], + 3, + true, + ) + .await; + + let mut all_sent = vec![]; + let node_0_balance = nodes[0].get_local_balance_from_channel(channels[0]); + let node_2_balance = nodes[2].get_local_balance_from_channel(channels[1]); + + let amount = 100000; + let mut node_0_sent_fee = 0; + let mut node_0_sent_amount = 0; + let mut node_2_sent_fee = 0; + let mut node_2_sent_amount = 0; + for _i in 0..4 { + for _k in 0..3 { + let payment1 = nodes[0] + .send_payment_keysend(&nodes[2], amount, false) + .await + .unwrap(); + eprintln!( + "send: {} payment_hash: {:?} sent, fee: {:?}", + _i, payment1.payment_hash, payment1.fee + ); + node_0_sent_fee += payment1.fee; + node_0_sent_amount += amount; + } + + let payment2 = nodes[2] + .send_payment_keysend(&nodes[0], amount, false) + .await + .unwrap(); + all_sent.push((2, payment2.payment_hash)); + eprintln!( + "send: {} payment_hash: {:?} sent, fee: {:?}", + _i, payment2.payment_hash, payment2.fee + ); + node_2_sent_fee += payment2.fee; + node_2_sent_amount += amount; + } + + loop { + for (node_index, payment_hash) in all_sent.clone().iter() { + let node = &nodes[*node_index]; + node.wait_until_success(*payment_hash).await; + all_sent.retain(|x| x.1 != *payment_hash); + } + if all_sent.is_empty() { + break; + } + } + tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + let new_node_0_balance = nodes[0].get_local_balance_from_channel(channels[0]); + let new_node_2_balance = nodes[2].get_local_balance_from_channel(channels[1]); + eprintln!( + "node_0_balance: {}, new_node_0_balance: {}, node_0_sent_amount: {}, node_0_sent_fee: {}", + node_0_balance, new_node_0_balance, node_0_sent_amount, node_0_sent_fee, + ); + eprintln!( + "node_2_balance: {}, new_node_2_balance: {}, node_2_sent_amount: {}, node_2_sent_fee: {}", + node_2_balance, new_node_2_balance, node_2_sent_amount, node_2_sent_fee + ); + assert_eq!( + new_node_0_balance, + node_0_balance - node_0_sent_fee - 8 * amount + ); + assert_eq!( + new_node_2_balance, + node_2_balance - node_2_sent_fee + 8 * amount + ); +} + #[tokio::test] async fn test_send_payment_three_nodes_bench_test() { init_tracing(); @@ -1431,7 +1512,6 @@ async fn test_send_payment_three_nodes_bench_test() { true, ) .await; - let [mut node_1, mut node_2, mut node_3] = nodes.try_into().expect("3 nodes"); tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; @@ -1444,14 +1524,14 @@ async fn test_send_payment_three_nodes_bench_test() { let mut node_2_ch1_sent_amount = 0; let mut node_2_ch2_sent_amount = 0; - let old_node_1_amount = node_1.get_local_balance_from_channel(channels[0]); - let old_node_2_chnnale1_amount = node_2.get_local_balance_from_channel(channels[0]); - let old_node_2_chnnale2_amount = node_2.get_local_balance_from_channel(channels[1]); - let old_node_3_amount = node_3.get_local_balance_from_channel(channels[1]); + let old_node_1_amount = nodes[0].get_local_balance_from_channel(channels[0]); + let old_node_2_chnnale1_amount = nodes[1].get_local_balance_from_channel(channels[0]); + let old_node_2_chnnale2_amount = nodes[1].get_local_balance_from_channel(channels[1]); + let old_node_3_amount = nodes[2].get_local_balance_from_channel(channels[1]); for i in 1..=4 { - let payment1 = node_1 - .send_payment_keysend(&node_3, 1000, false) + let payment1 = nodes[0] + .send_payment_keysend(&nodes[2], 1000, false) .await .unwrap(); all_sent.insert((1, payment1.payment_hash, payment1.fee)); @@ -1459,8 +1539,8 @@ async fn test_send_payment_three_nodes_bench_test() { node_1_sent_fee += payment1.fee; node_2_got_fee += payment1.fee; - let payment2 = node_2 - .send_payment_keysend(&node_3, 1000, false) + let payment2 = nodes[1] + .send_payment_keysend(&nodes[2], 1000, false) .await .unwrap(); all_sent.insert((2, payment2.payment_hash, payment2.fee)); @@ -1468,8 +1548,8 @@ async fn test_send_payment_three_nodes_bench_test() { node_2_ch1_sent_amount += 1000; node1_got_amount += 1000; - let payment3 = node_2 - .send_payment_keysend(&node_1, 1000, false) + let payment3 = nodes[1] + .send_payment_keysend(&nodes[0], 1000, false) .await .unwrap(); all_sent.insert((2, payment3.payment_hash, payment3.fee)); @@ -1477,39 +1557,29 @@ async fn test_send_payment_three_nodes_bench_test() { node_2_ch2_sent_amount += 1000; node3_got_amount += 1000; - let payment4 = node_3 - .send_payment_keysend(&node_1, 1000, false) + let payment4 = nodes[2] + .send_payment_keysend(&nodes[0], 1000, false) .await .unwrap(); all_sent.insert((3, payment4.payment_hash, payment4.fee)); eprintln!("send: {} payment_hash: {:?} sent", i, payment4.payment_hash); + assert!(payment4.fee > 0); node_3_sent_fee += payment4.fee; node_2_got_fee += payment4.fee; } loop { - tokio::time::sleep(tokio::time::Duration::from_millis(3000)).await; - for (node_index, payment_hash, fee) in all_sent.clone().iter() { - let node = match node_index { - 1 => &mut node_1, - 2 => &mut node_2, - 3 => &mut node_3, - _ => unreachable!(), - }; - let status = node.get_payment_status(*payment_hash).await; - tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; - eprintln!("got payment: {:?} status: {:?}", payment_hash, status); - if status == PaymentSessionStatus::Success { - eprintln!("payment_hash: {:?} success", payment_hash); - all_sent.remove(&(*node_index, *payment_hash, *fee)); - } + nodes[*node_index - 1] + .wait_until_success(*payment_hash) + .await; + all_sent.remove(&(*node_index, *payment_hash, *fee)); } - let res = node_1.node_info().await; + let res = nodes[0].node_info().await; eprintln!("node1 node_info: {:?}", res); - let res = node_2.node_info().await; + let res = nodes[1].node_info().await; eprintln!("node2 node_info: {:?}", res); - let res = node_3.node_info().await; + let res = nodes[2].node_info().await; eprintln!("node3 node_info: {:?}", res); if all_sent.is_empty() { break; @@ -1524,10 +1594,10 @@ async fn test_send_payment_three_nodes_bench_test() { // node3: sent 4 fee to node2, got 4000 from node2 // node2: got 8 from node1 and node3, sent 8000 to node1 and node3 - let node_1_amount = node_1.get_local_balance_from_channel(channels[0]); - let node_2_chnnale1_amount = node_2.get_local_balance_from_channel(channels[0]); - let node_2_chnnale2_amount = node_2.get_local_balance_from_channel(channels[1]); - let node_3_amount = node_3.get_local_balance_from_channel(channels[1]); + let node_1_amount = nodes[0].get_local_balance_from_channel(channels[0]); + let node_2_chnnale1_amount = nodes[1].get_local_balance_from_channel(channels[0]); + let node_2_chnnale2_amount = nodes[1].get_local_balance_from_channel(channels[1]); + let node_3_amount = nodes[2].get_local_balance_from_channel(channels[1]); let node_1_amount_diff = node_1_amount - old_node_1_amount; let node_2_chnnale1_amount_diff = old_node_2_chnnale1_amount - node_2_chnnale1_amount; From 38efe61f51d62dcec55036a6c335354392594ecf Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 24 Jan 2025 11:30:49 +0800 Subject: [PATCH 30/35] add filter failed tlc for tlc balance --- src/fiber/channel.rs | 26 ++++++++++++-------------- src/fiber/tests/payment.rs | 11 ++++++++--- src/rpc/channel.rs | 4 ++-- 3 files changed, 22 insertions(+), 19 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 181d19a6..915bc7ca 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -2614,18 +2614,14 @@ impl TlcInfo { self.status.as_inbound_status() } - pub fn is_remove_comfirmed(&self) -> bool { - match self.status { - TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, - TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) => true, - TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, - _ => false, - } - } - pub fn is_fail_remove_confirmed(&self) -> bool { matches!(self.removed_reason, Some(RemoveTlcReason::RemoveTlcFail(_))) - && self.is_remove_comfirmed() + && match self.status { + TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) => true, + TlcStatus::Outbound(OutboundTlcStatus::RemoveWaitAck) => true, + TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) => true, + _ => false, + } } fn get_hash(&self) -> ShortHash { @@ -4202,14 +4198,16 @@ impl ChannelActorState { self.to_remote_amount } - pub fn get_offered_tlc_balance(&self) -> u128 { + pub fn get_offered_tlc_balance(&self, exclude_failed_tls: bool) -> u128 { self.get_all_offer_tlcs() + .filter(|tlc| !(exclude_failed_tls && tlc.is_fail_remove_confirmed())) .map(|tlc| tlc.amount) .sum::() } - pub fn get_received_tlc_balance(&self) -> u128 { + pub fn get_received_tlc_balance(&self, exclude_failed_tls: bool) -> u128 { self.get_all_received_tlcs() + .filter(|tlc| !(exclude_failed_tls && tlc.is_fail_remove_confirmed())) .map(|tlc| tlc.amount) .sum::() } @@ -4649,13 +4647,13 @@ impl ChannelActorState { } } if tlc.is_offered() { - let sent_tlc_value = self.get_offered_tlc_balance(); + let sent_tlc_value = self.get_offered_tlc_balance(false); debug_assert!(self.to_local_amount >= sent_tlc_value); if sent_tlc_value + tlc.amount > self.to_local_amount { return Err(ProcessingChannelError::TlcAmountExceedLimit); } } else { - let received_tlc_value = self.get_received_tlc_balance(); + let received_tlc_value = self.get_received_tlc_balance(false); debug_assert!(self.to_remote_amount >= received_tlc_value); if received_tlc_value + tlc.amount > self.to_remote_amount { debug!( diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 97c04b4f..8dd01d80 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2009,7 +2009,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { // in this test, we will make sure the payment should recovery after the fee is updated by the middle hop // there are two channels between node_1 and node_2, they are with the same fee rate // path finding will pick the channel with latest time, so channels[2] will be picked - // but we will update the fee rate of channels[1] to a higher one + // but we will update the fee rate of channels[2] to a higher one // so the payment will fail, but after the payment failed, the path finding should pick the channels[1] in the next try // in the end, all the payments should success init_tracing(); @@ -2025,7 +2025,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { true, ) .await; - let [node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); + let [node_0, mut node_1, node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); for _i in 0..6 { @@ -2037,7 +2037,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; } - node_2 + node_1 .update_channel_with_command( channels[2], UpdateCommand { @@ -2069,6 +2069,10 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { break; } } + + let channel_state = node_0.get_channel_actor_state(channels[0]); + assert_eq!(channel_state.get_offered_tlc_balance(true), 0); + assert!(channel_state.get_offered_tlc_balance(false) > 0); } async fn run_complex_network_with_params( @@ -2128,6 +2132,7 @@ async fn run_complex_network_with_params( break; } } + result } diff --git a/src/rpc/channel.rs b/src/rpc/channel.rs index 1a1024f5..42278169 100644 --- a/src/rpc/channel.rs +++ b/src/rpc/channel.rs @@ -421,8 +421,8 @@ where state: state.state.into(), local_balance: state.get_local_balance(), remote_balance: state.get_remote_balance(), - offered_tlc_balance: state.get_offered_tlc_balance(), - received_tlc_balance: state.get_received_tlc_balance(), + offered_tlc_balance: state.get_offered_tlc_balance(true), + received_tlc_balance: state.get_received_tlc_balance(true), latest_commitment_transaction_hash: state .latest_commitment_transaction .as_ref() From c5afa2f6d0aa9b3caf6670627a669bc58c1579e7 Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 24 Jan 2025 12:17:37 +0800 Subject: [PATCH 31/35] fix failed test case --- src/fiber/tests/payment.rs | 10 +++++++++- 1 file changed, 9 insertions(+), 1 deletion(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 8dd01d80..4e7dd8af 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2051,6 +2051,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + let mut succ_count = 0; loop { assert!(node_0.get_triggered_unexpected_events().await.is_empty()); assert!(node_1.get_triggered_unexpected_events().await.is_empty()); @@ -2059,10 +2060,16 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { for payment_hash in all_sent.clone().iter() { let status = node_0.get_payment_status(*payment_hash).await; - if status == PaymentSessionStatus::Success { + // FIXME: check why the first failed payment got build router error + // maybe the time gap of update graph + if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); all_sent.remove(payment_hash); + if status == PaymentSessionStatus::Success { + succ_count += 1; + } } + tokio::time::sleep(tokio::time::Duration::from_millis(100)).await; } if all_sent.is_empty() { @@ -2070,6 +2077,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { } } + assert!(succ_count > 0); let channel_state = node_0.get_channel_actor_state(channels[0]); assert_eq!(channel_state.get_offered_tlc_balance(true), 0); assert!(channel_state.get_offered_tlc_balance(false) > 0); From a78226b2da78d64bd82d8d3e40ac2010d5f9d66d Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 24 Jan 2025 12:26:05 +0800 Subject: [PATCH 32/35] fix get_oldest_failed_tlcs --- src/fiber/channel.rs | 8 ++++---- src/fiber/tests/payment.rs | 8 ++++++-- 2 files changed, 10 insertions(+), 6 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 915bc7ca..854b01d4 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -2740,11 +2740,11 @@ impl PendingTlcs { }) .collect::>(); - let failed_tlc_num_limit = 2; - if failed_tlcs.len() >= failed_tlc_num_limit { - failed_tlcs.sort_by(|a, b| a.1.cmp(&b.1)); - failed_tlcs[0..failed_tlcs.len() - failed_tlc_num_limit] + if failed_tlcs.len() > 1 { + failed_tlcs.sort_by_key(|a| a.1); + failed_tlcs .iter() + .take(failed_tlcs.len() - 1) .map(|(tlc_id, _)| *tlc_id) .collect() } else { diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 4e7dd8af..028baec0 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1478,7 +1478,7 @@ async fn test_send_payment_three_nodes_send_each_other_no_wait() { break; } } - tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; + tokio::time::sleep(tokio::time::Duration::from_millis(2000)).await; let new_node_0_balance = nodes[0].get_local_balance_from_channel(channels[0]); let new_node_2_balance = nodes[2].get_local_balance_from_channel(channels[1]); eprintln!( @@ -2121,7 +2121,11 @@ async fn run_complex_network_with_params( let mut result = vec![]; loop { for i in 0..6 { - assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); + let unexpected_events = nodes[i].get_triggered_unexpected_events().await; + if !unexpected_events.is_empty() { + eprintln!("node_{} got unexpected events: {:?}", i, unexpected_events); + unreachable!("unexpected events"); + } } for (i, payment_hash) in all_sent.clone().into_iter() { From d665a40bd87b96a9034803ebc0e75abd83424a9c Mon Sep 17 00:00:00 2001 From: yukang Date: Fri, 24 Jan 2025 14:32:57 +0800 Subject: [PATCH 33/35] code refactoring for check insert tlc --- src/fiber/channel.rs | 38 ++++++++++++++++++++++++-------------- src/fiber/tests/payment.rs | 18 ++++++++++++++++-- src/fiber/tests/tlc_op.rs | 4 +++- 3 files changed, 43 insertions(+), 17 deletions(-) diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 854b01d4..897bc455 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -478,10 +478,10 @@ where FiberChannelMessage::RevokeAndAck(revoke_and_ack) => { let need_commitment_signed = state.handle_revoke_and_ack_peer_message(&self.network, revoke_and_ack)?; + self.update_tlc_status_on_ack(myself, state).await; if need_commitment_signed { self.handle_commitment_signed_command(state)?; } - self.update_tlc_status_on_ack(myself, state).await; Ok(()) } FiberChannelMessage::ChannelReady(_channel_ready) => { @@ -715,12 +715,14 @@ where ); let need_commitment_signed = state.tlc_state.update_for_commitment_signed(); + + // flush remove tlc for received tlcs after replying ack for peer + self.apply_settled_remove_tlcs(myself, state, true).await; + if need_commitment_signed && !state.tlc_state.waiting_ack { self.handle_commitment_signed_command(state)?; } - // flush remove tlc for received tlcs after replying ack for peer - self.apply_settled_remove_tlcs(myself, state, true).await; Ok(()) } @@ -2970,7 +2972,7 @@ impl TlcState { self.need_another_commitment_signed() } - pub fn update_for_revoke_and_ack(&mut self) -> bool { + pub fn update_for_revoke_and_ack(&mut self, commitment_number: CommitmentNumbers) -> bool { self.set_waiting_ack(false); for tlc in self.offered_tlcs.tlcs.iter_mut() { match tlc.outbound_status() { @@ -2982,7 +2984,7 @@ impl TlcState { } OutboundTlcStatus::RemoveWaitAck => { tlc.status = TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(now_timestamp_as_millis_u64()); + tlc.removed_confirmed_at = Some(commitment_number.get_local()); } _ => {} } @@ -2998,7 +3000,7 @@ impl TlcState { } InboundTlcStatus::LocalRemoved => { tlc.status = TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed); - tlc.removed_confirmed_at = Some(now_timestamp_as_millis_u64()); + tlc.removed_confirmed_at = Some(commitment_number.get_remote()); } _ => {} } @@ -4629,20 +4631,20 @@ impl ChannelActorState { ))); } let payment_hash = tlc.payment_hash; - let tlc_infos: Vec<_> = self + let mut tlc_infos = self .tlc_state .all_tlcs() .filter(|tlc| tlc.payment_hash == payment_hash) - .map(|info| info.clone()) - .collect(); - if !tlc_infos.is_empty() { - if tlc_infos.iter().all(|t| t.is_fail_remove_confirmed()) { + .peekable(); + + if tlc_infos.peek().is_some() { + if tlc_infos.all(|t| t.is_fail_remove_confirmed()) { // If all the tlcs with the same payment hash are confirmed to be failed, // then it's safe to insert the new tlc, the old tlcs will be removed later. } else { return Err(ProcessingChannelError::RepeatedProcessing(format!( - "Trying to insert tlc with duplicate payment hash {:?} with tlcs {:?}", - payment_hash, tlc_infos + "Trying to insert tlc with duplicate payment hash {:?}", + payment_hash ))); } } @@ -4735,6 +4737,12 @@ impl ChannelActorState { .iter() .chain(failed_received_tlcs.iter()) { + assert!(matches!( + self.tlc_state.get(tlc_id).expect("TLC exists").status, + TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) + | TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) + )); + assert!(self.tlc_state.applied_remove_tlcs.contains(&tlc_id)); self.tlc_state.apply_remove_tlc(*tlc_id); } } @@ -6034,7 +6042,9 @@ impl ChannelActorState { self.increment_local_commitment_number(); self.append_remote_commitment_point(next_per_commitment_point); - let need_commitment_signed = self.tlc_state.update_for_revoke_and_ack(); + let need_commitment_signed = self + .tlc_state + .update_for_revoke_and_ack(self.commitment_numbers); network .send_message(NetworkActorMessage::new_notification( NetworkServiceEvent::RevokeAndAckReceived( diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 028baec0..ae699d91 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2130,11 +2130,11 @@ async fn run_complex_network_with_params( for (i, payment_hash) in all_sent.clone().into_iter() { let status = nodes[i].get_payment_status(payment_hash).await; + eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); if matches!( status, PaymentSessionStatus::Success | PaymentSessionStatus::Failed ) { - eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); result.push((payment_hash, status)); all_sent.remove(&(i, payment_hash)); } @@ -2145,6 +2145,13 @@ async fn run_complex_network_with_params( } } + // make sure all the channels are still workable with small accounts + for i in 0..6 { + if let Ok(res) = nodes[i].send_payment_keysend_to_self(500, false).await { + nodes[i].wait_until_success(res.payment_hash).await; + } + } + result } @@ -2167,12 +2174,19 @@ async fn test_send_payment_complex_network_payself_amount_exceeded() { // the channel amount is not enough, so payments maybe be failed let ckb_unit = 100_000_000; let res = run_complex_network_with_params(MIN_RESERVED_CKB + 1000 * ckb_unit, || { - (450 as u128 + (rand::random::() % 100) as u128) * ckb_unit + (400 as u128 + (rand::random::() % 100) as u128) * ckb_unit }) .await; + + // some may failed and some may success let failed_count = res .iter() .filter(|(_, status)| *status == PaymentSessionStatus::Failed) .count(); assert!(failed_count > 0); + let succ_count = res + .iter() + .filter(|(_, status)| *status == PaymentSessionStatus::Success) + .count(); + assert!(succ_count > 0); } diff --git a/src/fiber/tests/tlc_op.rs b/src/fiber/tests/tlc_op.rs index 177e4c6a..f321344b 100644 --- a/src/fiber/tests/tlc_op.rs +++ b/src/fiber/tests/tlc_op.rs @@ -328,7 +328,9 @@ impl Actor for TlcActor { let hash = sign_tlcs(tlcs); assert_eq!(hash, peer_hash); - state.tlc_state.update_for_revoke_and_ack(); + state + .tlc_state + .update_for_revoke_and_ack(CommitmentNumbers::default()); } } Ok(()) From 77577ab86456b9d081d3dd8d6c8e3048a9feef46 Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 26 Jan 2025 09:47:09 +0800 Subject: [PATCH 34/35] refactoring test for payments --- src/fiber/tests/payment.rs | 38 +++++++++++++++++--------------------- 1 file changed, 17 insertions(+), 21 deletions(-) diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index ae699d91..190535b2 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -1944,7 +1944,7 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { // https://github.com/nervosnetwork/fiber/issues/480 init_tracing(); let _span = tracing::info_span!("node", node = "test").entered(); - let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + let (mut nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( &[ ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), @@ -1954,20 +1954,19 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { true, ) .await; - let [node_0, node_1, mut node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); for _i in 0..5 { - let res = node_0 - .send_payment_keysend(&node_3, 1000, false) + let res = nodes[0] + .send_payment_keysend(&nodes[3], 1000, false) .await .unwrap(); all_sent.insert(res.payment_hash); tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; } - node_2 + nodes[2] .update_channel_with_command( channels[2], UpdateCommand { @@ -1982,13 +1981,12 @@ async fn test_send_payment_middle_hop_update_fee_multiple_payments() { tokio::time::sleep(tokio::time::Duration::from_millis(1000)).await; loop { - assert!(node_0.get_triggered_unexpected_events().await.is_empty()); - assert!(node_1.get_triggered_unexpected_events().await.is_empty()); - assert!(node_2.get_triggered_unexpected_events().await.is_empty()); - assert!(node_3.get_triggered_unexpected_events().await.is_empty()); + for i in 0..4 { + assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); + } for payment_hash in all_sent.clone().iter() { - let status = node_0.get_payment_status(*payment_hash).await; + let status = nodes[0].get_payment_status(*payment_hash).await; //eprintln!("got payment: {:?} status: {:?}", payment_hash, status); if status == PaymentSessionStatus::Failed || status == PaymentSessionStatus::Success { eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); @@ -2014,7 +2012,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { // in the end, all the payments should success init_tracing(); let _span = tracing::info_span!("node", node = "test").entered(); - let (nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( + let (mut nodes, channels) = create_n_nodes_with_index_and_amounts_with_established_channel( &[ ((0, 1), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), ((1, 2), (HUGE_CKB_AMOUNT, HUGE_CKB_AMOUNT)), @@ -2025,19 +2023,18 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { true, ) .await; - let [node_0, mut node_1, node_2, node_3] = nodes.try_into().expect("4 nodes"); let mut all_sent = HashSet::new(); for _i in 0..6 { - let res = node_0 - .send_payment_keysend(&node_3, 1000, false) + let res = nodes[0] + .send_payment_keysend(&nodes[3], 1000, false) .await .unwrap(); all_sent.insert(res.payment_hash); tokio::time::sleep(tokio::time::Duration::from_millis(10)).await; } - node_1 + nodes[1] .update_channel_with_command( channels[2], UpdateCommand { @@ -2053,13 +2050,12 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { let mut succ_count = 0; loop { - assert!(node_0.get_triggered_unexpected_events().await.is_empty()); - assert!(node_1.get_triggered_unexpected_events().await.is_empty()); - assert!(node_2.get_triggered_unexpected_events().await.is_empty()); - assert!(node_3.get_triggered_unexpected_events().await.is_empty()); + for i in 0..4 { + assert!(nodes[i].get_triggered_unexpected_events().await.is_empty()); + } for payment_hash in all_sent.clone().iter() { - let status = node_0.get_payment_status(*payment_hash).await; + let status = nodes[0].get_payment_status(*payment_hash).await; // FIXME: check why the first failed payment got build router error // maybe the time gap of update graph if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { @@ -2078,7 +2074,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { } assert!(succ_count > 0); - let channel_state = node_0.get_channel_actor_state(channels[0]); + let channel_state = nodes[0].get_channel_actor_state(channels[0]); assert_eq!(channel_state.get_offered_tlc_balance(true), 0); assert!(channel_state.get_offered_tlc_balance(false) > 0); } From 6eb9d269517cb592f9f0526293d51a178c9d4cc0 Mon Sep 17 00:00:00 2001 From: yukang Date: Sun, 26 Jan 2025 10:21:28 +0800 Subject: [PATCH 35/35] fix index error for fee not enough --- Cargo.toml | 5 +++++ src/fiber/channel.rs | 7 +------ src/fiber/history.rs | 4 ++-- src/fiber/tests/payment.rs | 7 +++---- 4 files changed, 11 insertions(+), 12 deletions(-) diff --git a/Cargo.toml b/Cargo.toml index e6f6ad6d..1f4e184c 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -77,6 +77,11 @@ overflow-checks = true [profile.dev] panic = "abort" +[profile.quick_test] +inherits = "test" +opt-level = 3 +debug = false + [dev-dependencies] tempfile = "3.10.1" ckb-testtool = "0.13.2" diff --git a/src/fiber/channel.rs b/src/fiber/channel.rs index 897bc455..6d11d233 100644 --- a/src/fiber/channel.rs +++ b/src/fiber/channel.rs @@ -4737,12 +4737,7 @@ impl ChannelActorState { .iter() .chain(failed_received_tlcs.iter()) { - assert!(matches!( - self.tlc_state.get(tlc_id).expect("TLC exists").status, - TlcStatus::Outbound(OutboundTlcStatus::RemoveAckConfirmed) - | TlcStatus::Inbound(InboundTlcStatus::RemoveAckConfirmed) - )); - assert!(self.tlc_state.applied_remove_tlcs.contains(&tlc_id)); + debug_assert!(self.tlc_state.applied_remove_tlcs.contains(&tlc_id)); self.tlc_state.apply_remove_tlc(*tlc_id); } } diff --git a/src/fiber/history.rs b/src/fiber/history.rs index 9f034bf0..898667b3 100644 --- a/src/fiber/history.rs +++ b/src/fiber/history.rs @@ -259,9 +259,9 @@ impl InternalResult { } TlcErrorCode::FeeInsufficient => { need_to_retry = true; - self.fail_pair_balanced(nodes, index); + self.fail_pair_balanced(nodes, index + 1); if index > 1 { - self.succeed_range_pairs(nodes, 0, index - 1); + self.succeed_range_pairs(nodes, 0, index); } } TlcErrorCode::IncorrectTlcExpiry => { diff --git a/src/fiber/tests/payment.rs b/src/fiber/tests/payment.rs index 190535b2..5033c132 100644 --- a/src/fiber/tests/payment.rs +++ b/src/fiber/tests/payment.rs @@ -2025,7 +2025,8 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { .await; let mut all_sent = HashSet::new(); - for _i in 0..6 { + let tx_count = 6; + for _i in 0..tx_count { let res = nodes[0] .send_payment_keysend(&nodes[3], 1000, false) .await @@ -2056,8 +2057,6 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { for payment_hash in all_sent.clone().iter() { let status = nodes[0].get_payment_status(*payment_hash).await; - // FIXME: check why the first failed payment got build router error - // maybe the time gap of update graph if status == PaymentSessionStatus::Success || status == PaymentSessionStatus::Failed { eprintln!("payment_hash: {:?} got status : {:?}", payment_hash, status); all_sent.remove(payment_hash); @@ -2073,7 +2072,7 @@ async fn test_send_payment_middle_hop_update_fee_should_recovery() { } } - assert!(succ_count > 0); + assert_eq!(succ_count, tx_count); let channel_state = nodes[0].get_channel_actor_state(channels[0]); assert_eq!(channel_state.get_offered_tlc_balance(true), 0); assert!(channel_state.get_offered_tlc_balance(false) > 0);