From b119506c0991dda8f463cababfecd993f12d0f3b Mon Sep 17 00:00:00 2001 From: Raul Jimenez Ortega Date: Wed, 4 Nov 2026 14:57:43 +0100 Subject: [PATCH] fix(validator): wait as long as the ecosystem does, and tell slow from dead MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Closes #70. `validator.opentechevents.org` called `https://eventos.wiki/events.json` — a registered adopter's feed — `unreachable`, while the registration bot that links here told that publisher the same feed was valid. Measured: the feed answers 200 with ~554 KB in 23.6-51 s, consistently. Only the clock was wrong. **60 s, for the hop and the chain alike.** Not a number chosen here: the spec repo's daily health check and its adopter-registration bot both fetch with 60 s and retries, each after this same false negative was removed from it (spec PRs #43 and #46). The issue floats 20-30 s per hop, but the feed's slow runs reach 51 s, so anything under 60 reopens the bug on a slower day. The normal case is one hop and must be able to spend the whole budget; a redirect chain still cannot multiply the wait, since each hop takes only what the chain has left. **A connect deadline that actually exists.** Raising the number alone replaces one false negative with its mirror image: measured against the runtime, a live host with a filtered port spent the entire 60 s and came back reading "slow". `fetch` cannot separate the handshake from the bytes — one `AbortSignal` covers both — so each hop now opens a bare TCP connection first, under its own 8 s budget (`src/tcp-probe.ts`). The discrimination is stark: the adopter feed accepts a connection in 0.1 s and answers in 23.6 s, while nothing-is-listening is settled in 8. That case gets `no-connection`, never the word "slow". The probe **fails open**: anything other than a clean "nothing accepted a connection in time" is inconclusive and the fetch proceeds as if it had not run. It may shorten a hopeless wait; it must never invent a failure for a feed that would have loaded. Two findings from probing the real runtime, neither visible to a fake: `connect()` to an IP literal does not behave (an IPv4 literal timed out at 6 s where the hostname opened in 25 ms; an IPv6 literal is refused outright), so the probe connects by hostname, after the SSRF checks and reaching nothing they do not already permit; and `close()` on a socket that never opened is never awaited, because it may not settle and would hang the request past the budget the probe exists to impose. **One retry, never for a timeout.** A reset connection or a 502 from a shared host is not a verdict about a feed, so a hop gets a second attempt after a transport error or a 429/5xx — failures that arrive fast. 4xx is deterministic and is not asked twice. Deliberately narrower than the other two tools': they run unattended, while here somebody is watching a spinner, and having waited the full budget once, waiting it again ends in "slow" 60 s later anyway. **Slow and dead must not read alike**, which is why raising the clock is not the whole fix. The timeout message says the origin is slow and the feed is not invalid; `/badge` grows a `slow` state, apart from `unreachable`, because that image sits in a publisher's README. And #105's transport section still reports the 23.6 s: the feed now validates *and* is told what is wrong with how it is served. The badge caption on the page listed only the old vocabulary and would have lied about the new state. Verified against a local Worker, since this app's worst failures are invisible to vitest: | Case | Before | After | Badge | | --- | --- | --- | --- | | Valid, slow adopter feed | `timeout` @5.2 s | 200, 568 KB @23.7 s | `valid` | | Nothing listening on the port | 60.0 s, "slow" | `no-connection` @8.2 s | `unreachable` | | Hostname does not resolve | — | 0.12 s | `unreachable` | | Answers nothing past 60 s | `unreachable` | `slow`, TTL 300 s | `slow` | The page was driven in a browser for both the slow feed (valid, with the 23.1 s finding) and the unreachable one. The retry and `body.cancel()` paths ran live too: a 503 took 1.01 s against a 0.18 s baseline. Co-Authored-By: Claude Opus 5 --- apps/validator/index.html | 5 +- workers/validator/README.md | 104 +++++++- workers/validator/src/badge.ts | 49 +++- workers/validator/src/fetch-document.ts | 239 +++++++++++++++--- workers/validator/src/index.ts | 36 ++- workers/validator/src/tcp-probe.ts | 78 ++++++ workers/validator/test/badge.test.ts | 57 ++++- workers/validator/test/fetch-document.test.ts | 192 +++++++++++++- workers/validator/test/handler.test.ts | 22 +- 9 files changed, 723 insertions(+), 59 deletions(-) create mode 100644 workers/validator/src/tcp-probe.ts diff --git a/apps/validator/index.html b/apps/validator/index.html index fc3e537..4ef5036 100644 --- a/apps/validator/index.html +++ b/apps/validator/index.html @@ -173,8 +173,9 @@

OTE validator

- Markdown. The image says valid, invalid or no feed found, re-checked at most once - an hour. + Markdown. The image says valid, invalid, no feed found, several feeds, slow or + unreachable, re-checked at most once an hour. “Slow” means the fetch ran out of + time, which is not a verdict on the feed.

diff --git a/workers/validator/README.md b/workers/validator/README.md index ff9dae6..2711553 100644 --- a/workers/validator/README.md +++ b/workers/validator/README.md @@ -106,9 +106,28 @@ URL check. It runs the same two steps the page does, and keeps them apart for the same reason: **`no feed found` is not `invalid`**. The states are `valid`, `invalid`, `no feed found`, `several feeds` (the page declares more than one -and the badge refuses to pick, exactly as the UI does) and `unreachable`. The -state also travels as `x-ote-badge-state`, from that fixed vocabulary, so it -can be read with `curl` without parsing an image. +and the badge refuses to pick, exactly as the UI does), `unreachable` and +`slow`. The state also travels as `x-ote-badge-state`, from that fixed +vocabulary, so it can be read with `curl` without parsing an image. + +`slow` and `unreachable` are kept apart for the reason in #70: this image +lives in a publisher's README, and a feed that answers `200` in 51 s is not a +feed nobody can reach. Only the clock running out produces `slow`; a name that +does not resolve, nothing listening, or a 500 is `unreachable`, because there +is nothing at the other end to be slow. A feed that *is* valid and slow badges +`valid` — performance is not validity, and the page is where the seconds are +reported. Measured against the four cases that matter: + +| Feed | Badge | Time | +| --- | --- | --- | +| Valid, slow origin (the adopter feed in #70) | `valid` | 23.7 s | +| Nothing listening on the port | `unreachable` | 8.1 s | +| Hostname does not resolve | `unreachable` | 0.1 s | +| Answers nothing at all past 60 s | `slow` | 60 s | + +Resolving a badge can cost two fetches (a page, then the feed it declares), so +they share **one** 60 s budget rather than taking one each: a README reader's +connection must not be held for twice the ceiling this service advertises. Two properties make this endpoint different from `/fetch`: @@ -151,6 +170,12 @@ default, a proxy into whatever the server can reach. Every rule below lives in - **Non-HTTP ports** an HTTP client can still reach (25, 6379, 3306, …) are refused. +- **The connect probe runs after those checks, never instead of them**, and + connects by hostname because the runtime will not usefully connect to an IP + literal (above). It therefore learns exactly what the `fetch` on the next + line would learn — whether something accepts a connection — and adds no + reach the fetch does not already have. + **Known residual risk — DNS rebinding.** A Worker has no socket-level API to pin the connection to the address it just validated, so a resolver answer that changes between check and connect is not fully excluded. What is left is @@ -165,12 +190,73 @@ the runtime reduces the impact of a mistake, not the need to write them. cap without being buffered (there is a test for exactly that). - The cap counts **decompressed** bytes, which is what a decompression bomb inflates. -- **Timeouts**: 5 s per hop, 10 s for the whole chain. Deliberately shorter - than a feed reader's (those poll in the background and can wait 30 s); here - somebody is watching the page. The timeout message therefore names the limit - it hit **and** points at the file and paste modes, which validate the same - document in the browser without this service — a slow origin is the one - failure here that is nobody's bug to fix from this side. +- **Timeouts: 60 s, for the hop and for the whole chain alike.** Not a number + chosen here — it is the one the rest of the ecosystem already settled on. + The spec repo's daily health check and its adopter-registration bot both + fetch with 60 s and retries, each after this same false negative was removed + from it (spec PRs #43 and #46). At the previous 5 s/10 s this endpoint + answered `unreachable` for `https://eventos.wiki/events.json` — a registered + adopter's feed that answers `200` with ~554 KB in 23.6–51 s, consistently — + while the bot that links here told that publisher their feed was valid + (#70). Three tools, one feed, two answers. + + The hop and the chain carry the **same** budget deliberately. The normal + case is a single hop and it has to be able to spend all 60 s, since that is + what the measured feed needs; a redirect chain still cannot multiply the + wait, because each hop takes only what the chain has left. + +- **8 s to accept a connection, which is a different question from answering + one.** A long download deadline must not become a long *connect* deadline, + and `fetch` cannot tell the two apart: one `AbortSignal` covers the + handshake, the origin thinking and the bytes moving alike. Measured against + the runtime: a live host with a filtered port (`example.com:81`) spent the + entire 60 s and came back reading **slow** — the mirror image of the false + negative this issue is about, and a worse wait than the 10 s it replaced. + + So every hop opens a bare TCP connection first, under its own budget + (`src/tcp-probe.ts`, one extra subrequest per hop). The discrimination is + stark: the adopter feed accepts a connection in **0.1 s** and answers in + 23.6 s, while nothing-is-listening is established in 8. A host that proves + something is listening earns the long clock; one that does not gets + `no-connection` — and *not* the word "slow", because there is nothing there + to be slow. Measured end to end: 60.0 s → **8.2 s**. + + Two things the runtime decided for us, both found by probing it rather than + reading about it. **The probe connects to the hostname, not to the address + the SSRF check validated**: `connect()` to an IP literal does not behave — + `93.184.215.14:443` timed out at 6 s where `example.com:443` opened in 25 + ms, and an IPv6 literal is refused outright. And **`close()` is never + awaited** on a socket that never opened, because it may not settle, which + would hang the request past the very budget the probe exists to impose. + + **The probe fails open.** Anything other than a clean "nothing accepted a + connection in time" is treated as inconclusive and the fetch proceeds as if + no probe had run. It may shorten a hopeless wait; it must never be able to + invent a failure for a feed that would have loaded. + +- **One retry, and never for a timeout.** A reset connection, or a 502 from a + shared host, is not a verdict about a feed, so a hop gets a second attempt + (`maxAttempts: 2`) after a transport error or a 429/5xx — failures that + arrive *fast*. 4xx is deterministic and is not asked twice. The retry is + narrower than the health check's and the bot's on purpose: those run + unattended on a schedule, whereas here somebody is watching a spinner, and + having waited the full 60 s once, waiting it again turns a 60 s answer into + a 120 s one that still says "slow" at the end. + +- **The wording is part of the fix.** "Unreachable" is the wrong word for + "did not finish inside our budget": to a publisher whose feed is valid and + merely slow to generate it reads as an accusation. The timeout message names + the budget, says plainly that this makes the *origin* slow and not the + *feed* invalid, and points at the file and paste modes, which validate the + same document in the browser without this service. + + And raising the clock is not the whole fix — a feed that takes 23.6 s to + start answering still has something worth fixing. That is what the page's + "How this was served" section reports (`apps/validator/src/lib/transport.ts`, + #105): the gap between time-to-first-byte and total tells a publisher + whether the cost is the origin thinking or the bytes moving. A slow feed now + validates *and* is told it is slow; a dead one is still reported as dead. + The two must not end up telling the same story. - **Rate limiting per IP** via the optional `RATE_LIMITER` binding (`wrangler.jsonc`). The Worker runs without it — production should not. diff --git a/workers/validator/src/badge.ts b/workers/validator/src/badge.ts index 8fbe1f8..4a414cb 100644 --- a/workers/validator/src/badge.ts +++ b/workers/validator/src/badge.ts @@ -22,7 +22,12 @@ import { discover, detectDocumentKind } from "@opentechevents/discover-feed"; import { validateDocument } from "@opentechevents/validate"; -import { fetchDocument, type FetchDeps } from "./fetch-document.js"; +import { + DEFAULT_LIMITS, + fetchDocument, + type FetchDeps, + type FetchFailure, +} from "./fetch-document.js"; /** * What a badge can say. Deliberately coarse: a README has room for one word, @@ -37,8 +42,15 @@ export type BadgeState = | "not-discovered" /** The page declares several feeds; the badge refuses to pick, as the page does. */ | "ambiguous" - /** The document could not be fetched at all — DNS, timeout, refusal, 500. */ - | "unreachable"; + /** The document could not be fetched at all — DNS, refusal, 500. */ + | "unreachable" + /** + * The origin did not answer inside the fetch budget. Kept apart from + * `unreachable` deliberately: this badge sits in a publisher's README, and + * "unreachable" over a feed that is valid and merely slow to generate is an + * accusation (#70). A slow feed and a dead feed are different news. + */ + | "slow"; export interface BadgeVerdict { state: BadgeState; @@ -65,6 +77,8 @@ const STATES: Record = { ambiguous: { text: "several feeds", color: "#b06d00", ttlSeconds: 3600 }, // A transient outage must not stick to a README for an hour. unreachable: { text: "unreachable", color: "#b06d00", ttlSeconds: 300 }, + // Same short life, for the same reason: the origin may be quick tomorrow. + slow: { text: "slow", color: "#b06d00", ttlSeconds: 300 }, }; /** Cache lifetime for a verdict, in seconds. */ @@ -72,6 +86,16 @@ export function badgeTtlSeconds(state: BadgeState): number { return STATES[state].ttlSeconds; } +/** + * Which word a failed fetch earns. Only the clock running out becomes `slow`; + * everything else — a name that does not resolve, a refused connection, a + * 500, a URL this service will not fetch — is `unreachable`, because in those + * cases there really is nothing at the other end to be slow. + */ +function failureState(code: FetchFailure["code"]): BadgeState { + return code === "timeout" ? "slow" : "unreachable"; +} + /** * Judges an already-fetched document, exactly as the page's report does — * including which version's schemas do the judging. A badge that measured @@ -108,8 +132,19 @@ async function judge(text: string): Promise { * merged them would send organizers to the wrong file. */ export async function resolveBadge(target: string, deps: FetchDeps): Promise { - const first = await fetchDocument(target, deps); - if (!first.ok) return { state: "unreachable", detail: first.message }; + // One budget for the whole resolution, not one per fetch. A page that + // declares a feed costs two fetches, and with independent budgets a single + // badge request could hold a README reader's connection for twice the + // advertised ceiling — now 60 s a fetch, so the difference is not academic. + const budgeted: FetchDeps = { + ...deps, + deadline: + deps.deadline ?? + Date.now() + (deps.limits?.totalTimeoutMs ?? DEFAULT_LIMITS.totalTimeoutMs), + }; + + const first = await fetchDocument(target, budgeted); + if (!first.ok) return { state: failureState(first.code), detail: first.message }; const found = discover({ url: first.finalUrl, @@ -138,8 +173,8 @@ export async function resolveBadge(target: string, deps: FetchDeps): Promise; + /** + * The connect check. Absent means no preflight at all — which is how the + * unit tests run, since `cloudflare:sockets` exists only in the Workers + * runtime. `index.ts` wires the real one; a missing probe can only make + * this slower, never wrong. + */ + probe?: TcpProbe; + /** + * Absolute deadline (`Date.now()` + budget) shared by several calls. The + * badge resolves a page and then the feed that page links to; without this + * those are two independent budgets and one badge request can hold a + * reader's connection for twice the advertised ceiling. + */ + deadline?: number; } export interface FetchedDocument { @@ -76,7 +135,13 @@ export interface Transport { } /** Codes that describe a failed fetch rather than a refused URL. */ -export type FetchRejectionCode = "upstream-error" | "too-large" | "timeout" | "too-many-redirects"; +export type FetchRejectionCode = + | "upstream-error" + | "too-large" + | "timeout" + | "too-many-redirects" + /** Nothing accepted a connection. Not "slow": there is nothing there to be slow. */ + | "no-connection"; export interface FetchFailure { ok: false; @@ -102,23 +167,69 @@ function failure( } /** - * The timeout message names the limit it hit, and the two modes that do not - * depend on it. A slow origin is the one failure here that is nobody's bug — - * not the URL's, not this service's — and "took too long" alone leaves the - * organizer with no next step; the file and paste modes validate the exact - * same document in the browser, with this Worker out of the picture. + * The timeout message names the limit it hit, says what running out of clock + * does and does not mean, and points at the two modes that do not depend on + * this service at all. + * + * The wording matters as much as the number. A slow origin is the one failure + * here that is nobody’s bug — not the URL’s, not this service’s — and + * "unreachable" is the wrong word for "did not finish inside our budget": it + * reads as *your feed is broken* to a publisher whose feed is valid and + * merely slow to generate. So the message says **slow**, which is also the + * word the badge uses for this code, and leaves a next step rather than a + * verdict. */ function timedOut(limits: FetchLimits): FetchFailure { + // Only worth naming both numbers when they differ; with one budget for hop + // and chain alike, repeating it reads like two separate limits were hit. + const budget = + limits.hopTimeoutMs === limits.totalTimeoutMs + ? `${seconds(limits.totalTimeoutMs)} s, redirects included` + : `${seconds(limits.hopTimeoutMs)} s ` + + `(${seconds(limits.totalTimeoutMs)} s for the whole chain, redirects included)`; return failure( "timeout", - `That server did not answer within ${seconds(limits.hopTimeoutMs)} s ` + - `(${seconds(limits.totalTimeoutMs)} s for the whole chain, redirects included). ` + - "Download the document and use “Upload a file” or “Paste JSON”: both validate it in " + + `That server did not answer within ${budget}. That makes this origin slow, ` + + "not this feed invalid — the document may well be fine. " + + "Download it and use “Upload a file” or “Paste JSON”: both validate it in " + "your browser, without this fetch step.", 504, ); } +/** + * Nothing accepted a connection. Worded apart from the timeout above because + * it is a different diagnosis with a different next step: there, a document + * exists and the origin is slow to produce it; here, nothing answered the + * door, and downloading the feed by hand is not going to work either. + */ +function noConnection(limits: FetchLimits): FetchFailure { + return failure( + "no-connection", + `Nothing accepted a connection at that address within ${seconds(limits.connectTimeoutMs)} s. ` + + "The host may be down, or the port may be closed or firewalled. " + + "Check the URL and whether the feed is reachable from outside its own network.", + 502, + ); +} + +/** Where a probe should knock, when the URL leaves it implicit. */ +function portOf(url: URL): number { + if (url.port) return Number(url.port); + return url.protocol === "https:" ? 443 : 80; +} + +/** + * Statuses worth one more attempt. 429 and 5xx are the server saying "not + * now"; a 404 is it saying "not ever", and asking twice only doubles the load + * on an origin that already answered. + */ +function worthRetrying(status: number): boolean { + return status === 429 || status >= 500; +} + +const sleep = (ms: number): Promise => new Promise((resolve) => setTimeout(resolve, ms)); + /** * Reads at most `maxBytes` from the stream, then stops and reports. * @@ -154,6 +265,81 @@ async function readCapped( return { ok: true, text: chunks.join(""), bytes }; } +/** A hop that produced a response, with the clock reading when it started. */ +interface HopResponse { + ok: true; + response: Response; + startedAt: number; +} + +/** + * One hop, attempted up to `maxAttempts` times. + * + * The retry exists because the other two tools in the ecosystem have one, and + * for the same reason: a reset connection or a 502 from a shared host is not + * a verdict about the feed. It is deliberately *narrower* than theirs, because + * they run unattended on a schedule while this endpoint has somebody watching + * a spinner — **a timeout is never retried**. Having waited the full budget + * once, waiting it again turns a 60 s answer into a 120 s one and still says + * "slow" at the end. Retries are for failures that arrived fast. + */ +async function requestHop( + url: URL, + limits: FetchLimits, + deadline: number, + deps: FetchDeps, + roomForRetry: () => boolean, +): Promise { + // Once per hop, not once per attempt: a retry after a 5xx has already been + // answered by something, so there is nothing left to establish. + if (deps.probe) { + const budget = Math.min(limits.connectTimeoutMs, deadline - Date.now()); + if (budget <= 0) return timedOut(limits); + if ((await deps.probe(url.hostname, portOf(url), budget)) === "no-connection") { + return noConnection(limits); + } + } + + for (let attempt = 1; ; attempt++) { + const remaining = Math.min(limits.hopTimeoutMs, deadline - Date.now()); + if (remaining <= 0) return timedOut(limits); + + const startedAt = Date.now(); + let response: Response; + try { + response = await deps.fetchImpl(url.toString(), { + method: "GET", + redirect: "manual", + signal: AbortSignal.timeout(remaining), + // A fixed, honest, anonymous request: no cookies, no authorization, + // nothing identifying whoever asked for this URL. + headers: { + accept: + "application/ote+json, application/feed+json, application/json;q=0.9, text/html;q=0.8, */*;q=0.1", + "user-agent": "OTE-Validator/0.1 (+https://tools.opentechevents.org/validator/)", + }, + }); + } catch (error) { + if (error instanceof Error && error.name === "TimeoutError") return timedOut(limits); + if (attempt < limits.maxAttempts && roomForRetry()) { + await sleep(limits.retryBackoffMs); + continue; + } + return failure("upstream-error", "That URL could not be fetched.", 502); + } + + if (worthRetrying(response.status) && attempt < limits.maxAttempts && roomForRetry()) { + // The body of a discarded answer is never read, so release it rather + // than leaving a stream open for the rest of the invocation. + await response.body?.cancel().catch(() => {}); + await sleep(limits.retryBackoffMs); + continue; + } + + return { ok: true, response, startedAt }; + } +} + /** * Fetches a URL under the SSRF and resource rules. * @@ -172,10 +358,13 @@ async function readCapped( */ export async function fetchDocument(rawUrl: string, deps: FetchDeps): Promise { const limits = { ...DEFAULT_LIMITS, ...deps.limits }; - const deadline = Date.now() + limits.totalTimeoutMs; + const deadline = deps.deadline ?? Date.now() + limits.totalTimeoutMs; const redirects: string[] = []; let current = rawUrl; + /** Enough budget left that a second attempt can plausibly finish. */ + const roomForRetry = (): boolean => deadline - Date.now() > limits.retryBackoffMs + 1_000; + for (let hop = 0; hop <= limits.maxRedirects; hop++) { const checked = checkUrl(current); if (!checked.ok) return { ok: false, status: 400, code: checked.code, message: checked.message }; @@ -183,29 +372,9 @@ export async function fetchDocument(rawUrl: string, deps: FetchDeps): Promise Promise; + /** + * The connect check (`tcp-probe.ts`). Optional because the tests run under + * plain vitest, where `cloudflare:sockets` does not exist; see `lazyProbe`. + */ + probe?: TcpProbe; /** Absent in tests that do not care about caching, and in `wrangler dev`. */ cache?: BadgeCache; } @@ -184,7 +190,11 @@ async function handleBadge( ); } - const verdict = await resolveBadge(target, { fetchImpl: deps.fetchImpl, resolve: deps.resolve }); + const verdict = await resolveBadge(target, { + fetchImpl: deps.fetchImpl, + resolve: deps.resolve, + probe: deps.probe, + }); const ttl = badgeTtlSeconds(verdict.state); const response = new Response(renderBadge(verdict.state), { status: 200, @@ -319,7 +329,11 @@ export async function handleRequest(request: Request, env: Env, deps: Deps): Pro ); } - const result = await fetchDocument(target, { fetchImpl: deps.fetchImpl, resolve: deps.resolve }); + const result = await fetchDocument(target, { + fetchImpl: deps.fetchImpl, + resolve: deps.resolve, + probe: deps.probe, + }); return json(toResponseBody(result), result.ok ? 200 : result.status, cors); } @@ -335,11 +349,29 @@ export async function handleRequest(request: Request, env: Env, deps: Deps): Pro */ const boundFetch: typeof fetch = (input, init) => fetch(input, init); +/** + * The connect check, imported at first use rather than at module load. + * + * `cloudflare:sockets` exists only inside the Workers runtime, and this + * module is imported directly by the test suite, which runs on Node. A static + * import would make every test in `handler.test.ts` fail to load — so the + * import happens inside the call, which only ever happens in production. + * + * It is exported so a test can assert the wiring is here without evaluating + * it: a preflight that silently stopped being passed to `fetchDocument` would + * cost a visitor 52 extra seconds on a dead host and break no test. + */ +export const lazyProbe: TcpProbe = async (hostname, port, budgetMs) => { + const { tcpProbe } = await import("./tcp-probe.js"); + return tcpProbe(hostname, port, budgetMs); +}; + export default { fetch(request: Request, env: Env): Promise { return handleRequest(request, env, { fetchImpl: boundFetch, resolve: dohResolver(boundFetch), + probe: lazyProbe, cache: caches.default, }); }, diff --git a/workers/validator/src/tcp-probe.ts b/workers/validator/src/tcp-probe.ts new file mode 100644 index 0000000..f0b847e --- /dev/null +++ b/workers/validator/src/tcp-probe.ts @@ -0,0 +1,78 @@ +/** + * "Is anything listening there at all?" — the connect deadline, separated from + * the download one. + * + * `fetch` cannot express this. One `AbortSignal` covers connect, TLS, the + * origin thinking and the bytes moving alike, so a single budget has to be + * large enough for the slowest legitimate origin — 60 s, see + * `fetch-document.ts` — and a host whose SYNs are silently dropped then costs + * a visitor that whole 60 s before anyone says so. Measured against the + * deployed runtime: a closed-but-filtered port spends the entire budget and + * comes back indistinguishable from a slow feed. + * + * A bare TCP connection separates the two in well under a second. The + * registered feed this all started with (#70) takes 23.6 s to *answer* and + * 0.1 s to *accept a connection*; a filtered port accepts nothing, ever. So + * each hop opens a socket first, under a budget of its own, and only a host + * that proved something is listening earns the long clock. + * + * Two things learned the hard way, both from probing the real runtime: + * + * - **Probe the hostname, not the address we validated.** Connecting to an + * IP literal does not behave: `93.184.215.14:443` timed out at 6 s while + * `example.com:443` opened in 25 ms, and an IPv6 literal is refused by the + * runtime outright ("cannot connect to the specified address"). The SSRF + * checks still run on the resolved addresses before this is called, and the + * probe learns nothing the fetch that follows would not also learn. + * - **Never await `close()` on a socket that never opened.** It may not + * settle, and awaiting it hangs the request for longer than the budget this + * module exists to impose. + */ + +import { connect } from "cloudflare:sockets"; + +/** + * What the probe concluded. + * + * `inconclusive` is deliberately not a failure: see `tcpProbe`. + */ +export type ProbeOutcome = "open" | "no-connection" | "inconclusive"; + +export type TcpProbe = (hostname: string, port: number, budgetMs: number) => Promise; + +/** + * Opens a TCP connection and closes it, or gives up. + * + * **Fails open on purpose.** Anything other than a clean "nothing accepted a + * connection inside the budget" comes back `inconclusive`, and the caller + * proceeds to the real fetch as if no probe had run. A probe is an + * optimization on the clock, not a second opinion about whether a feed exists: + * it may shorten a hopeless wait, and it must never be able to invent a + * failure for a feed that would have loaded. The runtime refusing to connect + * to some address shape is exactly the case that would otherwise turn a + * working feed unreachable. + */ +export const tcpProbe: TcpProbe = async (hostname, port, budgetMs) => { + let timer: ReturnType | undefined; + try { + const socket = connect({ hostname, port }); + const outcome = await Promise.race([ + socket.opened.then( + () => "open", + // A refusal (RST) is not reported as `no-connection`: the fetch that + // follows fails on it just as fast, with a better message. + () => "inconclusive", + ), + new Promise((resolve) => { + timer = setTimeout(() => resolve("no-connection"), budgetMs); + }), + ]); + // Not awaited: closing a socket that never opened may never settle. + void socket.close().catch(() => {}); + return outcome; + } catch { + return "inconclusive"; + } finally { + if (timer) clearTimeout(timer); + } +}; diff --git a/workers/validator/test/badge.test.ts b/workers/validator/test/badge.test.ts index db9ad2a..3217d9e 100644 --- a/workers/validator/test/badge.test.ts +++ b/workers/validator/test/badge.test.ts @@ -1,6 +1,6 @@ import { describe, expect, it, vi } from "vitest"; -import { renderBadge, resolveBadge, type BadgeState } from "../src/badge.js"; +import { badgeTtlSeconds, renderBadge, resolveBadge, type BadgeState } from "../src/badge.js"; import { handleRequest, type BadgeCache } from "../src/index.js"; /** @@ -77,6 +77,18 @@ function network(pages: Record): }) as unknown as typeof fetch; } +/** A host that accepts the request and then says nothing until aborted. */ +function neverAnswers(): typeof fetch { + return (async (_input: unknown, init?: RequestInit) => + new Promise((_resolve, reject) => { + init?.signal?.addEventListener("abort", () => { + const error = new Error("timed out"); + error.name = "TimeoutError"; + reject(error); + }); + })) as unknown as typeof fetch; +} + const json = (body: string) => ({ body, contentType: "application/ote+json" }); const html = (body: string) => ({ body, contentType: "text/html" }); @@ -159,6 +171,48 @@ describe("resolveBadge", () => { expect(verdict.state).toBe("unreachable"); }); + it("says slow, not unreachable, when the origin is merely late", async () => { + // The visible half of #70: this badge sat on a registered adopter's + // README reading "OTE feed: unreachable" over a feed that answers 200. + const verdict = await resolveBadge("https://comunidad.example/feed.json", { + fetchImpl: neverAnswers(), + resolve, + limits: { hopTimeoutMs: 50, totalTimeoutMs: 50 }, + }); + expect(verdict.state).toBe("slow"); + expect(badgeTtlSeconds("slow")).toBeLessThanOrEqual(300); + }); + + it("keeps its two fetches inside one budget, not one each", async () => { + // A page that declares a feed costs two fetches. With a budget apiece, a + // single badge request could hold a reader's connection for 120 s. + const page = html( + '' + + "", + ); + const fetchImpl = (async (input: RequestInfo | URL, init?: RequestInit) => { + if (input.toString() === "https://comunidad.example/") { + await new Promise((resolve) => setTimeout(resolve, 80)); + return new Response(page.body, { + status: 200, + headers: { "content-type": page.contentType }, + }); + } + return neverAnswers()(input, init); + }) as unknown as typeof fetch; + + const started = Date.now(); + const verdict = await resolveBadge("https://comunidad.example/", { + fetchImpl, + resolve, + limits: { hopTimeoutMs: 120, totalTimeoutMs: 120 }, + }); + expect(verdict.state).toBe("slow"); + // 80 ms of the 120 went on the page, so the feed fetch had ~40 left. With + // a budget apiece this takes 80 + 120; sharing one, it ends at 120. + expect(Date.now() - started).toBeLessThan(160); + }); + it("applies the same SSRF rules as /fetch", async () => { const verdict = await resolveBadge("http://169.254.169.254/latest/meta-data/", { fetchImpl: network({}), @@ -176,6 +230,7 @@ describe("renderBadge", () => { "not-discovered", "ambiguous", "unreachable", + "slow", ]; it("draws only its own constants, never anything fetched", () => { diff --git a/workers/validator/test/fetch-document.test.ts b/workers/validator/test/fetch-document.test.ts index adb41b6..75dd015 100644 --- a/workers/validator/test/fetch-document.test.ts +++ b/workers/validator/test/fetch-document.test.ts @@ -1,6 +1,6 @@ import { describe, expect, it, vi } from "vitest"; -import { fetchDocument } from "../src/fetch-document.js"; +import { DEFAULT_LIMITS, fetchDocument } from "../src/fetch-document.js"; const PUBLIC_IP = "93.184.216.34"; @@ -38,6 +38,22 @@ function hugeStream(chunks: number): Response { return new Response(stream, { status: 200, headers: { "content-type": "application/json" } }); } +/** + * A host that accepts the request and then says nothing — the only failure + * that really does spend the whole budget, and the one indistinguishable from + * a slow origin from out here. + */ +function neverAnswers(): typeof fetch { + return (async (_input: unknown, init?: RequestInit) => + new Promise((_resolve, reject) => { + init?.signal?.addEventListener("abort", () => { + const error = new Error("timed out"); + error.name = "TimeoutError"; + reject(error); + }); + })) as unknown as typeof fetch; +} + describe("fetchDocument", () => { it("returns the bytes, the final URL and the content-type", async () => { const result = await fetchDocument("https://comunidad.example/feed.json", { @@ -109,6 +125,21 @@ describe("fetchDocument", () => { expect(result).toMatchObject({ ok: false, code: "too-many-redirects" }); }); + it("waits the 60 s the rest of the ecosystem waits", () => { + // Not a style preference: at 5 s/10 s this endpoint called a registered + // adopter's feed unreachable while the bot that links here told the same + // publisher it was valid (#70). https://eventos.wiki/events.json answers + // 200 with ~554 KB in 23.6-51 s, measured; the spec repo's health check + // and its registration bot both wait 60 s. Lower this and the bug is back + // on the feed's slower days. + expect(DEFAULT_LIMITS.totalTimeoutMs).toBeGreaterThanOrEqual(60_000); + // The one hop of a direct feed must be able to spend the whole budget — + // a per-hop ceiling below it would re-break exactly that feed. + expect(DEFAULT_LIMITS.hopTimeoutMs).toBeGreaterThanOrEqual( + DEFAULT_LIMITS.totalTimeoutMs, + ); + }); + it("names the limit it hit, and the modes that do not need this service", async () => { // A slow origin is nobody's bug, so the message has to leave the organizer // with a next step rather than just "took too long". @@ -133,6 +164,165 @@ describe("fetchDocument", () => { expect((result as { message: string }).message).toMatch(/Paste JSON/); }); + it("calls a slow origin slow, and never invalid or unreachable", async () => { + // The word is the fix (#70): "unreachable" over a feed that is valid and + // merely slow to generate reads as an accusation in the publisher's + // README, and the badge takes its wording from here. + const result = await fetchDocument("https://comunidad.example/slow.json", { + fetchImpl: neverAnswers(), + resolve: resolver(), + limits: { hopTimeoutMs: 100, totalTimeoutMs: 100 }, + }); + const message = (result as { message: string }).message; + expect(message).toMatch(/this origin slow/); + expect(message).not.toMatch(/unreachable/i); + // Says which of the two is at fault, rather than leaving it open. + expect(message).toMatch(/not this feed invalid/); + // One budget for hop and chain means one number in the message, not the + // same number twice as if two separate limits had been hit. + expect(message.match(/0\.1 s/g)).toHaveLength(1); + }); + + it("tries a second time after a transport error, and says so only once", async () => { + const attempts = vi.fn(); + const flaky = (async () => { + if (attempts.mock.calls.length === 0) { + attempts(); + throw new TypeError("network error"); + } + attempts(); + return json('{"a":1}'); + }) as unknown as typeof fetch; + + const result = await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: flaky, + resolve: resolver(), + limits: { retryBackoffMs: 1 }, + }); + expect(result).toMatchObject({ ok: true, body: '{"a":1}' }); + expect(attempts).toHaveBeenCalledTimes(2); + }); + + it("tries a second time after a 503, which is the host saying “not now”", async () => { + const spy = vi.fn(async () => new Response("busy", { status: 503 })); + const result = await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: spy as unknown as typeof fetch, + resolve: resolver(), + limits: { retryBackoffMs: 1 }, + }); + expect(result).toMatchObject({ ok: false, code: "upstream-error" }); + expect(spy).toHaveBeenCalledTimes(2); + }); + + it("does not ask twice about a 404, which is the host saying “not ever”", async () => { + const spy = vi.fn(async () => new Response("nope", { status: 404 })); + await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: spy as unknown as typeof fetch, + resolve: resolver(), + limits: { retryBackoffMs: 1 }, + }); + expect(spy).toHaveBeenCalledTimes(1); + }); + + it("never retries a timeout", async () => { + // The deliberate divergence from the health check and the registration + // bot, which do retry one: those run unattended, while somebody is + // watching this endpoint. Having waited the whole budget once, waiting it + // again doubles the wait and still ends in "slow". + const spy = vi.fn(neverAnswers()); + const result = await fetchDocument("https://comunidad.example/slow.json", { + fetchImpl: spy as unknown as typeof fetch, + resolve: resolver(), + limits: { hopTimeoutMs: 50, totalTimeoutMs: 50, retryBackoffMs: 1 }, + }); + expect(result).toMatchObject({ ok: false, code: "timeout" }); + expect(spy).toHaveBeenCalledTimes(1); + }); + + it("gives up in the connect budget when nothing is listening", async () => { + // The mirror-image false negative of #70, and the reason the 60 s above is + // affordable: measured against the deployed runtime, a live host with a + // filtered port spent the entire 60 s and came back reading "slow". A TCP + // probe settles it in 8, and the adopter feed that needs the long clock + // accepts a connection in 0.1 s. + const spy = vi.fn(neverAnswers()); + const result = await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: spy as unknown as typeof fetch, + resolve: resolver(), + probe: async () => "no-connection", + }); + expect(result).toMatchObject({ ok: false, code: "no-connection", status: 502 }); + // Nothing is listening, so no 60 s fetch is even started. + expect(spy).not.toHaveBeenCalled(); + const message = (result as { message: string }).message; + expect(message).toContain("8 s"); + // "Slow" is the other diagnosis, with a different next step; the upload + // and paste modes cannot rescue a URL that nothing answers. + expect(message).not.toMatch(/slow/i); + expect(message).not.toMatch(/Paste JSON/); + }); + + it("knocks on the port the URL implies, and only once per hop", async () => { + const probe = vi.fn(async (_host: string, _port: number, _budgetMs: number) => "open" as const); + await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: fakeFetch({ "https://comunidad.example/feed.json": () => json("{}") }), + resolve: resolver(), + probe, + }); + expect(probe).toHaveBeenCalledWith("comunidad.example", 443, 8_000); + + const explicit = vi.fn( + async (_host: string, _port: number, _budgetMs: number) => "open" as const, + ); + await fetchDocument("http://comunidad.example:8080/feed.json", { + fetchImpl: fakeFetch({ "http://comunidad.example:8080/feed.json": () => json("{}") }), + resolve: resolver(), + probe: explicit, + }); + expect(explicit).toHaveBeenCalledWith("comunidad.example", 8080, 8_000); + }); + + it("proceeds anyway when the probe cannot tell — it may shorten a wait, never invent a failure", async () => { + // The probe fails open by design. Connecting to an IP literal does not + // behave in the runtime (an IPv6 literal is refused outright), so an + // inconclusive probe must cost nothing rather than turn a working feed + // unreachable. + const result = await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: fakeFetch({ "https://comunidad.example/feed.json": () => json('{"a":1}') }), + resolve: resolver(), + probe: async () => "inconclusive", + }); + expect(result).toMatchObject({ ok: true, body: '{"a":1}' }); + }); + + it("re-probes each redirect hop, since a redirect can point anywhere", async () => { + const probe = vi.fn(async (_host: string, _port: number, _budgetMs: number) => "open" as const); + await fetchDocument("https://comunidad.example/feed", { + fetchImpl: fakeFetch({ + "https://comunidad.example/feed": () => redirect("https://cdn.example/feed.json"), + "https://cdn.example/feed.json": () => json("{}"), + }), + resolve: resolver(), + probe, + }); + expect(probe.mock.calls.map((call) => call[0])).toEqual([ + "comunidad.example", + "cdn.example", + ]); + }); + + it("honours a deadline set by its caller instead of starting a fresh budget", async () => { + // How the badge keeps its two fetches inside one advertised ceiling. + const spy = vi.fn(async () => json("{}")); + const result = await fetchDocument("https://comunidad.example/feed.json", { + fetchImpl: spy as unknown as typeof fetch, + resolve: resolver(), + deadline: Date.now() - 1, + }); + expect(result).toMatchObject({ ok: false, code: "timeout" }); + expect(spy).not.toHaveBeenCalled(); + }); + it("cuts a 50 MB response at the cap without buffering it", async () => { const result = await fetchDocument("https://comunidad.example/huge.json", { fetchImpl: fakeFetch({ "https://comunidad.example/huge.json": () => hugeStream(50) }), diff --git a/workers/validator/test/handler.test.ts b/workers/validator/test/handler.test.ts index b680360..60a60ba 100644 --- a/workers/validator/test/handler.test.ts +++ b/workers/validator/test/handler.test.ts @@ -1,6 +1,6 @@ import { describe, expect, it, vi } from "vitest"; -import { handleRequest, type Env } from "../src/index.js"; +import { handleRequest, lazyProbe, type Env } from "../src/index.js"; const ORIGIN = "https://tools.opentechevents.org"; @@ -162,6 +162,14 @@ describe("handleRequest", () => { expect(response.status).toBe(404); }); + it("wires the connect check into the deps the Worker actually runs with", () => { + // Asserted without calling it: `cloudflare:sockets` does not exist under + // vitest. The point is the wiring — a preflight that quietly stopped + // being passed through would cost a visitor 52 extra seconds on a dead + // host and break no other test in this file. + expect(typeof lazyProbe).toBe("function"); + }); + it("has a health endpoint that publishes its limits", async () => { const response = await handleRequest(new Request("https://validator.example/health"), {}, { fetchImpl: okFetch, @@ -169,7 +177,17 @@ describe("handleRequest", () => { }); await expect(response.json()).resolves.toMatchObject({ ok: true, - limits: { maxBytes: 5 * 1024 * 1024, maxRedirects: 3 }, + // The timeouts are published because callers reason about them: the + // other two tools in the ecosystem wait 60 s, and a reader has to be + // able to see that this one does too (#70). + limits: { + maxBytes: 5 * 1024 * 1024, + maxRedirects: 3, + hopTimeoutMs: 60_000, + totalTimeoutMs: 60_000, + connectTimeoutMs: 8_000, + maxAttempts: 2, + }, }); }); });