diff --git a/apps/dispatcher/src/container-stop.test.ts b/apps/dispatcher/src/container-stop.test.ts new file mode 100644 index 0000000..fdd18a7 --- /dev/null +++ b/apps/dispatcher/src/container-stop.test.ts @@ -0,0 +1,135 @@ +// Unit coverage for the container-stop record. +// +// A run whose container dies reports `exec failed (exit -1): internal error` +// and nothing about the container. The platform does say why, one layer down: +// `@cloudflare/containers` parses the runtime's own `runtime signalled the +// container to exit: ` into the `exitCode` it hands `onStop`. These pin that +// the number is kept, and that keeping it cannot make a stop worse. + +import { describe, expect, it, vi } from "vitest"; + +import { + containerStopKey, + containerStopRecord, + isStopWorthRecording, + recordContainerStop, + stopRecordsEnabled, + takeRequested, +} from "./container-stop"; + +/** An R2 stub that records `put` calls. */ +const makeBucket = () => { + const puts: { key: string; body: unknown }[] = []; + const bucket = { + put: async (key: string, body: unknown) => { + puts.push({ key, body }); + return {} as R2Object; + }, + } as unknown as R2Bucket; + return { bucket, puts }; +}; + +describe("containerStopRecord", () => { + it("preserves whatever exit code the platform reported", () => { + // Preserved, NOT interpreted. The code is evidence to read alongside the + // rest, not a discriminator — see the module header on why a 0 does not + // mean a clean exit. + const rec = containerStopRecord("offload-test-abc", { exitCode: 137, reason: "exit" }, 0, false); + expect(rec.exitCode).toBe(137); + expect(rec.sandbox).toBe("offload-test-abc"); + }); + + it("keeps a zero rather than dropping the field, since a zero is not nothing", () => { + expect(containerStopRecord("s", { exitCode: 0, reason: "exit" }, 0, false).exitCode).toBe(0); + }); + + it("distinguishes 'the platform said nothing' from 'we did not look'", () => { + // `null`, not absent — the two must not render the same way to whoever + // reads these records next. + const rec = containerStopRecord("s", undefined, 0, false); + expect(rec.exitCode).toBeNull(); + expect(rec.reason).toBeNull(); + expect(rec.observedAt).toBe(new Date(0).toISOString()); + }); + + it("keys one object per stop, under the sandbox that stopped", () => { + expect(containerStopKey("offload-test-abc", 1_700_000_000)).toBe( + "container-stops/offload-test-abc/1700000000.json", + ); + }); + + it("cannot be talked into writing outside its own prefix", () => { + // The name is derived from an execution id today and carries no separators, + // but the function takes any string, and a `/` would silently nest objects + // somewhere nobody looks for them. + expect(containerStopKey("../../artifacts/evil", 1)).toBe( + "container-stops/.._.._artifacts_evil/1.json", + ); + }); +}); + +describe("what is worth an object", () => { + it("stores the stops nobody asked for, and not our own teardowns", () => { + // NOT keyed on the exit code. `syncPendingStoppedEvents` hardcodes + // `exitCode: 0` when the container is gone but the state still reads + // healthy — the unexplained death — so a code-based filter would drop + // exactly the records this feature exists to produce. + expect(isStopWorthRecording(true)).toBe(false); + expect(isStopWorthRecording(false)).toBe(true); + }); + + it("consumes the destroy intent, so it cannot swallow a later real death", () => { + // `destroy()` does not reach `onStop` inline; the alarm loop delivers it + // later, so the intent has to cross that gap. Left set, the next stop this + // instance saw would also read as requested and be dropped — including a + // genuine death after a `destroy()` that threw. + const holder = { requested: false }; + holder.requested = true; + expect(takeRequested(holder)).toBe(true); + expect(takeRequested(holder)).toBe(false); + }); + + it("reports an unrequested stop when the intent never got set", () => { + // The eviction case: a fresh instance sees the stop, so our own teardown + // reads as unrequested. It records more, never less — which is the safe + // direction for a corpus about deaths. + expect(takeRequested({ requested: false })).toBe(false); + }); + + it("is switchable from config, because the deploy that carries it rebuilds images", () => { + expect(stopRecordsEnabled("off")).toBe(false); + expect(stopRecordsEnabled(undefined)).toBe(true); + expect(stopRecordsEnabled("on")).toBe(true); + }); +}); + +describe("recordContainerStop", () => { + it("persists the record and logs it", async () => { + const { bucket, puts } = makeBucket(); + const log = vi.spyOn(console, "log").mockImplementation(() => {}); + await recordContainerStop(bucket, "offload-test-abc", { exitCode: 137 }, 1_700_000_000, false); + expect(puts).toHaveLength(1); + expect(puts[0]?.key).toBe("container-stops/offload-test-abc/1700000000.json"); + expect(JSON.parse(String(puts[0]?.body)).exitCode).toBe(137); + expect(log).toHaveBeenCalled(); + log.mockRestore(); + }); + + it("never lets a failed write turn into a failed stop", async () => { + // This runs while the container is going away. Throwing would replace a + // stop we can explain with one we cannot. + const bucket = { + put: async () => { + throw new Error("R2 unavailable"); + }, + } as unknown as R2Bucket; + const log = vi.spyOn(console, "log").mockImplementation(() => {}); + const warn = vi.spyOn(console, "warn").mockImplementation(() => {}); + await expect(recordContainerStop(bucket, "s", { exitCode: 137 }, 1, false)).resolves.toBeUndefined(); + // …but it says so. A silent no-op here is indistinguishable from a deploy + // where the record never worked at all. + expect(warn).toHaveBeenCalled(); + log.mockRestore(); + warn.mockRestore(); + }); +}); diff --git a/apps/dispatcher/src/container-stop.ts b/apps/dispatcher/src/container-stop.ts new file mode 100644 index 0000000..2f72905 --- /dev/null +++ b/apps/dispatcher/src/container-stop.ts @@ -0,0 +1,215 @@ +// FlareDispatch Dispatcher — why a container stopped. +// +// A run whose container dies reports `ExecFailed: exec failed (exit -1): +// internal error` and nothing about the container itself. Every explanation +// offered for that class of failure — memory, disk, wall clock — has been +// measured and ruled out on the consumer that motivated it, which leaves a +// question only the platform can answer. +// +// The platform does answer it, one layer below where anyone was looking. +// `@cloudflare/containers` parses the runtime's own message — `runtime +// signalled the container to exit: `, or `container exited with unexpected +// exit code: ` — into the `exitCode` it hands `onStop`. A container the +// kernel or the platform killed carries a signal there; one that ran to +// completion carries 0. +// +// `reason` is NOT the discriminator, despite its type. `StopParams.reason` is +// declared `'exit' | 'runtime_signal'`, but `runtime_signal` appears nowhere in +// `@cloudflare/containers@0.3.7` outside that declaration — every `callOnStop` +// site passes `'exit'`. +// +// Two things a reader of these records has to know, both properties of the SDK +// rather than of this file: +// +// * A `0` is not proof of a clean exit. `syncPendingStoppedEvents` hardcodes +// `exitCode: 0` when the container is gone but the DO state still reads +// `healthy` (container.js:1596), which is a value the SDK invented — and is +// the shape an unexplained death takes. +// * ABSENCE of a record is not proof the container survived. When +// `getExitCodeFromError` cannot parse the runtime's message it calls +// `setStopped()` (container.js:1447, :1463), a status that matches neither +// branch of `syncPendingStoppedEvents`, so `callOnStop` is never reached +// and nothing is written. +// +// Kept in its own module, free of the Sandbox SDK import, so it is testable +// outside the workers pool. +// +// CONTAINER PATH ONLY. `apps/substrate/src/sandbox-do.ts` overrides `onStop` +// too and records no exit code, so every run that moves when +// `SUBSTRATE_BACKEND` flips to "on" loses this — silently, since nothing fails. +// Porting it is a prerequisite of the stage-2 cutover, not of this change. +// +// NOTHING PRUNES `container-stops/`. There is no lifecycle rule on the bucket +// and no reader route; the prefix is write-only and permanent until someone +// sets one. Volume is bounded by the `requested` filter below — a healthy run +// writes nothing — but that is a bound, not an expiry. Set a rule before +// leaving this on indefinitely: +// +// wrangler r2 bucket lifecycle add flare-dispatch \ +// --name expire-container-stops --prefix container-stops/ --expire-days 90 + +/** + * What the Container base class passes `onStop`. Both fields are optional here + * because the SDK's own `onStop` is declared with no parameters at all, so what + * arrives at runtime is wider than what the types promise. + */ +export type StopParamsLike = { exitCode?: number; reason?: string }; + +/** + * Ceiling on the R2 write. `callOnStop` awaits `onStop` and only then writes + * the DO's stopped state, so an unbounded put would leave the state reading + * `healthy` while the container is already gone. + */ +const STOP_WRITE_TIMEOUT_MS = 2000; + +/** + * The off switch. `CONTAINER_STOP_RECORDS: "off"` in the dispatcher's `vars` + * stops the durable writes; the log line is unaffected. + * + * It does NOT avoid a deploy — a `vars` change is still `wrangler deploy`, and + * the deploy that carries these classes rebuilds three container images either + * way. What it buys is a reviewed one-line config change instead of a code + * revert, and a switch someone can find by grepping. Same shape as + * `SUBSTRATE_BACKEND`. + */ +export const stopRecordsEnabled = (flag: string | undefined): boolean => flag !== "off"; + +/** One stop record, as persisted. */ +export type ContainerStopRecord = { + readonly sandbox: string; + readonly exitCode: number | null; + readonly reason: string | null; + /** Did this deploy ask for the stop (`destroy()`), or did it just happen? */ + readonly requested: boolean; + readonly observedAt: string; +}; + +/** + * Which stops are worth an object. + * + * NOT `exitCode !== 0`, which is the trap. `syncPendingStoppedEvents` hardcodes + * `{ exitCode: 0 }` when the container is gone but the state still reads + * `healthy` (@cloudflare/containers container.js:1596) — a value the SDK + * invented, not one the platform reported, and precisely the shape of the + * unexplained death this exists to catch. Filtering on the code would have + * thrown away the only records that matter. + * + * So the discriminator is whether WE asked. `workflow.ts` calls `destroy()` on + * every run through an `Effect.ensuring`, success or failure alike, and those + * teardowns are the volume. Everything else is a stop nobody requested, which + * is worth an object whatever number rides along. + * + * Two limits on reading `requested`, both worth knowing before trusting it: + * + * * `true` is reliable, `false` is best-effort. The flag lives on the DO + * instance, and `destroy()` does not call `onStop` inline — the alarm loop + * delivers it later. An instance evicted in between reports a teardown we + * asked for as one we did not. It fails toward recording MORE, never toward + * hiding a death. + * * An idle timeout is correctly `false` and is not routine volume. + * `onActivityExpired` returns early unless the container is still running + * (container.js:748), and the finalize `destroy()` has normally already + * stopped it — so this fires only where finalize was skipped, which is a + * Worker eviction or a deploy mid-run, and is worth seeing. + */ +export const isStopWorthRecording = (requested: boolean): boolean => !requested; + +/** + * Read the "we asked for this" intent and consume it, one shot. + * + * `destroy()` does not reach `onStop` inline — the alarm loop delivers it + * later — so the intent has to survive that gap and then stop surviving. Left + * set, it would swallow every subsequent stop the same instance sees, including + * a genuine death following a `destroy()` that threw. + * + * Extracted so the property is pinned by a test rather than by reading three + * lines of a Durable Object that cannot be constructed outside the workers pool. + */ +export const takeRequested = (holder: { requested: boolean }): boolean => { + const requested = holder.requested; + holder.requested = false; + return requested; +}; + +/** + * Keys are addressable FORWARD, which is the direction that matters. + * + * The sandbox name is `previewSafeSandboxId(executionId)`, which is lossy — it + * truncates and appends a digest above 40 chars, so a name cannot be reversed + * to an execution. It is deterministic though, so anything holding an execution + * id can compute the prefix and find that run's stops. Do not try to go the + * other way. + * + * The name is restricted rather than trusted: a `/` in it would silently nest + * objects outside the intended prefix. + */ +export const containerStopKey = (sandbox: string, now: number): string => + `container-stops/${sandbox.replace(/[^A-Za-z0-9._-]/g, "_")}/${now}.json`; + +export const containerStopRecord = ( + sandbox: string, + params: StopParamsLike | undefined, + now: number, + requested: boolean, +): ContainerStopRecord => ({ + sandbox, + requested, + // `null`, never absent: "the platform told us nothing" and "we did not look" + // must not render the same way to whoever reads these next. + exitCode: params?.exitCode ?? null, + reason: params?.reason ?? null, + // When the stop was OBSERVED, not when the container died. `onStop` arrives + // from the alarm loop, which can be a tick or a restart later than the event + // it reports (container.js:606 drains pending stopped events on the next + // start). Close enough to correlate a run against; not a precise time of + // death. + observedAt: new Date(now).toISOString(), +}); + +/** + * Persist the record, best-effort. + * + * This runs while the container is going away. A write that throws here would + * replace a stop we can explain with one we cannot, so the failure is caught — + * but LOGGED, because a silent no-op is indistinguishable from a deploy where + * the record never worked at all. + */ +export const recordContainerStop = async ( + bucket: R2Bucket, + sandbox: string, + params: StopParamsLike | undefined, + now: number, + requested: boolean, + flag?: string, +): Promise => { + const line = JSON.stringify(containerStopRecord(sandbox, params, now, requested)); + // Every stop is logged; only the ones nobody asked for are stored. + console.log(`sandbox.stop ${line}`); + if (!stopRecordsEnabled(flag) || !isStopWorthRecording(requested)) return; + try { + // Bounded, because this runs while the container is going away and the base + // class's teardown is waiting on it. R2 being slow must not hold a stop + // open — the log line above has already carried the record. + let timer: ReturnType | undefined; + try { + await Promise.race([ + bucket.put(containerStopKey(sandbox, now), `${line}\n`, { + httpMetadata: { contentType: "application/json" }, + }), + new Promise((_, reject) => { + timer = setTimeout(() => reject(new Error("timed out after 2s")), STOP_WRITE_TIMEOUT_MS); + }), + ]); + } finally { + // Cleared rather than left armed: this runs inside the alarm handler, and + // a stray pending timer there outlives the work it was bounding. + if (timer !== undefined) clearTimeout(timer); + } + } catch (cause) { + console.warn( + `sandbox.stop: could not persist stop record for ${sandbox} — ${ + cause instanceof Error ? cause.message : String(cause) + }`, + ); + } +}; diff --git a/apps/dispatcher/src/env.ts b/apps/dispatcher/src/env.ts index a3b5bc0..beca7b7 100644 --- a/apps/dispatcher/src/env.ts +++ b/apps/dispatcher/src/env.ts @@ -37,6 +37,17 @@ export interface Env { */ readonly SUBSTRATE_BACKEND?: string; + /** + * `"off"` stops the container-stop records being written to R2 (the log line + * is unaffected). Anything else, including absent, leaves them on. + * + * A `vars` entry rather than a code path because the deploy that carries the + * sandbox DO classes also rebuilds three container images, so backing the + * feature out would otherwise be an image-rebuilding redeploy rather than a + * config edit. See `apps/dispatcher/src/container-stop.ts`. + */ + readonly CONTAINER_STOP_RECORDS?: string; + /** * Shared HMAC-SHA256 secret — verifies inbound `POST /v1/dispatch/:run` * request bodies (specs/05-byoc.md § Secrets). A Worker secret, set via diff --git a/apps/dispatcher/src/sandbox.ts b/apps/dispatcher/src/sandbox.ts index e6bc6fa..05dce79 100644 --- a/apps/dispatcher/src/sandbox.ts +++ b/apps/dispatcher/src/sandbox.ts @@ -23,6 +23,7 @@ // Spec: specs/01-architecture.md § Sandbox, specs/pm/plan.md § PR4 + § 6. import { Sandbox } from "@cloudflare/sandbox"; +import { recordContainerStop, takeRequested, type StopParamsLike } from "./container-stop"; import type { Env } from "./env"; /** @@ -59,18 +60,77 @@ import type { Env } from "./env"; */ const SANDBOX_SLEEP_AFTER = "10m"; -/** The Durable Object class backing the lean `RUNS_SANDBOX` Container binding. */ -export class RunSandbox extends Sandbox { +/** + * The shared body of the three `onStop` overrides. + * + * The classes exist only to give each container image a named class (see the + * header), so the record belongs in one place rather than copied into each — + * and the ordering below is load-bearing, so it should not be re-derived three + * times either. + * + * Called AFTER `super.onStop()`: `callOnStop` in `@cloudflare/containers` + * awaits the override and only then writes the DO's stopped state, so doing the + * R2 put first would delay the SDK's own teardown and leave the state reading + * `healthy` while the container is already gone. + */ +const recordStopFor = async ( + env: Env, + ctx: DurableObjectState, + requested: boolean, + params?: StopParamsLike, +): Promise => + recordContainerStop( + env.RUNS_STORAGE, + ctx.id.name ?? String(ctx.id), + params, + Date.now(), + requested, + env.CONTAINER_STOP_RECORDS, + ); + +/** + * Everything the three named classes share. + * + * They exist only to give each container image a class wrangler can register + * (see the header), so the lifecycle logic lives here once. Three copies means + * three places to fix an ordering or flag-lifetime bug, and a miss in one is + * silent. + */ +abstract class RecordingSandbox extends Sandbox { override sleepAfter = SANDBOX_SLEEP_AFTER; + + /** + * Set by our own `destroy()` so the record can say who asked. `workflow.ts` + * tears every run down through an `Effect.ensuring`, so without this the + * corpus is mostly our own teardowns with nothing to tell them from the + * deaths worth reading. + */ + #intent = { requested: false }; + + override async destroy(): Promise { + this.#intent.requested = true; + await super.destroy(); + } + + override async onStop(params?: StopParamsLike): Promise { + // Read-and-clear. `destroy()` does not reach `onStop` inline — the alarm + // loop delivers it later — so the flag has to persist across that gap, and + // then NOT persist any further. Left set, it would swallow every subsequent + // stop this instance sees, including a real death after a failed destroy. + const requested = takeRequested(this.#intent); + await super.onStop(); + await recordStopFor(this.env, this.ctx, requested, params); + } } +/** The Durable Object class backing the lean `RUNS_SANDBOX` Container binding. */ +export class RunSandbox extends RecordingSandbox {} + /** * The Durable Object class backing the chromium-baked `RUNS_SANDBOX_BROWSER` * Container binding. Identical to `RunSandbox` — only the bound image differs. */ -export class RunSandboxBrowser extends Sandbox { - override sleepAfter = SANDBOX_SLEEP_AFTER; -} +export class RunSandboxBrowser extends RecordingSandbox {} /** * The Durable Object class backing the agent-tier `RUNS_SANDBOX_AGENT` Container @@ -79,6 +139,4 @@ export class RunSandboxBrowser extends Sandbox { * Container image, so the self-heal routing split needs this third class. * specs/08-self-healing.md § 6.2. */ -export class RunSandboxAgent extends Sandbox { - override sleepAfter = SANDBOX_SLEEP_AFTER; -} +export class RunSandboxAgent extends RecordingSandbox {} diff --git a/wrangler.jsonc b/wrangler.jsonc index a04317d..ca41750 100644 --- a/wrangler.jsonc +++ b/wrangler.jsonc @@ -88,6 +88,13 @@ // Per-run egress rollout position is a SEPARATE decision, in // apps/dispatcher/src/grant-catalog.ts. "SUBSTRATE_BACKEND": "off", + + // `"off"` stops the container-stop records (apps/dispatcher/src/container-stop.ts) + // being written to R2; the log line is unaffected. Declared here rather than + // left to default so the switch is greppable and diffable — turning it off + // is still a deploy, so what this buys is a reviewed one-line config change + // instead of a code revert. + "CONTAINER_STOP_RECORDS": "on", }, // The substrate facade (apps/substrate/specs/adr/0003-facade-only-consumption.md).