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

apps/process.ts freePort races: a deploy can lose its port to another process before the app binds it #8686

Merged opened this

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

Merged

mason/forge:mason/7709-apps-process-ts-freeport-races-a-deploy → main 3 commits fork

  • Merged. mason/7709-apps-process-ts-freeport-races-a-deploy was merged into main as a893d36.

Review

Sign in to review this change.
2 files changed +266 −107
src/apps/process.ts +154 −106
@@ -72,6 +72,8 @@ export interface StartInput {
7272 * start — the forge coming back, or an environment waking — only runs it.
7373 */
7474 readonly warm?: boolean | undefined;
75 /** Chooses the app's port; tests hold one open to prove the retry. */
76 readonly pickPort?: (() => number) | undefined;
7577 /**
7678 * The repository's shared bun cache (`checks/install.ts`
7779 * `checkInstallCache`), the one its checks fill (#7544). The forge fills
@@ -510,32 +512,36 @@ export async function startProcess(
510512 cell: stepCell(input),
511513 });
512514
513 const port = freePort();
514 log(`$ ${manifest.run} (PORT=${port})`);
515 const spawnedAt = Date.now();
516 let firstOutputAt: number | undefined;
517 const cell: Cell | undefined =
518 input.cell === undefined
519 ? undefined
520 : openCell(
521 {
522 dir: input.dir,
523 writable: [input.dataDir],
524 home: input.cell.home,
525 hide: input.cell.hide,
526 egress: manifest.egress ?? [],
527 granted: input.cell.granted,
528 reach: [input.forgeUrl],
529 limits: resolveLimits("app", manifest.limits),
530 listen: port,
531 onUndeclared: input.cell.onUndeclared,
532 egressMode: input.cell.egressMode,
533 label: input.cell.label,
534 },
535 log,
536 );
537 const command = `exec ${manifest.run}`;
538 const env = appEnv({
515 // The port is chosen, then released, then bound by the app: another
516 // process can take it in between. An app that dies on an address-in-use
517 // error is started again on a fresh port (`startOnFreshPort`).
518 const pick = input.pickPort ?? freePort;
519 const launch = async (port: number): Promise<Launch> => {
520 log(`$ ${manifest.run} (PORT=${port})`);
521 const spawnedAt = Date.now();
522 let firstOutputAt: number | undefined;
523 const cell: Cell | undefined =
524 input.cell === undefined
525 ? undefined
526 : openCell(
527 {
528 dir: input.dir,
529 writable: [input.dataDir],
530 home: input.cell.home,
531 hide: input.cell.hide,
532 egress: manifest.egress ?? [],
533 granted: input.cell.granted,
534 reach: [input.forgeUrl],
535 limits: resolveLimits("app", manifest.limits),
536 listen: port,
537 onUndeclared: input.cell.onUndeclared,
538 egressMode: input.cell.egressMode,
539 label: input.cell.label,
540 },
541 log,
542 );
543 const command = `exec ${manifest.run}`;
544 const env = appEnv({
539545 port,
540546 dataDir: input.dataDir,
541547 env: input.env,
@@ -546,91 +552,100 @@ export async function startProcess(
546552 ssh: input.ssh,
547553 vars: input.vars,
548554 forgeToken: input.forgeToken,
549 });
550 const proc = Bun.spawn(cell?.argv(command) ?? ["/bin/sh", "-c", command], {
551 cwd: input.dir,
552 env: cell?.env(env) ?? env,
553 stdin: "ignore",
554 stdout: "pipe",
555 stderr: "pipe",
556 // Without a cell, the app leads a process group of its own, so what it
557 // starts can be signalled with it (`signalGroup`). A cell's tree is
558 // bubblewrap's, walked by `signalTree` and `killTree`.
559 detached: cell === undefined,
560 });
561 // The cell's sockets and watch end with the process, however it ends.
562 // Without a cell, so does the rest of its group: a child that outlived
563 // the app, stopped or crashed, is not left running on its data.
564 // Read before the cell closes: its cgroup's OOM count goes with it.
565 let breach: string | undefined;
566 void proc.exited.then(() => {
567 breach = cell?.breach();
568 cell?.close();
569 if (cell === undefined) signalGroup(proc.pid, "SIGKILL");
570 });
571 cell?.watch(proc.pid, () => killTree(proc.pid));
572 // Output is pumped for the life of the process, not just the start.
573 const recent: string[] = [];
574 const dirs = spellings([input.dir, input.dataDir]);
575 const remember = (raw: string): void => {
576 firstOutputAt ??= Date.now();
577 const line = stripForgeDirs(dirs, raw);
578 recent.push(line);
579 if (recent.length > 20) recent.shift();
580 log(line);
581 };
582 void pump(proc.stdout, remember);
583 void pump(proc.stderr, remember);
555 });
556 const proc = Bun.spawn(cell?.argv(command) ?? ["/bin/sh", "-c", command], {
557 cwd: input.dir,
558 env: cell?.env(env) ?? env,
559 stdin: "ignore",
560 stdout: "pipe",
561 stderr: "pipe",
562 // Without a cell, the app leads a process group of its own, so what it
563 // starts can be signalled with it (`signalGroup`). A cell's tree is
564 // bubblewrap's, walked by `signalTree` and `killTree`.
565 detached: cell === undefined,
566 });
567 // The cell's sockets and watch end with the process, however it ends.
568 // Without a cell, so does the rest of its group: a child that outlived
569 // the app, stopped or crashed, is not left running on its data.
570 // Read before the cell closes: its cgroup's OOM count goes with it.
571 let breach: string | undefined;
572 void proc.exited.then(() => {
573 breach = cell?.breach();
574 cell?.close();
575 if (cell === undefined) signalGroup(proc.pid, "SIGKILL");
576 });
577 cell?.watch(proc.pid, () => killTree(proc.pid));
578 // Output is pumped for the life of the process, not just the start.
579 const recent: string[] = [];
580 const dirs = spellings([input.dir, input.dataDir]);
581 const remember = (raw: string): void => {
582 firstOutputAt ??= Date.now();
583 const line = stripForgeDirs(dirs, raw);
584 recent.push(line);
585 if (recent.length > 20) recent.shift();
586 log(line);
587 };
588 const drained = Promise.all([pump(proc.stdout, remember), pump(proc.stderr, remember)]);
584589
585 let inner: number | undefined;
586 const handle: ProcessHandle = {
587 // In a cell, the app's own pid rather than bubblewrap's: what has
588 // children when the app is busy (`apps/busy.ts`).
589 get pid() {
590 if (cell === undefined) return proc.pid;
591 inner ??= commandPid(proc.pid);
592 return inner ?? proc.pid;
593 },
594 port,
595 exited: proc.exited,
596 breach: () => breach,
597 stop: async () => {
598 if (proc.exitCode !== null || proc.signalCode !== null) return;
599 // In a cell the pid is bubblewrap's, which passes no signal on: the
600 // app itself is asked, so it shuts down the way it would anywhere.
601 if (cell === undefined) signalGroup(proc.pid, "SIGTERM");
602 else signalTree(proc.pid, "SIGTERM");
603 const gone = await Promise.race([
604 proc.exited.then(() => true),
605 Bun.sleep(STOP_GRACE_MS).then(() => false),
606 ]);
607 if (!gone) {
608 if (cell === undefined) signalGroup(proc.pid, "SIGKILL");
609 else killTree(proc.pid);
610 await proc.exited;
611 }
612 },
613 };
590 let inner: number | undefined;
591 const handle: ProcessHandle = {
592 // In a cell, the app's own pid rather than bubblewrap's: what has
593 // children when the app is busy (`apps/busy.ts`).
594 get pid() {
595 if (cell === undefined) return proc.pid;
596 inner ??= commandPid(proc.pid);
597 return inner ?? proc.pid;
598 },
599 port,
600 exited: proc.exited,
601 breach: () => breach,
602 stop: async () => {
603 if (proc.exitCode !== null || proc.signalCode !== null) return;
604 // In a cell the pid is bubblewrap's, which passes no signal on: the
605 // app itself is asked, so it shuts down the way it would anywhere.
606 if (cell === undefined) signalGroup(proc.pid, "SIGTERM");
607 else signalTree(proc.pid, "SIGTERM");
608 const gone = await Promise.race([
609 proc.exited.then(() => true),
610 Bun.sleep(STOP_GRACE_MS).then(() => false),
611 ]);
612 if (!gone) {
613 if (cell === undefined) signalGroup(proc.pid, "SIGKILL");
614 else killTree(proc.pid);
615 await proc.exited;
616 }
617 },
618 };
614619
615 const ready = await waitUntilReady({
616 port,
617 path: manifest.health,
618 timeoutMs: manifest.ready * 1000,
619 exited: proc.exited,
620 signal: input.signal,
621 });
622 if (!ready.ok) {
623 await handle.stop();
620 const ready = await waitUntilReady({
621 port,
622 path: manifest.health,
623 timeoutMs: manifest.ready * 1000,
624 exited: proc.exited,
625 signal: input.signal,
626 });
627 if (!ready.ok) {
628 await handle.stop();
629 // The exit can be seen before the pumps deliver its last lines, the
630 // address-in-use one among them; a pipe a child holds open is not waited on.
631 await Promise.race([drained, Bun.sleep(DRAIN_CAP_MS)]);
632 const tail = recent.length > 0 ? ` — ${failureReason(recent)}` : "";
633 return {
634 error: { stage: ready.error.stage, message: ready.error.message + tail },
635 portTaken: ready.error.exited && recent.some((line) => ADDRESS_IN_USE_RE.test(line)),
636 };
637 }
638 return { handle, spawnedAt, firstOutputAt };
639 };
640 const launched = await startOnFreshPort(launch, pick, input.signal, log);
641 if ("error" in launched) {
624642 // The app never came up: the test step running beside it has nothing
625643 // left to verify, and must not outlive this failed run.
626644 testAbort.abort();
627645 await tested.catch(() => {});
628 const tail = recent.length > 0 ? ` — ${failureReason(recent)}` : "";
629 return err({
630 stage: ready.error.stage,
631 message: ready.error.message + tail,
632 });
646 return err(launched.error);
633647 }
648 const { handle, spawnedAt, firstOutputAt } = launched;
634649 log(`ready: ${input.url}`);
635650 // How the process's own share of the start divides: the time until it
636651 // first said anything (the runtime loading the app, the app's own boot
@@ -652,7 +667,7 @@ async function waitUntilReady(input: {
652667 timeoutMs: number;
653668 exited: Promise<number>;
654669 signal: AbortSignal;
655 }): Promise<Result<void, StartError>> {
670 }): Promise<Result<void, StartError & { readonly exited: boolean }>> {
656671 const deadline = Date.now() + input.timeoutMs;
657672 let exitCode: number | undefined;
658673 void input.exited.then((code) => {
@@ -661,11 +676,12 @@ async function waitUntilReady(input: {
661676 let lastStatus: number | undefined;
662677 while (Date.now() < deadline) {
663678 if (input.signal.aborted)
664 return err({ stage: "start", message: "cancelled" });
679 return err({ stage: "start", message: "cancelled", exited: false });
665680 if (exitCode !== undefined)
666681 return err({
667682 stage: "start",
668683 message: `exited with code ${exitCode} before answering`,
684 exited: true,
669685 });
670686 try {
671687 const response = await fetch(
@@ -685,6 +701,7 @@ async function waitUntilReady(input: {
685701 }
686702 return err({
687703 stage: "ready",
704 exited: false,
688705 message:
689706 lastStatus === undefined
690707 ? `no answer on ${input.path} within ${Math.round(input.timeoutMs / 1000)}s`
@@ -692,6 +709,37 @@ async function waitUntilReady(input: {
692709 });
693710 }
694711
712 /** How many more times an app that lost its port is started on a fresh one. */
713 export const PORT_RETRIES = 2;
714 /** How long a failed start waits for the app's last output to arrive. */
715 const DRAIN_CAP_MS = 1_000;
716 const ADDRESS_IN_USE_RE = /address (?:already )?in use|EADDRINUSE|port \d+ in use/i;
717
718 /** One start of the app on one port: up, or the error and whether the port was lost. */
719 type Launch =
720 | {
721 readonly handle: ProcessHandle;
722 readonly spawnedAt: number;
723 readonly firstOutputAt: number | undefined;
724 }
725 | { readonly error: StartError; readonly portTaken: boolean };
726
727 /** Launch on a picked port; while the app lost it to another process, on a fresh one, up to PORT_RETRIES more times. */
728 async function startOnFreshPort(
729 launch: (port: number) => Promise<Launch>,
730 pick: () => number,
731 signal: AbortSignal,
732 log: (line: string) => void,
733 ): Promise<Launch> {
734 let launched = await launch(pick());
735 for (let retry = 0; retry < PORT_RETRIES; retry++) {
736 if (!("error" in launched) || !launched.portTaken || signal.aborted) break;
737 log("the port was taken before the app bound it; starting again on another");
738 launched = await launch(pick());
739 }
740 return launched;
741 }
742
695743 /** A port the OS says is free right now. */
696744 export function freePort(): number {
697745 const probe = Bun.serve({
test/apps.test.ts +112 −1
@@ -19,7 +19,7 @@ import { createApp, type App } from "../src/app.ts";
1919 import { AppsRuntime } from "../src/apps/runtime.ts";
2020 import { seconds, Stopwatch } from "../src/apps/timing.ts";
2121 import { envDataDir, envDir, previewEnv } from "../src/apps/data.ts";
22 import { childEnv, runStep, startProcess } from "../src/apps/process.ts";
22 import { childEnv, freePort, PORT_RETRIES, runStep, startProcess } from "../src/apps/process.ts";
2323 import type { AppManifest } from "../src/apps/manifest.ts";
2424 import {
2525 enableApp,
@@ -1260,3 +1260,114 @@ describe("a restart brings every app's production up before any preview", () =>
12601260 );
12611261 }, 90_000);
12621262 });
1263
1264 describe("start: a port lost to another process", () => {
1265 const manifest: AppManifest = {
1266 run: `bun -e 'Bun.serve({ port: Number(process.env.PORT), hostname: "127.0.0.1", fetch: () => new Response("ok") })'`,
1267 install: null,
1268 test: null,
1269 health: "/",
1270 ready: 5,
1271 tty: null,
1272 service: null,
1273 looks: ["/"],
1274 };
1275 // Another process holding a port: it accepts and hangs up, so the health
1276 // check never mistakes it for the app.
1277 const hold = () =>
1278 Bun.listen({
1279 hostname: "127.0.0.1",
1280 port: 0,
1281 socket: { open: (socket) => void socket.end(), data() {} },
1282 });
1283 const start = async (
1284 dir: string,
1285 ports: (() => number) | undefined,
1286 over: Partial<AppManifest> = {},
1287 ) => {
1288 const lines: string[] = [];
1289 const started = await startProcess({
1290 dir,
1291 dataDir: dir,
1292 manifest: { ...manifest, ...over },
1293 env: "production",
1294 url: "http://app.test",
1295 commitOid: "0".repeat(40),
1296 forgeUrl: "http://forge.test",
1297 identityKey: "key",
1298 log: (line) => void lines.push(line),
1299 signal: new AbortController().signal,
1300 pickPort: ports,
1301 });
1302 return { started, lines };
1303 };
1304
1305 test("an app that finds its port taken is started again on a fresh one", async () => {
1306 const dir = await mkdtemp(join(tmpdir(), "forge-port-race-"));
1307 const held = hold();
1308 const picks: number[] = [];
1309 try {
1310 const { started, lines } = await start(dir, () => {
1311 const port = picks.length === 0 ? held.port : freePort();
1312 picks.push(port);
1313 return port;
1314 });
1315 expect(picks.length).toBe(2);
1316 expect(picks[0]).toBe(held.port);
1317 expect(lines.join("\n")).toContain("the port was taken before the app bound it");
1318 expect(started.ok).toBe(true);
1319 if (!started.ok) return;
1320 expect(started.value.handle.port).toBe(picks[1]!);
1321 expect(started.value.handle.port).not.toBe(held.port);
1322 const answer = await fetch(`http://127.0.0.1:${started.value.handle.port}/`);
1323 expect(await answer.text()).toBe("ok");
1324 await started.value.handle.stop();
1325 } finally {
1326 held.stop(true);
1327 await rm(dir, { recursive: true, force: true });
1328 }
1329 }, 30_000);
1330
1331 test("retries stop after PORT_RETRIES when every port is held", async () => {
1332 const dir = await mkdtemp(join(tmpdir(), "forge-port-race-"));
1333 const holders = Array.from({ length: PORT_RETRIES + 1 }, hold);
1334 const picks: number[] = [];
1335 try {
1336 const { started, lines } = await start(
1337 dir,
1338 () => {
1339 const port = holders[picks.length]!.port;
1340 picks.push(port);
1341 return port;
1342 },
1343 { ready: 2 },
1344 );
1345 expect(started.ok).toBe(false);
1346 expect(picks.length).toBe(PORT_RETRIES + 1);
1347 expect(picks.length).toBe(3);
1348 expect(lines.filter((l) => l.includes("the port was taken")).length).toBe(PORT_RETRIES);
1349 } finally {
1350 for (const h of holders) h.stop(true);
1351 await rm(dir, { recursive: true, force: true });
1352 }
1353 }, 60_000);
1354
1355 test("an app that exits for another reason is not started again", async () => {
1356 const dir = await mkdtemp(join(tmpdir(), "forge-port-race-"));
1357 let picks = 0;
1358 try {
1359 const { started } = await start(
1360 dir,
1361 () => {
1362 picks++;
1363 return freePort();
1364 },
1365 { run: "echo boom 1>&2; exit 1" },
1366 );
1367 expect(started.ok).toBe(false);
1368 expect(picks).toBe(1);
1369 } finally {
1370 await rm(dir, { recursive: true, force: true });
1371 }
1372 }, 20_000);
1373 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs