From 672041e2631e93403c9bc7d9cc9d9fb8f27f835d Mon Sep 17 00:00:00 2001 From: nplusonedev <313439419+nplusonedev@users.noreply.github.com> Date: Sat, 15 Aug 2026 19:46:47 +0000 Subject: [PATCH] feat(sandbox): record why a container stopped MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A run whose container dies reports `ExecFailed: exec failed (exit -1): internal error` and nothing at all about the container. Every explanation offered for that class has now been measured and ruled out on the consumer that motivated it — peak memory 3.5 GiB of 11.9, disk 3.6 GB used of 12 free, and death times (137s, 647s, 1284s) shorter than the successes (2128s, 2176s). Nothing is scarce and no duration is safe, 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 something killed carries a signal there; one that ran to completion carries 0. Nothing in this repo was reading it. So the three DO classes override `onStop` and persist the number under `container-stops//.json`, logged as well as written. `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 — both `callOnStop` sites pass `'exit'`. Read `exitCode`. The write is best-effort and logged: it runs while the container is going away, so a failure must not replace a stop we can explain with one we cannot — but a silent no-op would be indistinguishable from a deploy where the record never worked. The record function lives in its own module, free of the Sandbox SDK import, so it is testable outside the workers pool. UNVERIFIED until a real container dies: whether `ctx.id.name` is populated, and whether a killed container reports 137 or the bare signal. The first stop answers both; nothing here depends on which. --- apps/dispatcher/src/container-stop.test.ts | 135 +++++++++++++ apps/dispatcher/src/container-stop.ts | 215 +++++++++++++++++++++ apps/dispatcher/src/env.ts | 11 ++ apps/dispatcher/src/sandbox.ts | 74 ++++++- wrangler.jsonc | 7 + 5 files changed, 434 insertions(+), 8 deletions(-) create mode 100644 apps/dispatcher/src/container-stop.test.ts create mode 100644 apps/dispatcher/src/container-stop.ts 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).