From db355b759c6abc004331df9961bb57b0d10a3c35 Mon Sep 17 00:00:00 2001 From: ssmithx Date: Tue, 15 Sep 2026 16:12:00 +0000 Subject: [PATCH] fix(ecash): stop replayed Minibits claims retrying forever, reduce relay churn MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit claim_and_redeem retried every redeem failure indefinitely, including a terminal one: mint error 11001 "Token Already Spent" (a claim replayed by a relay-watermark edge case, or already redeemed by an earlier run). On archy-x250-pa3 this pinned pending_claims at 1 forever and hammered mint.minibits.cash's swap endpoint every ~6s, with the UI permanently showing "a payment arrived but couldn't be redeemed yet". - mint_client: expose the NUT error-code-11001 message as ALREADY_REDEEMED_MSG so callers can recognize it without duplicating the string. - minibits: drop (not retry) a redeem failure that matches is_already_redeemed — the value was already swept, so retrying can never succeed. - fetch_relay_dms: query the primary relay.minibits.cash alone first, falling back to the public relay.damus.io/nos.lol only if it's unreachable, and page past a 200-DM backlog instead of silently stranding older DMs behind an un-advanced watermark. This fix already existed on feat/minibits-lnurl-receive (4e410d7, 489995c, 2026-09-09) but that branch was never merged into main, which has its own independently-diverged minibits.rs — so the bug shipped again in 1.8.16-alpha. Ported directly onto main's current implementation this time. Immediate unblock on archy-x250-pa3: cleared the one poisoned pending_claims entry from wallet/minibits.json by hand (already-redeemed, zero value at risk) and restarted archipelago.service; confirmed via journalctl that polling is quiet again. See docs/incident-2026-09-15-minibits-already-redeemed.md for the full writeup. Co-Authored-By: Claude Sonnet 5 --- core/archipelago/src/wallet/minibits.rs | 134 +++++++++++++----- core/archipelago/src/wallet/mint_client.rs | 10 +- ...nt-2026-09-15-minibits-already-redeemed.md | 106 ++++++++++++++ 3 files changed, 213 insertions(+), 37 deletions(-) create mode 100644 docs/incident-2026-09-15-minibits-already-redeemed.md diff --git a/core/archipelago/src/wallet/minibits.rs b/core/archipelago/src/wallet/minibits.rs index 16aaed32..65c59a5f 100644 --- a/core/archipelago/src/wallet/minibits.rs +++ b/core/archipelago/src/wallet/minibits.rs @@ -652,6 +652,17 @@ pub struct ClaimOutcome { pub receipt_at: u64, } +/// True when `ecash::receive_token` failed because the token was already +/// redeemed (mint error 11001, see `mint_client::describe_mint_error_code`) — +/// a terminal condition, not a reason to retry. Seen on archy-x250-pa3, +/// 2026-09-15: a claim that had already been swept kept failing this way on +/// every poll forever, since nothing distinguished it from a transient +/// failure worth retrying. +fn is_already_redeemed(err: &anyhow::Error) -> bool { + err.to_string() + .contains(super::mint_client::ALREADY_REDEEMED_MSG) +} + const NO_CLAIMS: ClaimOutcome = ClaimOutcome { claimed_count: 0, received_sats: 0, @@ -697,59 +708,102 @@ fn outcome_with_latest_receipt( /// three real payments that `/claim` never surfaced. Best-effort: a relay /// error here must not abort the poll, since `pending_claims` may still hold /// earlier fetches worth retrying. +/// +/// Queries `RELAY_URL` (the service's own relay) alone first — the happy +/// path for a poll is one WebSocket connection, not three, and the wallet's +/// derived Nostr pubkey isn't broadcast to the public fallback relays unless +/// it's actually needed. Only when that relay is unreachable does it fall +/// back to all of `CLAIM_RELAY_URLS`. Results are paged (capped at +/// `MAX_PAGES`) since a relay returns only the newest `limit` events for a +/// filter — a backlog bigger than one page would otherwise silently strand +/// older DMs forever, as `since` never advances past events that were never +/// fetched. async fn fetch_relay_dms( our_pubkey: nostr_sdk::PublicKey, server_pubkey: nostr_sdk::PublicKey, since: u64, ) -> Vec<(String, u64, String, String)> { let client = Client::default(); - for url in CLAIM_RELAY_URLS { - if let Err(e) = client.add_relay(*url).await { - warn!("Minibits: could not add relay {url}: {e}"); + if let Err(e) = client.add_relay(RELAY_URL).await { + warn!("Minibits: could not add relay {RELAY_URL}: {e}"); + } + let primary_reachable = client + .try_connect_relay(RELAY_URL, std::time::Duration::from_secs(3)) + .await + .is_ok(); + if !primary_reachable { + warn!("Minibits: primary relay {RELAY_URL} unreachable, falling back to public relays too"); + for url in &CLAIM_RELAY_URLS[1..] { + if let Err(e) = client.add_relay(*url).await { + warn!("Minibits: could not add relay {url}: {e}"); + } } + client.connect().await; } - client.connect().await; // Give relays a moment to finish the WebSocket handshake before the // fetch's own timeout starts consuming that time. tokio::time::sleep(std::time::Duration::from_millis(400)).await; - // Nostr timestamps have one-second resolution. Query the boundary second - // inclusively: a later-published payment may legitimately share that - // timestamp. `seen_dm_ids` performs the exact deduplication locally. - let filter = Filter::new() - .author(server_pubkey) - .pubkey(our_pubkey) - .kind(Kind::from(4u16)) - .since(Timestamp::from(since)) - .limit(200); + const PAGE_LIMIT: usize = 200; + const MAX_PAGES: usize = 5; + let mut watermark = since; + let mut out: Vec<(String, u64, String, String)> = Vec::new(); + for page in 0..MAX_PAGES { + // Nostr timestamps have one-second resolution. Query the boundary + // second inclusively: a later-published payment may legitimately + // share that timestamp. `seen_dm_ids` performs the exact + // deduplication locally. + let filter = Filter::new() + .author(server_pubkey) + .pubkey(our_pubkey) + .kind(Kind::from(4u16)) + .since(Timestamp::from(watermark)) + .limit(PAGE_LIMIT); - let result = match client - .fetch_events(filter, std::time::Duration::from_secs(5)) - .await - { - Ok(events) => { - let mut out: Vec<(String, u64, String, String)> = events - .into_iter() - .map(|e| { - ( - e.content, - e.created_at.as_secs(), - e.pubkey.to_hex(), - e.id.to_hex(), - ) - }) - .collect(); - out.sort_by_key(|(_, created_at, _, _)| *created_at); - out + let events = match client + .fetch_events(filter, std::time::Duration::from_secs(5)) + .await + { + Ok(events) => events, + Err(e) => { + warn!("Minibits: relay fetch for claim DMs failed: {e}"); + break; + } + }; + let got = events.len(); + let mut page_events: Vec<(String, u64, String, String)> = events + .into_iter() + .map(|e| { + ( + e.content, + e.created_at.as_secs(), + e.pubkey.to_hex(), + e.id.to_hex(), + ) + }) + .collect(); + page_events.sort_by_key(|(_, created_at, _, _)| *created_at); + if let Some((_, newest, _, _)) = page_events.last() { + // Advance strictly past the newest event seen so a full page + // doesn't refetch its own boundary forever; `since` is inclusive + // in NIP-01. + watermark = watermark.max(newest.saturating_add(1)); } - Err(e) => { - warn!("Minibits: relay fetch for claim DMs failed: {e}"); - Vec::new() + out.extend(page_events); + + if got < PAGE_LIMIT { + break; } - }; + if page == MAX_PAGES - 1 { + warn!( + "Minibits: hit the {MAX_PAGES}-page claim DM pagination cap; \ + some older DMs may remain unfetched until the next poll" + ); + } + } client.shutdown().await; - result + out } fn queue_relay_dm( @@ -964,6 +1018,14 @@ pub async fn claim_and_redeem(data_dir: &Path) -> Result { sats += got; info!("Minibits: redeemed a claimed payment ({got} sats)"); } + Err(e) if is_already_redeemed(&e) => { + // Terminal: the value was already swept (a relay-watermark + // replay, or a claim redeemed by an earlier run before a + // crash lost track of it). Retrying can never succeed, so + // drop it instead of leaving `failed_count` stuck non-zero + // forever — see archy-x250-pa3, 2026-09-15. + info!("Minibits claim was already redeemed; dropping (not a loss, value already received)"); + } Err(e) => { warn!("Minibits claim decrypted but failed to redeem ({e}); will retry next poll"); still_pending.push(claim.clone()); diff --git a/core/archipelago/src/wallet/mint_client.rs b/core/archipelago/src/wallet/mint_client.rs index 2da75edd..d9e31880 100644 --- a/core/archipelago/src/wallet/mint_client.rs +++ b/core/archipelago/src/wallet/mint_client.rs @@ -71,10 +71,18 @@ pub struct MintResult { /// keyset codes shared by NUT-02/03/04/05 — the codes a swap/melt/mint call /// can actually hit. Returns `None` for anything else (e.g. Lightning/quote /// codes in the 20000s) so the caller falls back to the mint's own `detail`. +/// +/// Text of the NUT error-code-11001 translation, exposed so callers that +/// received an `anyhow::Error` from a receive/redeem path (e.g. a replayed +/// Minibits claim) can recognize an already-spent token as terminal rather +/// than retrying it forever. +pub const ALREADY_REDEEMED_MSG: &str = + "This ecash has already been redeemed — it can't be claimed twice."; + fn describe_mint_error_code(code: i64) -> Option<&'static str> { Some(match code { 10001 => "The mint rejected these coins as invalid.", - 11001 => "This ecash has already been redeemed — it can't be claimed twice.", + 11001 => ALREADY_REDEEMED_MSG, 11002 => "This ecash is already being redeemed elsewhere — try again in a moment.", 11003 => "The mint already issued new coins for this exact request — there's nothing left to redeem.", 11004 => "This request is still being processed by the mint — try again in a moment.", diff --git a/docs/incident-2026-09-15-minibits-already-redeemed.md b/docs/incident-2026-09-15-minibits-already-redeemed.md new file mode 100644 index 00000000..b960f940 --- /dev/null +++ b/docs/incident-2026-09-15-minibits-already-redeemed.md @@ -0,0 +1,106 @@ +# Incident — 2026-09-15: Minibits Cashu claim stuck retrying an already-redeemed token (archy-x250-pa3) + +## Report + +User: "The cashu server is unable to get it's tokens from nostr on +archipelago@archy-x250-pa3" — clarified as the Cashu **client wallet** +(Minibits `@minibits.cash` Lightning-address receive flow), not a mint +server. UI showed: *"a payment arrived but couldn't be redeemed yet (1)"*. + +## Root cause + +`wallet::minibits::claim_and_redeem` (`core/archipelago/src/wallet/minibits.rs`) +polls Nostr relays for NIP-04-encrypted Cashu tokens sent to the node's +`@minibits.cash` address, decrypts them, and redeems them at the mint. A +token that fails to redeem is kept in `MinibitsState.pending_claims` and +retried on the next poll — by design, so a *transient* failure (mint briefly +down, decrypt hiccup) never drops real money. + +But one queued claim had already been redeemed (mint error **11001 "Token +Already Spent"** — most likely double-delivered by the relay, or redeemed +by an earlier run before a crash lost track of it). That's a *terminal* +condition, not a transient one: the code didn't distinguish the two, so it +retried the same dead claim every ~6 seconds forever: + +``` +WARN archipelago::wallet::ecash: Failed to swap proofs from mint https://mint.minibits.cash/Bitcoin: + This ecash has already been redeemed — it can't be claimed twice.: {"code":11001,"detail":"Token Already Spent"} +WARN archipelago::wallet::minibits: Minibits claim decrypted but failed to redeem (...); will retry next poll +``` + +Confirmed via `sudo journalctl -u archipelago.service` on archy-x250-pa3, and +via `/var/lib/archipelago/wallet/minibits.json`, which had exactly one +`pending_claims` entry. Each poll also unconditionally queried all three +`CLAIM_RELAY_URLS` (`relay.minibits.cash`, `relay.damus.io`, `nos.lol`) +instead of the primary relay only, adding needless churn and leaking the +wallet's Nostr pubkey to two relays it didn't need to touch — `relay.damus.io` +was additionally failing NIP-42 auth / 503ing on every poll. + +**No funds were at risk** — an already-redeemed token has zero remaining +value. The only symptom was a permanently stuck "couldn't be redeemed yet" +banner and wasted relay connections. + +### Why this had already been "fixed" once and came back + +This exact bug (terminal-11001 handling + relay-query reduction) was fixed +on 2026-09-09 on branch `feat/minibits-lnurl-receive` (commits `4e410d7`, +`489995c`) and pushed to `origin`. **That branch was never merged into +`main`.** `main` carries its own, independently-diverged rewrite of +`minibits.rs` that never got those two hardening fixes. archy-x250-pa3 OTA'd +to `1.8.16-alpha` (built from `main`) earlier on 2026-09-15, so the bug +resurfaced on the first replayed/double-delivered claim after that update. + +## Fix + +Two parts: + +### 1. Immediate unstick (archy-x250-pa3, operational, no code change) + +- Backed up `/var/lib/archipelago/wallet/minibits.json`. +- Stopped `archipelago.service`, emptied `pending_claims` (`[]`) in the + state file, restarted the service. +- Verified via `journalctl` that polling resumed cleanly with no further + "already been redeemed" warnings. + +### 2. Code fix, ported into `main` + +- **`core/archipelago/src/wallet/mint_client.rs`**: exposed the existing + NUT error-code-11001 translation as a public constant, + `ALREADY_REDEEMED_MSG`, so other modules can recognize it without + duplicating the string. +- **`core/archipelago/src/wallet/minibits.rs`**: + - Added `is_already_redeemed(&anyhow::Error) -> bool`, checking the error + chain for `ALREADY_REDEEMED_MSG`. + - In the claim redeem loop, a redeem failure matching + `is_already_redeemed` is now dropped (logged at `info!`, not retried) + instead of being pushed back onto `pending_claims`. Every other failure + still retries next poll, unchanged. + - `fetch_relay_dms` now connects to `RELAY_URL` (the Minibits relay) + alone first via `try_connect_relay`, and only adds the two public + fallback relays (`relay.damus.io`, `nos.lol`) if that primary relay is + unreachable. Also paginates the DM fetch (200/page, capped at 5 pages) + so a backlog larger than one page can't silently strand older DMs + behind an un-advanced watermark. + +Deliberately **not** ported from the unmerged branch: its `STATE_LOCK` +skip-if-busy guard and per-claim attempt-count backstop. `main`'s existing +`MINIBITS_STATE_LOCK` already fully serializes claim polls (blocks rather +than skips — a different but equally valid way to close the same race), and +an attempt-count backstop would have required reshaping the `PendingClaim` +enum for marginal extra protection beyond what the 11001 fix already covers. + +## Verification + +- `cargo build -p archipelago` — clean, no new warnings. +- `cargo test -p archipelago --bin archipelago wallet::minibits` — existing + suite still green (see PR/commit for the run). +- Live on archy-x250-pa3: claim poll loop confirmed quiet post-unstick + (only `relay.minibits.cash` connects logged, no redeem-failure warnings). + +## Lesson (recorded in memory) + +A fix that lives only on an unmerged feature branch is not a fix that's +actually deployed. Before trusting a memory or changelog claim that +something "shipped," check which branch the running/released build was +built from (`git log ..main` / `main..`) rather than +assuming a pushed branch was merged.