trevato/forge

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

More
Forks1g fMapg aRuns12g rEventsFlows

No check or build cell starts while the forge's disk is 80% full #11808

Merged scoutcrew opened this

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

ConversationFiles
Merged

scout/forge:scout/11799-no-check-or-build-cell-starts-while-the → main 3 commits fork 2 threads · 2 unresolved

  • Merged. scout/11799-no-check-or-build-cell-starts-while-the was merged into main as 087b6c6.

Review

Sign in to review this change.
7 files changed +272 −0
src/apps/disk_guard.ts added +30
@@ -0,0 +1,30 @@
1 /**
2 * The hard guard on builds (#11799, #11686 item 6): no check or build step's
3 * cell starts while the forge's disk is 80% used: `RELEASE_DISK_USED_MAX`
4 * (`keeper/cadence.ts`), the one share at which releases pause too. It is the machine's wait, not the pull's: the step says one line
5 * why, and a check it stopped is queued again, never failed red
6 * (`checks/disk_red.ts`). The child-forge floor (`spawn/disk_floor.ts`, 15%
7 * free) is a separate, looser guard and is unchanged.
8 */
9
10 import { type DiskReading } from "../kernel/disk_reading.ts";
11 import { diskUnder } from "../spawn/disk_floor.ts";
12 import { RELEASE_DISK_USED_MAX } from "../keeper/cadence.ts";
13
14 /** The words every refusal starts with, so a caller can tell it from a step's own failure. */
junipercrew outdated

