From 132e2d886179e8c90956cd93f932f160871505df Mon Sep 17 00:00:00 2001 From: Rasmus Widing Date: Tue, 28 Jul 2026 15:30:55 +0300 Subject: [PATCH 1/5] fix(engine-client): a call that is never answered is a failure, not a wait MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `fetch` has no timeout, so a connection the engine ACCEPTS and never answers hangs forever. Only the drain was bounded; every other call — including the one `kild watch` polls with — waited indefinitely. That defeats a guarantee already shipped. `kild watch` distinguishes a quiet engine (exit 2) from a dead one (exit 3), and a hung call sits inside a single poll past the whole window, reporting neither. The verb looks patient at exactly the moment it has stopped working, which is the failure it was built to remove. `engineFetch` now applies a 30s backstop when a caller supplies no signal of its own. Deliberately generous: it exists to stop an unbounded wait, not to budget latency, so it has to clear the slowest legitimate call — a land's merge, a new kild's worktree — without argument. A caller's own signal wins outright rather than being combined, because a narrower deadline was chosen for a reason and capping it at the default would make the tighter bound a lie. `kild watch` bounds each poll to its own cadence, floored at 1s so a deliberately tiny --interval cannot turn a healthy engine into a failing one. A hang is then an ordinary tolerated failure, and three of them an honest `unreachable`. The timeout is reported as what it is. An abort surfaces as "the operation was aborted", which tells a caller nothing about whether to retry — and a hook that swallowed it would be swallowing the one symptom separating a wedged engine from a quiet one. It now names the path and says the engine accepted the connection and did not answer. One test I wrote was wrong and I moved it rather than weakening it: a 5s hang never trips a 30s default, so it proved nothing. The wording is now asserted where the path is actually reachable — the drain's own 1.5s bound, and watch's per-poll bound — instead of behind a 30s test. Gates: 442 tests, typecheck, lint, e2e 70/70. Dogfooded against a real server that accepts and never answers: exit 3 in 4s, where before it would have waited out the full 300s window and reported nothing. --- engine/src/cli.attached.test.ts | 59 ++++++++++++++++++++++++++++++++ engine/src/cli.ts | 3 +- engine/src/kild/engine-client.ts | 44 ++++++++++++++++++++++-- engine/src/kild/watch.ts | 18 ++++++++++ 4 files changed, 120 insertions(+), 4 deletions(-) diff --git a/engine/src/cli.attached.test.ts b/engine/src/cli.attached.test.ts index 52985ee6..1ba4ec3c 100644 --- a/engine/src/cli.attached.test.ts +++ b/engine/src/cli.attached.test.ts @@ -38,6 +38,12 @@ let authHeaders: Array = []; /** What an `attach` answers with, when a test needs it to differ from `drainResponse` — a * send mints its credential through attach, so those tests need both to be distinct. */ let attachResponse: { status: number; body: unknown } | undefined; +/** Milliseconds a `/messages` request is left hanging before answering. The failure mode this + * models is NOT a refused connection — it is one the engine ACCEPTS and never answers, which + * `fetch` will wait on forever unless something bounds it. */ +let messagesHangMs = 0; +/** Same, for the drain — it carries its own tighter bound, so it needs its own hang. */ +let drainHangMs = 0; /** What `GET /messages` answers with. `kild watch` reads the log, never the inbox, so its * tests drive this rather than `drainResponse`. */ let messagesResponse: { status: number; body: unknown } | undefined; @@ -58,6 +64,12 @@ beforeAll(async () => { if (url.pathname.endsWith('/agents/attach') && attachResponse) { return Response.json(attachResponse.body, { status: attachResponse.status }); } + if (url.pathname.endsWith('/inbox/drain') && drainHangMs > 0) { + await new Promise((resolve) => setTimeout(resolve, drainHangMs)); + } + if (url.pathname.endsWith('/messages') && messagesHangMs > 0) { + await new Promise((resolve) => setTimeout(resolve, messagesHangMs)); + } if (url.pathname.endsWith('/messages') && messagesResponse) { return Response.json(messagesResponse.body, { status: messagesResponse.status }); } @@ -645,3 +657,50 @@ test('the quiet message reports the time that actually elapsed', async () => { expect(quiet.stderr).toMatch(/nothing new in \d+s/); messagesResponse = undefined; }); + +test('a hung engine is unreachable, not patient', async () => { + // The gap that survived the watch review: `fetch` has no timeout, so a connection the engine + // ACCEPTS and never answers hangs inside a single poll regardless of any deadline built on + // top of it. A watcher would sit past its whole window reporting neither mail nor a dead + // engine — defeating the exit-3 distinction it exists to draw. + messagesHangMs = 30_000; + const started = Date.now(); + const hung = await runCli([ + 'watch', + 'kild-9', + '--as', + 'kild', + '--since', + '1', + '--timeout', + '60', + '--interval', + '0.1', + ]); + const elapsed = Date.now() - started; + expect(hung.exitCode).toBe(3); + expect(hung.stderr).toContain('unreachable'); + expect(hung.stderr).toContain('timed out'); // the cause rides the report, not just "aborted" + + // Three attempts, each bounded by the 1s request floor — not the 60s window, and certainly + // not the 30s hang. + expect(elapsed).toBeLessThan(15_000); + messagesHangMs = 0; +}, 30_000); + +test('a drain against a hung engine times out, and says so', async () => { + // The drain carries its own 1.5s bound because it runs inside a turn-end hook. This proves + // the bound is actually applied and that the message names the cause — an opaque "aborted" + // tells a caller nothing about whether to retry. + messagesHangMs = 0; + drainHangMs = 10_000; + const loud = await runCli(['inbox', 'kild-9', '--as', 'kild']); + expect(loud.exitCode).toBe(1); + expect(loud.stderr).toContain('timed out'); + + // ...and the same failure inside the hook is silence, because a hook may never block a turn. + const hook = await runCli(['inbox', 'kild-9', '--as', 'kild', '--format', 'claude-stop']); + expect(hook.stdout).toBe(''); + expect(hook.exitCode).toBe(0); + drainHangMs = 0; +}, 30_000); diff --git a/engine/src/cli.ts b/engine/src/cli.ts index e4f9cf3e..14cf172b 100755 --- a/engine/src/cli.ts +++ b/engine/src/cli.ts @@ -40,6 +40,7 @@ import { WATCH_EXIT, WATCH_POLL_MS, WATCH_TOLERATED_FAILURES, + watchRequestTimeout, watchSummary, } from './kild/watch.ts'; @@ -407,7 +408,7 @@ async function kildWatch(idArg: string | undefined): Promise { since: number | undefined, ): Promise> | null> { try { - const batch = await kildMessages(kildId, since); + const batch = await kildMessages(kildId, since, watchRequestTimeout(interval)); failures = 0; return batch; } catch (err) { diff --git a/engine/src/kild/engine-client.ts b/engine/src/kild/engine-client.ts index 5e545a47..3859ba75 100644 --- a/engine/src/kild/engine-client.ts +++ b/engine/src/kild/engine-client.ts @@ -29,8 +29,39 @@ export interface KildActionResponse { message: string; } +/** + * How long any engine call may take before it is a failure rather than a wait. + * + * `fetch` has no timeout of its own, so a connection the engine ACCEPTS and then never + * answers hangs forever. That is not a hypothetical: it is the shape where a caller looks + * patient while it is actually dead, and it defeats every deadline built on top of it — + * `kild watch` could sit inside one poll past its whole window and report neither mail nor + * an unreachable engine, which is exactly the distinction its exit codes exist to draw. + * + * Generous on purpose. This is a backstop against hanging forever, not a latency budget: it + * has to clear the slowest legitimate call (a land's merge, a new kild's worktree) without + * argument. Anything needing tighter bounds passes its own `signal` — the drain does, because + * it runs inside a turn-end hook where a stall costs the operator a visible pause. + */ +const ENGINE_TIMEOUT_MS = 30_000; + async function engineFetch(path: string, init?: RequestInit): Promise { - const response = await fetch(`${ENGINE}${path}`, init); + // A caller's own signal wins outright rather than being combined: it is a narrower deadline + // chosen for a reason, and silently capping it at the default would make the tighter bound a + // lie. Nothing here may be slower than a caller asked for. + const signal = init?.signal ?? AbortSignal.timeout(ENGINE_TIMEOUT_MS); + let response: Response; + try { + response = await fetch(`${ENGINE}${path}`, { ...init, signal }); + } catch (err) { + // A timeout arrives as an opaque abort. Say what actually happened — "the operation was + // aborted" tells a caller nothing about whether to retry, and a hook that swallows it + // would be swallowing the one symptom that distinguishes a wedged engine from a quiet one. + if (err instanceof Error && (err.name === 'TimeoutError' || err.name === 'AbortError')) { + throw new Error(`${path} timed out — the engine accepted the connection and did not answer`); + } + throw err; + } if (!response.ok) { const body = (await response.json().catch(() => ({}))) as { error?: string }; throw new Error(body.error ?? `${path} failed (${response.status})`); @@ -127,9 +158,16 @@ export async function getKild(kildId: string): Promise { /** A kild's message log, cursored by `seq`. `since` is exclusive — pass the last seq you * saw. Works for an archived kild too: its log is the read-only record. */ -export async function kildMessages(kildId: string, since?: number): Promise { +export async function kildMessages( + kildId: string, + since?: number, + timeoutMs?: number, +): Promise { const suffix = since === undefined ? '' : `?since=${since}`; - return engineFetch(`/api/kilds/${encodeURIComponent(kildId)}/messages${suffix}`); + return engineFetch( + `/api/kilds/${encodeURIComponent(kildId)}/messages${suffix}`, + timeoutMs === undefined ? undefined : { signal: AbortSignal.timeout(timeoutMs) }, + ); } export interface AttachResponse extends KildActionResponse { diff --git a/engine/src/kild/watch.ts b/engine/src/kild/watch.ts index 930a0dec..b0ee4ba7 100644 --- a/engine/src/kild/watch.ts +++ b/engine/src/kild/watch.ts @@ -45,6 +45,24 @@ export const WATCH_TOLERATED_FAILURES = 3; * is not immortal. */ export const WATCH_DEFAULT_TIMEOUT_S = 1_800; +/** Floor for a single poll's request timeout. A deliberately tiny `--interval` must not turn a + * healthy engine into a failing one just because a loopback round-trip took a few more + * milliseconds than the cadence. */ +export const WATCH_REQUEST_FLOOR_MS = 1_000; + +/** + * How long ONE poll may wait for an answer. + * + * A poll that outlasts its own cadence is not waiting, it is stuck: without this the request + * inherits the client's 30s backstop and a single hung call can swallow a whole short window, + * so a wedged engine looks patient rather than unreachable — the precise distinction the exit + * codes exist to draw. Bounding each attempt turns a hang into a tolerated failure, and three + * of those into an honest `unreachable`. + */ +export function watchRequestTimeout(intervalMs: number): number { + return Math.max(intervalMs, WATCH_REQUEST_FLOOR_MS); +} + /** What one poll concluded. */ export interface WatchPoll { /** Messages from somebody other than the watcher, in arrival order. Empty means keep going. */ From c275d79e557fe5513ac55a8c8fbfbef9507387ca Mon Sep 17 00:00:00 2001 From: Rasmus Widing Date: Tue, 28 Jul 2026 15:46:26 +0300 Subject: [PATCH 2/5] fix(cli): one answer to "how much time is left", and never claim quiet unheard MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Review found this PR made a confidently-wrong exit reachable, which is worse than the hang it fixed. Six findings; all addressed. THE CRITICAL ONE, and it is the same defect for the third time on this feature: two decisions answering one question. The per-poll bound used the interval; the loop's deadline used the deadline. With `--interval 10 --timeout 3` against a hung engine the first poll blocked ten seconds, overran the window threefold, and then reported QUIET — asserting the engine had answered and had nothing, after every request had failed. `watchRequestTimeout` now takes what remains of the window as a required argument, so the two answers cannot drift because there is only one. The other half: "quiet" is a claim ABOUT the engine — that it responded and had nothing new. A watcher that never heard from it cannot make that claim. A window closing with no successful poll now exits `unreachable`, not `quiet`. That is a behaviour change and one existing test asserted the old answer; its expectation was wrong and is corrected rather than relaxed — what it exists to check is the elapsed time, which is unchanged. A CLIENT ABORT DOES NOT REACH THE ENGINE. Nothing passes a signal server-side and no git command it runs is cancellable, so a timed-out `land` may still merge and a timed-out `rm` may still remove the tree. Reporting that as a plain failure is the worst available answer: the operator retries a merge that already happened. Both now report the outcome as UNKNOWN and say to check before retrying — the same rule the disposal path already follows for its discard list. `kild show` swallowed every message failure into an empty log. Harmless while a hung engine hung visibly; a confident lie the moment a timeout made the call return. It reports the failure now. The timeout is decided by WHOSE signal fired, not by matching an error name. Name-matching would relabel the first future caller that cancels for any other reason — a Ctrl-C — as "the engine did not answer", the opposite of true. The original error rides along as `cause`. The backstop is overridable via KILD_ENGINE_TIMEOUT_MS. 30s is a guess about somebody else's disk, and an operator whose merge legitimately exceeds it needs a way out that is not editing the source. It also closes the coverage gap the review proved: removing the default left the suite green, because both hang tests supply their own signals and bypass it. A test now goes through `kild log`, which supplies none. Also corrected a claim of mine in the comment: `kild new` is NOT bounded by this call. `spawn` returns without awaiting and the worktree is created in the child. `land` and `rm` are the calls this budget actually has to clear. Gates: 445 tests, typecheck, lint, e2e 70/70. Dogfooded the exact reported regression against a server that accepts and never answers: 3040ms and exit 3, where it was 10036ms and exit 2. --- engine/src/cli.attached.test.ts | 65 +++++++++++++++++++++++++++++++- engine/src/cli.ts | 59 ++++++++++++++++++++++++++--- engine/src/kild/engine-client.ts | 36 +++++++++++------- engine/src/kild/watch.ts | 18 ++++++--- 4 files changed, 151 insertions(+), 27 deletions(-) diff --git a/engine/src/cli.attached.test.ts b/engine/src/cli.attached.test.ts index 1ba4ec3c..10a57ca2 100644 --- a/engine/src/cli.attached.test.ts +++ b/engine/src/cli.attached.test.ts @@ -44,6 +44,8 @@ let attachResponse: { status: number; body: unknown } | undefined; let messagesHangMs = 0; /** Same, for the drain — it carries its own tighter bound, so it needs its own hang. */ let drainHangMs = 0; +/** What the CLI under test uses as its default backstop. */ +let engineTimeoutMs = '30000'; /** What `GET /messages` answers with. `kild watch` reads the log, never the inbox, so its * tests drive this rather than `drainResponse`. */ let messagesResponse: { status: number; body: unknown } | undefined; @@ -110,6 +112,9 @@ async function runCli( ...process.env, KILD_ENGINE: engineOverride ?? engineUrl, KILD_HOME: kildHome, + // Keep the backstop testable. Without an override the only way to exercise the DEFAULT is + // a 30s test, so nothing covered it and removing it entirely left the suite green. + KILD_ENGINE_TIMEOUT_MS: engineTimeoutMs, }; for (const key of IDENTITY_ENV) delete env[key]; Object.assign(env, identity); @@ -631,8 +636,11 @@ test('the BOOTSTRAP path respects the window too, not just the poll loop', async 'http://127.0.0.1:1', ); const elapsed = Date.now() - started; - expect(overrun.exitCode).toBe(2); // quiet — the window closed, the engine was not declared dead - // A 1s window must not become a 6s one because the first fetch happened to fail. + // Exit 3, not 2. This assertion USED to expect quiet, and that expectation was wrong: the + // engine never answered once, so "nothing new" would assert a response that never came. + // What this test is actually for is the elapsed time — a 1s window must not become a 6s one + // because the first fetch happened to fail — and that is unchanged. + expect(overrun.exitCode).toBe(3); expect(elapsed).toBeLessThan(3_000); }, 15_000); @@ -704,3 +712,56 @@ test('a drain against a hung engine times out, and says so', async () => { expect(hook.exitCode).toBe(0); drainHangMs = 0; }, 30_000); + +test('a hung engine is UNREACHABLE even when the interval outlasts the window', async () => { + // Confirmed regression: with --interval >= --timeout the first poll blocked for its own + // bound (10s against a 3s window), the deadline was then already gone, and it reported + // QUIET — asserting the engine answered and had nothing, after every request had failed. + // Two answers to one question: the request bound used the interval, the loop used the + // deadline. The bound now takes what remains, and "quiet" is refused unless the engine + // actually answered at least once. + messagesHangMs = 30_000; + const started = Date.now(); + const hung = await runCli([ + 'watch', + 'kild-9', + '--as', + 'kild', + '--since', + '1', + '--timeout', + '3', + '--interval', + '10', + ]); + const elapsed = Date.now() - started; + expect(hung.exitCode).toBe(3); + expect(hung.stderr).not.toContain('nothing new'); // never claim quiet on an unanswered engine + expect(elapsed).toBeLessThan(9_000); // and never blow through the window by 3x + messagesHangMs = 0; +}, 30_000); + +test('the default backstop is applied when no caller supplies a signal', async () => { + // Removing the default left every test passing, because the two hang tests are protected by + // their own explicit signals and bypass it entirely. This one goes through `kild log`, which + // supplies none. + engineTimeoutMs = '600'; + messagesHangMs = 5_000; + const hung = await runCli(['log', 'kild-9', '--since', '1']); + expect(hung.exitCode).toBe(1); + expect(hung.stderr).toContain('timed out'); + messagesHangMs = 0; + engineTimeoutMs = '30000'; +}); + +test('`kild show` reports an unreachable engine instead of an empty log', async () => { + // It swallowed every failure into `[]`. Invisible while a hung engine simply hung; a + // confident wrong answer the moment a timeout made the call return. + engineTimeoutMs = '600'; + messagesHangMs = 5_000; + const shown = await runCli(['show', 'kild-9']); + expect(shown.exitCode).toBe(1); + expect(shown.stderr).toContain('timed out'); + messagesHangMs = 0; + engineTimeoutMs = '30000'; +}, 20_000); diff --git a/engine/src/cli.ts b/engine/src/cli.ts index 14cf172b..eddd8478 100755 --- a/engine/src/cli.ts +++ b/engine/src/cli.ts @@ -393,6 +393,11 @@ async function kildWatch(idArg: string | undefined): Promise { return new Promise((resolve) => setTimeout(resolve, interval)); } let failures = 0; + /** Whether the engine has answered even once. "Quiet" is a claim ABOUT the engine — that it + * responded and had nothing — so it cannot be reported by a watcher that never heard from + * it. Without this, a window that closed after nothing but failures exited 2, asserting the + * opposite of what was observed. */ + let answered = false; /** * Ask once. Returns the batch, or null when the failure was tolerated and the caller should @@ -408,8 +413,14 @@ async function kildWatch(idArg: string | undefined): Promise { since: number | undefined, ): Promise> | null> { try { - const batch = await kildMessages(kildId, since, watchRequestTimeout(interval)); + // The bound and the deadline are one question, asked once: never wait past the window. + const batch = await kildMessages( + kildId, + since, + watchRequestTimeout(interval, deadline - Date.now()), + ); failures = 0; + answered = true; return batch; } catch (err) { if (++failures < WATCH_TOLERATED_FAILURES) return null; @@ -437,7 +448,14 @@ async function kildWatch(idArg: string | undefined): Promise { function expire(): never { // Report the window that actually elapsed. Printing the requested `--timeout` made the // message a lie in exactly the case worth reporting — the one where waiting overran it. - console.error(`kild: nothing new in ${Math.round((Date.now() - started) / 1000)}s`); + const elapsed = Math.round((Date.now() - started) / 1000); + if (!answered) { + // Never heard from it. Saying "nothing new" would assert the engine responded and had + // nothing, which is the dead-looks-quiet conflation these codes exist to prevent. + console.error(`kild: engine did not answer within ${elapsed}s`); + process.exit(WATCH_EXIT.unreachable); + } + console.error(`kild: nothing new in ${elapsed}s`); process.exit(WATCH_EXIT.quiet); } @@ -537,6 +555,31 @@ async function kildInbox(idArg: string | undefined): Promise { if (drained.messages.length === 0) console.error(drained.capped ? 'wake cap reached' : 'no mail'); } +/** + * Run a MUTATING call, and if it times out, say the outcome is unknown rather than failed. + * + * A client-side abort does not reach the engine: nothing here passes a signal into the + * server, and no git command it runs is cancellable, so a timed-out `land` may still merge + * and a timed-out `rm` may still remove the tree. Reporting that as a plain failure would be + * the worst kind of wrong — the operator retries a merge that already happened, or treats a + * deleted worktree as surviving. + * + * This is the same rule the disposal path already follows for its discard list: an + * unanswerable question is not an empty list, and it is not a `no` either. + */ +async function mayHaveHappened(verb: string, call: () => Promise): Promise { + try { + return await call(); + } catch (err) { + if (!errText(err).includes('timed out')) throw err; + throw new Error( + `${verb} timed out — the engine does NOT cancel work when the client gives up, so this ` + + `may still be completing or already done. Check with \`kild ls\` and git before ` + + `retrying. (${errText(err)})`, + ); + } +} + /** `--since ` as a message cursor. A non-number is a usage error, never "from the * start" — a silently-ignored cursor replays the whole log as if it were new. */ function parseSince(): number | undefined { @@ -563,7 +606,11 @@ async function kildShow(id: string): Promise { // The detail route is what decides whether this kild exists; a missing LOG does not mean a // missing kild — an orphan tree is a kild with nothing ever said in it. const kild = await getKild(id); - const messages = await kildMessages(id).catch(() => []); + // NOT swallowed. This used to be `.catch(() => [])`, which reported an empty log for any + // failure — invisible while a hung engine simply hung, and a confident lie the moment a + // timeout made the call return. An archived kild's log is a real answer; an unreachable + // engine is not the same as a kild that said nothing. + const messages = await kildMessages(id); const compact = compactLiveKilds([kild])[0]; if (!compact) throw new Error(`no such kild: ${id}`); @@ -685,7 +732,7 @@ async function kildSpawn(id: string, handle: string): Promise { * `kild/` branch always survives, which is why `--force` costs no commits. */ async function kildRm(id: string): Promise { - const res = await disposeKild(id, values.force); + const res = await mayHaveHappened('rm', () => disposeKild(id, values.force)); if (json) return void console.log(JSON.stringify(res, null, 2)); console.log(res.message); // An unanswerable question is not an empty list, and this is the one moment the operator @@ -707,7 +754,9 @@ function formatLand(res: LandResponse): string { * that touches nothing; with it, the branch is merged into its base in the project's main * checkout and the merge sha is reported (and recorded on the kild for the ledger). */ async function kildLand(id: string): Promise { - const res = values.execute ? await landKild(id) : await landPreview(id); + const res = values.execute + ? await mayHaveHappened('land', () => landKild(id)) + : await landPreview(id); if (json) return void console.log(JSON.stringify(res, null, 2)); console.log(formatLand(res)); if (res.collides.length > 0) console.error(`collides: ${res.collides.join(', ')}`); diff --git a/engine/src/kild/engine-client.ts b/engine/src/kild/engine-client.ts index 3859ba75..4fba9d80 100644 --- a/engine/src/kild/engine-client.ts +++ b/engine/src/kild/engine-client.ts @@ -33,32 +33,40 @@ export interface KildActionResponse { * How long any engine call may take before it is a failure rather than a wait. * * `fetch` has no timeout of its own, so a connection the engine ACCEPTS and then never - * answers hangs forever. That is not a hypothetical: it is the shape where a caller looks - * patient while it is actually dead, and it defeats every deadline built on top of it — - * `kild watch` could sit inside one poll past its whole window and report neither mail nor - * an unreachable engine, which is exactly the distinction its exit codes exist to draw. + * answers hangs forever — the shape where a caller looks patient while it is actually dead, + * defeating every deadline built on top of it. * - * Generous on purpose. This is a backstop against hanging forever, not a latency budget: it - * has to clear the slowest legitimate call (a land's merge, a new kild's worktree) without - * argument. Anything needing tighter bounds passes its own `signal` — the drain does, because - * it runs inside a turn-end hook where a stall costs the operator a visible pause. + * Generous on purpose: a backstop against hanging forever, not a latency budget. The calls it + * actually has to clear are `land` (a `git merge --no-ff`) and `rm` (a forced worktree + * removal), which are synchronous end to end. `kild new` is NOT one of them — `spawn` returns + * without awaiting, and the worktree is created inside the spawned child — so do not reason + * about this bound from that call. + * + * Overridable because 30s is a guess about somebody else's disk. A large merge with rename + * detection, or a tree on a network mount, can legitimately exceed it, and an operator who + * hits that needs a way out that is not editing the source. */ -const ENGINE_TIMEOUT_MS = 30_000; +const ENGINE_TIMEOUT_MS = Number(process.env.KILD_ENGINE_TIMEOUT_MS ?? 30_000); async function engineFetch(path: string, init?: RequestInit): Promise { // A caller's own signal wins outright rather than being combined: it is a narrower deadline // chosen for a reason, and silently capping it at the default would make the tighter bound a // lie. Nothing here may be slower than a caller asked for. + const ourDeadline = init?.signal === undefined; const signal = init?.signal ?? AbortSignal.timeout(ENGINE_TIMEOUT_MS); let response: Response; try { response = await fetch(`${ENGINE}${path}`, { ...init, signal }); } catch (err) { - // A timeout arrives as an opaque abort. Say what actually happened — "the operation was - // aborted" tells a caller nothing about whether to retry, and a hook that swallows it - // would be swallowing the one symptom that distinguishes a wedged engine from a quiet one. - if (err instanceof Error && (err.name === 'TimeoutError' || err.name === 'AbortError')) { - throw new Error(`${path} timed out — the engine accepted the connection and did not answer`); + // Whether this was a deadline is decided by WHOSE signal fired, not by matching an error + // name. Name-matching would relabel the first future caller that cancels for any other + // reason — a Ctrl-C, say — as "the engine did not answer", which is the opposite of true. + if (signal.aborted && ourDeadline) { + throw new Error( + `${path} timed out after ${ENGINE_TIMEOUT_MS}ms — the engine accepted the connection ` + + 'and did not answer (set KILD_ENGINE_TIMEOUT_MS to allow longer)', + { cause: err }, + ); } throw err; } diff --git a/engine/src/kild/watch.ts b/engine/src/kild/watch.ts index b0ee4ba7..863bbe96 100644 --- a/engine/src/kild/watch.ts +++ b/engine/src/kild/watch.ts @@ -53,14 +53,20 @@ export const WATCH_REQUEST_FLOOR_MS = 1_000; /** * How long ONE poll may wait for an answer. * - * A poll that outlasts its own cadence is not waiting, it is stuck: without this the request - * inherits the client's 30s backstop and a single hung call can swallow a whole short window, + * A poll that outlasts its own cadence is not waiting, it is stuck: without a bound the + * request inherits the client's backstop and a single hung call swallows a whole short window, * so a wedged engine looks patient rather than unreachable — the precise distinction the exit - * codes exist to draw. Bounding each attempt turns a hang into a tolerated failure, and three - * of those into an honest `unreachable`. + * codes exist to draw. + * + * **`msRemaining` is not optional, and that is the point.** The bound and the loop's deadline + * are the same question — how much time is left — and answering it in two places is what made + * `--interval 10 --timeout 3` block ten seconds on its first poll, overrun the requested + * window threefold, and then report a QUIET engine after every single request had failed. + * Requiring the caller to pass what remains means the two answers cannot drift, because there + * is only one. */ -export function watchRequestTimeout(intervalMs: number): number { - return Math.max(intervalMs, WATCH_REQUEST_FLOOR_MS); +export function watchRequestTimeout(intervalMs: number, msRemaining: number): number { + return Math.min(Math.max(intervalMs, WATCH_REQUEST_FLOOR_MS), Math.max(msRemaining, 1)); } /** What one poll concluded. */ From c3a926fb8c3a80d2dd047139057e2e990695402f Mon Sep 17 00:00:00 2001 From: Rasmus Widing Date: Tue, 28 Jul 2026 16:34:45 +0300 Subject: [PATCH 3/5] fix(engine-client): the timeout is a type, and a bad override is refused MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Two defects I introduced in the previous round and found by probing my own change rather than waiting to be told. `mayHaveHappened` decided "this may have completed" by searching the error text for "timed out". That is reading intent out of prose, which this codebase forbids — and it is wrong for the exact reason the rule exists: an engine-side failure relayed verbatim can contain those words. A `git merge` that failed with "operation timed out talking to the object store" would have been reported as a merge that might have gone through, sending an operator to look for work that never happened. The timeout is now a type, `EngineTimeout`, and the decision is `instanceof`. `KILD_ENGINE_TIMEOUT_MS` was `Number(raw ?? 30_000)` with no validation. An empty value or "0" parses to zero, which aborts every request the instant it is made — indistinguishable from an engine refusing to talk, and caused by a variable the operator set to help. Non-numeric values reached `AbortSignal` and surfaced as a RangeError naming neither the variable nor the fix. It is parsed once now and an unusable value is refused by name. Both were in the fix for a review finding, which is the third time on this branch that a repair has needed a repair. The difference is that these two were found by asking what my own change could now do wrong — the string match and the unvalidated env read were both visible the moment I looked at them as inputs rather than as implementation. Gates: 451 tests, typecheck, lint, e2e 70/70. --- engine/src/cli.attached.test.ts | 33 ++++++++++++++++++++++++++++++++ engine/src/cli.ts | 6 +++++- engine/src/kild/engine-client.ts | 31 ++++++++++++++++++++++++++++-- 3 files changed, 67 insertions(+), 3 deletions(-) diff --git a/engine/src/cli.attached.test.ts b/engine/src/cli.attached.test.ts index 10a57ca2..e458dd9f 100644 --- a/engine/src/cli.attached.test.ts +++ b/engine/src/cli.attached.test.ts @@ -765,3 +765,36 @@ test('`kild show` reports an unreachable engine instead of an empty log', async messagesHangMs = 0; engineTimeoutMs = '30000'; }, 20_000); + +test.each([ + ['abc', 'non-numeric'], + ['', 'empty'], + ['0', 'zero'], + ['-5', 'negative'], + ['30s', 'a unit suffix'], +])('KILD_ENGINE_TIMEOUT_MS=%s is refused (%s)', async (value) => { + // An unusable override must not degrade into a timeout of zero, which aborts every request + // the instant it is made and looks exactly like an engine refusing to talk. Nor into a + // cryptic RangeError from AbortSignal, which names neither the variable nor the fix. + engineTimeoutMs = value; + const bad = await runCli(['log', 'kild-9']); + expect(bad.exitCode).toBe(1); + expect(bad.stderr).toContain('KILD_ENGINE_TIMEOUT_MS'); + engineTimeoutMs = '30000'; +}); + +test('an engine failure whose text contains "timed out" is NOT reported as maybe-completed', async () => { + // `land`/`rm` report an unknown outcome on a real timeout, because a client abort does not + // stop server-side work. Deciding that by searching the message for "timed out" would + // misread a relayed git error as "your merge may have gone through" — and send an operator + // looking for a merge that never happened. + drainResponse = { + status: 409, + body: { error: 'git merge failed: operation timed out talking to the object store' }, + }; + const landed = await runCli(['land', 'kild-9', '--execute']); + expect(landed.exitCode).toBe(1); + expect(landed.stderr).toContain('timed out talking to the object store'); + expect(landed.stderr).not.toContain('may still be completing'); + withNoMail(); +}); diff --git a/engine/src/cli.ts b/engine/src/cli.ts index eddd8478..58bf2035 100755 --- a/engine/src/cli.ts +++ b/engine/src/cli.ts @@ -17,6 +17,7 @@ import { attachAgent, disposeKild, drainInbox, + EngineTimeout, getKild, kildMessages, kildsStatus, @@ -571,7 +572,10 @@ async function mayHaveHappened(verb: string, call: () => Promise): Promise try { return await call(); } catch (err) { - if (!errText(err).includes('timed out')) throw err; + // Typed, not string-matched. An engine-side failure whose message merely CONTAINS "timed + // out" — a relayed git error, a 409 body — must never be reported as "this may have + // completed", because that sends an operator to check for a merge that never happened. + if (!(err instanceof EngineTimeout)) throw err; throw new Error( `${verb} timed out — the engine does NOT cancel work when the client gives up, so this ` + `may still be completing or already done. Check with \`kild ls\` and git before ` + diff --git a/engine/src/kild/engine-client.ts b/engine/src/kild/engine-client.ts index 4fba9d80..a8e6f6f6 100644 --- a/engine/src/kild/engine-client.ts +++ b/engine/src/kild/engine-client.ts @@ -46,7 +46,34 @@ export interface KildActionResponse { * detection, or a tree on a network mount, can legitimately exceed it, and an operator who * hits that needs a way out that is not editing the source. */ -const ENGINE_TIMEOUT_MS = Number(process.env.KILD_ENGINE_TIMEOUT_MS ?? 30_000); +const ENGINE_TIMEOUT_MS = engineTimeoutMs(); + +/** + * The error `engineFetch` throws when OUR deadline fired — a TYPE, not a phrase. + * + * Callers need to tell "the engine never answered" from "the engine answered with a failure", + * because for a mutating call the first means the outcome is unknown and the second means it + * did not happen. Deciding that by looking for "timed out" in the message would be reading + * intent out of prose, which this codebase forbids for exactly the reason it is wrong here: + * an engine-side error relayed verbatim (a git message, a 409 body) can contain those words + * and would be misread as "your merge might have gone through". + */ +export class EngineTimeout extends Error {} + +/** Parsed once, loudly. An unusable override must not degrade into a timeout of zero, which + * aborts every request the instant it is made — a misconfiguration that would look exactly + * like an engine that is refusing to talk. */ +function engineTimeoutMs(): number { + const raw = process.env.KILD_ENGINE_TIMEOUT_MS; + if (raw === undefined) return 30_000; + const parsed = Number(raw); + if (!Number.isFinite(parsed) || parsed <= 0) { + throw new Error( + `KILD_ENGINE_TIMEOUT_MS must be a positive number of milliseconds (got ${JSON.stringify(raw)})`, + ); + } + return parsed; +} async function engineFetch(path: string, init?: RequestInit): Promise { // A caller's own signal wins outright rather than being combined: it is a narrower deadline @@ -62,7 +89,7 @@ async function engineFetch(path: string, init?: RequestInit): Promise { // name. Name-matching would relabel the first future caller that cancels for any other // reason — a Ctrl-C, say — as "the engine did not answer", which is the opposite of true. if (signal.aborted && ourDeadline) { - throw new Error( + throw new EngineTimeout( `${path} timed out after ${ENGINE_TIMEOUT_MS}ms — the engine accepted the connection ` + 'and did not answer (set KILD_ENGINE_TIMEOUT_MS to allow longer)', { cause: err }, From 83c30800f551b63cf6646437577bb733b4d5095f Mon Sep 17 00:00:00 2001 From: Rasmus Widing Date: Tue, 28 Jul 2026 16:49:38 +0300 Subject: [PATCH 4/5] fix(cli): an orphan's missing log is a fact, and the two riskiest fixes get tests MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Second review: NO-MERGE, one critical and three important. All addressed. CRITICAL, and the same one-decision-two-places class again, in a new spot. Removing `kild show`'s blanket catch made it CRASH on an orphan kild. `GET /:id` answers for an orphan tree — resolveKild falls back to an orphan identity — while `GET /:id/messages` 404s, because the registry's log map holds live and archived kilds only. Two routes, two answers to "does this exist". The swallow had been hiding that disagreement; removing it turned it into an exit 1 with no output at all, against a case `kild show` has an explicit display branch for, and directly contradicting the comment I had just written two lines above it. Now a 404 is tolerated and nothing else is. It branches on a typed `EngineHttpError` carrying the status rather than on the message text — the same reason the timeout became a type last commit: reading meaning out of an error string is reading intent out of prose. The abort branch now reads the SIGNAL'S REASON instead of asking whose signal it was. `AbortSignal.timeout` sets a TimeoutError reason and a deliberate cancellation does not, so both deadlines are timeouts and each says which one it was. My previous version tested only "was it ours", which quietly regressed the drain — a caller-supplied deadline — to a bare "The operation timed out." naming neither the path nor the cause. The env validation is read per call, not at module load. Evaluated at import it threw before dispatch()'s handler existed, so a fat-fingered override killed EVERY command, including ones that make no engine call, with a raw Bun stack trace instead of this CLI's `error: `. The review proved by reverting that the two highest-severity fixes had NO coverage — remove `mayHaveHappened` from land and rm, or revert the typed timeout, and all 451 tests still passed. Both are pinned now, along with the orphan case, and I verified the same way rather than assuming: reverting each fix in a scratch copy fails 1, 1 and 3 tests respectively. Gates: 455 tests, typecheck, lint, e2e 70/70. `kild show` verified against a real orphan on the running engine. --- engine/src/cli.attached.test.ts | 63 ++++++++++++++++++++++++++++++++ engine/src/cli.ts | 18 ++++++--- engine/src/kild/engine-client.ts | 48 +++++++++++++++++++----- 3 files changed, 114 insertions(+), 15 deletions(-) diff --git a/engine/src/cli.attached.test.ts b/engine/src/cli.attached.test.ts index e458dd9f..1ebb511e 100644 --- a/engine/src/cli.attached.test.ts +++ b/engine/src/cli.attached.test.ts @@ -46,6 +46,8 @@ let messagesHangMs = 0; let drainHangMs = 0; /** What the CLI under test uses as its default backstop. */ let engineTimeoutMs = '30000'; +/** Hang the land route, to drive a MUTATING call through a real timeout. */ +let landHangMs = 0; /** What `GET /messages` answers with. `kild watch` reads the log, never the inbox, so its * tests drive this rather than `drainResponse`. */ let messagesResponse: { status: number; body: unknown } | undefined; @@ -66,6 +68,9 @@ beforeAll(async () => { if (url.pathname.endsWith('/agents/attach') && attachResponse) { return Response.json(attachResponse.body, { status: attachResponse.status }); } + if (url.pathname.endsWith('/land') && landHangMs > 0) { + await new Promise((resolve) => setTimeout(resolve, landHangMs)); + } if (url.pathname.endsWith('/inbox/drain') && drainHangMs > 0) { await new Promise((resolve) => setTimeout(resolve, drainHangMs)); } @@ -798,3 +803,61 @@ test('an engine failure whose text contains "timed out" is NOT reported as maybe expect(landed.stderr).not.toContain('may still be completing'); withNoMail(); }); + +test('a timed-out land reports an UNKNOWN outcome, not a failure', async () => { + // A client abort does not reach the engine — no signal is passed server-side and no git + // command it runs is cancellable — so a timed-out merge may well have happened. Reporting + // it as a plain failure sends the operator to retry a merge that already landed. Reverting + // `mayHaveHappened` left the whole suite green, so this is the test that pins it. + engineTimeoutMs = '600'; + landHangMs = 5_000; + const landed = await runCli(['land', 'kild-9', '--execute']); + expect(landed.exitCode).toBe(1); + expect(landed.stderr).toContain('may still be completing'); + expect(landed.stderr).toContain('kild ls'); + landHangMs = 0; + engineTimeoutMs = '30000'; +}, 20_000); + +test("a caller's own deadline is still a timeout, and says whose", async () => { + // The drain supplies its own 1.5s signal. Deciding "is this a timeout" by whether OUR signal + // fired reported the drain's deadline as a bare "The operation timed out." — naming neither + // the path nor the cause. The branch reads the signal's REASON instead, so both deadlines + // are timeouts and each says which one it was. + drainHangMs = 10_000; + const drained = await runCli(['inbox', 'kild-9', '--as', 'kild']); + expect(drained.exitCode).toBe(1); + expect(drained.stderr).toContain('timed out'); + expect(drained.stderr).toContain("caller's own deadline"); + expect(drained.stderr).toContain('/inbox/drain'); // the path, not an opaque abort + drainHangMs = 0; +}, 20_000); + +test('`kild show` still works on an ORPHAN, whose log legitimately 404s', async () => { + // `GET /:id` answers for an orphan tree; `GET /:id/messages` 404s, because the registry's + // log map holds live and archived kilds only. Removing the blanket catch turned that + // disagreement into a crash with no output at all — against a case this command has an + // explicit display branch for. + drainRequests = []; + drainResponse = { + status: 200, + body: { id: 'live-demo', name: 'live-demo', orphan: true, agents: [] }, + }; + messagesResponse = { status: 404, body: { error: 'no such kild: live-demo' } }; + const shown = await runCli(['show', 'live-demo']); + expect(shown.exitCode).toBe(0); + expect(shown.stdout).toContain('orphan tree'); + messagesResponse = undefined; + withNoMail(); +}); + +test('...but `kild show` still reports a non-404 log failure', async () => { + // Only "nothing was ever said here" is tolerated. An unreachable engine is not that. + drainResponse = { status: 200, body: { id: 'kild-9', name: 'k', agents: [] } }; + messagesResponse = { status: 500, body: { error: 'registry exploded' } }; + const shown = await runCli(['show', 'kild-9']); + expect(shown.exitCode).toBe(1); + expect(shown.stderr).toContain('registry exploded'); + messagesResponse = undefined; + withNoMail(); +}); diff --git a/engine/src/cli.ts b/engine/src/cli.ts index 58bf2035..f23cbbb6 100755 --- a/engine/src/cli.ts +++ b/engine/src/cli.ts @@ -17,6 +17,7 @@ import { attachAgent, disposeKild, drainInbox, + EngineHttpError, EngineTimeout, getKild, kildMessages, @@ -610,11 +611,18 @@ async function kildShow(id: string): Promise { // The detail route is what decides whether this kild exists; a missing LOG does not mean a // missing kild — an orphan tree is a kild with nothing ever said in it. const kild = await getKild(id); - // NOT swallowed. This used to be `.catch(() => [])`, which reported an empty log for any - // failure — invisible while a hung engine simply hung, and a confident lie the moment a - // timeout made the call return. An archived kild's log is a real answer; an unreachable - // engine is not the same as a kild that said nothing. - const messages = await kildMessages(id); + // A missing LOG does not mean a missing kild. An ORPHAN is a tree git reports with no kild + // record, so `GET /:id` answers for it (resolveKild falls back to an orphan identity) while + // `GET /:id/messages` 404s — the registry's log map holds live and archived kilds only. Two + // routes, two answers to "does this exist", and this is the seam between them. + // + // So a 404 is tolerated and nothing else is. The blanket `.catch(() => [])` this replaced + // reported an empty log for EVERY failure, which hid an unreachable engine behind a kild + // that looked simply quiet. + const messages = await kildMessages(id).catch((err) => { + if (err instanceof EngineHttpError && err.status === 404) return []; + throw err; + }); const compact = compactLiveKilds([kild])[0]; if (!compact) throw new Error(`no such kild: ${id}`); diff --git a/engine/src/kild/engine-client.ts b/engine/src/kild/engine-client.ts index a8e6f6f6..ff3d608d 100644 --- a/engine/src/kild/engine-client.ts +++ b/engine/src/kild/engine-client.ts @@ -46,7 +46,6 @@ export interface KildActionResponse { * detection, or a tree on a network mount, can legitimately exceed it, and an operator who * hits that needs a way out that is not editing the source. */ -const ENGINE_TIMEOUT_MS = engineTimeoutMs(); /** * The error `engineFetch` throws when OUR deadline fired — a TYPE, not a phrase. @@ -60,7 +59,24 @@ const ENGINE_TIMEOUT_MS = engineTimeoutMs(); */ export class EngineTimeout extends Error {} -/** Parsed once, loudly. An unusable override must not degrade into a timeout of zero, which +/** A response the engine actually sent, carrying its status so a caller can branch on the + * KIND of refusal without reading the message. `kild show` needs exactly this: a 404 for a + * log means "nothing was ever said here", which for an orphan tree is a fact, not a failure. */ +export class EngineHttpError extends Error { + constructor( + message: string, + readonly status: number, + ) { + super(message); + } +} + +/** Read per call, not at import. Evaluated at module load it threw before `dispatch()`'s own + * handler existed, so a fat-fingered override killed EVERY command — including ones that + * never make an engine call — with a raw stack trace instead of this CLI's `error: `. + * A bad variable should break what it affects and nothing else. + * + * Loudly, either way. An unusable override must not degrade into a timeout of zero, which * aborts every request the instant it is made — a misconfiguration that would look exactly * like an engine that is refusing to talk. */ function engineTimeoutMs(): number { @@ -80,7 +96,8 @@ async function engineFetch(path: string, init?: RequestInit): Promise { // chosen for a reason, and silently capping it at the default would make the tighter bound a // lie. Nothing here may be slower than a caller asked for. const ourDeadline = init?.signal === undefined; - const signal = init?.signal ?? AbortSignal.timeout(ENGINE_TIMEOUT_MS); + const timeoutMs = engineTimeoutMs(); + const signal = init?.signal ?? AbortSignal.timeout(timeoutMs); let response: Response; try { response = await fetch(`${ENGINE}${path}`, { ...init, signal }); @@ -88,18 +105,29 @@ async function engineFetch(path: string, init?: RequestInit): Promise { // Whether this was a deadline is decided by WHOSE signal fired, not by matching an error // name. Name-matching would relabel the first future caller that cancels for any other // reason — a Ctrl-C, say — as "the engine did not answer", which is the opposite of true. - if (signal.aborted && ourDeadline) { - throw new EngineTimeout( - `${path} timed out after ${ENGINE_TIMEOUT_MS}ms — the engine accepted the connection ` + - 'and did not answer (set KILD_ENGINE_TIMEOUT_MS to allow longer)', - { cause: err }, - ); + // Branch on WHY the signal fired, read from the signal itself. `AbortSignal.timeout` sets + // a TimeoutError reason; a deliberate cancellation does not. Matching the error NAME + // instead conflated the two, and testing only "was it our signal" left a caller's own + // deadline — the drain's — reported as a bare "The operation timed out." naming neither + // the path nor the cause. + if (signal.aborted) { + const reason = signal.reason as { name?: string } | undefined; + if (reason?.name === 'TimeoutError') { + const bound = ourDeadline + ? `${timeoutMs}ms (set KILD_ENGINE_TIMEOUT_MS to allow longer)` + : "the caller's own deadline"; + throw new EngineTimeout( + `${path} timed out after ${bound} — the engine accepted the connection and did not answer`, + { cause: err }, + ); + } + throw new Error(`${path} was cancelled before the engine answered`, { cause: err }); } throw err; } if (!response.ok) { const body = (await response.json().catch(() => ({}))) as { error?: string }; - throw new Error(body.error ?? `${path} failed (${response.status})`); + throw new EngineHttpError(body.error ?? `${path} failed (${response.status})`, response.status); } return response.json() as Promise; } From 168cf024c764a610c992ee2ef497c788c5ead0f0 Mon Sep 17 00:00:00 2001 From: Rasmus Widing Date: Tue, 28 Jul 2026 18:47:39 +0300 Subject: [PATCH 5/5] test(cli): pin the formatted error, not just the variable name MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The verification pass cleared this branch and found one gap by the same method that caught the last two criticals: reverting the per-call env read failed zero tests. Both versions exit 1 with KILD_ENGINE_TIMEOUT_MS in the text — the reverted one as a raw Bun stack trace naming a source line, the fixed one as the CLI's own formatted error — and asserting only the substring could not tell them apart. That is the fix having no coverage at all, which is exactly the shape that hid the previous two rounds. Asserting the absence of the stack trace closes it; reverting the fix now fails the suite. Gates: 455 tests, typecheck, lint, e2e 70/70. --- engine/src/cli.attached.test.ts | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/engine/src/cli.attached.test.ts b/engine/src/cli.attached.test.ts index 1ebb511e..4417dbb3 100644 --- a/engine/src/cli.attached.test.ts +++ b/engine/src/cli.attached.test.ts @@ -785,6 +785,12 @@ test.each([ const bad = await runCli(['log', 'kild-9']); expect(bad.exitCode).toBe(1); expect(bad.stderr).toContain('KILD_ENGINE_TIMEOUT_MS'); + // ...and as a FORMATTED CLI error, not a raw crash. Validating at module load threw before + // dispatch()'s handler existed, so every command died with a Bun stack trace naming a source + // line instead of the fix. Both exited 1 with the variable's name in the text, so asserting + // only that could not tell them apart — which is how this fix had no coverage at all. + expect(bad.stderr).not.toContain('Bun v'); + expect(bad.stderr).not.toContain('function engineTimeoutMs'); engineTimeoutMs = '30000'; });