trevato/forge

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

More
Forks1g fMapg aRunsg rEventsFlows

A check that reaches its CPU limit is slowed, not failed: no check is stopped for using the cores it was given #11588

scoutcrew opened this in answer to trevatoowner

Check · Review · Land · Live — No review yet. Next: reviewer, no review yet.

ConversationFiles
Ready to land

scout/forge:scout/11573-a-check-that-reaches-its-cpu-limit-is-sl → main 1 commit fork

Review

Sign in to review this change.
7 files changed +165 −27
docs/APPS.md +8
@@ -612,6 +612,14 @@ build ran out of its 2 GiB", "the build used more than its 2 cores".
612612 install or test step keeps the step's own memory and cores, so a 128 MiB app
613613 still has room to install.
614614
615 Cores are throttled, not stopped, where the kernel holds `cpu.max`. Where
616 only the watch holds them, a cell is stopped for CPU only when it averages
617 more than 1.5× its cores over two minutes: a check using all 16 of its 16
618 cores is using what it was given (#11573). A check stopped that way is the
619 machine's verdict, not the pull's red: it is queued once more ("failed:
620 infrastructure — stopped for CPU by the cell watch; queued again"), nobody
621 is handed it, and only a second stop in a row fails it.
622
615623 Memory is held twice. The watch reads every cell's resident memory once a
616624 second and stops one over its limit. Where the forge holds a delegated
617625 cgroup v2 (`apps/cgroup.ts`), the kernel holds it as well: each cell runs
src/apps/contain.ts +49 −20
@@ -855,8 +855,17 @@ function readMountinfo(): string {
855855
856856 // ---- the watch ----
857857
858 /** How often the process table is read, and over how long CPU is averaged. */
859 export const WATCH = { tickMs: 1_000, cpuWindowMs: 30_000, diskEveryTicks: 15 };
858 /**
859 * How often the process table is read, and over how long CPU is averaged:
860 * two minutes, so only a sustained breach stops a cell (#11573).
861 */
862 export const WATCH = { tickMs: 1_000, cpuWindowMs: 120_000, diskEveryTicks: 15 };
863 /**
864 * How far past its cores a cell must stay, over the whole window, before
865 * the watch stops it (#11573). A check given 16 cores that uses 16.1 is
866 * using what it was given; only a tree well past it (here 1.5×) is stopped.
867 */
868 export const CPU_STOP_FACTOR = 1.5;
860869 /** A cell's process limit: the watch's every tick, and the kernel's `pids.max` where pids is delegated. */
861870 export const PROCESSES_MAX = 512;
862871 const CLK_TCK = 100;
@@ -1138,6 +1147,36 @@ export function busiest(
11381147 return top;
11391148 }
11401149
1150 /** Whether `cores` averaged over the window is a breach of `cpus`: well past it, never at it (#11573). */
1151 export function cpuOver(cores: number, cpus: number): boolean {
1152 return cores > cpus * CPU_STOP_FACTOR;
1153 }
1154
1155 /**
1156 * One tick of the CPU watch: `samples` (mutated) takes this tick's total
1157 * `ticks`, drops what is older than the window, and the cores over a full
1158 * window are returned when they breach `cpus` (`cpuOver`); else undefined.
1159 */
1160 export function cpuWindow(
1161 samples: { at: number; ticks: number }[],
1162 now: number,
1163 ticks: number,
1164 cpus: number,
1165 ): { cores: number; seconds: number } | undefined {
1166 samples.push({ at: now, ticks });
1167 while (samples.length > 1 && now - (samples[1]?.at ?? now) >= WATCH.cpuWindowMs) samples.shift();
1168 const oldest = samples[0];
1169 if (oldest === undefined || now - oldest.at < WATCH.cpuWindowMs) return undefined;
1170 const seconds = (now - oldest.at) / 1000;
1171 const cores = (ticks - oldest.ticks) / CLK_TCK / seconds;
1172 return cpuOver(cores, cpus) ? { cores, seconds } : undefined;
1173 }
1174
1175 /** Whether a step's error is the watch's CPU stop (`cpuBreach`'s line): infrastructure, not the code's red (#11573). */
1176 export function cpuStopped(error: string): boolean {
1177 return /\bused [\d.]+ cores for \d+s, over\b/.test(error);
1178 }
1179
11411180 /**
11421181 * Why a cell was stopped for CPU: cores = Δticks / CLK_TCK / Δseconds over
11431182 * the window, against its limit, and the busiest process when there is
@@ -1236,24 +1275,14 @@ function tick(): void {
12361275 );
12371276 continue;
12381277 }
1239 entry.samples.push({ at: now, ticks });
1240 while (
1241 entry.samples.length > 1 &&
1242 now - (entry.samples[1]?.at ?? now) >= WATCH.cpuWindowMs
1243 )
1244 entry.samples.shift();
1245 const oldest = entry.samples[0];
1246 if (oldest !== undefined && now - oldest.at >= WATCH.cpuWindowMs) {
1247 const cores =
1248 (ticks - oldest.ticks) / CLK_TCK / ((now - oldest.at) / 1000);
1249 if (cores > limits.cpus) {
1250 // Read only now, at the stop: no tick pays for naming a process.
1251 const top = busiest(tree, (pid) => rows.get(pid)?.ticks ?? 0);
1252 entry.breach(
1253 cpuBreach(cores, (now - oldest.at) / 1000, limits.cpus, top === undefined ? undefined : { ...top, name: commandName(top.pid) }),
1254 );
1255 continue;
1256 }
1278 const over = cpuWindow(entry.samples, now, ticks, limits.cpus);
1279 if (over !== undefined) {
1280 // Read only now, at the stop: no tick pays for naming a process.
1281 const top = busiest(tree, (pid) => rows.get(pid)?.ticks ?? 0);
1282 entry.breach(
1283 cpuBreach(over.cores, over.seconds, limits.cpus, top === undefined ? undefined : { ...top, name: commandName(top.pid) }),
1284 );
1285 continue;
12571286 }
12581287 entry.ticks++;
12591288 if (entry.ticks % WATCH.diskEveryTicks === 0) {
src/checks/service.ts +19 −2
@@ -43,6 +43,8 @@ import {
4343 VANISHED_SUMMARY,
4444 infraBefore,
4545 INFRA_SUMMARY,
46 cpuStopBefore,
47 CPU_STOP_SUMMARY,
4648 requeueCheck,
4749 REQUEUED_SUMMARY,
4850 sweepAbandonedChecks,
@@ -106,6 +108,7 @@ import {
106108 } from "../core/capacity.ts";
107109 import {
108110 cellsAvailable,
111 cpuStopped,
109112 limitWarnings,
110113 resolveLimits,
111114 STEP_HOSTS,
@@ -852,6 +855,16 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
852855 return;
853856 }
854857 }
858 // The watch stopped it for CPU: the machine's verdict, not the
859 // pull's red. Queued once more, and nobody is handed it (#11573).
860 if (!outcome.ok && outcome.cpuStopped === true && !cpuStopBefore(app.db, claimed)) {
861 const moved = requeueCheck(app.db, run.id, undefined, CPU_STOP_SUMMARY);
862 if (moved) {
863 write(CPU_STOP_SUMMARY);
864 announceRun(app, moved.again, run.actorId ?? undefined);
865 return;
866 }
867 }
855868 // The install failed twice on what the machine did, not the code: the
856869 // check is queued once more and nothing reads it as red (#5093).
857870 if (!outcome.ok && outcome.infrastructure === true && !infraBefore(app.db, claimed)) {
@@ -905,7 +918,7 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
905918 signal: AbortSignal,
906919 ): Promise<
907920 | { ok: true; proven?: string; passed?: readonly string[] }
908 | { ok: false; error: string; detail?: CheckDetail | undefined; infrastructure?: boolean; passed?: readonly string[] }
921 | { ok: false; error: string; detail?: CheckDetail | undefined; infrastructure?: boolean; cpuStopped?: boolean; passed?: readonly string[] }
909922 > {
910923 const bare = await runDir(app.db, app.reposRoot, repo, run.issueId);
911924 // A pull's check is the fast tier, judged against where the pull left
@@ -991,6 +1004,8 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
9911004 /** A whole verification: the files its log ran to the end green (#9524). */
9921005 passed?: readonly string[];
9931006 infrastructure?: boolean;
1007 /** The watch stopped it for CPU: the machine's verdict, not the code's (#11573). */
1008 cpuStopped?: boolean;
9941009 /** Where it stopped red (#5276); none is before any step ran. */
9951010 stage?: GateStage;
9961011 /** The check step was ended by a signal from outside: no verdict (#6722). */
@@ -1445,6 +1460,7 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
14451460 ran.error,
14461461 );
14471462 const killed = killedStep(ran.error);
1463 const cpu = cpuStopped(ran.error);
14481464 // A red verification keeps the map it measured all the same, and
14491465 // names the files it failed in for the bisection (#7786).
14501466 const files = x.tier === "verify" ? failedFiles(checkLines) : [];
@@ -1458,8 +1474,9 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
14581474 }
14591475 return {
14601476 ok: false,
1461 error: killed ? ran.error : summary,
1477 error: killed || cpu ? ran.error : summary,
14621478 detail: redDetail(detail, files, checkLines),
1479 ...(cpu ? { cpuStopped: true } : {}),
14631480 ...(wholeVerify ? { passed: passedFiles(checkLines) } : {}),
14641481 stage: checkStage(ran.error),
14651482 ...(killed ? { killed } : {}),
src/core/runs.ts +8
@@ -525,6 +525,9 @@ export const VANISHED_SUMMARY = "interrupted: its cluster job vanished; queued a
525525 /** What a check whose install the machine failed twice says as it is queued again (#5093). */
526526 export const INFRA_SUMMARY = "failed: infrastructure — the install failed twice on a transient error; queued again";
527527
528 /** What a check the cell watch stopped for CPU says as it is queued again (#11573). */
529 export const CPU_STOP_SUMMARY = "failed: infrastructure — stopped for CPU by the cell watch; queued again";
530
528531 /**
529532 * How many times one check may be cut off by its forge going away and be
530533 * queued again. Past it the check fails once, saying so: a check that kills
@@ -592,6 +595,11 @@ export function infraBefore(db: Database, run: Run): boolean {
592595 return cutOffBefore(db, run, INFRA_SUMMARY);
593596 }
594597
598 /** Whether the attempt just before this one was stopped for CPU: it is queued again once (#11573). */
599 export function cpuStopBefore(db: Database, run: Run): boolean {
600 return cutOffBefore(db, run, CPU_STOP_SUMMARY);
601 }
602
595603 function cutOffBefore(db: Database, run: Run, prefix: string): boolean {
596604 return (
597605 db
test/cpu-breach.test.ts +46 −1
@@ -3,7 +3,7 @@
33 * (#11509), and only when one has spent any.
44 */
55 import { describe, expect, test } from "bun:test";
6 import { busiest, cpuBreach } from "../src/apps/contain.ts";
6 import { busiest, cpuBreach, cpuOver, cpuStopped, cpuWindow, WATCH } from "../src/apps/contain.ts";
77
88 describe("a cell stopped for CPU", () => {
99 test("the busiest process is the one with the most ticks in the tree", () => {
@@ -28,3 +28,48 @@ describe("a cell stopped for CPU", () => {
2828 expect(cpuBreach(3.1, 30, 1, undefined)).toBe("used 3.1 cores for 30s, over its limit of 1");
2929 });
3030 });
31
32 describe("a cell at its CPU limit is not stopped (#11573)", () => {
33 /** Plays `seconds` of one-second ticks at `coresAt(t)` through the watch; the first breach, or undefined. */
34 const play = (seconds: number, cpus: number, coresAt: (t: number) => number) => {
35 const samples: { at: number; ticks: number }[] = [];
36 let ticks = 0;
37 for (let t = 0; t <= seconds; t++) {
38 if (t > 0) ticks += coresAt(t) * 100;
39 const over = cpuWindow(samples, t * 1000, ticks, cpus);
40 if (over !== undefined) return { at: t, ...over };
41 }
42 return undefined;
43 };
44
45 test("using exactly the limit is not over it", () => {
46 expect(cpuOver(16, 16)).toBe(false);
47 expect(cpuOver(16.1, 16)).toBe(false);
48 expect(cpuOver(17.5, 16)).toBe(false);
49 expect(cpuOver(24, 16)).toBe(false);
50 expect(cpuOver(24.1, 16)).toBe(true);
51 });
52
53 test("a check using all 16 of its cores for three minutes finishes", () => {
54 expect(play(180, 16, () => 16)).toBeUndefined();
55 expect(play(180, 16, () => 17.5)).toBeUndefined();
56 });
57
58 test("a burst well past the limit shorter than the window is not a stop", () => {
59 expect(play(180, 16, (t) => (t <= 30 ? 40 : 16))).toBeUndefined();
60 });
61
62 test("only a breach well past the limit, sustained over two minutes, stops it", () => {
63 expect(WATCH.cpuWindowMs).toBeGreaterThanOrEqual(120_000);
64 const over = play(300, 16, () => 30);
65 expect(over?.at).toBe(WATCH.cpuWindowMs / 1000);
66 expect(over?.cores).toBeCloseTo(30, 5);
67 });
68
69 test("the stop's line is known as the machine's verdict, and nothing else is", () => {
70 expect(cpuStopped(`check stopped: it ${cpuBreach(30, 120, 16, undefined)}`)).toBe(true);
71 expect(cpuStopped("stopped: used 16.3 cores for 30s, over its limit of 16; the busiest process is sh (pid 1, 4s of CPU)")).toBe(true);
72 expect(cpuStopped("check stopped: it used 900 MiB of memory, over its 768 MiB limit (the default)")).toBe(false);
73 expect(cpuStopped('2 of 900 tests — "a" and "b"')).toBe(false);
74 });
75 });
test/cpu-stop-requeue.test.ts added +31
@@ -0,0 +1,31 @@
1 /**
2 * A check the cell watch stopped for CPU is the machine's verdict, not the
3 * pull's red (#11573): `checks/service.ts` queues it once more under
4 * `CPU_STOP_SUMMARY`, and only the attempt after that one may fail.
5 */
6 import { describe, expect, test } from "bun:test";
7 import { migrations } from "../src/core/schema.ts";
8 import { claimRun, cpuStopBefore, CPU_STOP_SUMMARY, createRun, infraBefore, requeueCheck } from "../src/core/runs.ts";
9 import { openDb } from "../src/kernel/db.ts";
10
11 describe("a check stopped for CPU", () => {
12 const db = openDb(":memory:", migrations);
13 db.run("INSERT INTO user (id, username, email, password_hash) VALUES ('u1', 'trevato', 't@x', '')");
14 db.run("INSERT INTO repo (id, owner_id, name) VALUES ('r1', 'u1', 'forge')");
15 db.run("INSERT INTO issue (id, repo_id, number, kind, title, author_id) VALUES ('i1', 'r1', 7, 'pull', 'p', 'u1')");
16
17 test("is queued once more; the attempt after it is not queued again", () => {
18 const first = createRun(db, { repoId: "r1", kind: "check", env: "pull-7", commitOid: "a".repeat(40), reason: "push", issueId: "i1" });
19 claimRun(db, first.id);
20 expect(cpuStopBefore(db, first)).toBe(false);
21 const moved = requeueCheck(db, first.id, undefined, CPU_STOP_SUMMARY);
22 expect(moved?.cancelled.summary).toBe(CPU_STOP_SUMMARY);
23 expect(moved?.cancelled.state).toBe("cancelled");
24 const again = moved!.again;
25 expect(again.state).toBe("queued");
26 // The second attempt sees the first was a CPU stop: it fails, not loops.
27 expect(cpuStopBefore(db, again)).toBe(true);
28 // And it is its own reason, not the install's.
29 expect(infraBefore(db, again)).toBe(false);
30 });
31 });
test/forges-side-by-side.test.ts +4 −4
@@ -71,10 +71,10 @@ describe("coresOf", () => {
7171 const samples = [{ at: 0, ticks: 0 }];
7272 test("null before the samples span half the window, a figure after", () => {
7373 expect(coresOf(samples, { ticks: 500 }, WATCH.cpuWindowMs / 2 - 1)).toBeNull();
74 expect(coresOf([], { ticks: 500 }, 99_999)).toBeNull();
75 expect(coresOf(samples, undefined, 99_999)).toBeNull();
76 // 1500 ticks at 100/s over 30 s is half a core.
77 expect(coresOf(samples, { ticks: 1500 }, 30_000)).toBeCloseTo(0.5, 5);
74 expect(coresOf([], { ticks: 500 }, WATCH.cpuWindowMs)).toBeNull();
75 expect(coresOf(samples, undefined, WATCH.cpuWindowMs)).toBeNull();
76 // Half a core: 50 ticks a second (at 100/s) over the whole window.
77 expect(coresOf(samples, { ticks: (WATCH.cpuWindowMs / 1000) * 50 }, WATCH.cpuWindowMs)).toBeCloseTo(0.5, 5);
7878 });
7979 });
8080

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs