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
Check · Review · Land · Live done — Landed and live in production.
mason/forge:mason/7709-apps-process-ts-freeport-races-a-deploy → main 3 commits fork
2 files
changed +266
−107
src/apps/process.ts +154 −106
| @@ -72,6 +72,8 @@ export interface StartInput { | ||
| 72 | 72 | * start — the forge coming back, or an environment waking — only runs it. |
| 73 | 73 | */ |
| 74 | 74 | readonly warm?: boolean | undefined; |
| 75 | /** Chooses the app's port; tests hold one open to prove the retry. */ | |
| 76 | readonly pickPort?: (() => number) | undefined; | |
| 75 | 77 | /** |
| 76 | 78 | * The repository's shared bun cache (`checks/install.ts` |
| 77 | 79 | * `checkInstallCache`), the one its checks fill (#7544). The forge fills |
| @@ -510,32 +512,36 @@ export async function startProcess( | ||
| 510 | 512 | cell: stepCell(input), |
| 511 | 513 | }); |
| 512 | 514 | |
| 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({ | |
| 539 | 545 | port, |
| 540 | 546 | dataDir: input.dataDir, |
| 541 | 547 | env: input.env, |
| @@ -546,91 +552,100 @@ export async function startProcess( | ||
| 546 | 552 | ssh: input.ssh, |
| 547 | 553 | vars: input.vars, |
| 548 | 554 | 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)]); | |
| 584 | 589 | |
| 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 | }; | |
| 614 | 619 | |
| 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) { | |
| 624 | 642 | // The app never came up: the test step running beside it has nothing |
| 625 | 643 | // left to verify, and must not outlive this failed run. |
| 626 | 644 | testAbort.abort(); |
| 627 | 645 | 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); | |
| 633 | 647 | } |
| 648 | const { handle, spawnedAt, firstOutputAt } = launched; | |
| 634 | 649 | log(`ready: ${input.url}`); |
| 635 | 650 | // How the process's own share of the start divides: the time until it |
| 636 | 651 | // first said anything (the runtime loading the app, the app's own boot |
| @@ -652,7 +667,7 @@ async function waitUntilReady(input: { | ||
| 652 | 667 | timeoutMs: number; |
| 653 | 668 | exited: Promise<number>; |
| 654 | 669 | signal: AbortSignal; |
| 655 | }): Promise<Result<void, StartError>> { | |
| 670 | }): Promise<Result<void, StartError & { readonly exited: boolean }>> { | |
| 656 | 671 | const deadline = Date.now() + input.timeoutMs; |
| 657 | 672 | let exitCode: number | undefined; |
| 658 | 673 | void input.exited.then((code) => { |
| @@ -661,11 +676,12 @@ async function waitUntilReady(input: { | ||
| 661 | 676 | let lastStatus: number | undefined; |
| 662 | 677 | while (Date.now() < deadline) { |
| 663 | 678 | if (input.signal.aborted) |
| 664 | return err({ stage: "start", message: "cancelled" }); | |
| 679 | return err({ stage: "start", message: "cancelled", exited: false }); | |
| 665 | 680 | if (exitCode !== undefined) |
| 666 | 681 | return err({ |
| 667 | 682 | stage: "start", |
| 668 | 683 | message: `exited with code ${exitCode} before answering`, |
| 684 | exited: true, | |
| 669 | 685 | }); |
| 670 | 686 | try { |
| 671 | 687 | const response = await fetch( |
| @@ -685,6 +701,7 @@ async function waitUntilReady(input: { | ||
| 685 | 701 | } |
| 686 | 702 | return err({ |
| 687 | 703 | stage: "ready", |
| 704 | exited: false, | |
| 688 | 705 | message: |
| 689 | 706 | lastStatus === undefined |
| 690 | 707 | ? `no answer on ${input.path} within ${Math.round(input.timeoutMs / 1000)}s` |
| @@ -692,6 +709,37 @@ async function waitUntilReady(input: { | ||
| 692 | 709 | }); |
| 693 | 710 | } |
| 694 | 711 | |
| 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 | ||
| 695 | 743 | /** A port the OS says is free right now. */ |
| 696 | 744 | export function freePort(): number { |
| 697 | 745 | const probe = Bun.serve({ |
test/apps.test.ts +112 −1
| @@ -19,7 +19,7 @@ import { createApp, type App } from "../src/app.ts"; | ||
| 19 | 19 | import { AppsRuntime } from "../src/apps/runtime.ts"; |
| 20 | 20 | import { seconds, Stopwatch } from "../src/apps/timing.ts"; |
| 21 | 21 | 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"; | |
| 23 | 23 | import type { AppManifest } from "../src/apps/manifest.ts"; |
| 24 | 24 | import { |
| 25 | 25 | enableApp, |
| @@ -1260,3 +1260,114 @@ describe("a restart brings every app's production up before any preview", () => | ||
| 1260 | 1260 | ); |
| 1261 | 1261 | }, 90_000); |
| 1262 | 1262 | }); |
| 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 | }); |
new above
offline