Public: anyone can read this; the crew can change it.
A forge answers every request in its first ten minutes: no 503 "Waking up" on a POST, and no unclean restart after it is made #11159
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/11155-a-forge-answers-every-request-in-its-fir → main 6 commits fork 4 threads · 4 unresolved
7 files
changed +384
−25
docs/features/new-forge-first-minutes.md added +12
| @@ -0,0 +1,12 @@ | ||
| 1 | # A new forge's first ten minutes | |
| 2 | ||
| 3 | For site admins. A forge started in its own cell (a child forge) is treated gently while it is new. | |
| 4 | ||
| 5 | - **Requests are held while it wakes.** A request for a sleeping forge, a form's POST included, waits up to 20 seconds (`wakeLimits.waitMs` in `src/spawn/host.ts`) for the cell to come up and gets its real answer. A wake that takes longer gets the self-refreshing "waking up" page. At most 16 requests wait on one forge at a time (`wakeLimits.waiters`); the rest get the waking page at once, so a crowd cannot pin connections. | |
| 6 | - **No idle sleep.** The idle sweep leaves a forge alone for 10 minutes after its start (`NEW_FORGE_MS` in `src/spawn/cell.ts`). | |
| 7 | - **A minute to start.** The parent waits about 60 seconds (`START_PROBES`) for a first start to answer. A start that never answers is asked to stop as a sleep is (SIGTERM first), so a slow boot is not written down as a crash. | |
| 8 | - **The boots proof.** The forge's reachability proofs include `boots`: it fails when a start in the first ten minutes of the child's record never exited cleanly. It is read from the child's own `boots.json`, and an early unclean start stops counting an hour after it happened, so the alarm clears on its own. | |
| 9 | - **Where a person sees it.** On the web, `/forges` (Forges you sent); in the terminal, the "Forges you sent" screen. Each forge's line there reads `Running, not reachable: boots 1 unclean restart in the first ten minutes` while the proof fails, next to any other failing proof. A passing proof adds no words. The proof is read when reachability is next swept (every five minutes). | |
| 10 | - **What the proof cannot see.** The newest start is left out: from outside, a start that is still running cannot be told from one that crashed. So a crash with no start after it counts only once the next start is written, for example when the forge next wakes. The window counts from the forge's very first start (`firstAt` in `boots.json`), even after the ledger keeps only its last 50 starts. | |
| 11 | ||
| 12 | Code: `src/spawn/cell.ts` (`firstAnswer`, `sleepIdle`), `src/spawn/host.ts` (`wakeLimits`), `src/kernel/boots.ts` (`uncleanInFirstMinutes`), `src/spawn/reach.ts` (`proveBoots`). Tests: `test/first-ten-minutes.test.ts`. |
src/kernel/boots.ts +29 −1
| @@ -32,6 +32,8 @@ interface Start { | ||
| 32 | 32 | interface Ledger { |
| 33 | 33 | total: number; |
| 34 | 34 | starts: Start[]; |
| 35 | /** When the very first start happened, ms; kept when the oldest of `starts` is trimmed. Absent in older ledgers. */ | |
| 36 | firstAt?: number; | |
| 35 | 37 | } |
| 36 | 38 | |
| 37 | 39 | /** What the ledger says, from this process's point of view. */ |
| @@ -65,7 +67,8 @@ function read(dataDir: string): Ledger { | ||
| 65 | 67 | typeof r.total === "number" && Number.isSafeInteger(r.total) && r.total >= starts.length |
| 66 | 68 | ? r.total |
| 67 | 69 | : starts.length; |
| 68 | return { total, starts }; | |
| 70 | const firstAt = typeof (raw as { firstAt?: unknown }).firstAt === "number" ? (raw as { firstAt: number }).firstAt : undefined; | |
| 71 | return firstAt === undefined ? { total, starts } : { total, starts, firstAt }; | |
| 69 | 72 | } catch { |
| 70 | 73 | return { total: 0, starts: [] }; |
| 71 | 74 | } |
| @@ -97,6 +100,8 @@ export function recordBoot( | ||
| 97 | 100 | ): BootCounts { |
| 98 | 101 | thisStart = id; |
| 99 | 102 | const ledger = read(dataDir); |
| 103 | // An older ledger that never trimmed still knows its first start; one that did, only from here. | |
| 104 | ledger.firstAt ??= ledger.starts[0]?.at ?? now; | |
| 100 | 105 | ledger.total += 1; |
| 101 | 106 | ledger.starts = [...ledger.starts, { id, at: now, clean: false }].slice(-KEPT); |
| 102 | 107 | try { |
| @@ -124,3 +129,26 @@ export function recordCleanExit(dataDir: string, id = thisStart): void { | ||
| 124 | 129 | export function bootCounts(dataDir: string, id = thisStart): BootCounts { |
| 125 | 130 | return countsOf(read(dataDir), id); |
| 126 | 131 | } |
| 132 | ||
| 133 | /** How long a new forge's first start is watched for crashes and kills (#11155). */ | |
| 134 | export const FIRST_MINUTES_MS = 10 * 60_000; | |
| 135 | ||
| 136 | /** An unclean first-minutes start stops counting this long after it happened, so the alarm it raised clears. */ | |
| 137 | export const FIRST_MINUTES_MEMORY_MS = 60 * 60_000; | |
| 138 | ||
| 139 | /** | |
| 140 | * Starts that never exited cleanly within `windowMs` of the forge's first | |
| 141 | * start (`firstAt`, which outlives the trimming of `starts` to {@link KEPT}) | |
| 142 | * and less than `memoryMs` ago; null when this directory has no ledger. Read | |
| 143 | * from outside: a parent reads its child's. | |
| 144 | * | |
| 145 | * The newest start is left out: it may still be running, and from outside it | |
| 146 | * cannot be told from one that crashed. So a crash with no start after it is | |
| 147 | * counted only once the next start is written (a sleeping child's next wake). | |
| 148 | */ | |
| 149 | export function uncleanInFirstMinutes(dataDir: string, windowMs = FIRST_MINUTES_MS, now = Date.now(), memoryMs = FIRST_MINUTES_MEMORY_MS): number | null { | |
| 150 | const ledger = read(dataDir); | |
| 151 | const firstAt = ledger.firstAt ?? ledger.starts[0]?.at; | |
| 152 | if (firstAt === undefined) return null; | |
| 153 | return ledger.starts.slice(0, -1).filter((s) => !s.clean && s.at - firstAt <= windowMs && now - s.at < memoryMs).length; | |
| 154 | } |
src/spawn/cell.ts +59 −13
| @@ -88,6 +88,9 @@ function alive(pid: number): boolean { | ||
| 88 | 88 | } |
| 89 | 89 | } |
| 90 | 90 | |
| 91 | /** A forge started within this long is not put to sleep by the idle sweep (#11155). */ | |
| 92 | export const NEW_FORGE_MS = 10 * 60_000; | |
| 93 | ||
| 91 | 94 | /** After a child fails to start, requests are answered 503 at once for this long. */ |
| 92 | 95 | export const START_BACKOFF_MS = 30_000; |
| 93 | 96 | |
| @@ -224,10 +227,38 @@ export function cellChildren(parent: App): CellChildren { | ||
| 224 | 227 | return r; |
| 225 | 228 | } |
| 226 | 229 | |
| 227 | async function answers(port: number, gone: Promise<unknown>): Promise<boolean> { | |
| 230 | /** Starts a child and resolves once it answers; undefined (with `fail` told why) when it does not. */ | |
| 231 | export type Launcher = (input: { bodyId: string; name: string; size: Size }, fail: (why: string) => void) => Promise<CellChild | undefined>; | |
| 232 | ||
| 233 | /** Probes a starting child gets, 100 ms apart: about a minute for a slow first boot. */ | |
| 234 | export const START_PROBES = 600; | |
| 235 | ||
| 236 | /** Whether a forge started at `startedAt` is still inside its first ten minutes at `now`. */ | |
| 237 | export const isNewForge = (startedAt: number | undefined, now: number): boolean => startedAt !== undefined && now - startedAt < NEW_FORGE_MS; | |
| 238 | ||
| 239 | /** | |
| 240 | * Wait for a just-spawned child to answer on `port`. One that never does is | |
| 241 | * asked to go as a sleep is (SIGTERM first, `stopGently`), so a slow first | |
| 242 | * boot is not also written down as a crash; `silent` hears it before the stop. | |
| 243 | */ | |
| 244 | export async function firstAnswer( | |
| 245 | child: { readonly pid: number; readonly exited: Promise<unknown> }, | |
| 246 | port: number, | |
| 247 | silent: () => void = () => {}, | |
| 248 | probes = START_PROBES, | |
| 249 | graceMs = STOP_GRACE_MS, | |
| 250 | ): Promise<boolean> { | |
| 251 | if (await answers(port, child.exited, probes)) return true; | |
| 252 | silent(); | |
| 253 | await stopGently(child, graceMs); | |
| 254 | return false; | |
| 255 | } | |
| 256 | ||
| 257 | /** True once something answers on `port`; false when `gone` settles first or the probes run out. */ | |
| 258 | export async function answers(port: number, gone: Promise<unknown>, probes = START_PROBES): Promise<boolean> { | |
| 228 | 259 | let over = false; |
| 229 | 260 | void gone.then(() => (over = true)); |
| 230 | for (let i = 0; i < 300 && !over; i++) { | |
| 261 | for (let i = 0; i < probes && !over; i++) { | |
| 231 | 262 | try { |
| 232 | 263 | await fetch(`http://127.0.0.1:${port}/`, { redirect: "manual", signal: AbortSignal.timeout(500) }); |
| 233 | 264 | return true; |
| @@ -266,29 +297,33 @@ export function launchSpecFor( | ||
| 266 | 297 | }); |
| 267 | 298 | } |
| 268 | 299 | |
| 269 | function makeRegistry(parent: App): CellChildren { | |
| 270 | const held = new Map<string, Held>(); | |
| 300 | /** A registry of its own, not the parent's: tests pass a launcher in place of a cell's. */ | |
| 301 | export function makeRegistry(parent: App, launcher?: Launcher): CellChildren { | |
| 302 | const held = new Map<string, CellChild>(); | |
| 271 | 303 | const starting = new Map<string, Promise<CellChild | undefined>>(); |
| 272 | 304 | /** When a start last failed: a broken child is not relaunched on every request. */ |
| 273 | 305 | const failed = new Map<string, { at: number; why: string }>(); |
| 274 | 306 | /** Held once it answers, never before: a start in flight is in `starting`. */ |
| 275 | 307 | /** When a request last reached each running child, ms. */ |
| 276 | 308 | const seen = new Map<string, number>(); |
| 309 | /** When each running child was started: a new forge is not slept in its first ten minutes. */ | |
| 310 | const startedAt = new Map<string, number>(); | |
| 277 | 311 | /** Requests under way, by body id. */ |
| 278 | 312 | const busy = new Map<string, number>(); |
| 279 | 313 | |
| 280 | const launch = async (input: { bodyId: string; name: string; size: Size }): Promise<CellChild | undefined> => { | |
| 314 | const failOf = (bodyId: string) => (why: string): void => void failed.set(bodyId, { at: Date.now(), why }); | |
| 315 | const launchInCell: Launcher = async (input, fail) => { | |
| 281 | 316 | // Below the disk floor no child cell starts, a sleeping one included (#10850). |
| 282 | 317 | const floor = floorRefusal(parent.config.dataDir); |
| 283 | 318 | if (floor !== undefined) { |
| 284 | 319 | parent.log.warn("child cell not started", { name: input.name, reason: floor }); |
| 285 | failed.set(input.bodyId, { at: Date.now(), why: floor }); | |
| 320 | fail(floor); | |
| 286 | 321 | return undefined; |
| 287 | 322 | } |
| 288 | 323 | const cells = await cellsAvailable(); |
| 289 | 324 | if (!cells.ok) { |
| 290 | 325 | parent.log.warn("child cell not started", { name: input.name, reason: cells.reason }); |
| 291 | failed.set(input.bodyId, { at: Date.now(), why: cells.reason }); | |
| 326 | fail(cells.reason); | |
| 292 | 327 | return undefined; |
| 293 | 328 | } |
| 294 | 329 | const recent: string[] = []; |
| @@ -325,7 +360,6 @@ function makeRegistry(parent: App): CellChildren { | ||
| 325 | 360 | if (why !== undefined) parent.log.warn("child forge stopped", { name: input.name, why }); |
| 326 | 361 | cell.close(); |
| 327 | 362 | door.close(); |
| 328 | if (held.get(input.bodyId)?.proc === proc) held.delete(input.bodyId); | |
| 329 | 363 | if (why !== undefined) recent.push(why); |
| 330 | 364 | return code; |
| 331 | 365 | }); |
| @@ -333,15 +367,25 @@ function makeRegistry(parent: App): CellChildren { | ||
| 333 | 367 | void drain(proc.stdout, log); |
| 334 | 368 | void drain(proc.stderr, log); |
| 335 | 369 | const child: Held = { ...input, port, limits: spec.limits, pid: proc.pid, exited, cell, proc, door }; |
| 336 | if (!(await answers(port, exited))) { | |
| 370 | const up = await firstAnswer(child, port, () => { | |
| 337 | 371 | const why = `its cell did not come up: ${recent.slice(-3).join(" | ") || "no output"}`.slice(0, 400); |
| 338 | 372 | parent.log.warn("child forge did not answer", { name: input.name, why }); |
| 339 | failed.set(input.bodyId, { at: Date.now(), why }); | |
| 340 | killTree(proc.pid); | |
| 341 | return undefined; | |
| 342 | } | |
| 373 | fail(why); | |
| 374 | }); | |
| 375 | return up ? child : undefined; | |
| 376 | }; | |
| 377 | const launch = async (input: { bodyId: string; name: string; size: Size }): Promise<CellChild | undefined> => { | |
| 378 | const child = await (launcher ?? launchInCell)(input, failOf(input.bodyId)); | |
| 379 | if (child === undefined) return undefined; | |
| 343 | 380 | held.set(input.bodyId, child); |
| 344 | 381 | seen.set(input.bodyId, Date.now()); |
| 382 | startedAt.set(input.bodyId, Date.now()); | |
| 383 | void child.exited.then(() => { | |
| 384 | if (held.get(input.bodyId) === child) { | |
| 385 | held.delete(input.bodyId); | |
| 386 | startedAt.delete(input.bodyId); | |
| 387 | } | |
| 388 | }); | |
| 345 | 389 | return child; |
| 346 | 390 | }; |
| 347 | 391 | |
| @@ -373,6 +417,7 @@ function makeRegistry(parent: App): CellChildren { | ||
| 373 | 417 | const child = held.get(bodyId); |
| 374 | 418 | if (child === undefined) return; |
| 375 | 419 | held.delete(bodyId); |
| 420 | startedAt.delete(bodyId); | |
| 376 | 421 | await stopGently(child); |
| 377 | 422 | }, |
| 378 | 423 | get: (bodyId) => held.get(bodyId), |
| @@ -395,6 +440,7 @@ function makeRegistry(parent: App): CellChildren { | ||
| 395 | 440 | async sleepIdle(idleMs, now = Date.now()) { |
| 396 | 441 | const asleep: string[] = []; |
| 397 | 442 | for (const child of [...held.values()]) { |
| 443 | if (isNewForge(startedAt.get(child.bodyId), now)) continue; | |
| 398 | 444 | if (now - (seen.get(child.bodyId) ?? now) < idleMs || (busy.get(child.bodyId) ?? 0) > 0) continue; |
| 399 | 445 | if (crewAtWork(childDirOf(parent, child.bodyId))) continue; |
| 400 | 446 | asleep.push(child.name); |
src/spawn/host.ts +23 −8
| @@ -638,13 +638,22 @@ export async function answerFromCell(parent: App, request: Request, named?: stri | ||
| 638 | 638 | release(); |
| 639 | 639 | } |
| 640 | 640 | } |
| 641 | // Asleep: it wakes behind this answer. A git push or an API call waits a few | |
| 642 | // seconds for it; a page, or a wake that takes longer, is a plain "waking up" page. | |
| 643 | // A page never waits: it starts the cell and gets the waking page at once. | |
| 644 | const path = new URL(request.url).pathname; | |
| 645 | const patient = path.startsWith("/api/") || path.includes(".git/"); | |
| 641 | // Asleep: it wakes behind this answer. Every request, a form's POST included, is | |
| 642 | // held until the cell is up (wakeLimits.waitMs) so a submit is never lost; only a wake | |
| 643 | // that takes longer is answered with the "waking up" page, which tries again by itself. | |
| 646 | 644 | const starting = settleCell(parent, ledger); |
| 647 | const woke = patient ? await Promise.race([starting, Bun.sleep(WAKE_WAIT_MS).then(() => undefined)]) : undefined; | |
| 645 | // Only so many wait on one cell: the rest are told it is waking at once, so a crowd cannot pin connections and bodies. | |
| 646 | const waiting = waiters.get(ledger.bodyId) ?? 0; | |
| 647 | if (waiting >= wakeLimits.waiters) return wakingResponse(parent, request, ledger.name); | |
| 648 | waiters.set(ledger.bodyId, waiting + 1); | |
| 649 | let woke: CellChild | undefined; | |
| 650 | try { | |
| 651 | woke = await Promise.race([starting, Bun.sleep(wakeLimits.waitMs).then(() => undefined)]); | |
| 652 | } finally { | |
| 653 | const left = (waiters.get(ledger.bodyId) ?? 1) - 1; | |
| 654 | if (left <= 0) waiters.delete(ledger.bodyId); | |
| 655 | else waiters.set(ledger.bodyId, left); | |
| 656 | } | |
| 648 | 657 | if (woke !== undefined) { |
| 649 | 658 | const release = cells.hold(ledger.bodyId); |
| 650 | 659 | try { |
| @@ -656,8 +665,14 @@ export async function answerFromCell(parent: App, request: Request, named?: stri | ||
| 656 | 665 | return wakingResponse(parent, request, ledger.name); |
| 657 | 666 | } |
| 658 | 667 | |
| 659 | /** How long a request waits for a sleeping cell forge before it is told it is waking. */ | |
| 660 | const WAKE_WAIT_MS = 4000; | |
| 668 | /** How long a request waits for a sleeping cell forge before it is told it is waking, and how many may wait on one cell. */ | |
| 669 | export const wakeLimits = { waitMs: 20_000, waiters: 16 }; | |
| 670 | ||
| 671 | /** Requests held for a waking cell now, by body id. */ | |
| 672 | const waiters = new Map<string, number>(); | |
| 673 | ||
| 674 | /** How many requests wait on this cell's wake now. */ | |
| 675 | export const waitingFor = (bodyId: string): number => waiters.get(bodyId) ?? 0; | |
| 661 | 676 | |
| 662 | 677 | /** |
| 663 | 678 | * A websocket handshake for a child in its own cell (its home or one of its |
src/spawn/reach.ts +20
| @@ -25,6 +25,7 @@ import type { App } from "../app.ts"; | ||
| 25 | 25 | import { isSlug, slugFor } from "../core/apps.ts"; |
| 26 | 26 | import type { FiredAlarm } from "../flow/alarms.ts"; |
| 27 | 27 | import { childPublicUrl, parentOrigin } from "./placement.ts"; |
| 28 | import { uncleanInFirstMinutes } from "../kernel/boots.ts"; | |
| 28 | 29 | import { during } from "../perf/jobs.ts"; |
| 29 | 30 | |
| 30 | 31 | export const APP_HEADER = "x-forge-app"; |
| @@ -154,6 +155,23 @@ export async function proveApp(fetcher: FetchLike, url: string, slug: string): P | ||
| 154 | 155 | return { label: slug, url, ok: true, status: got.status, says: `answered ${got.status}` }; |
| 155 | 156 | } |
| 156 | 157 | |
| 158 | /** | |
| 159 | * A child's own record of its starts: none of them in its first ten minutes | |
| 160 | * may have ended uncleanly. Absent (undefined) while it has no record yet. | |
| 161 | */ | |
| 162 | export function proveBoots(app: App, child: Pick<Child, "url" | "bodyId">): Proof | undefined { | |
| 163 | const unclean = uncleanInFirstMinutes(childDirOf(app, child.bodyId)); | |
This proof fails permanently once any early unclean start is on record, so the unreachable alarm never clears. Bound it to a recent window or let a later clean run clear it. |
||
| 164 | if (unclean === null) return undefined; | |
| 165 | const ok = unclean === 0; | |
| 166 | return { | |
| 167 | label: "boots", | |
| 168 | url: child.url, | |
| 169 | ok, | |
| 170 | status: null, | |
| 171 | says: ok ? "no unclean restart in the first ten minutes" : `${unclean} unclean restart${unclean === 1 ? "" : "s"} in the first ten minutes`, | |
| 172 | }; | |
| 173 | } | |
| 174 | ||
| 157 | 175 | /** Ask every public address of a child, as a visitor does. Nothing is kept. */ |
| 158 | 176 | export async function proveChild(app: App, child: Child): Promise<ChildReach> { |
| 159 | 177 | const fetcher = optionsOf(app).fetch ?? fetch; |
| @@ -161,6 +179,8 @@ export async function proveChild(app: App, child: Child): Promise<ChildReach> { | ||
| 161 | 179 | proveHome(fetcher, child), |
| 162 | 180 | ...slugsOf(app, child).map((slug) => proveApp(fetcher, appUrlOf(app, child, slug), slug)), |
| 163 | 181 | ]); |
| 182 | const boots = proveBoots(app, child); | |
| 183 | if (boots !== undefined) proofs.push(boots); | |
| 164 | 184 | return { name: child.name, at: new Date().toISOString(), ok: proofs.every((p) => p.ok), since: null, alarmed: false, proofs }; |
| 165 | 185 | } |
| 166 | 186 |
test/first-ten-minutes.test.ts added +239
| @@ -0,0 +1,239 @@ | ||
| 1 | /** A forge answers everything in its first ten minutes (#11155). */ | |
| 2 | import { afterAll, describe, expect, test } from "bun:test"; | |
| 3 | import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from "node:fs"; | |
| 4 | import { tmpdir } from "node:os"; | |
| 5 | import { join } from "node:path"; | |
| 6 | import { createApp } from "../src/app.ts"; | |
| 7 | import { childDirOf } from "../src/actions/spawn.ts"; | |
| 8 | import { recordBoot, recordCleanExit, uncleanInFirstMinutes } from "../src/kernel/boots.ts"; | |
| 9 | import { proveBoots } from "../src/spawn/reach.ts"; | |
| 10 | import { answers, cellChildren, firstAnswer, isNewForge, makeRegistry, NEW_FORGE_MS, START_PROBES, type CellChild } from "../src/spawn/cell.ts"; | |
| 11 | import { answerFromCell, waitingFor, wakeLimits } from "../src/spawn/host.ts"; | |
| 12 | import { quietLogs } from "./helpers/globals.ts"; | |
| 13 | ||
| 14 | quietLogs(); | |
| 15 | const tmp = mkdtempSync(join(tmpdir(), "first-ten-")); | |
| 16 | afterAll(() => rmSync(tmp, { recursive: true, force: true })); | |
| 17 | ||
| 18 | describe("the boots proof", () => { | |
| 19 | test("a clean first ten minutes is ok, an unclean restart in them is not, and it alarms through reach", () => { | |
| 20 | const dir = join(tmp, "b"); | |
| 21 | mkdirSync(dir); | |
| 22 | expect(uncleanInFirstMinutes(dir)).toBeNull(); | |
| 23 | recordBoot(dir, "a", 1_000); | |
| 24 | recordCleanExit(dir, "a"); | |
| 25 | recordBoot(dir, "b", 2_000); | |
| 26 | expect(uncleanInFirstMinutes(dir, undefined, 4_000)).toBe(0); | |
| 27 | recordBoot(dir, "c", 3_000); // "b" never said goodbye | |
| 28 | expect(uncleanInFirstMinutes(dir, undefined, 4_000)).toBe(1); | |
| 29 | recordBoot(dir, "d", 20 * 60_000); // an unclean start long after the first ten minutes | |
| 30 | expect(uncleanInFirstMinutes(dir, undefined, 20 * 60_000)).toBe(2); // b and c; d is the running one | |
| 31 | }); | |
| 32 | ||
| 33 | test("an early unclean start stops counting after the memory, so the alarm clears", () => { | |
| 34 | const dir = join(tmp, "m"); | |
| 35 | mkdirSync(dir); | |
| 36 | recordBoot(dir, "a", 1_000); | |
| 37 | recordBoot(dir, "b", 2_000); | |
| 38 | expect(uncleanInFirstMinutes(dir, undefined, 3_000)).toBe(1); | |
| 39 | expect(uncleanInFirstMinutes(dir, undefined, 2 * 3_600_000)).toBe(0); | |
| 40 | }); | |
| 41 | ||
| 42 | test("the window is anchored on the first start, even after the ledger trims its oldest", () => { | |
| 43 | const dir = join(tmp, "trim"); | |
| 44 | mkdirSync(dir); | |
| 45 | const min = 60_000; | |
| 46 | recordBoot(dir, "first", 0); | |
| 47 | recordCleanExit(dir, "first"); | |
| 48 | for (let i = 0; i < 50; i++) { | |
| 49 | recordBoot(dir, `later-${i}`, 30 * min + i); | |
| 50 | recordCleanExit(dir, `later-${i}`); | |
| 51 | } | |
| 52 | recordBoot(dir, "crashed", 31 * min); // unclean, but twenty minutes past the first start | |
| 53 | recordBoot(dir, "now", 32 * min); | |
| 54 | expect(uncleanInFirstMinutes(dir, undefined, 32 * min)).toBe(0); | |
| 55 | }); | |
| 56 | ||
| 57 | test("proveBoots reads the child's own ledger", () => { | |
| 58 | const parent = createApp({ dataDir: join(tmp, "p"), url: "https://f.test" }); | |
| 59 | const child = { url: "https://kid--f.test", bodyId: "body-1" }; | |
| 60 | expect(proveBoots(parent, child)).toBeUndefined(); | |
| 61 | mkdirSync(childDirOf(parent, "body-1"), { recursive: true }); | |
| 62 | const t = Date.now(); | |
| 63 | recordBoot(childDirOf(parent, "body-1"), "a", t - 2_000); | |
| 64 | recordBoot(childDirOf(parent, "body-1"), "b", t - 1_000); | |
| 65 | expect(proveBoots(parent, child)).toMatchObject({ label: "boots", ok: false, says: "1 unclean restart in the first ten minutes" }); | |
| 66 | parent.close(); | |
| 67 | }); | |
| 68 | }); | |
| 69 | ||
| 70 | describe("a new forge is not slept, and a start gets its minute", () => { | |
| 71 | test("isNewForge: under ten minutes stays, older sleeps, unknown start sleeps", () => { | |
| 72 | expect(isNewForge(1_000, 1_000 + NEW_FORGE_MS - 1)).toBe(true); | |
| 73 | expect(isNewForge(1_000, 1_000 + NEW_FORGE_MS)).toBe(false); | |
| 74 | expect(isNewForge(undefined, 5)).toBe(false); | |
| 75 | }); | |
| 76 | ||
| 77 | test("a start gets about a minute: 600 probes, 100 ms apart", () => { | |
| 78 | expect(START_PROBES).toBe(600); | |
| 79 | }); | |
| 80 | ||
| 81 | test("answers finds a port that begins listening late, and stops when the child is gone or probes run out", async () => { | |
| 82 | const free = Bun.serve({ port: 0, hostname: "127.0.0.1", fetch: () => new Response("x") }); | |
| 83 | const port = free.port!; | |
| 84 | free.stop(true); | |
| 85 | const found = answers(port, new Promise(() => {}), 300); | |
| 86 | // Bind once the first probe has had its chance to fail; tried again until the port is ours. | |
| 87 | let late: ReturnType<typeof Bun.serve> | undefined; | |
| 88 | await Bun.sleep(100); | |
| 89 | while (late === undefined) { | |
| 90 | try { | |
| 91 | late = Bun.serve({ port, hostname: "127.0.0.1", fetch: () => new Response("up") }); | |
| 92 | } catch { | |
| 93 | await Bun.sleep(50); | |
| 94 | } | |
| 95 | } | |
| 96 | expect(await found).toBe(true); | |
| 97 | late.stop(true); | |
| 98 | expect(await answers(port, new Promise(() => {}), 2)).toBe(false); | |
| 99 | expect(await answers(port, Promise.resolve(), 600)).toBe(false); | |
| 100 | }); | |
| 101 | }); | |
| 102 | ||
| 103 | /** A process that says "ready" once it listens for SIGTERM, and exits 7 on it: 7 is a gentle stop, a SIGKILL has no code. */ | |
| 104 | async function gentleProcess() { | |
| 105 | const proc = Bun.spawn([process.execPath, "-e", "process.on('SIGTERM', () => process.exit(7)); console.log('ready'); setInterval(() => {}, 1000)"], { | |
| 106 | stdin: "ignore", | |
| 107 | stdout: "pipe", | |
| 108 | stderr: "ignore", | |
| 109 | }); | |
| 110 | const reader = proc.stdout.getReader(); | |
| 111 | let said = ""; | |
| 112 | while (!said.includes("ready")) { | |
| 113 | const { value, done } = await reader.read(); | |
| 114 | if (done) break; | |
| 115 | said += new TextDecoder().decode(value); | |
| 116 | } | |
| 117 | reader.releaseLock(); | |
| 118 | return proc; | |
| 119 | } | |
| 120 | ||
| 121 | describe("the idle sweep and a failed start", () => { | |
| 122 | test("sleepIdle leaves a just-started forge alone past the idle time, and sleeps it after its first ten minutes", async () => { | |
| 123 | const parent = createApp({ dataDir: join(tmp, "sweep"), url: "https://f.test" }); | |
| 124 | const proc = await gentleProcess(); | |
| 125 | const cells = makeRegistry(parent, async (input) => ({ ...input, port: 1, limits: {} as CellChild["limits"], pid: proc.pid, exited: proc.exited })); | |
| 126 | try { | |
| 127 | const idle = 60_000; | |
| 128 | const start = Date.now(); | |
| 129 | expect(await cells.start({ bodyId: "kid-1", name: "kid", size: "small" })).toBeDefined(); | |
| 130 | expect(await cells.sleepIdle(idle, start + idle * 2)).toEqual([]); | |
| 131 | expect(cells.get("kid-1")).toBeDefined(); | |
| 132 | expect(await cells.sleepIdle(idle, Date.now() + NEW_FORGE_MS + idle)).toEqual(["kid"]); | |
| 133 | expect(cells.get("kid-1")).toBeUndefined(); | |
| 134 | expect(await proc.exited).toBe(7); | |
| 135 | } finally { | |
| 136 | proc.kill("SIGKILL"); | |
| 137 | parent.close(); | |
| 138 | } | |
| 139 | }); | |
| 140 | ||
| 141 | test("a start that never answers is asked to go with SIGTERM first, not killed", async () => { | |
| 142 | const free = Bun.serve({ port: 0, hostname: "127.0.0.1", fetch: () => new Response("x") }); | |
| 143 | const port = free.port!; | |
| 144 | free.stop(true); | |
| 145 | const proc = await gentleProcess(); | |
| 146 | let told = 0; | |
| 147 | try { | |
| 148 | expect(await firstAnswer({ pid: proc.pid, exited: proc.exited }, port, () => told++, 2)).toBe(false); | |
| 149 | expect(told).toBe(1); | |
| 150 | expect(await proc.exited).toBe(7); | |
| 151 | expect(proc.signalCode).toBeNull(); | |
| 152 | } finally { | |
| 153 | proc.kill("SIGKILL"); | |
| 154 | } | |
| 155 | }); | |
| 156 | }); | |
| 157 | ||
| 158 | /** A start the test lets finish when it says so. */ | |
| 159 | function gate<T>() { | |
| 160 | let open!: (v: T) => void; | |
| 161 | const shut = new Promise<T>((r) => (open = r)); | |
| 162 | return { shut, open }; | |
| 163 | } | |
| 164 | ||
| 165 | describe("a request while a cell wakes", () => { | |
| 166 | test("a POST is held until the cell is up and gets its answer, not a 503", async () => { | |
| 167 | const dataDir = join(tmp, "w"); | |
| 168 | mkdirSync(join(dataDir, "spawn"), { recursive: true }); | |
| 169 | writeFileSync(join(dataDir, "spawn", "kid.json"), JSON.stringify({ name: "kid", bodyId: "cell-w", size: "small", done: true, placement: "cell" })); | |
| 170 | const parent = createApp({ dataDir, url: "https://f.test" }); | |
| 171 | const upstream = Bun.serve({ port: 0, hostname: "127.0.0.1", fetch: async (r) => new Response(`got ${r.method} ${await r.text()}`) }); | |
| 172 | const cells = cellChildren(parent); | |
| 173 | cells.start = async () => { | |
| 174 | await Bun.sleep(300); // a POST is held while the cell wakes, however long a page's old patience was | |
| 175 | return { port: upstream.port } as unknown as CellChild; | |
| 176 | }; | |
| 177 | try { | |
| 178 | const res = await answerFromCell(parent, new Request("https://kid--f.test/create", { method: "POST", body: "name=x", headers: { host: "kid--f.test", accept: "text/html" } })); | |
| 179 | expect(res.status).toBe(200); | |
| 180 | expect(await res.text()).toBe("got POST name=x"); | |
| 181 | } finally { | |
| 182 | upstream.stop(true); | |
| 183 | parent.close(); | |
| 184 | } | |
| 185 | }); | |
| 186 | ||
| 187 | const asleep = (dir: string, body: string) => { | |
| 188 | mkdirSync(join(dir, "spawn"), { recursive: true }); | |
| 189 | writeFileSync(join(dir, "spawn", "kid.json"), JSON.stringify({ name: "kid", bodyId: body, size: "small", done: true, placement: "cell" })); | |
| 190 | return createApp({ dataDir: dir, url: "https://f.test" }); | |
| 191 | }; | |
| 192 | const post = () => new Request("https://kid--f.test/create", { method: "POST", body: "n=1", headers: { host: "kid--f.test", accept: "text/html" } }); | |
| 193 | ||
| 194 | test("a wake longer than the wait gets the waking page, and the wait is the limit", async () => { | |
| 195 | const parent = asleep(join(tmp, "slow"), "cell-slow"); | |
| 196 | const was = wakeLimits.waitMs; | |
| 197 | wakeLimits.waitMs = 100; | |
| 198 | const wake = gate<CellChild | undefined>(); | |
| 199 | let woken = false; | |
| 200 | cellChildren(parent).start = () => wake.shut.then((c) => ((woken = true), c)); | |
| 201 | try { | |
| 202 | const res = await answerFromCell(parent, post()); | |
| 203 | expect(woken).toBe(false); // answered while the wake is still under way | |
| 204 | expect(res.status).toBe(503); | |
| 205 | expect(await res.text()).toContain("waking"); | |
| 206 | } finally { | |
| 207 | wake.open(undefined); | |
| 208 | wakeLimits.waitMs = was; | |
| 209 | parent.close(); | |
| 210 | } | |
| 211 | }); | |
| 212 | ||
| 213 | test("past the waiter cap a request is answered at once with the waking page; the held ones still get their answer", async () => { | |
| 214 | const parent = asleep(join(tmp, "cap"), "cell-cap"); | |
| 215 | const upstream = Bun.serve({ port: 0, hostname: "127.0.0.1", fetch: () => new Response("ok") }); | |
| 216 | const was = { ...wakeLimits }; | |
| 217 | wakeLimits.waiters = 2; | |
| 218 | const wake = gate<CellChild>(); | |
| 219 | cellChildren(parent).start = () => wake.shut; | |
| 220 | try { | |
| 221 | const settled: string[] = []; | |
| 222 | const held = [answerFromCell(parent, post()), answerFromCell(parent, post())].map((p) => p.then((r) => (settled.push("held"), r))); | |
| 223 | while (waitingFor("cell-cap") < 2) await Bun.sleep(5); | |
| 224 | const over = await answerFromCell(parent, post()); | |
| 225 | settled.push("over"); | |
| 226 | expect(over.status).toBe(503); | |
| 227 | wake.open({ port: upstream.port } as unknown as CellChild); | |
| 228 | for (const r of await Promise.all(held)) expect(r.status).toBe(200); | |
| 229 | expect(settled).toEqual(["over", "held", "held"]); // the one past the cap is answered before the held ones | |
| 230 | expect(waitingFor("cell-cap")).toBe(0); | |
| 231 | // The cap frees as waiters leave. | |
| 232 | expect((await answerFromCell(parent, post())).status).toBe(200); | |
| 233 | } finally { | |
| 234 | Object.assign(wakeLimits, was); | |
| 235 | upstream.stop(true); | |
| 236 | parent.close(); | |
| 237 | } | |
| 238 | }); | |
| 239 | }); |
test/spawn-cell.test.ts +2 −3
| @@ -417,7 +417,7 @@ describe("a child that will not start", () => { | ||
| 417 | 417 | const cellTools = process.platform === "linux" && !portInsteadOfSocket() && !missing("bwrap", "socat"); |
| 418 | 418 | |
| 419 | 419 | describe("a real child forge", () => { |
| 420 | test.skipIf(!cellTools)("boots in its own forge:<name> cell and answers / through the forward; its first request does not wait for it", async () => { | |
| 420 | test.skipIf(!cellTools)("boots in its own forge:<name> cell and answers / through the forward; its first request is held until it is up", async () => { | |
| 421 | 421 | const env: Record<string, string> = {}; |
| 422 | 422 | for (const [k, v] of Object.entries(process.env)) if (v !== undefined && k !== "FORGE_CELLS") env[k] = v; |
| 423 | 423 | const proc = Bun.spawn([process.execPath, join(import.meta.dir, "helpers", "real-child-forge.ts")], { env, stdout: "pipe", stderr: "pipe" }); |
| @@ -435,8 +435,7 @@ describe("a real child forge", () => { | ||
| 435 | 435 | } |
| 436 | 436 | // The child's own reason and the machine's disk and load, not a bare mismatch. |
| 437 | 437 | if (seen["failure"] !== null || seen["health"] !== 200) throw new Error(failedWith("the child forge did not come up in its cell", { seen, out: out.slice(-1500) }, errText)); |
| 438 | expect(seen["first"]).toBe(503); | |
| 439 | expect(seen["firstMs"] as number).toBeLessThan(1_000); | |
| 438 | expect(seen["first"]).toBe(200); | |
| 440 | 439 | expect(seen["limits"]).toEqual({ memoryMiB: 2048, cpus: 1, diskMiB: 2048 }); |
| 441 | 440 | expect(seen["root"] as number).toBeLessThan(400); |
| 442 | 441 | expect(seen["health"]).toBe(200); |
Unbounded hold for every request, unauthenticated included, for 20 s. Cap waiters per cell and fall back to the waking page over the cap.