From 18cde831ad87cc1594c174587d7c0f4226d87656 Mon Sep 17 00:00:00 2001 From: benthecarman Date: Mon, 11 May 2026 11:49:05 -0500 Subject: [PATCH 1/3] Splice and open channels with all on-chain funds Use ldk-node's new splice_in_with_all and open_channel_with_all APIs, which compute the maximum drain amount net of fees and anchor reserves. This replaces the hand-rolled fee subtraction on splice and the hardcoded fee constant on channel open. Drop the amt parameter from the LightningWallet trait's open_channel_with_lsp and splice_to_lsp_channel methods. Every implementation discarded it; the signature now matches the contract. Co-Authored-By: Claude Opus 4.7 (1M context) --- graduated-rebalancer/src/lib.rs | 14 ++++---- orange-sdk/src/lightning_wallet.rs | 51 ++++++------------------------ 2 files changed, 17 insertions(+), 48 deletions(-) diff --git a/graduated-rebalancer/src/lib.rs b/graduated-rebalancer/src/lib.rs index 2afe6e3..3774eac 100644 --- a/graduated-rebalancer/src/lib.rs +++ b/graduated-rebalancer/src/lib.rs @@ -110,9 +110,10 @@ pub trait LightningWallet: Send + Sync { /// Check if we already have a channel with the LSP fn has_channel_with_lsp(&self) -> bool; - /// Open a channel with the LSP using on-chain funds + /// Open a channel with the LSP using all available on-chain funds + /// (minus fees and anchor reserves). fn open_channel_with_lsp( - &self, amt: Amount, + &self, ) -> Pin> + Send + '_>>; /// Wait for a channel pending notification, returns the new channel's outpoint @@ -120,9 +121,10 @@ pub trait LightningWallet: Send + Sync { &self, channel_id: u128, ) -> Pin + Send + '_>>; - /// Splice funds from on-chain to an existing channel with the LSP + /// Splice all available on-chain funds (minus fees and anchor reserves) into + /// an existing channel with the LSP. fn splice_to_lsp_channel( - &self, amt: Amount, + &self, ) -> Pin> + Send + '_>>; /// Wait for a splice pending notification, returns the splice outpoint @@ -344,7 +346,7 @@ where let (channel_outpoint, user_channel_id) = if self.ln_wallet.has_channel_with_lsp() { log_info!(self.logger, "Splicing into channel with LSP with on-chain funds"); - let user_chan_id = match self.ln_wallet.splice_to_lsp_channel(params.amount).await { + let user_chan_id = match self.ln_wallet.splice_to_lsp_channel().await { Ok(chan_id) => chan_id, Err(e) => { log_error!(self.logger, "Failed to open channel with LSP: {e:?}"); @@ -362,7 +364,7 @@ where } else { log_info!(self.logger, "Opening channel with LSP with on-chain funds"); - let user_chan_id = match self.ln_wallet.open_channel_with_lsp(params.amount).await { + let user_chan_id = match self.ln_wallet.open_channel_with_lsp().await { Ok(chan_id) => chan_id, Err(e) => { log_error!(self.logger, "Failed to open channel with LSP: {e:?}"); diff --git a/orange-sdk/src/lightning_wallet.rs b/orange-sdk/src/lightning_wallet.rs index 37961f6..21939c7 100644 --- a/orange-sdk/src/lightning_wallet.rs +++ b/orange-sdk/src/lightning_wallet.rs @@ -400,20 +400,16 @@ impl LightningWallet { } } - pub(crate) async fn splice_balance_into_channel( - &self, amount: Amount, - ) -> Result { + pub(crate) async fn splice_all_into_channel(&self) -> Result { // find existing channel to splice into let channels = self.inner.ldk_node.list_channels(); let channel = channels.iter().find(|c| c.counterparty_node_id == self.inner.lsp_node_id); match channel { Some(chan) => { - self.inner.ldk_node.splice_in( - &chan.user_channel_id, - chan.counterparty_node_id, - amount.sats_rounding_up(), - )?; + self.inner + .ldk_node + .splice_in_with_all(&chan.user_channel_id, chan.counterparty_node_id)?; Ok(chan.user_channel_id) }, None => { @@ -424,23 +420,9 @@ impl LightningWallet { } pub(crate) async fn open_channel_with_lsp(&self) -> Result { - let bal = self.inner.ldk_node.list_balances().spendable_onchain_balance_sats; - - // need a dummy p2wsh address to estimate the fee, p2wsh is used for LN channels - // let fake_addr = Address::p2wsh(Script::new(), self.inner.ldk_node.config().network); - // - // let fee = self - // .inner - // .ldk_node - // .onchain_payment() - // .estimate_send_all_to_address(&fake_addr, true, None)?; - // todo get real fee - let fee = 1000; - - let id = self.inner.ldk_node.open_channel( + let id = self.inner.ldk_node.open_channel_with_all( self.inner.lsp_node_id, self.inner.lsp_socket_addr.clone(), - bal - fee, None, None, )?; @@ -541,12 +523,9 @@ impl graduated_rebalancer::LightningWallet for LightningWallet { } fn open_channel_with_lsp( - &self, _amt: Amount, + &self, ) -> Pin> + Send + '_>> { - Box::pin(async move { - // we don't use the amount and just use our full spendable balance in open_channel_with_lsp - self.open_channel_with_lsp().await.map(|c| c.0) - }) + Box::pin(async move { self.open_channel_with_lsp().await.map(|c| c.0) }) } fn await_channel_pending( @@ -570,21 +549,9 @@ impl graduated_rebalancer::LightningWallet for LightningWallet { } fn splice_to_lsp_channel( - &self, amt: Amount, + &self, ) -> Pin> + Send + '_>> { - let bal = self.inner.ldk_node.list_balances(); - // if we don't have enough onchain balance, return error - // if we are within 1,000 sats of the amount, reduce the amount to account for fees - if bal.spendable_onchain_balance_sats < amt.sats_rounding_up() { - return Box::pin(async move { Err(NodeError::InsufficientFunds) }); - } else if bal.spendable_onchain_balance_sats < amt.sats_rounding_up() + 1_000 { - let reduced_amt = amt.saturating_sub(Amount::from_sats(1_000).expect("valid amount")); - return Box::pin(async move { - self.splice_balance_into_channel(reduced_amt).await.map(|c| c.0) - }); - } - - Box::pin(async move { self.splice_balance_into_channel(amt).await.map(|c| c.0) }) + Box::pin(async move { self.splice_all_into_channel().await.map(|c| c.0) }) } fn await_splice_pending( From df2bb05a0c1e131682579a7c1eca460e102d9ead Mon Sep 17 00:00:00 2001 From: benthecarman Date: Tue, 12 May 2026 16:05:38 -0500 Subject: [PATCH 2/3] Fix dummy wallet test stalls The dummy trusted wallet can miss payment wakeups or leave the rebalancer waiting after a failed LDK payment. Bound the dummy payment wait path and route test-only LDK shutdown through async timeouts so failures surface as test errors instead of CI stalls. --- orange-sdk/src/trusted_wallet/dummy.rs | 17 ++++++++++++----- orange-sdk/tests/integration_tests.rs | 2 +- orange-sdk/tests/test_utils.rs | 26 ++++++++++++++++++++++---- 3 files changed, 35 insertions(+), 10 deletions(-) diff --git a/orange-sdk/src/trusted_wallet/dummy.rs b/orange-sdk/src/trusted_wallet/dummy.rs index e223e01..a9b5bcd 100644 --- a/orange-sdk/src/trusted_wallet/dummy.rs +++ b/orange-sdk/src/trusted_wallet/dummy.rs @@ -166,6 +166,8 @@ impl DummyTrustedWallet { .await .unwrap(); } + + let _ = payment_success_sender.send(()); }, Event::PaymentReceived { payment_id, amount_msat, payment_hash, .. } => { // convert id @@ -258,10 +260,8 @@ impl DummyTrustedWallet { DummyTrustedWallet { current_bal_msats, payments, ldk_node, payment_success_flag } } - pub(crate) async fn await_payment_success(&self) { - let mut flag = self.payment_success_flag.clone(); - flag.mark_unchanged(); - let _ = flag.changed().await; + fn payment_wait_timeout() -> Duration { + if std::env::var("CI").is_ok() { Duration::from_secs(120) } else { Duration::from_secs(20) } } } @@ -384,6 +384,8 @@ impl TrustedWalletInterface for DummyTrustedWallet { ) -> Pin> + Send + '_>> { Box::pin(async move { let id = channelmanager::PaymentId(payment_hash); + let mut flag = self.payment_success_flag.clone(); + flag.mark_unchanged(); loop { if let Some(payment) = self.ldk_node.payment(&id) { let counterparty_skimmed_fee_msat = match payment.kind { @@ -408,7 +410,12 @@ impl TrustedWalletInterface for DummyTrustedWallet { PaymentStatus::Failed => return None, } } - self.await_payment_success().await; + if !matches!( + tokio::time::timeout(Self::payment_wait_timeout(), flag.changed()).await, + Ok(Ok(())) + ) { + return None; + } } }) } diff --git a/orange-sdk/tests/integration_tests.rs b/orange-sdk/tests/integration_tests.rs index 2ca01e6..eed4ff7 100644 --- a/orange-sdk/tests/integration_tests.rs +++ b/orange-sdk/tests/integration_tests.rs @@ -2208,7 +2208,7 @@ async fn test_lsp_connectivity_fallback() { assert!(!uri_with_lsp.from_trusted); // Now simulate LSP being offline by stopping it - let _ = lsp.stop(); + test_utils::stop_ldk_node("lsp", Arc::clone(&lsp)).await; // Wait a moment for the stop to take effect tokio::time::sleep(Duration::from_secs(2)).await; diff --git a/orange-sdk/tests/test_utils.rs b/orange-sdk/tests/test_utils.rs index c9defd5..c105f08 100644 --- a/orange-sdk/tests/test_utils.rs +++ b/orange-sdk/tests/test_utils.rs @@ -267,7 +267,7 @@ pub struct TestParams { impl TestParams { async fn stop(&self) { - self.wallet.stop().await; + stop_wallet("wallet", Arc::clone(&self.wallet)).await; #[cfg(feature = "_cashu-tests")] let _ = self._mint.stop().await; @@ -279,7 +279,25 @@ impl TestParams { } } -async fn stop_ldk_node(name: &'static str, node: Arc) { +async fn stop_wallet(name: &'static str, wallet: Arc) { + let (sender, receiver) = tokio::sync::oneshot::channel(); + std::thread::spawn(move || { + let res = tokio::runtime::Builder::new_multi_thread() + .enable_all() + .build() + .map(|runtime| runtime.block_on(async move { wallet.stop().await })); + if let Err(e) = res { + eprintln!("Warning: failed to create runtime for {name} stop: {e}"); + } + let _ = sender.send(()); + }); + + if tokio::time::timeout(Duration::from_secs(20), receiver).await.is_err() { + eprintln!("Warning: {name} stop timed out"); + } +} + +pub(crate) async fn stop_ldk_node(name: &'static str, node: Arc) { let (sender, receiver) = tokio::sync::oneshot::channel(); std::thread::spawn(move || { let _ = node.stop(); @@ -317,13 +335,13 @@ where res = &mut test_task => Ok(res), _ = tokio::time::sleep(test_timeout) => { test_task.abort(); - let _ = test_task.await; + let _ = tokio::time::timeout(Duration::from_secs(5), &mut test_task).await; Err(()) }, }; // Always clean up - let timeout = Duration::from_secs(30); + let timeout = Duration::from_secs(45); if tokio::time::timeout(timeout, params.stop()).await.is_err() { eprintln!("Warning: params stop timed out after {timeout:?}"); } From 124178e907b0afd21577f40b7b6033818c3676fb Mon Sep 17 00:00:00 2001 From: benthecarman Date: Tue, 12 May 2026 16:58:51 -0500 Subject: [PATCH 3/3] Log Rust test progress in CI Enable CI to show Rust integration test logs by running both Rust test jobs with nocapture and setting RUST_LOG for the SDK, rebalancer, LDK node, and test harness targets. Mark the integration tests with the existing test-log attribute and add progress breadcrumbs around shared setup, polling waits, test execution, and cleanup. This should make future stalls show the phase and test location that stopped making progress. --- .github/workflows/tests.yml | 8 ++- orange-sdk/tests/integration_tests.rs | 24 +++++++++ orange-sdk/tests/test_utils.rs | 75 +++++++++++++++++++++++++-- 3 files changed, 102 insertions(+), 5 deletions(-) diff --git a/.github/workflows/tests.yml b/.github/workflows/tests.yml index c44d042..78721d4 100644 --- a/.github/workflows/tests.yml +++ b/.github/workflows/tests.yml @@ -11,6 +11,10 @@ concurrency: group: ${{ github.workflow }}-${{ github.ref }} cancel-in-progress: true +env: + RUST_BACKTRACE: 1 + RUST_LOG: orange_sdk=debug,graduated_rebalancer=debug,ldk_node=info,integration_tests=info,test_utils=info + jobs: rust_tests: name: Rust Checks @@ -40,7 +44,7 @@ jobs: run: cargo check -p orange-cli - name: Run tests - run: cargo test --features _test-utils -- --test-threads=2 + run: cargo test --features _test-utils -- --test-threads=2 --nocapture cashu_tests: name: Cashu Tests @@ -59,4 +63,4 @@ jobs: - uses: Swatinem/rust-cache@v2.7.8 - name: Run cashu tests - run: cargo test --features _cashu-tests -- --test-threads=2 + run: cargo test --features _cashu-tests -- --test-threads=2 --nocapture diff --git a/orange-sdk/tests/integration_tests.rs b/orange-sdk/tests/integration_tests.rs index eed4ff7..a2dac0e 100644 --- a/orange-sdk/tests/integration_tests.rs +++ b/orange-sdk/tests/integration_tests.rs @@ -16,6 +16,7 @@ use std::time::Duration; mod test_utils; #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_node_start() { test_utils::run_test(|params| async move { let bal = params.wallet.get_balance().await.unwrap(); @@ -84,6 +85,7 @@ async fn test_receive_to_trusted() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_pay_from_trusted() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -168,6 +170,7 @@ async fn test_pay_from_trusted() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_sweep_to_ln() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -327,6 +330,7 @@ async fn test_sweep_to_ln() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_receive_to_ln() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -694,6 +698,7 @@ async fn run_test_pay_lightning_from_self_custody(amountless: bool) { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_pay_lightning_from_self_custody() { run_test_pay_lightning_from_self_custody(false).await; run_test_pay_lightning_from_self_custody(true).await; @@ -788,12 +793,14 @@ async fn run_test_pay_bolt12_from_self_custody(amountless: bool) { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_pay_bolt12_from_self_custody() { run_test_pay_bolt12_from_self_custody(false).await; run_test_pay_bolt12_from_self_custody(true).await; } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_pay_onchain_from_self_custody() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1009,6 +1016,7 @@ async fn test_pay_onchain_from_channel() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_force_close_handling() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1058,6 +1066,7 @@ async fn test_force_close_handling() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_close_all_channels() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1099,6 +1108,7 @@ async fn test_close_all_channels() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_threshold_boundary_trusted_balance_limit() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1182,6 +1192,7 @@ async fn test_threshold_boundary_trusted_balance_limit() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_threshold_boundary_rebalance_min() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1260,6 +1271,7 @@ async fn test_threshold_boundary_rebalance_min() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_threshold_boundary_onchain_receive_threshold() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1329,6 +1341,7 @@ async fn test_threshold_boundary_onchain_receive_threshold() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_threshold_combinations_and_edge_cases() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1393,6 +1406,7 @@ async fn test_threshold_combinations_and_edge_cases() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_invalid_payment_instructions() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1459,6 +1473,7 @@ async fn test_invalid_payment_instructions() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_payment_with_expired_invoice() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1492,6 +1507,7 @@ async fn test_payment_with_expired_invoice() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_payment_network_mismatch() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1554,6 +1570,7 @@ async fn test_payment_network_mismatch() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_concurrent_payments() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1750,6 +1767,7 @@ async fn test_concurrent_payments() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_concurrent_receive_operations() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1809,6 +1827,7 @@ async fn test_concurrent_receive_operations() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_balance_consistency_under_load() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1864,6 +1883,7 @@ async fn test_balance_consistency_under_load() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_invalid_tunables_relationships() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -1956,6 +1976,7 @@ async fn test_invalid_tunables_relationships() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_extreme_amount_handling() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -2027,6 +2048,7 @@ async fn test_extreme_amount_handling() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_wallet_configuration_validation() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -2093,6 +2115,7 @@ async fn test_wallet_configuration_validation() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_edge_case_payment_instruction_parsing() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); @@ -2149,6 +2172,7 @@ async fn test_edge_case_payment_instruction_parsing() { } #[tokio::test(flavor = "multi_thread")] +#[test_log::test] async fn test_lsp_connectivity_fallback() { test_utils::run_test(|params| async move { let wallet = Arc::clone(¶ms.wallet); diff --git a/orange-sdk/tests/test_utils.rs b/orange-sdk/tests/test_utils.rs index c105f08..2436f6a 100644 --- a/orange-sdk/tests/test_utils.rs +++ b/orange-sdk/tests/test_utils.rs @@ -45,11 +45,14 @@ where }; let start = tokio::time::Instant::now(); let mut delay = Duration::from_millis(50); + log::info!("waiting for condition: {condition_name}"); loop { if condition().await { + log::info!("condition met: {condition_name} after {:?}", start.elapsed()); return; } if start.elapsed() >= timeout { + log::warn!("condition timed out: {condition_name} after {:?}", start.elapsed()); panic!("Timeout waiting for condition: {condition_name}"); } tokio::time::sleep(delay).await; @@ -312,14 +315,63 @@ pub(crate) async fn stop_ldk_node(name: &'static str, node: Arc) { /// Runs a test with automatically managed TestParams lifecycle. /// The test closure receives TestParams and must return it when done. /// Cleanup happens automatically after the test completes. -pub async fn run_test(test: F) +#[track_caller] +pub fn run_test(test: F) -> impl Future where F: FnOnce(TestParams) -> Fut + Send + 'static, Fut: Future + Send + 'static, { + let caller = std::panic::Location::caller(); + let test_name = format!("{}:{}", caller.file(), caller.line()); + + async move { run_test_with_name(test_name, test).await } +} + +async fn run_test_with_name(test_name: String, test: F) +where + F: FnOnce(TestParams) -> Fut + Send + 'static, + Fut: Future + Send + 'static, +{ + let lifecycle_timeout = if std::env::var("CI").is_ok() { + Duration::from_secs(20 * 60) + } else { + Duration::from_secs(10 * 60) + }; + + log::info!("spawning test lifecycle for {test_name}"); + + let (sender, receiver) = tokio::sync::oneshot::channel(); + let lifecycle_name = test_name.clone(); + std::thread::spawn(move || { + let result = std::panic::catch_unwind(std::panic::AssertUnwindSafe(|| { + let runtime = tokio::runtime::Builder::new_multi_thread() + .enable_all() + .build() + .expect("failed to create test runtime"); + runtime.block_on(run_test_inner(lifecycle_name, test)); + })); + let _ = sender.send(result); + }); + + match tokio::time::timeout(lifecycle_timeout, receiver).await { + Ok(Ok(Ok(()))) => {}, + Ok(Ok(Err(panic))) => std::panic::resume_unwind(panic), + Ok(Err(_)) => panic!("test lifecycle thread exited without a result"), + Err(_) => panic!("test lifecycle timed out after {lifecycle_timeout:?} for {test_name}"), + } +} + +async fn run_test_inner(test_name: String, test: F) +where + F: FnOnce(TestParams) -> Fut + Send + 'static, + Fut: Future + Send + 'static, +{ + log::info!("test lifecycle started for {test_name}"); + log::info!("building test nodes for {test_name}"); let params = build_test_nodes().await; - println!("=== test start ==="); + log::info!("test body starting for {test_name}"); + println!("=== test start: {test_name} ==="); let test_timeout = if std::env::var("CI").is_ok() { Duration::from_secs(15 * 60) @@ -334,6 +386,7 @@ where let test_result = tokio::select! { res = &mut test_task => Ok(res), _ = tokio::time::sleep(test_timeout) => { + log::warn!("test body timed out for {test_name} after {test_timeout:?}"); test_task.abort(); let _ = tokio::time::timeout(Duration::from_secs(5), &mut test_task).await; Err(()) @@ -342,9 +395,12 @@ where // Always clean up let timeout = Duration::from_secs(45); + log::info!("test cleanup starting for {test_name}"); if tokio::time::timeout(timeout, params.stop()).await.is_err() { + log::warn!("test cleanup timed out for {test_name} after {timeout:?}"); eprintln!("Warning: params stop timed out after {timeout:?}"); } + log::info!("test cleanup finished for {test_name}"); match test_result { Ok(Ok(())) => {}, @@ -356,11 +412,14 @@ where async fn build_test_nodes() -> TestParams { let test_id = Uuid::now_v7(); + log::info!("creating bitcoind and electrsd for {test_id}"); let (bitcoind, electrsd) = create_bitcoind(test_id).await; + log::info!("creating LSP and third-party nodes for {test_id}"); let lsp = create_lsp(test_id, &bitcoind); let third_party = create_third_party(test_id, &bitcoind); let start_bal = third_party.list_balances().total_onchain_balance_sats; + log::info!("funding LSP and third-party nodes for {test_id}"); fund_two_nodes(&lsp, &third_party, &bitcoind, &electrsd).await; // wait for node to sync (needs blocking wait as we are not in async context here) @@ -374,6 +433,7 @@ async fn build_test_nodes() -> TestParams { let lsp_listen = lsp.listening_addresses().unwrap().first().unwrap().clone(); // open a channel from payer to LSP + log::info!("opening third-party channel to LSP for {test_id}"); third_party.open_channel(lsp.node_id(), lsp_listen.clone(), 10_000_000, None, None).unwrap(); wait_for_tx_broadcast(&bitcoind).await; generate_blocks(&bitcoind, &electrsd, 6).await; @@ -395,6 +455,7 @@ async fn build_test_nodes() -> TestParams { #[cfg(not(feature = "_cashu-tests"))] let wallet = { + log::info!("creating dummy trusted wallet for {test_id}"); let dummy_wallet_config = DummyTrustedWalletExtraConfig { uuid: test_id, lsp: Arc::clone(&lsp), @@ -427,6 +488,7 @@ async fn build_test_nodes() -> TestParams { #[cfg(feature = "_cashu-tests")] { let tmp = temp_dir().join(format!("orange-test-{test_id}/cashu-ldk-node")); + log::info!("creating Cashu trusted wallet fixtures for {test_id}"); let cookie = bitcoind.params.get_cookie_values().unwrap().unwrap(); let bitcoind_port = bitcoind.params.rpc_socket.port(); let cdk_port = { @@ -569,11 +631,15 @@ async fn build_test_nodes() -> TestParams { }; let wallet = Arc::new(Wallet::new(wallet_config).await.unwrap()); + log::info!("finished building test nodes for {test_id}"); return TestParams { wallet, lsp, third_party, bitcoind, electrsd, _mint: mint }; }; #[cfg(not(feature = "_cashu-tests"))] - TestParams { wallet, lsp, third_party, bitcoind, electrsd } + { + log::info!("finished building test nodes for {test_id}"); + TestParams { wallet, lsp, third_party, bitcoind, electrsd } + } } pub async fn open_channel_from_lsp(wallet: &orange_sdk::Wallet, payer: Arc) -> Amount { @@ -626,12 +692,15 @@ async fn wait_for_tx_broadcast(bitcoind: &Bitcoind) { }; let start = tokio::time::Instant::now(); let mut delay = Duration::from_millis(50); + log::info!("waiting for tx broadcast"); loop { let num_txs = bitcoind.client.get_mempool_info().unwrap().size; if num_txs > 0 { + log::info!("tx broadcast observed after {:?}", start.elapsed()); break; } if start.elapsed() >= timeout { + log::warn!("tx broadcast timed out after {:?}", start.elapsed()); panic!("Timeout waiting for tx broadcast"); } tokio::time::sleep(delay).await;