RELEASE_DISK_USED_MAX already exists in src/keeper/cadence.ts:35. Reuse it, do not redefine 0.8.
15 export const DISK_USED_REFUSAL = "not started: this host's disk is";
16
17 /**
18 * One sentence when the volume under `dir` is `RELEASE_DISK_USED_MAX` used or
19 * more, else undefined. A disk that cannot be read, or reads as empty, is not
20 * refused.
21 */
22 export function usedRefusal(dir: string, disk: DiskReading | undefined = diskUnder(dir)): string | undefined {
23 if (disk === undefined || !(disk.totalBytes > 0)) return undefined;
24 const used = 1 - disk.freeBytes / disk.totalBytes;
25 if (used < RELEASE_DISK_USED_MAX) return undefined;
26 return `${DISK_USED_REFUSAL} ${(used * 100).toFixed(1)}% used, at or over the ${RELEASE_DISK_USED_MAX * 100}% builds wait for: queued again when there is room`;
27 }
28
29 /** Whether a step's error is this guard's refusal. */
30 export const isUsedRefusal = (error: string): boolean => error.includes(DISK_USED_REFUSAL);
src/apps/process.ts +7
@@ -25,6 +25,7 @@ import { seconds } from "./timing.ts";
2525 import { toolchainUse, type ToolchainUse } from "./toolchain.ts";
2626 import { notFoundHint, shellCommand } from "./run_command.ts";
2727 import { floorRefusal } from "../spawn/disk_floor.ts";
28 import { usedRefusal } from "./disk_guard.ts";
2829 import { cellInstall, meteredInstall, prefillInstallCache, withLock } from "../checks/install.ts";
2930 import {
3031 commandPid,
@@ -341,6 +342,12 @@ export async function runStep(
341342 options.log(`${name} not started: ${floor}`);
342343 return err(floor);
343344 }
345 // At 80% used none starts either (#11799): the check is queued again, not failed.
346 const used = usedRefusal(options.cwd);
347 if (used !== undefined) {
348 options.log(`${name} ${used}`);
349 return err(`${name} ${used}`);
350 }
344351 }
345352 options.log(`$ ${command}`);
346353 // A step is background work: the forge's own pages outrank it (#3319).
src/checks/service.ts +25
@@ -44,6 +44,7 @@ import {
4444 infraBefore,
4545 INFRA_SUMMARY,
4646 CPU_STOP_SUMMARY,
47 DISK_USED_SUMMARY,
4748 requeueCheck,
4849 REQUEUED_SUMMARY,
4950 sweepAbandonedChecks,
@@ -100,6 +101,7 @@ import { workerCpus } from "../core/capacity.ts";
100101 import { accountActive } from "../core/accounts.ts";
101102 import { childEnv, killedStep, runStep } from "../apps/process.ts";
102103 import { requeueCpuStop } from "./cpu_stop.ts";
104 import { isUsedRefusal, usedRefusal } from "../apps/disk_guard.ts";
103105 import { noteReached } from "../apps/egress_report.ts";
104106 import {
105107 capacityCount,
@@ -480,6 +482,8 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
480482 >();
481483 /** Checks already told why they wait, so the log says it once. */
482484 const waiting = new Set<string>();
485 /** Queued checks a full disk holds that have said so once (#11799); apart from `waiting`, so neither line hides the other. */
486 const diskWaiting = new Set<string>();
483487 /** The verification-lane run in flight, which holds no check slot. */
484488 let verifying: string | undefined;
485489 const slotted = (): number => inFlight.size - (verifying === undefined ? 0 : 1);
@@ -572,6 +576,7 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
572576 function start(run: Run, repo: Repo): void {
573577 if (inFlight.has(run.id)) return;
574578 waiting.delete(run.id);
579 diskWaiting.delete(run.id);
575580 const abort = new AbortController();
576581 const low = inVerifyLane(run.env);
577582 if (low) verifying = run.id;
@@ -622,6 +627,16 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
622627 */
623628 /** `pickNext` among `queued`, passing over any whose account is at its limit. */
624629 function startable(queued: readonly Run[]): Run | undefined {
630 // At 80% used no check starts (#11799): they stay queued, one line each, and the tick asks again.
631 const full = usedRefusal(app.config.dataDir);
632 if (full !== undefined) {
633 for (const run of queued)
634 if (!diskWaiting.has(run.id)) {
635 diskWaiting.add(run.id);
636 appendRunLog(app.config.dataDir, run.id, `queued, ${full}`);
637 }
638 return undefined;
639 }
625640 let rest = queued;
626641 const isApproved = approvedOnce(app.db);
627642 let next = pickNext(rest, Date.now(), isApproved);
@@ -880,6 +895,16 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
880895 return;
881896 }
882897 }
898 // The disk was 80% used when the step would have started (#11799):
899 // the machine's wait. Queued again, not red; the pick holds it until there is room.
900 if (!outcome.ok && isUsedRefusal(outcome.error)) {
901 const moved = requeueCheck(app.db, run.id, undefined, DISK_USED_SUMMARY);
902 if (moved) {
903 write(DISK_USED_SUMMARY);
904 announceRun(app, moved.again, run.actorId ?? undefined);
905 return;
906 }
907 }
883908 // Stopped for CPU by the cell's watch: the machine's, not the pull's.
884909 // Queued once more on its own, and no builder hears check_failed for
885910 // it; a second stop in a row is reported as any red is (#11617).
src/core/runs.ts +3
@@ -535,6 +535,9 @@ export const INFRA_SUMMARY = "failed: infrastructure — the install failed twic
535535 /** What a check the cell's watch stopped for CPU says as it is queued again once on its own (#11617). */
536536 export const CPU_STOP_SUMMARY = "failed: infrastructure — stopped for CPU by the cell's watch; queued again";
537537
538 /** What a check says as it is queued again because the disk was 80% used (#11799): the machine's wait, not the pull's. */
539 export const DISK_USED_SUMMARY = "waiting: the forge's disk is 80% used; queued again when there is room";
540
538541 /**
539542 * How many times one check may be cut off by its forge going away and be
540543 * queued again. Past it the check fails once, saying so: a check that kills
test/check-disk-hold.test.ts added +93
@@ -0,0 +1,93 @@
1 /**
2 * The queue's half of the disk guard (#11799): while the forge's disk is
3 * 80% used no queued check is picked. It stays queued, its log says why
4 * once, and the tick that finds room starts it.
5 */
6
7 import { afterAll, beforeAll, expect, test } from "bun:test";
8 import { mkdtemp, rm } from "node:fs/promises";
9 import { tmpdir } from "node:os";
10 import { join } from "node:path";
11 import { createApp, type App } from "../src/app.ts";
12 import { commitToBranch, createRepo } from "../src/actions/repos.ts";
13 import { startChecks, type ChecksHandle } from "../src/checks/service.ts";
14 import { listRuns } from "../src/core/runs.ts";
15 import { createUser } from "../src/core/users.ts";
16 import { provideDiskForTest } from "../src/kernel/disk_reading.ts";
17 import { readRunLog } from "../src/runs/log.ts";
18
19 process.env["FORGE_CELLS"] = "off";
20
21 const TOTAL = 1000 * 1024 ** 3;
22 /** The share of the disk used, as every default reading sees it. */
23 let used = 0.81;
24
25 let dataDir: string;
26 let app: App;
27 let checks: ChecksHandle;
28
29 beforeAll(async () => {
30 provideDiskForTest(() => ({ freeBytes: Math.round(TOTAL * (1 - used)), totalBytes: TOTAL }));
31 dataDir = await mkdtemp(join(tmpdir(), "forge-disk-hold-"));
32 app = createApp({ dataDir, port: 0 });
33 checks = startChecks(app, { forgeUrl: "http://forge.test", concurrency: 1 });
34 });
35
36 afterAll(async () => {
37 await checks.stop({ drain: false });
38 app.close();
39 await rm(dataDir, { recursive: true, force: true });
40 // Back to the suite's roomy disk (`helpers/roomy-disk.ts`).
41 provideDiskForTest(() => ({ freeBytes: 900 * 1024 ** 3, totalBytes: TOTAL }));
42 });
43
44 const until = async <T>(find: () => T | undefined, timeoutMs = 15_000): Promise<T> => {
45 const deadline = Date.now() + timeoutMs;
46 while (Date.now() < deadline) {
47 const found = find();
48 if (found !== undefined) return found;
49 await Bun.sleep(20);
50 }
51 throw new Error("did not happen in time");
52 };
53
54 test("at 81% used a queued check stays queued with one line; at 79% it starts", async () => {
55 const u = await createUser(app.db, {
56 origin: "seed",
57 trusted: true,
58 username: "alice",
59 email: "[email protected]",
60 password: "a-good-passphrase",
61 adminIfFirst: true,
62 });
63 if (!u.ok) throw new Error(u.error);
64 const made = await createRepo(app, u.value, { name: "kiln", visibility: "public" });
65 if (!made.ok) throw new Error(String(made.error));
66 const repo = made.value;
67 const pushed = await commitToBranch(app, u.value, repo, {
68 message: "A check",
69 files: [{ path: "forge.json", content: `{"check": {"run": "exit 0", "install": ""}}\n` }],
70 });
71 if (!pushed.ok) throw new Error(JSON.stringify(pushed.error));
72 const oid = pushed.value.commitOid;
73 const check = () => listRuns(app.db, repo.id, { kind: "check", limit: 50 }).find((r) => r.commitOid === oid);
74
75 const queued = await until(check);
76 const held = await until(() => {
77 const log = readRunLog(dataDir, queued.id).lines.join("\n");
78 return log.includes("queued, not started: this host's disk is 81.0% used") ? log : undefined;
79 });
80 // A tick passes and the check is still queued, its line said once.
81 await Bun.sleep(5_500);
82 expect(check()?.state).toBe("queued");
83 const lines = readRunLog(dataDir, queued.id).lines.filter((l) => l.includes("this host's disk is"));
84 expect(lines).toHaveLength(1);
85 expect(held).toContain("80% builds wait for");
86
87 used = 0.79;
88 const done = await until(() => {
89 const run = check();
90 return run && run.state !== "queued" && run.state !== "running" ? run : undefined;
91 });
92 expect(done.state).toBe("ok");
93 }, 30_000);
test/check-disk-used.test.ts added +86
@@ -0,0 +1,86 @@
1 /**
2 * A check a full disk refused, through the checks service and the crew
3 * (#11799): its step says the one line, the check is cancelled as the
4 * machine's and queued again, and its builder hears no check_failed.
5 */
6
7 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
8 import { existsSync } from "node:fs";
9 import { join } from "node:path";
10 import type { App } from "../src/app.ts";
11 import type { User } from "../src/core/users.ts";
12 import { addToCrew } from "../src/actions/crew.ts";
13 import { assignIssue, openIssue } from "../src/actions/issues.ts";
14 import { commitToBranch, createRepo } from "../src/actions/repos.ts";
15 import { usedRefusal } from "../src/apps/disk_guard.ts";
16 import type { runStep } from "../src/apps/process.ts";
17 import { DISK_USED_SUMMARY, listRuns } from "../src/core/runs.ts";
18 import { err, ok } from "../src/kernel/result.ts";
19 import { startStandInCrew, stopStandInCrew, type StandInCrew } from "./helpers/crew-standin.ts";
20
21 const REFUSAL = `check ${usedRefusal("/", { freeBytes: 19, totalBytes: 100 })}`;
22
23 describe("a pull's check the disk refused, through the service", () => {
24 let standIn: StandInCrew;
25 let app: App;
26 let alice: User;
27 let bot: User;
28 let refusals = 0;
29
30 // The pull's checkout holds CREW.md; its first check meets a disk at 81% used, later ones pass.
31 const checkStep: typeof runStep = async (_name, command, options) => {
32 options.log(`$ ${command}`);
33 if (!existsSync(join(options.cwd, "CREW.md")) || refusals >= 1) return ok();
34 refusals++;
35 options.log(REFUSAL);
36 return err(REFUSAL);
37 };
38
39 beforeAll(async () => {
40 standIn = await startStandInCrew({ tickMs: 50, checkStep });
41 ({ app, alice, bot } = standIn);
42 }, 30_000);
43
44 afterAll(() => stopStandInCrew(standIn));
45
46 const until = async <T>(find: () => T | undefined, timeoutMs = 20_000): Promise<T> => {
47 const deadline = Date.now() + timeoutMs;
48 while (Date.now() < deadline) {
49 const found = find();
50 if (found !== undefined) return found;
51 await Bun.sleep(20);
52 }
53 throw new Error("did not happen in time");
54 };
55
56 test("refused once: cancelled, queued again, never red, no rework", async () => {
57 const made = await createRepo(app, alice, { name: "kiln", visibility: "private" });
58 if (!made.ok) throw new Error(String(made.error));
59 const kiln = made.value;
60 const seeded = await commitToBranch(app, alice, kiln, {
61 message: "Start",
62 files: [
63 { path: "README.md", content: "# kiln\n" },
64 { path: "forge.json", content: '{"check": {"run": "exit 0", "install": ""}}\n' },
65 ],
66 });
67 if (!seeded.ok) throw new Error(JSON.stringify(seeded.error));
68 expect(addToCrew(app, alice, kiln, "bot").ok).toBe(true);
69 const issue = openIssue(app, alice, kiln, { title: "Fire the kiln", body: "Slowly." });
70 if (!issue.ok) throw new Error(String(issue.error));
71 expect(assignIssue(app, alice, kiln, issue.value, bot).ok).toBe(true);
72
73 const built = await until(() =>
74 listRuns(app.db, kiln.id, { kind: "agent", limit: 50 }).find((r) => r.reason === "assigned" && r.state === "ok"),
75 );
76 const pullNumber = Number(built.summary.match(/#(\d+)/)?.[1]);
77 const pullChecks = () => listRuns(app.db, kiln.id, { kind: "check", env: `pull-${pullNumber}`, limit: 50 });
78
79 const first = await until(() => pullChecks().find((r) => r.attempt === 0 && r.state === "cancelled"));
80 expect(first.summary).toBe(DISK_USED_SUMMARY);
81 const retry = await until(() => pullChecks().find((r) => r.attempt === 1 && r.state === "ok"));
82 expect(retry.commitOid).toBe(first.commitOid);
83 expect(pullChecks().some((r) => r.state === "failed")).toBe(false);
84 expect(listRuns(app.db, kiln.id, { kind: "agent", limit: 50 }).filter((r) => r.reason === "check_failed")).toHaveLength(0);
85 }, 30_000);
86 });
test/disk-floor.test.ts +28
@@ -24,6 +24,8 @@ import { quietLogs } from "./helpers/globals.ts";
2424 import { provideDiskForTest, type DiskReading } from "../src/kernel/disk_reading.ts";
2525 import { vitals } from "../src/kernel/vitals.ts";
2626 import { cellChildren, stopCellChildren } from "../src/spawn/cell.ts";
27 import { usedRefusal } from "../src/apps/disk_guard.ts";
28 import { RELEASE_DISK_USED_MAX } from "../src/keeper/cadence.ts";
2729 import { DISK_FLOOR, floorRefusal } from "../src/spawn/disk_floor.ts";
2830 import { quotaFull, quotaRefusal } from "../src/spawn/quota.ts";
2931
@@ -240,3 +242,29 @@ describe("the owner hears once per crossing (#10873)", () => {
240242 expect(pages).toEqual(["disk-floor", "disk", "disk-floor"]);
241243 });
242244 });
245
246 describe("no step's cell starts at 80% used (#11799)", () => {
247 test("the guard is 80% and the child floor stays 15%", () => {
248 expect(RELEASE_DISK_USED_MAX).toBe(0.8);
249 expect(DISK_FLOOR).toBe(0.15);
250 });
251
252 test("81% used is refused with one line; 79% is not", () => {
253 expect(usedRefusal(tmp, reading(19))).toContain("81.0% used");
254 expect(usedRefusal(tmp, reading(21))).toBeUndefined();
255 expect(usedRefusal(tmp, undefined)).toBeUndefined();
256 });
257
258 test("a step at 81% logs the line and fails with it; at 79% it runs", async () => {
259 const lines: string[] = [];
260 const step = (cell?: CellSpec) =>
261 runStep("check", "true", { cwd: tmp, env: childEnv({}), log: (l) => lines.push(l), signal: new AbortController().signal, cell });
262 provideDiskForTest(() => reading(19));
263 const refused = await step({} as CellSpec);
264 expect(refused.ok).toBe(false);
265 if (!refused.ok) expect(refused.error).toBe(`check ${usedRefusal(tmp, reading(19))}`);
266 expect(lines).toEqual([`check ${usedRefusal(tmp, reading(19))}`]);
267 provideDiskForTest(() => reading(21));
268 expect((await step()).ok).toBe(true);
269 });
270 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs