diff --git a/core/archipelago/src/api/rpc/package/dependencies.rs b/core/archipelago/src/api/rpc/package/dependencies.rs index fbac1fc1..db61187d 100644 --- a/core/archipelago/src/api/rpc/package/dependencies.rs +++ b/core/archipelago/src/api/rpc/package/dependencies.rs @@ -467,6 +467,55 @@ where /// ElectrumX and Mempool's Electrum backend need historical blocks from an /// unpruned node while building their indexes. A pruned Bitcoin node can be /// running and RPC-reachable but still leave them stuck with closed ports. +/// How long to let Bitcoin finish starting before giving up on the pruning +/// pre-check. Matches `wait_for_bitcoin_rpc_gate`'s 180s so the two waits in +/// one install path agree about how patient "Bitcoin is starting" deserves to +/// be. +const BITCOIN_WARMUP_BUDGET: std::time::Duration = std::time::Duration::from_secs(180); + +/// Is this JSON-RPC error bitcoind saying "not ready yet" rather than "broken"? +/// +/// `-28` is RPC_IN_WARMUP: "Loading block index…", "Verifying blocks…", +/// "Rewinding blocks…". It is the normal path on every start, not a fault, and +/// it is the only error class worth waiting out — anything else (bad auth, +/// method not found) will not fix itself by retrying. Matched on the code, with +/// the message text as a fallback for any proxy that rewrites the envelope. +fn bitcoin_is_warming_up(error: &serde_json::Value) -> bool { + if error.get("code").and_then(serde_json::Value::as_i64) == Some(-28) { + return true; + } + error + .get("message") + .and_then(serde_json::Value::as_str) + .is_some_and(|m| { + let m = m.to_ascii_lowercase(); + m.contains("loading block index") + || m.contains("verifying blocks") + || m.contains("rewinding blocks") + || m.contains("loading wallet") + || m.contains("starting network threads") + }) +} + +/// Say once, in the install log, that we are waiting on Bitcoin — so a slow +/// install reads as "waiting for Bitcoin" instead of a stall, without one line +/// every two seconds. +async fn announce_warmup(announced: &mut bool, package_id: &str, error: &serde_json::Value) { + if *announced { + return; + } + *announced = true; + let detail = error + .get("message") + .and_then(serde_json::Value::as_str) + .unwrap_or("starting up"); + super::install::install_log(&format!( + "INSTALL WAIT: {package_id} — Bitcoin is still starting ({detail}); waiting up to {}s before the pruning check", + BITCOIN_WARMUP_BUDGET.as_secs() + )) + .await; +} + pub(super) async fn check_bitcoin_pruning_compatibility(package_id: &str) -> Result<()> { if !requires_unpruned_bitcoin(package_id) { return Ok(()); @@ -485,8 +534,27 @@ pub(super) async fn check_bitcoin_pruning_compatibility(package_id: &str) -> Res .build() .context("building Bitcoin RPC client")?; + // Bitcoin's warm-up is not a failure, and this check used to treat it as + // one. `for _ in 0..3` with a 2s sleep gave the node about six seconds to + // answer; bitcoind replies `-28` ("Loading block index…", "Verifying + // blocks…") for MINUTES on a large chainstate. So pressing install on any + // app that needs unpruned Bitcoin, in the ordinary window after Bitcoin + // starts, failed with a raw JSON-RPC error — reproduced on archi-dev-box + // 2026-08-08 installing ElectrumX right after Bitcoin Knots came up, and + // the likely mechanism behind "fedimint gateway disappeared at 88% + // install". + // + // The same install path already knows better: `wait_for_bitcoin_rpc_gate` + // waits up to 180s precisely because getblockchaininfo answers during + // sync. This check runs earlier and now shares that budget, so one concern + // is not handled two contradictory ways in one install. + // + // Only NOT-READY is waited out. A genuine fault — bad auth, connection + // refused, garbage response — still ends the loop on its own terms below. + let deadline = tokio::time::Instant::now() + BITCOIN_WARMUP_BUDGET; let mut last_error = None; - for _ in 0..3 { + let mut announced_warmup = false; + loop { match client .post(crate::constants::BITCOIN_RPC_URL) .basic_auth(&rpc_user, Some(&rpc_pass)) @@ -500,17 +568,33 @@ pub(super) async fn check_bitcoin_pruning_compatibility(package_id: &str) -> Res match resp.json::().await { Ok(json) if status.is_success() => { if let Some(error) = json.get("error").filter(|e| !e.is_null()) { - last_error = Some(format!( - "Bitcoin RPC error while checking pruning status: {error}" - )); + if bitcoin_is_warming_up(error) { + announce_warmup(&mut announced_warmup, package_id, error).await; + } else { + last_error = Some(format!( + "Bitcoin RPC error while checking pruning status: {error}" + )); + } } else { return check_blockchain_info_for_pruning(package_id, &json); } } + // bitcoind answers -28 with an HTTP 500, so warm-up lands + // here rather than in the success arm above. Ok(json) => { - last_error = Some(format!( - "Bitcoin RPC returned {status} while checking pruning status: {json}" - )); + let rpc_error = json.get("error").filter(|e| !e.is_null()); + if rpc_error.is_some_and(bitcoin_is_warming_up) { + announce_warmup( + &mut announced_warmup, + package_id, + rpc_error.unwrap_or(&serde_json::Value::Null), + ) + .await; + } else { + last_error = Some(format!( + "Bitcoin RPC returned {status} while checking pruning status: {json}" + )); + } } Err(e) => { last_error = Some(format!("decode Bitcoin RPC response: {e}")); @@ -521,6 +605,17 @@ pub(super) async fn check_bitcoin_pruning_compatibility(package_id: &str) -> Res last_error = Some(format!("checking Bitcoin pruning status: {e}")); } } + // A real fault ends the wait immediately — only NOT-READY loops. + if last_error.is_some() { + break; + } + if tokio::time::Instant::now() >= deadline { + last_error = Some(format!( + "Bitcoin was still starting up after {}s while checking pruning status", + BITCOIN_WARMUP_BUDGET.as_secs() + )); + break; + } tokio::time::sleep(std::time::Duration::from_secs(2)).await; } @@ -528,10 +623,19 @@ pub(super) async fn check_bitcoin_pruning_compatibility(package_id: &str) -> Res anyhow::bail!(archival_bitcoin_required_message(package_id)); } - anyhow::bail!( - "Bitcoin RPC unavailable while checking pruning status: {}", - last_error.unwrap_or_else(|| "unknown error".to_string()) - ); + // Say what the operator can act on. The old message pasted the raw + // JSON-RPC envelope, so a node that was merely still starting reported + // `{"error":{"code":-28,"message":"Verifying blocks…"}}` — accurate and + // useless to anyone deciding what to do next. + let detail = last_error.unwrap_or_else(|| "unknown error".to_string()); + if announced_warmup { + anyhow::bail!( + "Bitcoin is still starting up, so {package_id} can't be installed yet. \ + This can take several minutes on a large chain. Wait until Bitcoin \ + reports it's synced, then try again. (Details: {detail})" + ); + } + anyhow::bail!("Bitcoin RPC unavailable while checking pruning status: {detail}"); } fn check_blockchain_info_for_pruning(package_id: &str, json: &serde_json::Value) -> Result<()> { @@ -769,8 +873,9 @@ pub(super) fn configure_fedimint_lnd( #[cfg(test)] mod tests { use super::{ - dependency_list_declares_archival_bitcoin, manifest_declares_archival_bitcoin, - order_present_containers, requires_unpruned_bitcoin, startup_order, + bitcoin_is_warming_up, dependency_list_declares_archival_bitcoin, + manifest_declares_archival_bitcoin, order_present_containers, requires_unpruned_bitcoin, + startup_order, BITCOIN_WARMUP_BUDGET, }; use archipelago_container::Dependency; @@ -1218,4 +1323,55 @@ mod tests { // (bitcoin_integration.rpc_access: none) and correctly stays excluded. assert!(!requires_unpruned_bitcoin("archy-mempool-web")); } + + /// The distinction the pruning pre-check now turns on: bitcoind saying + /// "not ready yet" must be waited out, everything else must fail fast. + /// Getting this wrong in either direction is a real bug — too strict and + /// installs fail during every startup window (the ElectrumX failure on + /// archi-dev-box, 2026-08-08); too loose and a genuinely broken RPC hangs + /// the install for the full budget. + #[test] + fn warmup_is_recognised_by_code_and_by_message() { + let by_code = serde_json::json!({"code": -28, "message": "Verifying blocks…"}); + assert!(bitcoin_is_warming_up(&by_code)); + + // The exact payload that failed the ElectrumX install. + let observed = serde_json::json!({"code": -28, "message": "Verifying blocks…"}); + assert!(bitcoin_is_warming_up(&observed)); + + // Message fallback, for a proxy that rewrites the envelope and drops + // the code. + for msg in [ + "Loading block index...", + "Verifying blocks…", + "Rewinding blocks...", + "LOADING BLOCK INDEX", + ] { + let e = serde_json::json!({ "message": msg }); + assert!(bitcoin_is_warming_up(&e), "should be warm-up: {msg}"); + } + } + + #[test] + fn real_faults_are_not_mistaken_for_warmup() { + // These never fix themselves by waiting, so they must end the loop + // immediately rather than burn the full 180s budget. + for e in [ + serde_json::json!({"code": -32601, "message": "Method not found"}), + serde_json::json!({"code": -1, "message": "unauthorized"}), + serde_json::json!({"message": "Work queue depth exceeded"}), + serde_json::json!({}), + serde_json::Value::Null, + ] { + assert!(!bitcoin_is_warming_up(&e), "should NOT be warm-up: {e}"); + } + } + + #[test] + fn the_warmup_budget_matches_the_other_bitcoin_wait_in_this_install_path() { + // install.rs's wait_for_bitcoin_rpc_gate waits 180s for the same + // condition. Two different answers to "how long is Bitcoin allowed to + // be starting?" in one install is how this bug happened. + assert_eq!(BITCOIN_WARMUP_BUDGET.as_secs(), 180); + } }