diff --git a/apps/facilitator/src/adapters/http-timeouts.ts b/apps/facilitator/src/adapters/http-timeouts.ts new file mode 100644 index 00000000..4ef466a9 --- /dev/null +++ b/apps/facilitator/src/adapters/http-timeouts.ts @@ -0,0 +1,16 @@ +import { Agent, Pool } from "undici"; + +/** + * The process's HTTP dispatcher: a request ends after `defaultMs` without headers or body data, + * and a request to an origin in `shorter` after that origin's own bound. + */ +export function boundedAgent(defaultMs: number, shorter: Readonly>): Agent { + return new Agent({ + headersTimeout: defaultMs, + bodyTimeout: defaultMs, + factory: (origin, opts) => { + const ms = shorter[new URL(String(origin)).origin] ?? defaultMs; + return new Pool(origin, { ...opts, headersTimeout: ms, bodyTimeout: ms }); + }, + }); +} diff --git a/apps/facilitator/src/main.ts b/apps/facilitator/src/main.ts index efe18d20..549a3823 100644 --- a/apps/facilitator/src/main.ts +++ b/apps/facilitator/src/main.ts @@ -5,10 +5,17 @@ import { type SorobanRpc, type TransactionSigner, } from "@stellar-x402/signer-pool"; -import { getNetworkPassphrase, getUsdcAddress, type FacilitatorStellarSigner } from "@x402/stellar"; +import { + DEFAULT_PUBNET_HORIZON_URL, + DEFAULT_TESTNET_HORIZON_URL, + getNetworkPassphrase, + getUsdcAddress, + type FacilitatorStellarSigner, +} from "@x402/stellar"; import type pg from "pg"; -import { Agent, setGlobalDispatcher } from "undici"; +import { setGlobalDispatcher } from "undici"; import { emfMetrics } from "./adapters/emf-metrics.js"; +import { boundedAgent } from "./adapters/http-timeouts.js"; import { openBaoSigner, type OpenBaoSigner } from "./adapters/openbao-signer.js"; import { MIGRATIONS, migrate, pendingMigrations } from "./adapters/postgres-schema.js"; import { createPool, postgresStores } from "./adapters/postgres.js"; @@ -36,6 +43,7 @@ import { createRecords } from "./settlement/records.js"; import { SETTLE_MIN_VALIDITY_LEDGERS, createSettler, type Settle } from "./settlement/settle.js"; import { createTrustlineLookup } from "./settlement/trustline.js"; import { + HORIZON_TIMEOUT_MS, UPSTREAM_TIMEOUT_MS, buildUpstream, failureReason, @@ -461,8 +469,13 @@ export async function main( // an upstream call cut off by its deadline can't be cancelled. undici's defaults would hold its // socket for 300 s; these end it after 10 s without headers or body data. Process-wide: any // other `fetch` in this process gets the same bounds (the facilitator makes no other). + // Horizon gets 2 s: upstream verify reads it on every payment, with no timeout of its own, and + // a hung one would take every RPC URL past its 10 s. Past 2 s upstream assumes 5 s a ledger. setGlobalDispatcher( - new Agent({ headersTimeout: UPSTREAM_TIMEOUT_MS, bodyTimeout: UPSTREAM_TIMEOUT_MS }), + boundedAgent(UPSTREAM_TIMEOUT_MS, { + [new URL(DEFAULT_TESTNET_HORIZON_URL).origin]: HORIZON_TIMEOUT_MS, + [new URL(DEFAULT_PUBNET_HORIZON_URL).origin]: HORIZON_TIMEOUT_MS, + }), ); // The stores need a migrated schema (`pnpm migrate`); the service never migrates it. // Reservations queue on the global scope's lock, a flood's hits on its key's row lock, and a diff --git a/apps/facilitator/src/settlement/upstream.ts b/apps/facilitator/src/settlement/upstream.ts index dcce1b05..1861a791 100644 --- a/apps/facilitator/src/settlement/upstream.ts +++ b/apps/facilitator/src/settlement/upstream.ts @@ -19,6 +19,13 @@ import { */ export const UPSTREAM_TIMEOUT_MS = 10_000; +/** + * How long upstream's Horizon read of the ledger time may wait for headers or body data: Horizon + * answers in under 1 s (0.46 to 0.73 s, 30 calls on testnet, 2026-11-05), and upstream falls back + * to 5 s a ledger when the read fails, so a hung Horizon costs a payment 2 s, not every RPC URL. + */ +export const HORIZON_TIMEOUT_MS = 2_000; + /** Slack on the whole upstream call's deadline, so the last URL's own deadline fires first. */ export const UPSTREAM_DEADLINE_SLACK_MS = 1_000; diff --git a/apps/facilitator/test/http-timeouts.test.ts b/apps/facilitator/test/http-timeouts.test.ts new file mode 100644 index 00000000..01cadcb7 --- /dev/null +++ b/apps/facilitator/test/http-timeouts.test.ts @@ -0,0 +1,41 @@ +import { createServer, type Server } from "node:http"; +import { once } from "node:events"; +import { fetch } from "undici"; +import { afterAll, describe, expect, it } from "vitest"; +import { boundedAgent } from "../src/adapters/http-timeouts.js"; + +async function listen(handle: Parameters[1]): Promise<[Server, string]> { + const server = createServer(handle); + server.listen(0, "127.0.0.1"); + await once(server, "listening"); + const { port } = server.address() as { port: number }; + return [server, `http://127.0.0.1:${port}`]; +} + +describe("boundedAgent", () => { + const servers: Server[] = []; + afterAll(() => { + for (const server of servers) { + server.closeAllConnections(); + server.close(); + } + }); + + it("ends a request to a listed origin at its own bound, and leaves the others the default", async () => { + const [hung, hungUrl] = await listen(() => {}); + const [slow, slowUrl] = await listen((_req, res) => { + setTimeout(() => res.end("ok"), 300); + }); + servers.push(hung, slow); + const agent = boundedAgent(5_000, { [hungUrl]: 100 }); + + const started = Date.now(); + await expect(fetch(`${hungUrl}/ledgers`, { dispatcher: agent })).rejects.toThrow(); + expect(Date.now() - started).toBeLessThan(2_000); + + // 300 ms, past the listed origin's 100 ms, inside the default 5 s. + const answer = await fetch(`${slowUrl}/`, { dispatcher: agent }); + expect(await answer.text()).toBe("ok"); + await agent.close(); + }); +}); diff --git a/docs/architecture/m1-spine.md b/docs/architecture/m1-spine.md index f7b5caec..373bf04e 100644 --- a/docs/architecture/m1-spine.md +++ b/docs/architecture/m1-spine.md @@ -96,7 +96,7 @@ graph TD - With fee-stats bids (AD-10), the bid is read once per call, before any URL's 10 s starts and before the call reads the active URL, and each bid gets one scheme per URL. A bid read that waits out a hung URL moves the shared URL, so the verify call starts on the next one. - Upstream's deadline is 10 s per URL, plus, with fee-stats bids, the bid read before them (`FallbackRpc` bounds it at 10 s per URL), plus 1 s, so the last URL's own deadline fires first: 21 s with two URLs and a fixed bid, 41 s with fee-stats, 61 s with three URLs and fee-stats. It is not `/verify`'s whole time: the AD-22 ledger read after it can add `FallbackRpc`'s 10 s per URL. With the shared URL a hung `RPC_URLS[0]` costs one of these waits, not one per client, so the first `/settle` fits its budget (ADR 0011); calls already waiting on it when it is moved still wait their own 10 s. - A call cut off by its 10 s keeps running, since upstream's clients can't be cancelled. `main()` sets undici's global header and body timeouts to 10 s, which stellar-sdk's `fetch` uses, so the abandoned request ends instead of holding its socket for undici's default 300 s. - - Upstream's Horizon read of the ledger close time has no URL of ours to fail over to. It falls back to upstream's default on an error. Upstream reads it after its RPC calls, so a Horizon that hangs takes the URL being tried past its 10 s, which counts as that URL's timeout and moves the shared URL: `rpc_failover` with `by: "verify"` blames an RPC URL for Horizon's delay. With healthy RPCs the probe that the last URL's timeout starts brings calls back (`rpc_failback`), so while Horizon hangs the two lines repeat. Every URL times out, `rpc_exhausted` lists them, and the answer is a 503 `rpc_unavailable`, from the `UpstreamTimeoutError` of the first URL tried, the active one, not always `RPC_URLS[0]`: it blames the RPC for Horizon's delay too. Payments are unaffected: the pool's reads and sends answer on either URL. + - Upstream's Horizon read of the ledger close time has no URL of ours to fail over to. It falls back to upstream's default, 5 s a ledger, on an error. It has no timeout of its own and runs inside each RPC URL's 10 s, so a Horizon that hung would take every URL past its deadline and move the shared URL off healthy RPCs. The process's HTTP dispatcher gives the two Horizon origins 2 s instead (`HORIZON_TIMEOUT_MS`; Horizon answered in 0.46 to 0.73 s in 30 testnet calls): past it the read fails, upstream assumes 5 s a ledger, and the payment is verified on the same URL. - **`/verify`** = upstream `verify()`, then address credentials only, the AD-5 channel check, the AD-6 one-payer-entry check, then the AD-22 validity check. The first rejection returns `isValid: false` with its reason. - Address credentials only: an auth entry with source-account credentials would authorize as the call's source, which the pool makes a channel. Upstream refuses it too (`…_unsupported_credential_type`); we check it again because the pin `~2.28.0` lets upstream patches float, and the pool refuses such a call as well. - A network check runs first: the requirements' `network` picks that network's RPC endpoints, pool, key and store, and a network the process doesn't serve is `invalid_network`, since upstream would verify its payload against that network's default RPC. One process serves both networks (task 0077); until 0126's code, it serves the one in `NETWORK`. A V0 envelope is rejected as malformed there too: upstream parses it, but can't assemble its simulation onto it. diff --git a/docs/monitoring.md b/docs/monitoring.md index 0633d7c8..773efdaa 100644 --- a/docs/monitoring.md +++ b/docs/monitoring.md @@ -310,10 +310,9 @@ are refused. A burst sends one message. 1. In Logs Insights on `/x402/production/app`, the `verify_rpc_unavailable` and `rpc_exhausted` lines around that time: `rpc_exhausted` names each `RPC_URLS[i]#fingerprint` and why it failed. -2. If every URL timed out and `rpc-stalled` stays quiet, the ledger still moves: check Horizon - (`horizon.stellar.org` or `horizon-testnet.stellar.org`). Upstream's verify reads it on every - payment, with no timeout of its own, so a hung Horizon times out every RPC URL. -3. Otherwise fix the endpoint, or reorder `RPC_URLS` ([runbook, Credentials](runbook.md#credentials)). +2. Fix the endpoint, or reorder `RPC_URLS` ([runbook, Credentials](runbook.md#credentials)). A + hung Horizon doesn't cause this alarm: upstream's verify reads it with a 2 s bound + (`HORIZON_TIMEOUT_MS`) and then assumes 5 s a ledger. ### rpc-stalled