fix(run): a run is orphaned when it predates the process, not when it is 30 minutes old

backend-ts/src/routes/runs.ts

@@ -122,10 +122,24 @@ function externalTriggeredBy(raw: unknown): string {
 // The store factory selects the SQLite floor or the Postgres ceiling (when DATABASE_URL is set) and
 // runs schema init once per env. CANONICAL schema/migrations stay Taleef-owned (CLAUDE.md).
 //
-// Boot recovery: an ALL_PROGRAMS/SITE run is advanced by an in-process `ctx.waitUntil` task that does
-// NOT survive a container restart, so a run interrupted by a restart is stuck RUNNING forever. The
-// first runs access in a process fires a best-effort sweep that fails such stuck runs. It is
-// fire-and-forget (never blocks or fails the request) and time-thresholded (never touches a live run).
+// Boot recovery, SECOND trigger. An ALL_PROGRAMS/SITE run is advanced by an in-process
+// `ctx.waitUntil` task that does NOT survive a container restart, so a run interrupted by a restart is
+// stuck RUNNING forever. `server.ts` sweeps once at startup on a Postgres stack; this fires on the
+// first runs access in a process, and is the ONLY trigger on a stack without DATABASE_URL.
+//
+// Both run on a Postgres boot, because they hold different `env` objects and the `WeakSet` below is
+// keyed on identity. That is harmless: `failStuckRuns` re-checks `status = 'RUNNING'` under the row
+// lock, so the loser returns no rows and writes no duplicate RUN_RECOVERED.
+//
+// It was the ONLY trigger until 2026-09-09, and that had two consequences. An orphan stayed visible as
+// RUNNING until somebody happened to open the runs page — sixteen hours, once. And because the cutoff
+// was a flat 30 minutes sized for a "~5-6 min" run, the sweep failed a HEALTHY six-measure nightly at
+// 98.7% complete the moment the page was opened. `orphanThresholdMs` now ANCHORS the cutoff to this
+// process's boot, so neither trigger can reach past the moment the process booted. "Anchors", not
+// "widens": the swept set is everything created before boot, back to the epoch — an eighteen-hour-old
+// orphan goes on the first sweep — while everything created after boot is spared however old it gets.
+//
+// Fire-and-forget: never blocks or fails the request.
 const sweptForOrphans = new WeakSet<object>();
 async function store(env: RunsEnv): Promise<RunStore> {
   const stores = await getStores(env);

backend-ts/src/run/backfill-scale.ts

@@ -63,8 +63,10 @@ export async function backfillScalePopulation(deps: ScaleBackfillDeps, args: Sca
   // double-writes. To re-seed with a different --subjects, roll back first (see header).
   // Only treat COMPLETED runs as fully seeded. A run in RUNNING or FAILED status means a prior
   // invocation crashed between createRun and finalizeRun — we must not skip that measure, or the
-  // dashboard will aggregate a partial population. The orphaned partial run will be marked FAILED
-  // by failStuckRuns after 30 min; the new COMPLETED run then becomes the rollup source.
+  // dashboard will aggregate a partial population. The orphaned partial run is marked FAILED by the
+  // recovery sweep on the NEXT process start (the cutoff is that process's boot — not a 30-minute
+  // age, which is what this said before 2026-09-09); the new COMPLETED run then becomes the rollup
+  // source either way, since this filter only counts COMPLETED.
   const seededMeasures = new Set(
     (await deps.runStore.listRuns(100_000))
       .filter((r) => r.triggeredBy === SCALE_TRIGGER && r.status === "COMPLETED" && r.scopeId)

backend-ts/src/run/recover-stuck-runs.test.ts

@@ -15,7 +15,12 @@ import { SqliteRunStore } from "../stores/sqlite/run-store-sqlite.ts";
 import { SqliteCaseEventStore } from "../stores/sqlite/case-event-store-sqlite.ts";
 import type { CreateRunInput } from "../stores/run-store.ts";
 import type { AlertChannel, RunAlert } from "./alert-channel.ts";
-import { recoverStuckRuns } from "./recover-stuck-runs.ts";
+import { recoverStuckRuns, orphanThresholdMs, bootInstant } from "./recover-stuck-runs.ts";
+
+/** Captured at module load, to prove the production boot instant precedes it (see the last test). */
+const TEST_MODULE_LOADED_AT = Date.now();
+/** Mirrors CUTOFF_MARGIN_MS; kept local so the test states the value it expects rather than importing it. */
+const CUTOFF_MARGIN_MS_FOR_TEST = 1000;
 
 const sampleRun = (): CreateRunInput => ({
   scopeType: "ALL_PROGRAMS",
@@ -234,3 +239,174 @@ test("Fable M15: finalizeRun does not resurrect a run already FAILED by the swee
     }
   }
 });
+
+/**
+ * Drive `recoverStuckRuns` against the real SQLite store with NO explicit threshold, so the wiring's
+ * default (`orphanThresholdMs`) is what decides. Returns the ids it recovered plus each run's status.
+ */
+async function sweepWith(
+  bootedAt: number,
+  runsToCreate: readonly { label: string; startedAt: number }[],
+): Promise<{ recovered: string[]; statusOf: Record<string, string | undefined> }> {
+  const dbPath = join(tmpdir(), `workwell-recover-${crypto.randomUUID()}.sqlite`);
+  const db = await createSqliteD1(dbPath);
+  await db.exec(RUN_STORE_FLOOR_DDL.replace(/\n/g, " "));
+  const runs = new SqliteRunStore(db);
+  const events = new SqliteCaseEventStore(db);
+  try {
+    const ids = new Map<string, string>();
+    for (const r of runsToCreate) {
+      const created = await runs.createRun({ ...sampleRun(), startedAt: new Date(r.startedAt).toISOString() });
+      await runs.markRunning(created.id); // QUEUED → RUNNING, leaving claimed_by NULL as the real path does
+      ids.set(r.label, created.id);
+    }
+    const recovered = await recoverStuckRuns({ runs, events, bootedAt });
+    const statusOf: Record<string, string | undefined> = {};
+    for (const [label, id] of ids) statusOf[label] = (await runs.getRun(id))?.status;
+    const labelOf = new Map([...ids].map(([label, id]) => [id, label]));
+    return { recovered: recovered.map((r) => labelOf.get(r.id) ?? r.id), statusOf };
+  } finally {
+    try {
+      rmSync(dbPath, { force: true });
+    } catch {
+      /* best effort */
+    }
+  }
+}
+
+// The two halves of the 2026-09-09 incident need OPPOSITE fixtures — demonstrating that the flat
+// 30-minute default misses a young orphan requires a recent boot, and that it kills a healthy long
+// run requires an old one — so they cannot share a test. The previous single test used a 45-minute-old
+// boot with a 55-minute-old orphan, which the flat default would ALSO have swept: it failed on revert
+// only because the live run died too, and its comment claimed a mechanism it did not test.
+
+test("a run created BEFORE boot is swept even when it is far younger than the old flat threshold", async () => {
+  // The deploy-mid-run case, and the one the flat 30-minute default provably missed: the orphan is
+  // 25 minutes old, so `failStuckRuns`'s own default would leave it RUNNING for ever (both triggers
+  // are one-shot per process). Reverting the wiring to `failStuckRuns(olderThanMs, …)` fails here.
+  const bootedAt = Date.now() - 20 * 60 * 1000;
+  const { recovered, statusOf } = await sweepWith(bootedAt, [
+    { label: "orphan", startedAt: bootedAt - 5 * 60 * 1000 }, // 25 min old — under the flat 30 min
+  ]);
+  assert.deepEqual(recovered, ["orphan"], "a pre-boot run is orphaned at ANY age, not only past 30 minutes");
+  assert.equal(statusOf.orphan, "FAILED");
+});
+
+test("a run created AFTER boot survives however long it has been running", async () => {
+  // The half that broke the pilot: an 88-minute nightly is healthy, and the flat 30-minute default
+  // failed it at 98.7% complete. Setting CUTOFF_MARGIN_MS or the age term so the cutoff lands after
+  // boot fails here.
+  const bootedAt = Date.now() - 90 * 60 * 1000;
+  const { recovered, statusOf } = await sweepWith(bootedAt, [
+    { label: "live", startedAt: bootedAt + 2 * 60 * 1000 }, // 88 min old, started after boot
+  ]);
+  assert.deepEqual(recovered, [], "a long-running LIVE run is never swept");
+  assert.equal(statusOf.live, "RUNNING");
+});
+
+test("the cutoff sits BEFORE boot by the full margin, not at boot and not after it", async () => {
+  // Pins the margin's SIGN and its MAGNITUDE. An earlier version only placed a run 200ms after boot,
+  // which left `CUTOFF_MARGIN_MS = 0` (and anything up to 199) green — the cutoff exactly at boot,
+  // with no absorption at all for the gap between computing the threshold and the store applying it
+  // against its own clock. `withinMargin` sits 500ms BEFORE boot and must survive, which is only true
+  // while the margin actually pushes the cutoff back past it.
+  const bootedAt = Date.now() - 10 * 60 * 1000;
+  const { recovered, statusOf } = await sweepWith(bootedAt, [
+    { label: "justAfterBoot", startedAt: bootedAt + 200 },
+    { label: "withinMargin", startedAt: bootedAt - 500 },
+    { label: "beforeMargin", startedAt: bootedAt - 60 * 1000 },
+  ]);
+  assert.deepEqual(recovered, ["beforeMargin"], "only the run older than boot MINUS the margin is swept");
+  assert.equal(statusOf.justAfterBoot, "RUNNING");
+  assert.equal(statusOf.withinMargin, "RUNNING", "the margin must place the cutoff strictly before boot");
+});
+
+test("recoverStuckRuns with NO injected bootedAt uses this process's real boot", async () => {
+  // The production signature. Every other store-driven test passes `bootedAt` in, so the wiring's
+  // `deps.bootedAt` default — and with it the real `BOOTED_AT` — was never exercised end to end.
+  const dbPath = join(tmpdir(), `workwell-recover-${crypto.randomUUID()}.sqlite`);
+  const db = await createSqliteD1(dbPath);
+  await db.exec(RUN_STORE_FLOOR_DDL.replace(/\n/g, " "));
+  const runs = new SqliteRunStore(db);
+  const events = new SqliteCaseEventStore(db);
+  try {
+    // The live run is placed just after the REAL boot instant rather than at `now`, and that is the
+    // whole point of the test. A run created at `now` survives under any cutoff at or before now, so
+    // it cannot tell the real boot from a substitute — `deps.bootedAt ?? Date.now()` (a cutoff one
+    // second back) spares it too, and passed an earlier version of this test. A run sitting just
+    // after boot is spared ONLY by a cutoff actually anchored to boot.
+    //
+    // That requires this process to have more uptime than the margin, or "just after boot" and "just
+    // before now" are the same instant. Waited for explicitly so the discrimination is deterministic
+    // rather than dependent on how long the suite happened to take to get here.
+    while (process.uptime() * 1000 < 2 * CUTOFF_MARGIN_MS_FOR_TEST) {
+      await new Promise((r) => setTimeout(r, 100));
+    }
+    const realBoot = bootInstant(Date.now(), process.uptime());
+
+    // Created an hour before this process existed: orphaned under the real boot instant.
+    const orphan = await runs.createRun({ ...sampleRun(), startedAt: new Date(Date.now() - 60 * 60 * 1000).toISOString() });
+    await runs.markRunning(orphan.id);
+    // Created 100ms after this process booted — after boot, but further back than the margin.
+    const live = await runs.createRun({ ...sampleRun(), startedAt: new Date(realBoot + 100).toISOString() });
+    await runs.markRunning(live.id);
+
+    const recovered = await recoverStuckRuns({ runs, events }); // no bootedAt, no threshold
+
+    assert.deepEqual(recovered.map((r) => r.id), [orphan.id]);
+    assert.equal((await runs.getRun(live.id))?.status, "RUNNING");
+  } finally {
+    try {
+      rmSync(dbPath, { force: true });
+    } catch {
+      /* best effort */
+    }
+  }
+});
+
+test("bootInstant subtracts uptime in SECONDS from a millisecond clock", async () => {
+  // The arithmetic of `BOOTED_AT` itself, which no runtime assertion can pin precisely (a test's own
+  // process has only a second or two of uptime, so a wrong sign or a seconds/milliseconds mix-up
+  // lands within any tolerance loose enough not to be flaky). Extracted so it can be checked exactly.
+  assert.equal(bootInstant(1_000_000, 30), 970_000, "30s of uptime is 30,000ms BEFORE now");
+  assert.equal(bootInstant(1_000_000, 0), 1_000_000, "a just-started process booted now");
+  assert.ok(bootInstant(1_000_000, 30) < 1_000_000, "boot is in the past, never the future");
+});
+
+test("a clock that moved BACKWARDS sweeps nothing, rather than sweeping everything", async () => {
+  // The critical guard, and the only one whose failure is unbounded. `Math.max(0, …)` — the previous
+  // clamp — turned a negative age into a threshold of 0, which makes the store's cutoff `Date.now()`
+  // and matches EVERY unclaimed RUNNING row: the 2026-09-09 incident reproduced by an NTP step. The
+  // fixture puts boot an hour in the future of `now`, which is what a backward step looks like.
+  const bootedAt = Date.now() + 60 * 60 * 1000;
+  const { recovered, statusOf } = await sweepWith(bootedAt, [
+    { label: "live", startedAt: Date.now() - 5 * 60 * 1000 },
+    { label: "old", startedAt: Date.now() - 10 * 60 * 60 * 1000 },
+  ]);
+  assert.deepEqual(recovered, [], "an untrustworthy clock must sweep NOTHING");
+  assert.equal(statusOf.live, "RUNNING");
+  assert.equal(statusOf.old, "RUNNING");
+});
+
+test("orphanThresholdMs with no arguments measures PROCESS start, not module load", async () => {
+  // The production default `BOOTED_AT` is otherwise never evaluated under assertion, and a loose band
+  // here is not enough: `const BOOTED_AT = Date.now()` at module load — the exact regression the
+  // source comment warns about — lands within a few seconds of uptime and passes it.
+  //
+  // What separates the two is that this process necessarily spent time starting (node boot, tsx,
+  // imports) BEFORE this module was loaded. So a correct boot instant is measurably earlier than the
+  // moment this test file was evaluated; a module-load stamp is not.
+  const uptimeMs = process.uptime() * 1000;
+  const threshold = orphanThresholdMs();
+  const derivedBoot = Date.now() - threshold + CUTOFF_MARGIN_MS_FOR_TEST;
+
+  assert.ok(
+    threshold >= uptimeMs - 50 && threshold <= uptimeMs + 5_000,
+    `expected a threshold near this process's uptime (${Math.round(uptimeMs)}ms), got ${threshold}ms`,
+  );
+  assert.ok(
+    derivedBoot <= TEST_MODULE_LOADED_AT - 50,
+    `boot (${derivedBoot}) must precede this module's load (${TEST_MODULE_LOADED_AT}) by more than the ` +
+      `50ms of startup that certainly elapsed; a module-load stamp would make them equal`,
+  );
+});