From fa504102743ccf7a315d54a22eb339ee6c3d4a87 Mon Sep 17 00:00:00 2001 From: pi agent Date: Tue, 29 Sep 2026 15:58:54 +0000 Subject: [PATCH 1/4] fix(nwc): bound NWC requests so nwc status cannot hang forever applesauce-wallet-connect applies its request timeout only after it has negotiated encryption from the wallet's kind:13194 info event. On a stale or half-open relay subscription that negotiation never completes, so wallet.getInfo()/getBalance() wait forever and GET /nwc/status blocks indefinitely (the CLI fetch had no timeout either). - Bound NWC reads with withTimeout, rebuild the relay pool once on timeout, then retry; return a bounded error for status/fund. - Bound invoice payments and rebuild on timeout so later calls recover without a daemon restart. - Always start the auto-refill loop when configured, even when no wallet is connected yet, so a hot nwc connect activates it (previously it only started when a connection string existed at adapter creation). - Add a 120s AbortController timeout to CLI daemon requests. - Add timeout + recovery regression tests. --- src/daemon/wallet/auto-refill.ts | 11 +- src/daemon/wallet/index.nwc.test.ts | 155 +++++++++++++++++++++ src/daemon/wallet/index.ts | 204 ++++++++++++++++++++++------ src/utils/daemon-client.ts | 20 +++ src/utils/with-timeout.test.ts | 23 ++++ src/utils/with-timeout.ts | 20 +++ 6 files changed, 389 insertions(+), 44 deletions(-) create mode 100644 src/daemon/wallet/index.nwc.test.ts create mode 100644 src/utils/with-timeout.test.ts create mode 100644 src/utils/with-timeout.ts diff --git a/src/daemon/wallet/auto-refill.ts b/src/daemon/wallet/auto-refill.ts index 5f3fbae..39e9ea5 100644 --- a/src/daemon/wallet/auto-refill.ts +++ b/src/daemon/wallet/auto-refill.ts @@ -37,6 +37,15 @@ export function startAutoRefillLoop( getWallet: () => WalletConnect | undefined, getConfig: () => AutoRefillConfig | undefined, intervalMs: number = 5000, + payInvoice: ( + invoice: string, + ) => Promise<{ preimage?: string; fees_paid?: number }> = (invoice) => { + const wallet = getWallet(); + if (!wallet?.service) { + return Promise.reject(new Error("NWC not connected")); + } + return wallet.payInvoice(invoice); + }, ): () => void { let lastRefillAt = 0; let lastAttemptAt = 0; // tracks last attempt (success or failure) for backoff @@ -113,7 +122,7 @@ export function startAutoRefillLoop( logger.log("[auto-refill] Wallet disconnected during refill check"); return; } - const payment = await currentWallet.payInvoice(invoice); + const payment = await payInvoice(invoice); // Step 3: The Cashu mint should automatically detect the paid invoice // and issue tokens. We don't need to explicitly mint here; cocod diff --git a/src/daemon/wallet/index.nwc.test.ts b/src/daemon/wallet/index.nwc.test.ts new file mode 100644 index 0000000..b98c779 --- /dev/null +++ b/src/daemon/wallet/index.nwc.test.ts @@ -0,0 +1,155 @@ +import { afterAll, beforeEach, describe, expect, it, mock } from "bun:test"; +import type { CocodClient } from "./cocod-client"; + +/** + * Regression tests for the NWC hang fixed in this change. + * + * `applesauce-wallet-connect` applies its request timeout only after it has + * negotiated encryption from the wallet's `kind:13194` info event. On a stale + * relay subscription that negotiation never completes, so `getInfo()` / + * `getBalance()` wait forever. The adapter must bound the wait, rebuild the + * relay connection, and retry once instead of hanging `routstrd nwc status`. + */ + +type Behavior = "resolve" | "hang"; + +const state = { + infoQueue: [] as Behavior[], + balanceQueue: [] as Behavior[], + payQueue: [] as Behavior[], + createdInstances: 0, +}; + +function next(queue: Behavior[]): Behavior { + return queue.shift() ?? "resolve"; +} + +class MockRelayPool { + relays = new Map([["wss://relay.example", {}]]); + remove(url: string, _close?: boolean): void { + this.relays.delete(url); + } +} + +class MockWalletConnect { + service = "ab".repeat(32); + relays = ["wss://relay.example"]; + + constructor() { + state.createdInstances += 1; + } + + static fromConnectURI(_uri: string): MockWalletConnect { + return new MockWalletConnect(); + } + + waitForService(): Promise { + return Promise.resolve(this.service); + } + + getInfo(): Promise<{ + alias: string; + pubkey: string; + network: string; + methods: string[]; + }> { + if (next(state.infoQueue) === "hang") return new Promise(() => {}); + return Promise.resolve({ + alias: "Test Wallet", + pubkey: "cd".repeat(32), + network: "mainnet", + methods: ["get_balance", "get_info"], + }); + } + + getBalance(): Promise<{ balance: number }> { + if (next(state.balanceQueue) === "hang") return new Promise(() => {}); + return Promise.resolve({ balance: 123_000 }); + } + + payInvoice( + _invoice: string, + ): Promise<{ preimage: string; fees_paid: number }> { + if (next(state.payQueue) === "hang") return new Promise(() => {}); + return Promise.resolve({ preimage: "00".repeat(32), fees_paid: 1000 }); + } +} + +mock.module("applesauce-wallet-connect", () => ({ + WalletConnect: MockWalletConnect, +})); +mock.module("applesauce-relay", () => ({ RelayPool: MockRelayPool })); + +const { createWalletAdapter } = await import("./index"); + +function makeClient(): CocodClient { + return { + getBalances: async () => ({ "https://mint.example": 0 }), + getDefaultMint: async () => "https://mint.example", + receiveBolt11: async () => ({ invoice: "lnbc-test-invoice" }), + receiveCashu: async () => "ok", + } as unknown as CocodClient; +} + +function makeAdapter(timeoutMs = 25) { + return createWalletAdapter({ + walletClient: makeClient(), + nwcConnectionString: + "nostr+walletconnect://" + + "ab".repeat(32) + + "?relay=wss%3A%2F%2Frelay.example&secret=" + + "11".repeat(32), + nwcReadTimeoutMs: timeoutMs, + nwcPayTimeoutMs: timeoutMs, + }); +} + +beforeEach(() => { + state.infoQueue = []; + state.balanceQueue = []; + state.payQueue = []; + state.createdInstances = 0; +}); + +afterAll(() => { + mock.restore(); +}); + +describe("NWC status resilience", () => { + it("rebuilds a stale relay connection and still reports status", async () => { + state.infoQueue = ["hang"]; // first attempt stalls, retry succeeds + + const adapter = await makeAdapter(); + const status = await adapter.getNwcStatus(); + + expect(status.connected).toBe(true); + expect(status.alias).toBe("Test Wallet"); + expect(status.balance).toBe(123); + // initial connection + one rebuild + expect(state.createdInstances).toBe(2); + }); + + it("returns a bounded error instead of hanging forever", async () => { + state.infoQueue = ["hang", "hang"]; // every attempt stalls + + const adapter = await makeAdapter(); + const startedAt = Date.now(); + const status = await adapter.getNwcStatus(); + + expect(status.connected).toBe(false); + expect(status.error).toContain("timed out"); + expect(Date.now() - startedAt).toBeLessThan(2_000); + }); + + it("bounds a hung invoice payment and surfaces the error", async () => { + state.payQueue = ["hang"]; + + const adapter = await makeAdapter(); + const startedAt = Date.now(); + const result = await adapter.fundFromNWC(2100); + + expect(result.success).toBe(false); + expect(result.error).toContain("timed out"); + expect(Date.now() - startedAt).toBeLessThan(2_000); + }); +}); diff --git a/src/daemon/wallet/index.ts b/src/daemon/wallet/index.ts index a752c0a..99cf9e2 100644 --- a/src/daemon/wallet/index.ts +++ b/src/daemon/wallet/index.ts @@ -3,9 +3,21 @@ import { InsufficientBalanceError } from "@routstr/sdk"; import { WalletConnect } from "applesauce-wallet-connect"; import { RelayPool } from "applesauce-relay"; import { logger } from "../../utils/logger"; +import { withTimeout } from "../../utils/with-timeout"; import { createCocodClient, type CocodClient } from "./cocod-client"; import { startAutoRefillLoop, type AutoRefillConfig } from "./auto-refill"; +/** + * NWC reads (get_info/get_balance) should answer in a couple of seconds. If + * they don't, the long-lived relay subscription is presumed stale and the + * connection is rebuilt before one retry. + */ +const NWC_READ_TIMEOUT_MS = 15_000; +/** Lightning payments can legitimately take a little longer to settle. */ +const NWC_PAY_TIMEOUT_MS = 45_000; + +type NwcPayment = { preimage?: string; fees_paid?: number }; + export function decodeCashuTokenAmount(token: string): { amount: number; unit: "sat" | "msat"; @@ -37,6 +49,10 @@ export interface WalletAdapterOptions { walletClient?: CocodClient; /** NWC connection string for Lightning funding (uses applesauce-wallet-connect) */ nwcConnectionString?: string; + /** Override the NWC read timeout in milliseconds (test hook). */ + nwcReadTimeoutMs?: number; + /** Override the NWC payment timeout in milliseconds (test hook). */ + nwcPayTimeoutMs?: number; /** Auto-refill configuration (static, for startup only) */ autoRefill?: AutoRefillConfig; /** @@ -82,19 +98,44 @@ export async function createWalletAdapter( let wallet: WalletConnect | undefined; let pool: RelayPool | undefined; + let nwcConnectionString = options.nwcConnectionString; + const nwcReadTimeoutMs = options.nwcReadTimeoutMs ?? NWC_READ_TIMEOUT_MS; + const nwcPayTimeoutMs = options.nwcPayTimeoutMs ?? NWC_PAY_TIMEOUT_MS; // Getter for the current wallet instance (used by auto-refill loop) const getWallet = (): WalletConnect | undefined => wallet; - if (options.nwcConnectionString) { - pool = new RelayPool(); - wallet = WalletConnect.fromConnectURI(options.nwcConnectionString, { pool }); + /** Close the active relay pool, if any. */ + function closeNwcPool(): void { + if (pool) { + for (const [url] of pool.relays) { + pool.remove(url, true); + } + } + pool = undefined; + } + + /** + * (Re)create the relay pool + WalletConnect client for a connection string. + * Shared by interactive connects and self-healing recovery so both paths use + * identical setup. + */ + function connectNwc(connectionString: string, reason: string): void { + const nextPool = new RelayPool(); + const nextWallet = WalletConnect.fromConnectURI(connectionString, { + pool: nextPool, + }); + + pool = nextPool; + wallet = nextWallet; + nwcConnectionString = connectionString; // Connect in background (non-blocking) - wallet.waitForService() + nextWallet + .waitForService() .then(() => { logger.log( - `[nwc] NWC wallet connected. Relay: ${wallet!.relays[0]}, Service: ${wallet!.service}`, + `[nwc] NWC wallet ${reason}. Relay: ${nextWallet.relays[0]}, Service: ${nextWallet.service}`, ); }) .catch((err) => { @@ -102,41 +143,99 @@ export async function createWalletAdapter( }); } + /** + * Rebuild the NWC connection in place after a request stalled. applesauce's + * request timeout only covers the response stream, so a stale relay + * subscription can leave `getInfo`/`getBalance` pending forever while it + * negotiates encryption. Recreating the pool gives the next call a fresh + * subscription. + */ + function rebuildNwcConnection(reason: string): void { + if (!nwcConnectionString) return; + closeNwcPool(); + wallet = undefined; + connectNwc(nwcConnectionString, reason); + } + + /** + * Run an idempotent NWC read, bounding the wait and rebuilding the connection + * once if it stalls. + */ + async function nwcRead( + label: string, + operation: (w: WalletConnect) => Promise, + ): Promise { + const first = wallet; + if (!first?.service) { + throw new Error("NWC not connected"); + } + try { + return await withTimeout( + operation(first), + nwcReadTimeoutMs, + `${label} timed out`, + ); + } catch (error) { + if (!nwcConnectionString) throw error; + logger.warn( + `[nwc] ${label} failed (${(error as Error).message}); rebuilding NWC connection and retrying`, + ); + rebuildNwcConnection("reconnected after timeout"); + const retry = wallet; + if (!retry?.service) throw error; + return await withTimeout( + operation(retry), + nwcReadTimeoutMs, + `${label} timed out after reconnect`, + ); + } + } + + /** + * Pay a BOLT-11 invoice over NWC with a bounded wait. A timeout rebuilds the + * relay connection so later calls recover without a daemon restart. The + * payment is not retried here: the invoice itself is single-use, and the + * caller decides whether to attempt a fresh invoice. + */ + async function payNwcInvoice(invoice: string): Promise { + const payer = wallet; + if (!payer?.service) throw new Error("NWC not connected"); + try { + return await withTimeout( + payer.payInvoice(invoice), + nwcPayTimeoutMs, + "NWC payment timed out", + ); + } catch (error) { + rebuildNwcConnection("reconnected after payment timeout"); + throw error; + } + } + + if (options.nwcConnectionString) { + connectNwc(options.nwcConnectionString, "connected"); + } + const walletAdapter = { async reconnect(connectionString?: string): Promise { logger.log( `[nwc] Reconnecting NWC wallet... ${connectionString ? "new connection string provided" : "disconnecting"}`, ); - // 1. Close existing relay pool connections - if (pool) { - for (const [url] of pool.relays) { - pool.remove(url, true); - } - } - - // 2. Update wallet reference + // Close existing relay pool connections and update the wallet reference + closeNwcPool(); wallet = undefined; - pool = undefined; - // 3. Create new wallet if connection string provided if (connectionString) { - pool = new RelayPool(); - wallet = WalletConnect.fromConnectURI(connectionString, { pool }); - - // Connect in background (non-blocking) - wallet.waitForService() - .then(() => { - logger.log( - `[nwc] NWC wallet reconnected. Relay: ${wallet!.relays[0]}, Service: ${wallet!.service}`, - ); - }) - .catch((err) => { - logger.error(`[nwc] NWC reconnection failed: ${err.message}`); - }); + connectNwc(connectionString, "reconnected"); } else { + nwcConnectionString = undefined; logger.log("[nwc] NWC wallet disconnected."); } + + // A connection added after startup previously never started the + // auto-refill loop, so it silently stayed disabled until a restart. + ensureAutoRefillLoop(); }, async getBalances(): Promise> { @@ -192,9 +291,9 @@ export async function createWalletAdapter( const { invoice } = await client.receiveBolt11(amount, mintUrl); logger.log(`[nwc] Invoice: ${invoice}`); - // Step 3: Pay it via NWC + // Step 3: Pay it via NWC (bounded — a stale relay must not hang the CLI) logger.log("[nwc] Paying invoice via NWC..."); - const { preimage, fees_paid } = await wallet.payInvoice(invoice); + const { preimage, fees_paid } = await payNwcInvoice(invoice); logger.log(`[nwc] ✅ Payment successful!`); logger.log(`[nwc] Preimage: ${preimage}`); if (fees_paid !== undefined) { @@ -244,10 +343,10 @@ export async function createWalletAdapter( } try { - const info = await wallet.getInfo(); + const info = await nwcRead("get_info", (w) => w.getInfo()); let balance: number | undefined; try { - const bal = await wallet.getBalance(); + const bal = await nwcRead("get_balance", (w) => w.getBalance()); balance = Math.floor(bal.balance / 1000); // msats → sats } catch { // Balance might not be available @@ -326,21 +425,40 @@ export async function createWalletAdapter( let stopAutoRefill: (() => void) | undefined; + /** + * Start the auto-refill loop if it is not already running. Safe to call more + * than once; it becomes a no-op after the first call. + */ + function ensureAutoRefillLoop(): void { + if (stopAutoRefill) return; + const getConfig = options.getAutoRefillConfig ?? (() => options.autoRefill); + stopAutoRefill = startAutoRefillLoop( + client, + getWallet, + getConfig, + 5000, + payNwcInvoice, + ); + } + const autoRefillConfig = options.getAutoRefillConfig ? options.getAutoRefillConfig() : options.autoRefill; - if (autoRefillConfig && wallet) { - const getConfig = options.getAutoRefillConfig ?? (() => options.autoRefill); - stopAutoRefill = startAutoRefillLoop(client, getWallet, getConfig); - logger.log( - `[wallet] Auto-refill enabled: threshold=${autoRefillConfig.threshold} sats, amount=${autoRefillConfig.amount} sats, cooldown=${autoRefillConfig.cooldownMs / 60000} minutes`, - ); - } else if (wallet && options.getAutoRefillConfig) { - // Wallet exists but auto-refill is not currently enabled. - // Start the loop anyway so it can pick up changes without a restart. - stopAutoRefill = startAutoRefillLoop(client, getWallet, options.getAutoRefillConfig); - logger.log("[wallet] Auto-refill loop started (currently disabled — enable via CLI to activate)"); + if (options.getAutoRefillConfig || options.autoRefill) { + // Start the loop even when no wallet is connected yet: it reads the wallet + // and config fresh each cycle, so a later `nwc connect` activates refills + // without a daemon restart. + ensureAutoRefillLoop(); + if (autoRefillConfig) { + logger.log( + `[wallet] Auto-refill enabled: threshold=${autoRefillConfig.threshold} sats, amount=${autoRefillConfig.amount} sats, cooldown=${autoRefillConfig.cooldownMs / 60000} minutes`, + ); + } else { + logger.log( + "[wallet] Auto-refill loop started (currently disabled — enable via CLI to activate)", + ); + } } try { diff --git a/src/utils/daemon-client.ts b/src/utils/daemon-client.ts index 7ae13ef..a10e161 100644 --- a/src/utils/daemon-client.ts +++ b/src/utils/daemon-client.ts @@ -56,6 +56,13 @@ class DaemonConnectionError extends Error { } } +/** + * Upper bound for a single daemon request. The daemon bounds its own NWC + * operations, so this only guards against a wedged server; without it a hung + * request would block the CLI forever. + */ +export const DAEMON_REQUEST_TIMEOUT_MS = 120_000; + export function getDaemonBaseUrl(config: RoutstrdConfig): string { if (config.daemonUrl) { return config.daemonUrl.replace(/\/$/, ""); @@ -100,14 +107,27 @@ async function _callUrl( if (bodyString) headers.set("Content-Type", "application/json"); let response: Response; + const controller = new AbortController(); + const timeoutId = setTimeout( + () => controller.abort(), + DAEMON_REQUEST_TIMEOUT_MS, + ); try { response = await fetch(url, { method, headers, body: bodyString, + signal: controller.signal, }); } catch (error) { + if (controller.signal.aborted) { + throw new Error( + `Daemon request timed out after ${DAEMON_REQUEST_TIMEOUT_MS / 1000}s`, + ); + } throw new DaemonConnectionError(error); + } finally { + clearTimeout(timeoutId); } if (!response.ok) { diff --git a/src/utils/with-timeout.test.ts b/src/utils/with-timeout.test.ts new file mode 100644 index 0000000..88ab40d --- /dev/null +++ b/src/utils/with-timeout.test.ts @@ -0,0 +1,23 @@ +import { describe, expect, test } from "bun:test"; +import { withTimeout } from "./with-timeout"; + +describe("withTimeout", () => { + test("passes through a settled value", async () => { + await expect(withTimeout(Promise.resolve(42), 1000, "nope")).resolves.toBe( + 42, + ); + }); + + test("rejects with the provided message once the deadline elapses", async () => { + const never = new Promise(() => {}); + await expect(withTimeout(never, 20, "operation timed out")).rejects.toThrow( + "operation timed out", + ); + }); + + test("propagates the original rejection", async () => { + await expect( + withTimeout(Promise.reject(new Error("boom")), 1000, "unused"), + ).rejects.toThrow("boom"); + }); +}); diff --git a/src/utils/with-timeout.ts b/src/utils/with-timeout.ts new file mode 100644 index 0000000..f6d6fa4 --- /dev/null +++ b/src/utils/with-timeout.ts @@ -0,0 +1,20 @@ +/** + * Rejects when `timeoutMs` elapses before `promise` settles. + * + * Used to bound requests that may otherwise wait forever — notably NWC calls + * whose underlying library applies its own timeout only after a support/encryption + * handshake that can itself hang on a stale relay subscription. + */ +export function withTimeout( + promise: Promise, + timeoutMs: number, + message = "Operation timed out", +): Promise { + let timer: ReturnType | undefined; + const timeout = new Promise((_resolve, reject) => { + timer = setTimeout(() => reject(new Error(message)), timeoutMs); + }); + return Promise.race([promise, timeout]).finally(() => { + if (timer !== undefined) clearTimeout(timer); + }); +} From c3a29900ffc5df549787a376e2696c7883f4a66c Mon Sep 17 00:00:00 2001 From: pi agent Date: Tue, 29 Sep 2026 16:01:43 +0000 Subject: [PATCH 2/4] docs: add NWC_BUG.md writeup for the nwc status hang --- NWC_BUG.md | 238 +++++++++++++++++++++++++++++++++++++++++++++++++++++ 1 file changed, 238 insertions(+) create mode 100644 NWC_BUG.md diff --git a/NWC_BUG.md b/NWC_BUG.md new file mode 100644 index 0000000..03aa668 --- /dev/null +++ b/NWC_BUG.md @@ -0,0 +1,238 @@ +# NWC hang: `routstrd nwc status` never returns + +Investigation, root cause, fix, build, deployment, and verification. + +- **Date:** 2026-09-29 +- **Affected command:** `routstrd nwc status` (also `nwc fund` and the auto-refill loop) +- **Base version:** `routstrd` v0.4.11 +- **Fix branch / commit:** `fix/nwc-status-hang` — `ceb6d72` +- **Library involved:** `applesauce-wallet-connect@6.2.0` (latest at the time) + +--- + +## 1. Symptom + +`routstrd nwc status` hung forever. The local daemon was alive and healthy; +only the NWC endpoint blocked. + +``` +$ curl -m 6 http://127.0.0.1:8008/health # 3 ms +$ curl -m 85 http://127.0.0.1:8008/nwc/status # still pending after 85 s +``` + +The daemon logs showed the same wedge for manual funding attempts, which never +printed a result: + +``` +14:14:19 [nwc] Paying invoice via NWC... <- never completed +14:16:03 [nwc] Paying invoice via NWC... <- never completed +``` + +## 2. Call chain + +``` +cli.ts:2198 nwc status action + -> handleDaemonCommand("/nwc/status") utils/daemon-client.ts + -> ensureDaemonRunning() (health check, OK) + -> fetch(...) (no timeout originally) + -> GET /nwc/status daemon/http/index.ts:660 + -> deps.walletAdapter.getNwcStatus() wallet/index.ts + -> await wallet.getInfo() wallet/index.ts + -> await wallet.getBalance() wallet/index.ts +``` + +`wallet` is a `WalletConnect` instance from `applesauce-wallet-connect`. + +## 3. Root cause + +`applesauce-wallet-connect` applies its per-request timeout **only after** it has +negotiated an encryption scheme from the wallet's `kind:13194` info event: + +```js +genericCall(method, params, options = {}) { + return defer(async () => { + const encryption = await firstValueFrom(this.encryption$); // can block forever + return await WalletRequestFactory.create(...).sign(); + }).pipe( + switchMap((requestEvent) => { + const responses$ = this.events$.pipe( + ..., + simpleTimeout(options.timeout || this.defaultTimeout), // 30 s default + ); + return merge(request$, responses$); + }), + ); +} +``` + +If `encryption$` never emits, the `switchMap` (and therefore the timeout) is +never even created. `encryption$` derives from `support$`, which only emits when +the wallet service publishes a `kind:13194` wallet-info event. On a stale or +half-open relay subscription that event never arrives, so `getInfo()` / +`getBalance()` wait forever. + +The `"nip04"` fallback in `encryption$` is effectively unreachable (it maps over +`support$`, which is filtered to wallet-info events only). NWC only needs the +info event to *choose* encryption — it could default to nip04 and proceed, since +the service pubkey is already known from the connection URI. + +### Proof + +A standalone probe against an unreachable relay still had `getInfo()` pending +after 45 s, despite the library's advertised 30 s internal timeout: + +``` +service set from URI: true +internal defaultTimeout (s): 30 +RESULT: getInfo() STILL PENDING after 45.004s — internal timeout never fires +``` + +A fresh `WalletConnect` to the real relay returned `getInfo` in ~2 s, so the +wallet/relay themselves were fine — the daemon's long-lived relay subscription +had gone stale (the daemon still held a TCP socket to the relay, `67.205.128.242:443`). + +## 4. Contributing bugs in routstrd + +Even with the library defect, routstrd should not have been able to hang forever: + +1. **No timeout in the daemon's NWC calls.** `getNwcStatus`, `fundFromNWC` + (`wallet.payInvoice`), and the auto-refill loop had no bound. +2. **No timeout on the HTTP route.** `GET /nwc/status` just `await`s the payload; + so did every other route. +3. **No timeout on the CLI `fetch`.** `_callUrl()` in `utils/daemon-client.ts` + used `fetch` with no `AbortController`, so a hung daemon blocked the CLI. +4. **Auto-refill never started after a hot connect.** The loop was only started + during `createWalletAdapter(...)` when a connection string already existed at + startup. `nwc connect` hot-reloads via `walletAdapter.reconnect()`, which did + not start the loop — hence no `auto-refill` log lines at all. + +## 5. The fix + +Branch `fix/nwc-status-hang` (based on tag `v0.4.11`), commit `ceb6d72`. + +- **`src/utils/with-timeout.ts`** (new) + `withTimeout(promise, ms, message)` — `Promise.race` with a clearing timer. + +- **`src/daemon/wallet/index.ts`** + - NWC reads (`get_info` / `get_balance`) are bounded (default 15 s). On timeout, + the relay pool is closed, a fresh `WalletConnect`/`RelayPool` is created from + the stored connection string, and the read is retried once. + - Invoice payments are bounded (default 45 s). A timeout rebuilds the + connection so later calls recover without a daemon restart; the payment is + not auto-retried (the invoice is single-use — the caller decides). + - `ensureAutoRefillLoop()` starts the loop whenever auto-refill is configured, + even if no wallet is connected yet. `reconnect()` calls it, so a hot + `nwc connect` now activates refills without a restart. + - Timeouts are injectable (`nwcReadTimeoutMs`, `nwcPayTimeoutMs`) for tests. + +- **`src/daemon/wallet/auto-refill.ts`** + Takes the bounded `payInvoice` function instead of calling + `wallet.payInvoice` directly. + +- **`src/utils/daemon-client.ts`** + 120 s `AbortController` timeout on CLI daemon requests, with a distinct + "Daemon request timed out" error instead of a generic connection failure. + +- **Tests** + - `src/daemon/wallet/index.nwc.test.ts` — mocks `applesauce-wallet-connect` / + `applesauce-relay` and proves: (a) a stale connection is rebuilt and status + still succeeds, (b) two consecutive hangs produce a bounded error, (c) a hung + invoice payment returns an error instead of hanging. + - `src/utils/with-timeout.test.ts` — unit tests for the helper. + +Design note: this is defense-in-depth on routstrd's side. A request that stalls +now fails in bounded time and self-heals instead of blocking a user command or +the daemon's auto-refill loop. + +## 6. Build, install, restart + +```sh +cd /root/workspace/routstrd +bun run build # dist/index.js + dist/daemon/index.js +``` + +The original global package was backed up first: + +``` +/root/routstrd-backup-20260929-155718 +# path also stored in /root/.routstrd-build-backup-path +``` + +The new `dist/` (and matching `src/` files) were copied into +`/root/.bun/install/global/node_modules/routstrd/`, then: + +```sh +routstrd restart +``` + +Old daemon PID `90` -> new PID `21452`; `/health` was polled until healthy +before the command returned (~2 s). + +## 7. Verification + +``` +$ time routstrd nwc status +{ + "connected": true, + "alias": "Megalithic.me", + "network": "mainnet", + "balance": 60876, + "autoRefill": { "threshold": 30000, "amount": 21000, "cooldownMs": 30000 } +} +real 0m1.540s +``` + +``` +$ time curl -m30 http://127.0.0.1:8008/nwc/status +real 0m1.347s +``` + +The auto-refill loop now starts and actually runs: + +``` +[wallet] Auto-refill enabled: threshold=30000 sats, amount=21000 sats ... +[nwc] NWC wallet connected. Relay: wss://relay-nwc.rizful.com/v1 ... +[auto-refill] Paying invoice via NWC... +[auto-refill] Successfully refilled 21000 sats. Preimage: 49b20b7b... +``` + +`routstrd status` reports `wallet: connected`, balance `22820` sats. + +## 8. Test results + +New tests: **6 pass, 0 fail**. `bunx tsc --noEmit` is clean. + +The full suite still reports 4 failures that are **pre-existing on a clean +`v0.4.11`** and unrelated to this change: + +- 3 in `tests/utils/daemon-client.test.ts` — `tests/integrations/pi.test.ts` + calls `mock.module("../../src/utils/daemon-client", ...)` and the mock leaks + across files depending on run order. +- 1 in `src/daemon/wallet/diagnostics.test.ts` — the unreadable-file test relies + on `chmod 000`, which does not block reads when running as root. + +Confirmed by stashing the fix and running the suite on the pristine tag: same +4 failures. + +## 9. Rollback + +```sh +cp /root/routstrd-backup-20260929-155718/dist/index.js \ + /root/.bun/install/global/node_modules/routstrd/dist/index.js +cp /root/routstrd-backup-20260929-155718/dist/daemon/index.js \ + /root/.bun/install/global/node_modules/routstrd/dist/daemon/index.js +routstrd restart +``` + +## 10. Upstream recommendation + +`applesauce-wallet-connect@6.2.0` still has this defect. Suggested fixes +upstream: + +1. Apply the request timeout around the **whole** pipeline, e.g. move + `simpleTimeout` so it wraps `defer(async () => { ... }).pipe(switchMap(...))`, + not just the `responses$` stream inside it. +2. Make the `"nip04"` encryption fallback reachable (e.g. `startWith` on + `support$`, or default to nip04 when wallet info is not yet known). +3. Let `getInfo()` / `getBalance()` forward a timeout / `AbortSignal` to + `genericCall`. From 01fe864257b0dd2f62f08d98682134e09eaa7fd8 Mon Sep 17 00:00:00 2001 From: redshift <213178690+1ftredsh@users.noreply.github.com> Date: Fri, 2 Oct 2026 02:10:51 +0800 Subject: [PATCH 3/4] fix(nwc): preserve wallet error responses and bound CLI response bodies --- NWC_BUG.md | 238 ------------------------ docs/nwc-timeouts.md | 13 ++ src/daemon/wallet/coco-client.ts | 12 +- src/daemon/wallet/index.nwc.test.ts | 87 ++++++++- src/daemon/wallet/index.ts | 19 +- src/utils/daemon-client.timeout.test.ts | 79 ++++++++ src/utils/daemon-client.ts | 61 +++--- src/utils/with-timeout.ts | 1 + 8 files changed, 221 insertions(+), 289 deletions(-) delete mode 100644 NWC_BUG.md create mode 100644 docs/nwc-timeouts.md create mode 100644 src/utils/daemon-client.timeout.test.ts diff --git a/NWC_BUG.md b/NWC_BUG.md deleted file mode 100644 index 03aa668..0000000 --- a/NWC_BUG.md +++ /dev/null @@ -1,238 +0,0 @@ -# NWC hang: `routstrd nwc status` never returns - -Investigation, root cause, fix, build, deployment, and verification. - -- **Date:** 2026-09-29 -- **Affected command:** `routstrd nwc status` (also `nwc fund` and the auto-refill loop) -- **Base version:** `routstrd` v0.4.11 -- **Fix branch / commit:** `fix/nwc-status-hang` — `ceb6d72` -- **Library involved:** `applesauce-wallet-connect@6.2.0` (latest at the time) - ---- - -## 1. Symptom - -`routstrd nwc status` hung forever. The local daemon was alive and healthy; -only the NWC endpoint blocked. - -``` -$ curl -m 6 http://127.0.0.1:8008/health # 3 ms -$ curl -m 85 http://127.0.0.1:8008/nwc/status # still pending after 85 s -``` - -The daemon logs showed the same wedge for manual funding attempts, which never -printed a result: - -``` -14:14:19 [nwc] Paying invoice via NWC... <- never completed -14:16:03 [nwc] Paying invoice via NWC... <- never completed -``` - -## 2. Call chain - -``` -cli.ts:2198 nwc status action - -> handleDaemonCommand("/nwc/status") utils/daemon-client.ts - -> ensureDaemonRunning() (health check, OK) - -> fetch(...) (no timeout originally) - -> GET /nwc/status daemon/http/index.ts:660 - -> deps.walletAdapter.getNwcStatus() wallet/index.ts - -> await wallet.getInfo() wallet/index.ts - -> await wallet.getBalance() wallet/index.ts -``` - -`wallet` is a `WalletConnect` instance from `applesauce-wallet-connect`. - -## 3. Root cause - -`applesauce-wallet-connect` applies its per-request timeout **only after** it has -negotiated an encryption scheme from the wallet's `kind:13194` info event: - -```js -genericCall(method, params, options = {}) { - return defer(async () => { - const encryption = await firstValueFrom(this.encryption$); // can block forever - return await WalletRequestFactory.create(...).sign(); - }).pipe( - switchMap((requestEvent) => { - const responses$ = this.events$.pipe( - ..., - simpleTimeout(options.timeout || this.defaultTimeout), // 30 s default - ); - return merge(request$, responses$); - }), - ); -} -``` - -If `encryption$` never emits, the `switchMap` (and therefore the timeout) is -never even created. `encryption$` derives from `support$`, which only emits when -the wallet service publishes a `kind:13194` wallet-info event. On a stale or -half-open relay subscription that event never arrives, so `getInfo()` / -`getBalance()` wait forever. - -The `"nip04"` fallback in `encryption$` is effectively unreachable (it maps over -`support$`, which is filtered to wallet-info events only). NWC only needs the -info event to *choose* encryption — it could default to nip04 and proceed, since -the service pubkey is already known from the connection URI. - -### Proof - -A standalone probe against an unreachable relay still had `getInfo()` pending -after 45 s, despite the library's advertised 30 s internal timeout: - -``` -service set from URI: true -internal defaultTimeout (s): 30 -RESULT: getInfo() STILL PENDING after 45.004s — internal timeout never fires -``` - -A fresh `WalletConnect` to the real relay returned `getInfo` in ~2 s, so the -wallet/relay themselves were fine — the daemon's long-lived relay subscription -had gone stale (the daemon still held a TCP socket to the relay, `67.205.128.242:443`). - -## 4. Contributing bugs in routstrd - -Even with the library defect, routstrd should not have been able to hang forever: - -1. **No timeout in the daemon's NWC calls.** `getNwcStatus`, `fundFromNWC` - (`wallet.payInvoice`), and the auto-refill loop had no bound. -2. **No timeout on the HTTP route.** `GET /nwc/status` just `await`s the payload; - so did every other route. -3. **No timeout on the CLI `fetch`.** `_callUrl()` in `utils/daemon-client.ts` - used `fetch` with no `AbortController`, so a hung daemon blocked the CLI. -4. **Auto-refill never started after a hot connect.** The loop was only started - during `createWalletAdapter(...)` when a connection string already existed at - startup. `nwc connect` hot-reloads via `walletAdapter.reconnect()`, which did - not start the loop — hence no `auto-refill` log lines at all. - -## 5. The fix - -Branch `fix/nwc-status-hang` (based on tag `v0.4.11`), commit `ceb6d72`. - -- **`src/utils/with-timeout.ts`** (new) - `withTimeout(promise, ms, message)` — `Promise.race` with a clearing timer. - -- **`src/daemon/wallet/index.ts`** - - NWC reads (`get_info` / `get_balance`) are bounded (default 15 s). On timeout, - the relay pool is closed, a fresh `WalletConnect`/`RelayPool` is created from - the stored connection string, and the read is retried once. - - Invoice payments are bounded (default 45 s). A timeout rebuilds the - connection so later calls recover without a daemon restart; the payment is - not auto-retried (the invoice is single-use — the caller decides). - - `ensureAutoRefillLoop()` starts the loop whenever auto-refill is configured, - even if no wallet is connected yet. `reconnect()` calls it, so a hot - `nwc connect` now activates refills without a restart. - - Timeouts are injectable (`nwcReadTimeoutMs`, `nwcPayTimeoutMs`) for tests. - -- **`src/daemon/wallet/auto-refill.ts`** - Takes the bounded `payInvoice` function instead of calling - `wallet.payInvoice` directly. - -- **`src/utils/daemon-client.ts`** - 120 s `AbortController` timeout on CLI daemon requests, with a distinct - "Daemon request timed out" error instead of a generic connection failure. - -- **Tests** - - `src/daemon/wallet/index.nwc.test.ts` — mocks `applesauce-wallet-connect` / - `applesauce-relay` and proves: (a) a stale connection is rebuilt and status - still succeeds, (b) two consecutive hangs produce a bounded error, (c) a hung - invoice payment returns an error instead of hanging. - - `src/utils/with-timeout.test.ts` — unit tests for the helper. - -Design note: this is defense-in-depth on routstrd's side. A request that stalls -now fails in bounded time and self-heals instead of blocking a user command or -the daemon's auto-refill loop. - -## 6. Build, install, restart - -```sh -cd /root/workspace/routstrd -bun run build # dist/index.js + dist/daemon/index.js -``` - -The original global package was backed up first: - -``` -/root/routstrd-backup-20260929-155718 -# path also stored in /root/.routstrd-build-backup-path -``` - -The new `dist/` (and matching `src/` files) were copied into -`/root/.bun/install/global/node_modules/routstrd/`, then: - -```sh -routstrd restart -``` - -Old daemon PID `90` -> new PID `21452`; `/health` was polled until healthy -before the command returned (~2 s). - -## 7. Verification - -``` -$ time routstrd nwc status -{ - "connected": true, - "alias": "Megalithic.me", - "network": "mainnet", - "balance": 60876, - "autoRefill": { "threshold": 30000, "amount": 21000, "cooldownMs": 30000 } -} -real 0m1.540s -``` - -``` -$ time curl -m30 http://127.0.0.1:8008/nwc/status -real 0m1.347s -``` - -The auto-refill loop now starts and actually runs: - -``` -[wallet] Auto-refill enabled: threshold=30000 sats, amount=21000 sats ... -[nwc] NWC wallet connected. Relay: wss://relay-nwc.rizful.com/v1 ... -[auto-refill] Paying invoice via NWC... -[auto-refill] Successfully refilled 21000 sats. Preimage: 49b20b7b... -``` - -`routstrd status` reports `wallet: connected`, balance `22820` sats. - -## 8. Test results - -New tests: **6 pass, 0 fail**. `bunx tsc --noEmit` is clean. - -The full suite still reports 4 failures that are **pre-existing on a clean -`v0.4.11`** and unrelated to this change: - -- 3 in `tests/utils/daemon-client.test.ts` — `tests/integrations/pi.test.ts` - calls `mock.module("../../src/utils/daemon-client", ...)` and the mock leaks - across files depending on run order. -- 1 in `src/daemon/wallet/diagnostics.test.ts` — the unreadable-file test relies - on `chmod 000`, which does not block reads when running as root. - -Confirmed by stashing the fix and running the suite on the pristine tag: same -4 failures. - -## 9. Rollback - -```sh -cp /root/routstrd-backup-20260929-155718/dist/index.js \ - /root/.bun/install/global/node_modules/routstrd/dist/index.js -cp /root/routstrd-backup-20260929-155718/dist/daemon/index.js \ - /root/.bun/install/global/node_modules/routstrd/dist/daemon/index.js -routstrd restart -``` - -## 10. Upstream recommendation - -`applesauce-wallet-connect@6.2.0` still has this defect. Suggested fixes -upstream: - -1. Apply the request timeout around the **whole** pipeline, e.g. move - `simpleTimeout` so it wraps `defer(async () => { ... }).pipe(switchMap(...))`, - not just the `responses$` stream inside it. -2. Make the `"nip04"` encryption fallback reachable (e.g. `startWith` on - `support$`, or default to nip04 when wallet info is not yet known). -3. Let `getInfo()` / `getBalance()` forward a timeout / `AbortSignal` to - `genericCall`. diff --git a/docs/nwc-timeouts.md b/docs/nwc-timeouts.md new file mode 100644 index 0000000..1d8421d --- /dev/null +++ b/docs/nwc-timeouts.md @@ -0,0 +1,13 @@ +# NWC request timeouts + +In `applesauce-wallet-connect@6.2.0`, encryption negotiation waits for a wallet-info event (kind 13194) before starting the response timeout. If a relay subscription stalls before that event arrives, the library request can remain pending indefinitely. + +The wallet adapter adds an overall deadline: 15 seconds per read attempt and 45 seconds per payment. Reads can rebuild the relay connection and retry once. Payments are never automatically retried. The library still applies its own 30-second response timeout after negotiation; the 45-second deadline does not extend it. + +Normal NIP-47 wallet errors do not rebuild the shared relay connection: a wallet error proves a response arrived, and rebuilding could interrupt unrelated payments. Transport failures and timeouts, including the library's own timeout, still trigger recovery. + +CLI `/nwc/*` requests have a 120-second deadline covering headers and response-body consumption. Other daemon routes are not subject to this cap because mint payment operations may run longer and cannot be cancelled by aborting the CLI request. + +A payment timeout is an **unknown outcome**, not proof that no payment occurred. Promise deadlines do not cancel the underlying operation. Check the mint quote, wallet transactions, and Cashu balance before creating and paying another invoice. + +The auto-refill loop starts when static configuration or a dynamic configuration getter is supplied, even without an NWC connection at startup. It reads the current wallet and configuration each cycle, so a later connection can activate refills without restarting the daemon. diff --git a/src/daemon/wallet/coco-client.ts b/src/daemon/wallet/coco-client.ts index c8077c8..30a7854 100644 --- a/src/daemon/wallet/coco-client.ts +++ b/src/daemon/wallet/coco-client.ts @@ -1,3 +1,4 @@ +import { withTimeout as withRequestTimeout } from "../../utils/with-timeout"; import { Manager, OperationInProgressError, @@ -629,16 +630,7 @@ const EXPIRED_MINT_OBSERVATION_DEADLINE_MS = 15_000; /** Rejects when `timeoutMs` elapses before `promise` settles. */ function withTimeout(promise: Promise, timeoutMs: number): Promise { - let timer: ReturnType | undefined; - const timeout = new Promise((_resolve, reject) => { - timer = setTimeout( - () => reject(new Error("Timed out contacting mint")), - timeoutMs, - ); - }); - return Promise.race([promise, timeout]).finally(() => { - if (timer !== undefined) clearTimeout(timer); - }); + return withRequestTimeout(promise, timeoutMs, "Timed out contacting mint"); } /** Structural subset of coco's Manager used by expired-quote settlement. */ diff --git a/src/daemon/wallet/index.nwc.test.ts b/src/daemon/wallet/index.nwc.test.ts index b98c779..7cb86a1 100644 --- a/src/daemon/wallet/index.nwc.test.ts +++ b/src/daemon/wallet/index.nwc.test.ts @@ -1,4 +1,5 @@ import { afterAll, beforeEach, describe, expect, it, mock } from "bun:test"; +import { RestrictedError } from "applesauce-wallet-connect/helpers/error"; import type { CocodClient } from "./cocod-client"; /** @@ -11,13 +12,16 @@ import type { CocodClient } from "./cocod-client"; * relay connection, and retry once instead of hanging `routstrd nwc status`. */ -type Behavior = "resolve" | "hang"; +type Behavior = "resolve" | "hang" | "restricted" | "library-timeout" | "deferred"; const state = { infoQueue: [] as Behavior[], balanceQueue: [] as Behavior[], payQueue: [] as Behavior[], createdInstances: 0, + pendingPayments: [] as (() => void)[], + paymentStarted: undefined as (() => void) | undefined, + closedPools: 0, }; function next(queue: Behavior[]): Behavior { @@ -27,6 +31,7 @@ function next(queue: Behavior[]): Behavior { class MockRelayPool { relays = new Map([["wss://relay.example", {}]]); remove(url: string, _close?: boolean): void { + state.closedPools++; this.relays.delete(url); } } @@ -53,7 +58,10 @@ class MockWalletConnect { network: string; methods: string[]; }> { - if (next(state.infoQueue) === "hang") return new Promise(() => {}); + const behavior = next(state.infoQueue); + if (behavior === "hang") return new Promise(() => {}); + if (behavior === "restricted") return Promise.reject(new RestrictedError("restricted")); + if (behavior === "library-timeout") return Promise.reject(new Error("Timeout")); return Promise.resolve({ alias: "Test Wallet", pubkey: "cd".repeat(32), @@ -63,14 +71,31 @@ class MockWalletConnect { } getBalance(): Promise<{ balance: number }> { - if (next(state.balanceQueue) === "hang") return new Promise(() => {}); + const behavior = next(state.balanceQueue); + if (behavior === "hang") return new Promise(() => {}); + if (behavior === "restricted") return Promise.reject(new RestrictedError("restricted")); return Promise.resolve({ balance: 123_000 }); } payInvoice( _invoice: string, ): Promise<{ preimage: string; fees_paid: number }> { - if (next(state.payQueue) === "hang") return new Promise(() => {}); + const behavior = next(state.payQueue); + if (behavior === "hang") return new Promise(() => {}); + if (behavior === "restricted") return Promise.reject(new RestrictedError("restricted")); + if (behavior === "library-timeout") return Promise.reject(new Error("Timeout")); + if (behavior === "deferred") { + return new Promise((resolve) => { + const closedAtStart = state.closedPools; + state.pendingPayments.push(() => { + // Closing the shared pool loses the original payment response. + if (state.closedPools === closedAtStart) { + resolve({ preimage: "00".repeat(32), fees_paid: 1000 }); + } + }); + state.paymentStarted?.(); + }); + } return Promise.resolve({ preimage: "00".repeat(32), fees_paid: 1000 }); } } @@ -109,6 +134,9 @@ beforeEach(() => { state.balanceQueue = []; state.payQueue = []; state.createdInstances = 0; + state.closedPools = 0; + state.pendingPayments = []; + state.paymentStarted = undefined; }); afterAll(() => { @@ -153,3 +181,54 @@ describe("NWC status resilience", () => { expect(Date.now() - startedAt).toBeLessThan(2_000); }); }); + +describe("NWC wallet errors versus transport stalls", () => { + it("does not retry or rebuild on a wallet read error", async () => { + state.infoQueue = ["restricted"]; + const adapter = await makeAdapter(); + expect((await adapter.getNwcStatus()).error).toBe("restricted"); + expect(state.createdInstances).toBe(1); + expect(state.closedPools).toBe(0); + }); + + it("keeps an in-flight payment alive during a pay-only status check", async () => { + state.payQueue = ["deferred"]; + state.balanceQueue = ["restricted"]; + const adapter = await makeAdapter(500); + const started = new Promise((resolve) => { state.paymentStarted = resolve; }); + const payment = adapter.fundFromNWC(2100); + await started; + expect((await adapter.getNwcStatus()).connected).toBe(true); + expect(state.createdInstances).toBe(1); + state.pendingPayments[0]!(); + expect((await payment).success).toBe(true); + expect(state.closedPools).toBe(0); + }); + + it("keeps a slow payment alive when an overlapping payment gets a wallet error", async () => { + state.payQueue = ["deferred", "restricted"]; + const adapter = await makeAdapter(500); + const started = new Promise((resolve) => { state.paymentStarted = resolve; }); + const slow = adapter.fundFromNWC(2100); + await started; + expect((await adapter.fundFromNWC(2100)).error).toBe("restricted"); + state.pendingPayments[0]!(); + expect((await slow).success).toBe(true); + expect(state.createdInstances).toBe(1); + }); + + it("rebuilds and retries reads on the library's own timeout", async () => { + state.infoQueue = ["library-timeout"]; + const adapter = await makeAdapter(); + expect((await adapter.getNwcStatus()).connected).toBe(true); + expect(state.createdInstances).toBe(2); + }); + + it("rebuilds after the library's payment timeout without retrying payment", async () => { + state.payQueue = ["library-timeout", "restricted"]; + const adapter = await makeAdapter(); + expect((await adapter.fundFromNWC(2100)).error).toBe("Timeout"); + expect(state.createdInstances).toBe(2); + expect(state.payQueue).toEqual(["restricted"]); + }); +}); diff --git a/src/daemon/wallet/index.ts b/src/daemon/wallet/index.ts index 99cf9e2..58ee991 100644 --- a/src/daemon/wallet/index.ts +++ b/src/daemon/wallet/index.ts @@ -1,6 +1,7 @@ import { getTokenMetadata } from "@cashu/cashu-ts"; import { InsufficientBalanceError } from "@routstr/sdk"; import { WalletConnect } from "applesauce-wallet-connect"; +import { WalletBaseError } from "applesauce-wallet-connect/helpers/error"; import { RelayPool } from "applesauce-relay"; import { logger } from "../../utils/logger"; import { withTimeout } from "../../utils/with-timeout"; @@ -13,7 +14,7 @@ import { startAutoRefillLoop, type AutoRefillConfig } from "./auto-refill"; * connection is rebuilt before one retry. */ const NWC_READ_TIMEOUT_MS = 15_000; -/** Lightning payments can legitimately take a little longer to settle. */ +/** Overall bound including encryption negotiation; replies have a library 30s timeout. */ const NWC_PAY_TIMEOUT_MS = 45_000; type NwcPayment = { preimage?: string; fees_paid?: number }; @@ -176,7 +177,8 @@ export async function createWalletAdapter( `${label} timed out`, ); } catch (error) { - if (!nwcConnectionString) throw error; + // A normal NIP-47 error proves the wallet answered. Keep other calls alive. + if (error instanceof WalletBaseError || !nwcConnectionString) throw error; logger.warn( `[nwc] ${label} failed (${(error as Error).message}); rebuilding NWC connection and retrying`, ); @@ -194,8 +196,8 @@ export async function createWalletAdapter( /** * Pay a BOLT-11 invoice over NWC with a bounded wait. A timeout rebuilds the * relay connection so later calls recover without a daemon restart. The - * payment is not retried here: the invoice itself is single-use, and the - * caller decides whether to attempt a fresh invoice. + * payment is not retried here. A timeout is an unknown payment outcome, + * not proof of failure; callers must reconcile before trying a fresh invoice. */ async function payNwcInvoice(invoice: string): Promise { const payer = wallet; @@ -207,7 +209,10 @@ export async function createWalletAdapter( "NWC payment timed out", ); } catch (error) { - rebuildNwcConnection("reconnected after payment timeout"); + // Include the library's own timeout, but not normal wallet error replies. + if (!(error instanceof WalletBaseError)) { + rebuildNwcConnection("reconnected after payment timeout"); + } throw error; } } @@ -232,10 +237,6 @@ export async function createWalletAdapter( nwcConnectionString = undefined; logger.log("[nwc] NWC wallet disconnected."); } - - // A connection added after startup previously never started the - // auto-refill loop, so it silently stayed disabled until a restart. - ensureAutoRefillLoop(); }, async getBalances(): Promise> { diff --git a/src/utils/daemon-client.timeout.test.ts b/src/utils/daemon-client.timeout.test.ts new file mode 100644 index 0000000..c7e1b85 --- /dev/null +++ b/src/utils/daemon-client.timeout.test.ts @@ -0,0 +1,79 @@ +import { afterEach, describe, expect, test } from "bun:test"; +import { callDaemonUrl, DAEMON_REQUEST_TIMEOUT_MS } from "./daemon-client"; +import { DEFAULT_CONFIG } from "./config"; + +const originalFetch = globalThis.fetch; +const originalSetTimeout = globalThis.setTimeout; +const originalClearTimeout = globalThis.clearTimeout; + +afterEach(() => { + globalThis.fetch = originalFetch; + globalThis.setTimeout = originalSetTimeout; + globalThis.clearTimeout = originalClearTimeout; +}); + +function shortenDeadline(): void { + globalThis.setTimeout = ((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => + originalSetTimeout(callback, delay === DAEMON_REQUEST_TIMEOUT_MS ? 20 : delay, ...args) + ) as typeof setTimeout; +} + +function stalledResponse(status = 200): void { + globalThis.fetch = (async (_input: string | URL | Request, init?: RequestInit) => { + const signal = init?.signal; + return new Response(new ReadableStream({ + start(controller) { + controller.enqueue(new TextEncoder().encode('{"output":')); + signal?.addEventListener("abort", () => controller.error(signal.reason), { once: true }); + }, + }), { status }); + }) as unknown as typeof fetch; +} + +const request = (path = "/nwc/status") => + callDaemonUrl("http://daemon.example", path, {}, DEFAULT_CONFIG); + +describe("NWC daemon request deadline", () => { + test("bounds the wait for response headers", async () => { + shortenDeadline(); + globalThis.fetch = ((_input: string | URL | Request, init?: RequestInit) => new Promise((_resolve, reject) => { + init?.signal?.addEventListener("abort", () => reject(init.signal!.reason), { once: true }); + })) as unknown as typeof fetch; + await expect(request()).rejects.toThrow("Daemon request timed out"); + }); + + for (const status of [200, 500]) { + test(`bounds a stalled ${status} response body`, async () => { + shortenDeadline(); + stalledResponse(status); + await expect(request()).rejects.toThrow("payment outcome is unknown"); + }); + } + + test("does not impose the NWC deadline on mint payment routes", async () => { + let deadlines = 0; + globalThis.setTimeout = ((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { + if (delay === DAEMON_REQUEST_TIMEOUT_MS) deadlines++; + return originalSetTimeout(callback, delay, ...args); + }) as typeof setTimeout; + globalThis.fetch = (async () => Response.json({ output: "paid" })) as unknown as typeof fetch; + expect(await request("/wallet/send/bolt11")).toEqual({ output: "paid" }); + expect(deadlines).toBe(0); + }); + + test("clears the deadline after consuming a successful response", async () => { + let cleared = 0; + globalThis.clearTimeout = ((timer) => { + cleared++; + originalClearTimeout(timer as ReturnType); + }) as typeof clearTimeout; + globalThis.fetch = (async () => Response.json({ output: "ok" })) as unknown as typeof fetch; + expect(await request()).toEqual({ output: "ok" }); + expect(cleared).toBe(1); + }); + + test("preserves HTTP errors rather than labeling them connection failures", async () => { + globalThis.fetch = (async () => Response.json({ error: "restricted" }, { status: 403 })) as unknown as typeof fetch; + await expect(request()).rejects.toThrow("restricted"); + }); +}); diff --git a/src/utils/daemon-client.ts b/src/utils/daemon-client.ts index a10e161..c6fed08 100644 --- a/src/utils/daemon-client.ts +++ b/src/utils/daemon-client.ts @@ -57,9 +57,9 @@ class DaemonConnectionError extends Error { } /** - * Upper bound for a single daemon request. The daemon bounds its own NWC - * operations, so this only guards against a wedged server; without it a hung - * request would block the CLI forever. + * Upper bound for NWC requests, including response-body consumption. + * Other routes can perform long-running mint payments; aborting the client + * does not cancel those operations, so do not impose this cap on them. */ export const DAEMON_REQUEST_TIMEOUT_MS = 120_000; @@ -77,7 +77,7 @@ export function getAuthBaseUrl(config: RoutstrdConfig): string { return getDaemonBaseUrl(config); } -async function _callUrl( +export async function callDaemonUrl( baseUrl: string, path: string, options: { method?: "GET" | "POST" | "PATCH" | "DELETE"; body?: object }, @@ -106,36 +106,41 @@ async function _callUrl( if (authorization) headers.set("Authorization", authorization); if (bodyString) headers.set("Content-Type", "application/json"); - let response: Response; const controller = new AbortController(); - const timeoutId = setTimeout( - () => controller.abort(), - DAEMON_REQUEST_TIMEOUT_MS, - ); + const timeoutId = path.startsWith("/nwc/") + ? setTimeout(() => controller.abort(), DAEMON_REQUEST_TIMEOUT_MS) + : undefined; try { - response = await fetch(url, { - method, - headers, - body: bodyString, - signal: controller.signal, - }); + let response: Response; + try { + response = await fetch(url, { + method, + headers, + body: bodyString, + signal: controller.signal, + }); + } catch (error) { + if (controller.signal.aborted) throw error; + // Only connection failures qualify for alternate-host retries. + throw new DaemonConnectionError(error); + } + + if (!response.ok) { + const errorData = (await response.json()) as { error?: string }; + throw new Error(errorData.error || `HTTP ${response.status}`); + } + return await response.json() as CommandResponse; } catch (error) { if (controller.signal.aborted) { throw new Error( - `Daemon request timed out after ${DAEMON_REQUEST_TIMEOUT_MS / 1000}s`, + `Daemon request timed out after ${DAEMON_REQUEST_TIMEOUT_MS / 1000}s; ` + + "any payment outcome is unknown — check before retrying", ); } - throw new DaemonConnectionError(error); + throw error; } finally { - clearTimeout(timeoutId); + if (timeoutId !== undefined) clearTimeout(timeoutId); } - - if (!response.ok) { - const errorData = (await response.json()) as { error?: string }; - throw new Error(errorData.error || `HTTP ${response.status}`); - } - - return response.json() as Promise; } async function callLocalDaemon( @@ -147,7 +152,7 @@ async function callLocalDaemon( let connectionError: DaemonConnectionError | undefined; for (const baseUrl of localDaemonBaseUrls(config)) { try { - return await _callUrl(baseUrl, path, options, config); + return await callDaemonUrl(baseUrl, path, options, config); } catch (error) { if (!(error instanceof DaemonConnectionError)) throw error; connectionError = error; @@ -162,7 +167,7 @@ export async function callDaemon( ): Promise { const config = await loadConfig(); if (config.daemonUrl) { - return _callUrl(getDaemonBaseUrl(config), path, options, config); + return callDaemonUrl(getDaemonBaseUrl(config), path, options, config); } return callLocalDaemon(path, options, config); } @@ -177,7 +182,7 @@ export async function callAuth( if (!config.authUrl && !config.daemonUrl) { return callLocalDaemon(path, options, config); } - return _callUrl(getAuthBaseUrl(config), path, options, config); + return callDaemonUrl(getAuthBaseUrl(config), path, options, config); } export async function isDaemonRunning(): Promise { diff --git a/src/utils/with-timeout.ts b/src/utils/with-timeout.ts index f6d6fa4..8a0f143 100644 --- a/src/utils/with-timeout.ts +++ b/src/utils/with-timeout.ts @@ -1,5 +1,6 @@ /** * Rejects when `timeoutMs` elapses before `promise` settles. + * This bounds the caller's wait; it does not cancel the underlying operation. * * Used to bound requests that may otherwise wait forever — notably NWC calls * whose underlying library applies its own timeout only after a support/encryption From ad49fbe64ca914d6487cd50afec550d548fb3b78 Mon Sep 17 00:00:00 2001 From: redshift <213178690+1ftredsh@users.noreply.github.com> Date: Fri, 2 Oct 2026 16:47:09 +0800 Subject: [PATCH 4/4] fix(nwc): bound every CLI daemon request with a two-tier deadline Graft the cleaner daemon-client structure onto the review follow-up: - Replace the manual AbortController/setTimeout with AbortSignal.timeout; the signal stays armed while the body is read, so stalled bodies are bounded on all routes, not just /nwc/*. - 120s default deadline for every route; 600s for value-moving wallet routes (/wallet/send/*, /wallet/receive/*) whose mint operations can legitimately run longer. A wedged daemon can no longer hang the CLI forever on any route. The 'payment outcome is unknown' timeout warning now applies on both tiers. - Rename rebuild log reasons to 'stall': wallet-error replies no longer rebuild the connection, so 'timeout' was inaccurate. - Derive the NWC test client type from WalletAdapterOptions so the tests keep compiling when the legacy CocodClient is replaced (#118). - Rewrite the daemon-client deadline tests around AbortSignal.timeout, asserting the requested tier per route and covering stalled bodies on long-running routes. Update docs/nwc-timeouts.md to match. --- docs/nwc-timeouts.md | 2 +- src/daemon/wallet/index.nwc.test.ts | 12 +++- src/daemon/wallet/index.ts | 4 +- src/utils/daemon-client.timeout.test.ts | 66 ++++++++++++--------- src/utils/daemon-client.ts | 79 +++++++++++++++---------- 5 files changed, 100 insertions(+), 63 deletions(-) diff --git a/docs/nwc-timeouts.md b/docs/nwc-timeouts.md index 1d8421d..b4a59db 100644 --- a/docs/nwc-timeouts.md +++ b/docs/nwc-timeouts.md @@ -6,7 +6,7 @@ The wallet adapter adds an overall deadline: 15 seconds per read attempt and 45 Normal NIP-47 wallet errors do not rebuild the shared relay connection: a wallet error proves a response arrived, and rebuilding could interrupt unrelated payments. Transport failures and timeouts, including the library's own timeout, still trigger recovery. -CLI `/nwc/*` requests have a 120-second deadline covering headers and response-body consumption. Other daemon routes are not subject to this cap because mint payment operations may run longer and cannot be cancelled by aborting the CLI request. +Every CLI daemon request has a deadline covering headers and response-body consumption: 120 seconds by default, and 600 seconds for value-moving wallet routes (`/wallet/send/*`, `/wallet/receive/*`), whose mint operations can legitimately run longer. Aborting the CLI request never cancels the daemon-side operation; the longer bound only delays how soon the CLI reports the stall. A payment timeout is an **unknown outcome**, not proof that no payment occurred. Promise deadlines do not cancel the underlying operation. Check the mint quote, wallet transactions, and Cashu balance before creating and paying another invoice. diff --git a/src/daemon/wallet/index.nwc.test.ts b/src/daemon/wallet/index.nwc.test.ts index 7cb86a1..3bbf064 100644 --- a/src/daemon/wallet/index.nwc.test.ts +++ b/src/daemon/wallet/index.nwc.test.ts @@ -1,6 +1,6 @@ import { afterAll, beforeEach, describe, expect, it, mock } from "bun:test"; import { RestrictedError } from "applesauce-wallet-connect/helpers/error"; -import type { CocodClient } from "./cocod-client"; +import type { WalletAdapterOptions } from "./index"; /** * Regression tests for the NWC hang fixed in this change. @@ -107,13 +107,19 @@ mock.module("applesauce-relay", () => ({ RelayPool: MockRelayPool })); const { createWalletAdapter } = await import("./index"); -function makeClient(): CocodClient { +/** + * Type of the injected wallet client, derived from the adapter options so this + * test keeps compiling when the legacy `CocodClient` is replaced (see #118). + */ +type WalletClientOption = NonNullable; + +function makeClient(): WalletClientOption { return { getBalances: async () => ({ "https://mint.example": 0 }), getDefaultMint: async () => "https://mint.example", receiveBolt11: async () => ({ invoice: "lnbc-test-invoice" }), receiveCashu: async () => "ok", - } as unknown as CocodClient; + } as unknown as WalletClientOption; } function makeAdapter(timeoutMs = 25) { diff --git a/src/daemon/wallet/index.ts b/src/daemon/wallet/index.ts index 58ee991..4a7d2fe 100644 --- a/src/daemon/wallet/index.ts +++ b/src/daemon/wallet/index.ts @@ -182,7 +182,7 @@ export async function createWalletAdapter( logger.warn( `[nwc] ${label} failed (${(error as Error).message}); rebuilding NWC connection and retrying`, ); - rebuildNwcConnection("reconnected after timeout"); + rebuildNwcConnection("reconnected after stall"); const retry = wallet; if (!retry?.service) throw error; return await withTimeout( @@ -211,7 +211,7 @@ export async function createWalletAdapter( } catch (error) { // Include the library's own timeout, but not normal wallet error replies. if (!(error instanceof WalletBaseError)) { - rebuildNwcConnection("reconnected after payment timeout"); + rebuildNwcConnection("reconnected after payment stall"); } throw error; } diff --git a/src/utils/daemon-client.timeout.test.ts b/src/utils/daemon-client.timeout.test.ts index c7e1b85..43f829c 100644 --- a/src/utils/daemon-client.timeout.test.ts +++ b/src/utils/daemon-client.timeout.test.ts @@ -1,21 +1,32 @@ import { afterEach, describe, expect, test } from "bun:test"; -import { callDaemonUrl, DAEMON_REQUEST_TIMEOUT_MS } from "./daemon-client"; +import { + callDaemonUrl, + DAEMON_LONG_REQUEST_TIMEOUT_MS, + DAEMON_REQUEST_TIMEOUT_MS, +} from "./daemon-client"; import { DEFAULT_CONFIG } from "./config"; const originalFetch = globalThis.fetch; -const originalSetTimeout = globalThis.setTimeout; -const originalClearTimeout = globalThis.clearTimeout; +const originalAbortTimeout = AbortSignal.timeout; + +/** Deadline (ms) passed to AbortSignal.timeout by the last request. */ +let requestedDeadlines: number[] = []; afterEach(() => { globalThis.fetch = originalFetch; - globalThis.setTimeout = originalSetTimeout; - globalThis.clearTimeout = originalClearTimeout; + AbortSignal.timeout = originalAbortTimeout; + requestedDeadlines = []; }); +/** + * Record the requested deadline and arm a fast one instead, so tests do not + * wait out the real 120s/600s bounds. + */ function shortenDeadline(): void { - globalThis.setTimeout = ((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => - originalSetTimeout(callback, delay === DAEMON_REQUEST_TIMEOUT_MS ? 20 : delay, ...args) - ) as typeof setTimeout; + AbortSignal.timeout = ((ms: number) => { + requestedDeadlines.push(ms); + return originalAbortTimeout(20); + }) as typeof AbortSignal.timeout; } function stalledResponse(status = 200): void { @@ -33,7 +44,7 @@ function stalledResponse(status = 200): void { const request = (path = "/nwc/status") => callDaemonUrl("http://daemon.example", path, {}, DEFAULT_CONFIG); -describe("NWC daemon request deadline", () => { +describe("daemon request deadline", () => { test("bounds the wait for response headers", async () => { shortenDeadline(); globalThis.fetch = ((_input: string | URL | Request, init?: RequestInit) => new Promise((_resolve, reject) => { @@ -50,26 +61,27 @@ describe("NWC daemon request deadline", () => { }); } - test("does not impose the NWC deadline on mint payment routes", async () => { - let deadlines = 0; - globalThis.setTimeout = ((callback: (...args: unknown[]) => void, delay?: number, ...args: unknown[]) => { - if (delay === DAEMON_REQUEST_TIMEOUT_MS) deadlines++; - return originalSetTimeout(callback, delay, ...args); - }) as typeof setTimeout; - globalThis.fetch = (async () => Response.json({ output: "paid" })) as unknown as typeof fetch; - expect(await request("/wallet/send/bolt11")).toEqual({ output: "paid" }); - expect(deadlines).toBe(0); + test("applies the default deadline to ordinary routes", async () => { + shortenDeadline(); + globalThis.fetch = (async () => Response.json({ output: "ok" })) as unknown as typeof fetch; + expect(await request("/nwc/status")).toEqual({ output: "ok" }); + expect(requestedDeadlines).toEqual([DAEMON_REQUEST_TIMEOUT_MS]); }); - test("clears the deadline after consuming a successful response", async () => { - let cleared = 0; - globalThis.clearTimeout = ((timer) => { - cleared++; - originalClearTimeout(timer as ReturnType); - }) as typeof clearTimeout; - globalThis.fetch = (async () => Response.json({ output: "ok" })) as unknown as typeof fetch; - expect(await request()).toEqual({ output: "ok" }); - expect(cleared).toBe(1); + for (const path of ["/wallet/send/bolt11", "/wallet/receive/cashu"]) { + test(`uses the long deadline for value-moving route ${path}`, async () => { + shortenDeadline(); + globalThis.fetch = (async () => Response.json({ output: "paid" })) as unknown as typeof fetch; + expect(await request(path)).toEqual({ output: "paid" }); + expect(requestedDeadlines).toEqual([DAEMON_LONG_REQUEST_TIMEOUT_MS]); + }); + } + + test("bounds a stalled body on a long-running route too", async () => { + shortenDeadline(); + stalledResponse(); + await expect(request("/wallet/send/bolt11")).rejects.toThrow("payment outcome is unknown"); + expect(requestedDeadlines).toEqual([DAEMON_LONG_REQUEST_TIMEOUT_MS]); }); test("preserves HTTP errors rather than labeling them connection failures", async () => { diff --git a/src/utils/daemon-client.ts b/src/utils/daemon-client.ts index c6fed08..fe763f0 100644 --- a/src/utils/daemon-client.ts +++ b/src/utils/daemon-client.ts @@ -57,12 +57,31 @@ class DaemonConnectionError extends Error { } /** - * Upper bound for NWC requests, including response-body consumption. - * Other routes can perform long-running mint payments; aborting the client - * does not cancel those operations, so do not impose this cap on them. + * Upper bound for a single daemon request, including response-body + * consumption. The daemon bounds its own NWC operations, so this only guards + * against a wedged server; without it a hung request would block the CLI + * forever. */ export const DAEMON_REQUEST_TIMEOUT_MS = 120_000; +/** + * Upper bound for value-moving wallet routes. A cashu melt/swap can + * legitimately run longer than {@link DAEMON_REQUEST_TIMEOUT_MS} (the mint has + * no request timeout in routstrd), so these get a more generous bound that + * still prevents an indefinite CLI hang. + */ +export const DAEMON_LONG_REQUEST_TIMEOUT_MS = 600_000; + +/** Routes that may legitimately outlive the default request timeout. */ +const LONG_RUNNING_ROUTES = ["/wallet/send/", "/wallet/receive/"]; + +function requestTimeoutMs(path: string): number { + const pathname = path.split("?")[0] ?? path; + return LONG_RUNNING_ROUTES.some((route) => pathname.startsWith(route)) + ? DAEMON_LONG_REQUEST_TIMEOUT_MS + : DAEMON_REQUEST_TIMEOUT_MS; +} + export function getDaemonBaseUrl(config: RoutstrdConfig): string { if (config.daemonUrl) { return config.daemonUrl.replace(/\/$/, ""); @@ -106,40 +125,40 @@ export async function callDaemonUrl( if (authorization) headers.set("Authorization", authorization); if (bodyString) headers.set("Content-Type", "application/json"); - const controller = new AbortController(); - const timeoutId = path.startsWith("/nwc/") - ? setTimeout(() => controller.abort(), DAEMON_REQUEST_TIMEOUT_MS) - : undefined; - try { - let response: Response; - try { - response = await fetch(url, { - method, - headers, - body: bodyString, - signal: controller.signal, - }); - } catch (error) { - if (controller.signal.aborted) throw error; - // Only connection failures qualify for alternate-host retries. - throw new DaemonConnectionError(error); - } + const timeoutMs = requestTimeoutMs(path); + const timeoutError = () => + new Error( + `Daemon request timed out after ${timeoutMs / 1000}s; ` + + "any payment outcome is unknown — check before retrying", + ); + // The signal stays armed while the body is read, so a daemon that sends + // headers and then stalls the body cannot hang the CLI either. Aborting + // here never cancels the daemon's operation — see timeoutError's warning. + const signal = AbortSignal.timeout(timeoutMs); + let response: Response; + try { + response = await fetch(url, { + method, + headers, + body: bodyString, + signal, + }); + } catch (error) { + if (signal.aborted) throw timeoutError(); + // Only connection failures qualify for alternate-host retries. + throw new DaemonConnectionError(error); + } + + try { if (!response.ok) { const errorData = (await response.json()) as { error?: string }; throw new Error(errorData.error || `HTTP ${response.status}`); } - return await response.json() as CommandResponse; + return (await response.json()) as CommandResponse; } catch (error) { - if (controller.signal.aborted) { - throw new Error( - `Daemon request timed out after ${DAEMON_REQUEST_TIMEOUT_MS / 1000}s; ` + - "any payment outcome is unknown — check before retrying", - ); - } + if (signal.aborted) throw timeoutError(); throw error; - } finally { - if (timeoutId !== undefined) clearTimeout(timeoutId); } }