Public: anyone can read this; the crew can change it.

A deploy the forge's own restart interrupted reads as Failed, beside a real failure #286

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

scout/forge:scout/255-a-deploy-the-forge-s-own-restart-interru → main 2 commits fork

  • Merged. scout/255-a-deploy-the-forge-s-own-restart-interru was merged into main as 023de96.

Review

Sign in to review this change.
7 files changed +251 −26
src/apps/process.ts +25 −5
@@ -186,20 +186,26 @@ export async function runStep(
186186 options.log(stripForgeDirs([options.cwd], line));
187187 const timeoutMs = options.timeoutMs ?? STEP_TIMEOUT_MS;
188188 let why: string | undefined;
189 // A killed process's pipes are not guaranteed to close on their own
190 // (see `pump`); this stops the reads directly the same moment the kill
191 // is sent, so a step in flight never outlives its own cancellation.
192 const stopReading = new AbortController();
189193 const timer = setTimeout(() => {
190194 why = `${name} took longer than ${Math.round(timeoutMs / 1000)}s`;
191195 proc.kill("SIGKILL");
196 stopReading.abort();
192197 }, timeoutMs);
193198 const onAbort = (): void => {
194199 why = `${name} cancelled`;
195200 proc.kill("SIGKILL");
201 stopReading.abort();
196202 };
197203 if (options.signal.aborted) onAbort();
198204 else options.signal.addEventListener("abort", onAbort, { once: true });
199205 try {
200206 const [, , code] = await Promise.all([
201 pump(proc.stdout, scrub),
202 pump(proc.stderr, scrub),
207 pump(proc.stdout, scrub, stopReading.signal),
208 pump(proc.stderr, scrub, stopReading.signal),
203209 proc.exited,
204210 ]);
205211 if (why !== undefined) return err(why);
@@ -396,17 +402,29 @@ export function freePort(): number {
396402 return port;
397403 }
398404
399 /** Read a stream as lines, calling `onLine` for each; never throws. */
405 /**
406 * Read a stream as lines, calling `onLine` for each; never throws. A killed
407 * process's pipe does not always signal end-of-stream on its own — `signal`
408 * cancels the read directly, or a caller racing a dead process would wait on
409 * a stream that never closes.
410 */
400411 export async function pump(
401412 stream: ReadableStream<Uint8Array> | null | undefined,
402413 onLine: (line: string) => void,
414 signal?: AbortSignal,
403415 ): Promise<void> {
404416 if (!stream) return;
405417 const decoder = new TextDecoder();
406418 let carry = "";
419 const reader = stream.getReader();
420 const onAbort = (): void => void reader.cancel().catch(() => {});
421 if (signal?.aborted) onAbort();
422 else signal?.addEventListener("abort", onAbort, { once: true });
407423 try {
408 for await (const chunk of stream) {
409 carry += decoder.decode(chunk, { stream: true });
424 while (true) {
425 const { done, value } = await reader.read();
426 if (done) break;
427 carry += decoder.decode(value, { stream: true });
410428 let at = carry.indexOf("\n");
411429 while (at !== -1) {
412430 onLine(carry.slice(0, at).replace(/\r$/, ""));
@@ -418,5 +436,7 @@ export async function pump(
418436 if (carry !== "") onLine(carry);
419437 } catch {
420438 // The process went away mid-read; whatever arrived was delivered.
439 } finally {
440 signal?.removeEventListener("abort", onAbort);
421441 }
422442 }
src/apps/runtime.ts +34 −1
@@ -157,6 +157,14 @@ interface Live {
157157 */
158158 const PUSH_REASONS: readonly string[] = ["push", "opened", "merge"];
159159
160 /**
161 * The one summary every cancellation the runtime itself causes by stopping
162 * carries — a run still queued when `stop()` runs, and one aborted mid-step
163 * alike, so `runWord` (`web/studio/words.ts`) has one fact to recognise
164 * rather than two spellings of the same reason.
165 */
166 export const STOPPED_SUMMARY = "the forge stopped";
167
160168 /** How long between two instants, in seconds to one decimal place: `3.4s`. */
161169 function elapsedSeconds(fromIso: string, toIso: string): string {
162170 const ms = Math.max(0, Date.parse(toIso) - Date.parse(fromIso));
@@ -348,6 +356,19 @@ export class AppsRuntime {
348356 ...(failedDeploy === undefined ? {} : { failedDeploy }),
349357 };
350358 }
359 // Nothing is live and nothing is in flight yet, but a deploy already
360 // waits its turn on the chain — a restart's own reconcile queues one
361 // the instant it boots. That is "starting", not the stale error (if
362 // any) a cancelled attempt before it left behind.
363 if (state.queued !== undefined) {
364 return {
365 env: state.env,
366 state: "deploying",
367 commitOid: state.queued.commitOid,
368 url,
369 runId: state.queued.id,
370 };
371 }
351372 return {
352373 env: state.env,
353374 state: state.lastError === undefined ? "stopped" : "failed",
@@ -397,7 +418,7 @@ export class AppsRuntime {
397418 for (const state of this.envs.values()) {
398419 state.deploying?.abort.abort();
399420 if (state.queued)
400 cancelRun(this.app.db, state.queued.id, "the forge stopped");
421 cancelRun(this.app.db, state.queued.id, STOPPED_SUMMARY);
401422 if (state.live) stops.push(state.live.handle.stop());
402423 // Abort only cancels the step in flight; the `execute()` continuation
403424 // chained onto `state.chain` still runs afterwards to record the
@@ -689,6 +710,18 @@ export class AppsRuntime {
689710 if (!outcome.ok) {
690711 state.deploying = undefined;
691712 lease();
713 // The runtime itself stopping is what aborted the step in flight —
714 // the forge's own business, never this commit's fault, and the same
715 // honest reason the still-queued case already carries. A real
716 // failure (a non-zero exit, a genuine timeout) still fails the run
717 // below even if the runtime happens to be stopping at the same time:
718 // only an abort this runtime raised earns the quieter outcome.
719 if (this.stopped && abort.signal.aborted) {
720 const done = cancelRun(this.app.db, run.id, STOPPED_SUMMARY);
721 write(`cancelled: ${STOPPED_SUMMARY}`);
722 if (done) announceRun(this.app, done);
723 return;
724 }
692725 state.lastError = outcome.error;
693726 state.lastErrorCommitOid = run.commitOid;
694727 const done = finishRun(this.app.db, run.id, {
src/web/client.ts +2 −1
@@ -516,7 +516,8 @@ export const studioRunJs = /* js */ `
516516 function studioWord(run) {
517517 if (run.state === 'queued') return 'waiting';
518518 if (run.state === 'running') return 'working';
519 if (run.state === 'failed' || run.state === 'cancelled') return 'stopped';
519 if (run.state === 'cancelled') return 'cancelled';
520 if (run.state === 'failed') return 'stopped';
520521 var s = run.summary || '';
521522 if (/opened pull|updated pull/.test(s)) return 'look';
522523 if (/planned|no changes pushed/.test(s)) return 'planned';
src/web/studio/lists.ts +5 −3
@@ -49,9 +49,10 @@ import {
4949
5050 /** The five words a studio list filters by. `waiting` and `planned` are
5151 * still moving, so they fold into `working`; `done` is a deploy or a check
52 * that finished with nothing else to show, so it folds into `shipped` — the
53 * one place the eight-word vocabulary above buckets down to the five a list
54 * links to. */
52 * that finished with nothing else to show, so it folds into `shipped`;
53 * `cancelled` is still a run that did not land, so it folds into `stopped`
54 * — the one place the nine-word vocabulary above buckets down to the five a
55 * list links to. */
5556 type WordFilter = "told" | "working" | "look" | "shipped" | "stopped";
5657
5758 const WORD_FILTERS: readonly WordFilter[] = [
@@ -65,6 +66,7 @@ const WORD_FILTERS: readonly WordFilter[] = [
6566 function listBucket(word: Word): WordFilter {
6667 if (word === "waiting" || word === "planned") return "working";
6768 if (word === "done") return "shipped";
69 if (word === "cancelled") return "stopped";
6870 return word;
6971 }
7072
src/web/studio/words.ts +33 −11
@@ -1,16 +1,20 @@
11 /**
2 * The studio's vocabulary: the five words (and the three that only ever fold
3 * into them — `waiting`, `planned` into `working`, `done` into `shipped`) a
4 * person reads on every studio page, and the badge that draws one. `runWord`
5 * and `pullWord` are the one place a word is decided, from facts in git and
6 * the tables — never from a run's own summary text — so the home, the app, a
7 * change, a tell and every list say the same thing about the same commit.
8 * Nothing here knows about a page.
2 * The studio's vocabulary: the five words (and the four that only ever fold
3 * into them — `waiting`, `planned` into `working`, `done` into `shipped`,
4 * `cancelled` into `stopped`) a person reads on every studio page, and the
5 * badge that draws one. `runWord` and `pullWord` are the one place a word is
6 * decided, from facts in git and the tables — never from a run's own summary
7 * text — so the home, the app, a change, a tell and every list say the same
8 * thing about the same commit. Nothing here knows about a page.
99 */
1010
1111 import type { Database } from "bun:sqlite";
1212 import { mergeBase } from "../../git/merge.ts";
13 import type { AppsRuntime, EnvStatus } from "../../apps/runtime.ts";
13 import {
14 STOPPED_SUMMARY,
15 type AppsRuntime,
16 type EnvStatus,
17 } from "../../apps/runtime.ts";
1418 import type { AppRecord } from "../../core/apps.ts";
1519 import { getIssueById } from "../../core/issues.ts";
1620 import { getPull, pullForBranch, type Pull } from "../../core/pulls.ts";
@@ -31,7 +35,8 @@ export type Word =
3135 | "waiting"
3236 | "planned"
3337 | "told"
34 | "done";
38 | "done"
39 | "cancelled";
3540
3641 /**
3742 * Everything the word functions below need to see production: the repo's
@@ -174,8 +179,22 @@ export async function runWord(
174179 ? { word: "waiting", note: "queued" }
175180 : { word: "waiting", note: "paused, resumes soon" };
176181 if (run.state === "running") return { word: "working", note: "now" };
177 if (run.state === "failed" || run.state === "cancelled")
182 if (run.state === "failed")
178183 return { word: "stopped", note: run.summary || run.state };
184 // A cancelled run is not a broken one — superseded by a newer push, its
185 // environment torn down, a person's own Cancel, or the runtime itself
186 // stopping (`STOPPED_SUMMARY`, the one summary that earns a friendlier
187 // note than the raw fact, the same way it already reads on the run's own
188 // log). The word is always the quiet one; only the note still comes from
189 // the summary, exactly as every other word's note already does.
190 if (run.state === "cancelled")
191 return {
192 word: "cancelled",
193 note:
194 run.summary === STOPPED_SUMMARY
195 ? "interrupted by a restart"
196 : run.summary || run.state,
197 };
179198 const pull = pullFromRun(ctx.db, run);
180199 if (pull !== undefined) return await pullWord(ctx, pull);
181200 if (run.kind !== "agent")
@@ -280,10 +299,13 @@ const WORD_ICON: Record<Word, Parameters<typeof icon>[0]> = {
280299 planned: "map",
281300 told: "clock",
282301 done: "check",
302 cancelled: "ban",
283303 };
284304
285305 /** One of the five (or six) studio words, as a badge. An id names the one a
286 * live script repaints as a run finishes (`studioRunJs`). */
306 * live script repaints as a run finishes (`studioRunJs`). `cancelled` draws
307 * the same quiet, secondary look as `waiting` and `planned` — a restart is
308 * never the danger red a real failure earns. */
287309 export function wordBadge(word: Word, id?: string): Html {
288310 const variant =
289311 word === "look" || word === "shipped" || word === "done"
test/apps-adversarial.test.ts +9 −3
@@ -1180,6 +1180,11 @@ describe("apps adversarial: teardown races, grants, the proxy, and rule 1/4", ()
11801180 const repo = made.value.repo;
11811181 await settled(repo.id, (r) => r.env === "production");
11821182
1183 // A merge lands this same forge.json on the default branch and
1184 // production redeploys it too, running this same test step to
1185 // completion (nothing aborts a deploy that was never in flight when the
1186 // pull closed) — a marker keyed by $FORGE_APP_ENV keeps that legitimate
1187 // production run from being mistaken for the preview's orphan.
11831188 const marker = join(work, `slowtest-marker-${Date.now()}`);
11841189 const committed = await commitToBranch(app, alice, repo, {
11851190 branch: "slow-test",
@@ -1192,7 +1197,7 @@ describe("apps adversarial: teardown races, grants, the proxy, and rule 1/4", ()
11921197 {
11931198 app: {
11941199 run: "bun run src/server.ts",
1195 test: `sleep 5 && touch ${marker}`,
1200 test: `sleep 5 && touch ${marker}-$FORGE_APP_ENV`,
11961201 },
11971202 },
11981203 null,
@@ -1237,9 +1242,10 @@ describe("apps adversarial: teardown races, grants, the proxy, and rule 1/4", ()
12371242 expect(closed.ok).toBe(true);
12381243
12391244 // Wait well past the sleep the test step was doing, and confirm it
1240 // never finished: the marker it would have written is not there.
1245 // never finished: the preview's own marker is not there (production's,
1246 // from its own unrelated redeploy of the same merged commit, may be).
12411247 await Bun.sleep(6_500);
1242 expect(existsSync(marker)).toBe(false);
1248 expect(existsSync(`${marker}-preview`)).toBe(false);
12431249 }, 60_000);
12441250
12451251 test("private grant: forged, tampered, expired, wrong-env, and open-redirect are all refused; cookie is HttpOnly/SameSite", async () => {
test/apps.test.ts +143 −2
@@ -13,7 +13,7 @@ import { mkdtemp, rm } from "node:fs/promises";
1313 import { tmpdir } from "node:os";
1414 import { join } from "node:path";
1515 import { createApp, type App } from "../src/app.ts";
16 import { AppsRuntime } from "../src/apps/runtime.ts";
16 import { AppsRuntime, STOPPED_SUMMARY } from "../src/apps/runtime.ts";
1717 import { envDataDir, envDir, previewEnv } from "../src/apps/data.ts";
1818 import {
1919 enableApp,
@@ -40,7 +40,8 @@ import { getPull, type Pull } from "../src/core/pulls.ts";
4040 import { getRepoById, type Repo } from "../src/core/repos.ts";
4141 import { resolveOid } from "../src/git/merge.ts";
4242 import { repoDir } from "../src/git/repos.ts";
43 import { listRuns, type Run } from "../src/core/runs.ts";
43 import { getRun, listRuns, type Run } from "../src/core/runs.ts";
44 import { runWord } from "../src/web/studio/words.ts";
4445 import { createToken } from "../src/core/tokens.ts";
4546 import { createUser, type User } from "../src/core/users.ts";
4647 import { serve, type Servers } from "../src/http/server.ts";
@@ -1747,3 +1748,143 @@ describe("the App page's terminal line survives an email-scanning edge (issue #2
17471748 expect(html).toContain("host key SHA256:abcdefghijklmnopqrstuvwxyz");
17481749 });
17491750 });
1751
1752 describe("the forge's own restart never reads as this deploy's failure (issue #255)", () => {
1753 let dataDir: string;
1754 let app: App;
1755 let servers: Servers;
1756 let runtime: AppsRuntime;
1757 let alice: User;
1758 const DOMAIN = "stop-mid-deploy.test";
1759
1760 beforeAll(async () => {
1761 dataDir = await mkdtemp(join(tmpdir(), "forge-stop-mid-deploy-"));
1762 app = createApp({ dataDir, port: 0 });
1763 servers = await serve(app);
1764 runtime = new AppsRuntime(app, {
1765 domain: DOMAIN,
1766 scheme: "http",
1767 publicPort: servers.port,
1768 forgeUrl: servers.url,
1769 concurrency: 2,
1770 });
1771 await runtime.start();
1772 const created = await createUser(app.db, {
1773 username: "alice",
1774 email: "[email protected]",
1775 password: "a-good-passphrase",
1776 adminIfFirst: true,
1777 });
1778 if (!created.ok) throw new Error(created.error);
1779 alice = created.value;
1780 }, 30_000);
1781
1782 afterAll(async () => {
1783 await runtime.stop();
1784 servers.stop();
1785 app.close();
1786 await rm(dataDir, { recursive: true, force: true });
1787 });
1788
1789 test("an install still in flight when the runtime stops finishes cancelled, not failed", async () => {
1790 const made = await createRepo(app, alice, {
1791 name: "slow-install",
1792 visibility: "public",
1793 });
1794 expect(made.ok).toBe(true);
1795 if (!made.ok) return;
1796 const repo = made.value;
1797 // A single simple command as `sh -c`'s whole argument execs straight
1798 // into it (no forked shell left to orphan): a `SIGKILL` reaches this
1799 // `sleep` directly, so aborting it does not itself depend on the fix
1800 // under test.
1801 const committed = await commitToBranch(app, alice, repo, {
1802 message: "An install that blocks until stopped",
1803 files: [
1804 {
1805 path: "forge.json",
1806 content: JSON.stringify({
1807 app: {
1808 run: "bun -e \"Bun.serve({port:Number(process.env.PORT),hostname:'127.0.0.1',fetch:()=>new Response('ok')})\"",
1809 install: "sleep 30",
1810 health: "/",
1811 ready: 5,
1812 },
1813 }),
1814 },
1815 ],
1816 });
1817 expect(committed.ok).toBe(true);
1818 if (!committed.ok) return;
1819 const enabled = enableApp(app, alice, repo, {});
1820 expect(enabled.ok).toBe(true);
1821 if (!enabled.ok) return;
1822 const record = enabled.value;
1823
1824 // Wait for the install step to actually be running before pulling the
1825 // rug: a stop before it ever started would prove nothing about the
1826 // abort path this test means to cover.
1827 const deadline = Date.now() + 10_000;
1828 let runId: string | undefined;
1829 while (Date.now() < deadline) {
1830 const inFlight = listRuns(app.db, repo.id, { kind: "deploy" }).find(
1831 (r) => r.env === "production",
1832 );
1833 if (
1834 inFlight?.state === "running" &&
1835 readRunLog(dataDir, inFlight.id).lines.some((l) => l.includes("$ sleep 30"))
1836 ) {
1837 runId = inFlight.id;
1838 break;
1839 }
1840 await Bun.sleep(20);
1841 }
1842 expect(runId).toBeDefined();
1843
1844 await runtime.stop();
1845
1846 const finished = getRun(app.db, runId!);
1847 expect(finished?.state).toBe("cancelled");
1848 expect(finished?.summary).toBe(STOPPED_SUMMARY);
1849
1850 const word = await runWord(
1851 {
1852 db: app.db,
1853 dir: repoDir(app.reposRoot, repo.ownerName, repo.name),
1854 runtime: undefined,
1855 record: undefined,
1856 },
1857 finished!,
1858 );
1859 expect(word).toEqual({ word: "cancelled", note: "interrupted by a restart" });
1860
1861 // The studio's own word for it is the quiet one, never the word for a
1862 // broken deploy — and that is what the run's own page renders.
1863 const cookie = (
1864 (
1865 await fetch(`${servers.url}/signin`, {
1866 method: "POST",
1867 body: new URLSearchParams({
1868 username: "alice",
1869 password: "a-good-passphrase",
1870 }),
1871 redirect: "manual",
1872 })
1873 ).headers.get("set-cookie") ?? ""
1874 ).split(";")[0]!;
1875 const page = await fetch(
1876 `${servers.url}/${repo.ownerName}/${repo.name}/runs/${runId}`,
1877 { headers: { cookie: `${cookie}; forge_mode=studio` } },
1878 );
1879 expect(page.status).toBe(200);
1880 const html = await page.text();
1881 expect(html).toContain('data-word="cancelled"');
1882 expect(html).not.toContain('data-word="stopped"');
1883
1884 // The environment itself does not advertise the restart as why it is
1885 // down: nothing ever served, and no error carries over from a run that
1886 // was never this commit's fault.
1887 const status = runtime.envStatus(record, "production");
1888 expect(status?.error).toBeUndefined();
1889 }, 30_000);
1890 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs