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

Every test fast: a budget per test and per file enforced by the gate, the full suite under five minutes #12086

Merged opened this in answer to

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

Merged

mason/forge:mason/1242-every-test-fast-a-budget-per-test-and-pe → main 16 commits fork 2 threads · 2 unresolved

  • Merged. mason/1242-every-test-fast-a-budget-per-test-and-pe was merged into main as a4add02.

Review

Sign in to review this change.
7 files changed +642 −23
docs/DEVELOP.md +16
@@ -189,6 +189,22 @@ whose description carries ten green runs in random order under load:
189189 its own `bun test --randomize` with a fresh seed beside busy loops, prints the
190190 record and exits non-zero unless all ten are green.
191191
192 Every gated file is held to a budget (#1242, `scripts/test-budget.ts`): the
193 file alone in its own `bun test` under 20 s, and each test in it under 2 s
194 (read from the JUnit report `bun test` writes beside its console output; a
195 `beforeAll` counts toward the file, not the test). Over is red on the whole
196 gate, and on the fast tier for a test file the pull itself changed, as a
197 `(fail)` line saying the fix; a slice run by hand names it and stays green.
198 A breach is timed once more alone, without coverage, and
199 judged by that run, so one busy moment on the box is not a red. A file that
200 cannot be brought under goes in `SLOW` in `scripts/gate.ts` with a reason and
201 the issue that owns it; `bun scripts/gate.ts` refuses a stale, doubled or
202 unowned entry. A green full gate writes each test's time to
203 `.forge-cache/test-times-tests.json` beside the per-file table, and its
204 summary names the five slowest tests and their share of the run, then
205 ends with every breach, slowest first, so a log kept by its tail still says
206 what to fix or name in `SLOW`.
207
192208 A brand-new test file does not need that record: it joins the gate on its
193209 own green check, not ten runs. That is accepted on purpose — a flaky new
194210 test can turn the gate red once before anyone sees it — and the nightly
scripts/gate.ts +57 −15
@@ -16,6 +16,10 @@
1616 * leaves it only through `bun scripts/flake-hunt.ts quarantine`, under the
1717 * issue the nightly hunt filed (`src/nightly/`).
1818 *
19 * `SLOW` is the other list: gated files allowed over the test budget
20 * (`scripts/test-budget.ts`, #1242), each with its reason and owning issue,
21 * audited the same way by `slowRefusal`.
22 *
1923 * The excluded files are not unseen: the forge's nightly job (`src/nightly/`)
2024 * runs `outsideFiles` nightly and files a `Red:` issue for each that fails (#812).
2125 *
@@ -37,6 +41,35 @@ export type Exclusion = {
3741
3842 export const EXCLUDED: readonly Exclusion[] = [];
3943
44 /**
45 * The files allowed over the test budget (#1242): each with why it is slow
46 * and the issue that owns bringing it under. Every other gated file is held
47 * to `FILE_BUDGET_SECONDS` and each of its tests to `TEST_BUDGET_SECONDS`
48 * (`scripts/test-budget.ts`); over is red, like a failing assertion, on the
49 * whole gate and on the fast tier for a file the pull changed. Keep it
50 * short: an entry is a debt with an owner, not a home.
51 */
52 export const SLOW: readonly Exclusion[] = [];
53
54 /** Everything wrong with one list of named files, `list` its name in the lines. */
55 function auditList(list: "EXCLUDED" | "SLOW", present: readonly string[], entries: readonly Exclusion[]): string[] {
56 const problems: string[] = [];
57 const exists = new Set(present);
58 const seen = new Set<string>();
59 const what = list === "EXCLUDED" ? "excluded" : "in SLOW";
60 for (const { file, reason, issue } of entries) {
61 if (seen.has(file)) problems.push(`${file} is in ${list} twice`);
62 seen.add(file);
63 if (!exists.has(file))
64 problems.push(`${file} is in ${list} but does not exist`);
65 if (typeof reason !== "string" || reason.trim() === "")
66 problems.push(`${file} is ${what} with no reason`);
67 if (!Number.isInteger(issue) || issue <= 0)
68 problems.push(`${file} is ${what} with no issue number`);
69 }
70 return problems;
71 }
72
4073 /**
4174 * Everything wrong with the quarantine, against the test files that exist:
4275 * one line per problem, none when every exclusion is sound.
@@ -45,20 +78,29 @@ export function auditGate(
4578 present: readonly string[],
4679 excluded: readonly Exclusion[],
4780 ): string[] {
48 const problems: string[] = [];
49 const exists = new Set(present);
50 const out = new Set<string>();
51 for (const { file, reason, issue } of excluded) {
52 if (out.has(file)) problems.push(`${file} is in EXCLUDED twice`);
53 out.add(file);
54 if (!exists.has(file))
55 problems.push(`${file} is in EXCLUDED but does not exist`);
56 if (typeof reason !== "string" || reason.trim() === "")
57 problems.push(`${file} is excluded with no reason`);
58 if (!Number.isInteger(issue) || issue <= 0)
59 problems.push(`${file} is excluded with no issue number`);
60 }
61 return problems;
81 return auditList("EXCLUDED", present, excluded);
82 }
83
84 /**
85 * Everything wrong with `SLOW`: what `auditGate` asks of an exclusion, and
86 * no file both excluded and slow (an excluded file is not timed at all).
87 * The last line names the files to fix, as `gateRefusal`'s does.
88 */
89 export function slowRefusal(
90 present: readonly string[],
91 slow: readonly Exclusion[] = SLOW,
92 excluded: readonly Exclusion[] = EXCLUDED,
93 ): string[] {
94 const out = new Set(excluded.map((e) => e.file));
95 const problems = [
96 ...auditList("SLOW", present, slow),
97 ...[...new Set(slow.map((e) => e.file))].filter((f) => out.has(f)).map((f) => `${f} is in both EXCLUDED and SLOW`),
98 ];
99 if (problems.length === 0) return [];
100 const named = [...new Set(problems.map((p) => p.match(/^(test\/\S+\.test\.ts) /)?.[1]))].filter(
101 (f): f is string => f !== undefined,
102 );
103 return [...problems, `${named.join(", ")}: fix its SLOW entry in scripts/gate.ts`];
62104 }
63105
64106 /** The `test/*.test.ts` files under `root`, as the gate names them. */
@@ -307,7 +349,7 @@ export async function directionRefusal(cwd: string = process.cwd()): Promise<str
307349 // `bun scripts/gate.ts`: the audit alone, first in `forge.json`'s check, so
308350 // a stale exclusion fails in under a second — not after install and tsc.
309351 if (import.meta.main) {
310 const refusal = [...gateRefusal(presentTests()), ...(await pinRefusal()), ...(await tryItRefusal()), ...(await bothDoorsRefusal()), ...(await directionRefusal()), ...strayTestRefusal(), ...reviewRefusal(), ...(await addedRefusal()), ...billingDeletesRefusal()];
352 const refusal = [...gateRefusal(presentTests()), ...slowRefusal(presentTests()), ...(await pinRefusal()), ...(await tryItRefusal()), ...(await bothDoorsRefusal()), ...(await directionRefusal()), ...strayTestRefusal(), ...reviewRefusal(), ...(await addedRefusal()), ...billingDeletesRefusal()];
311353 for (const line of refusal) console.error(`gate: ${line}`);
312354 process.exit(refusal.length === 0 ? 0 : 2);
313355 }
scripts/test-budget.ts added +205
@@ -0,0 +1,205 @@
1 /**
2 * The test budget (#1242): no gated file over {@link FILE_BUDGET_SECONDS},
3 * no single test over {@link TEST_BUDGET_SECONDS}, unless the file is named
4 * in `SLOW` in `scripts/gate.ts` with the issue that owns it.
5 *
6 * Plain data in, lines out. `scripts/test-shards.ts` times each file and
7 * hands in each test's time, read from the JUnit report `bun test` writes
8 * beside its console output (`--reporter=junit`); this says which are over,
9 * in lines shaped like bun's own `(fail)` lines, so a budget red is counted,
10 * named and attributed like a failing assertion.
11 */
12
13 /** A gated file, run alone in its own `bun test`, may take this long. */
14 export const FILE_BUDGET_SECONDS = 20;

The 20 s / 2 s numbers are only enforced for the pull's changed files on the fast tier; the gate does not go red on them. That is what #1242 box 1 asks for.

15 /** One test may take this long (its hooks are the file's, not its own). */
16 export const TEST_BUDGET_SECONDS = 2;
17 /** How many of the slowest tests the gate's summary names. */
18 export const SLOWEST_TESTS = 5;
19
20 export type TestTime = { file: string; test: string; seconds: number };
21 export type FileTime = { file: string; seconds: number };
22
23 export type Budgets = { file: number; test: number };
24
25 /**
26 * The budgets a run holds to: the constants, or tighter where
27 * `FORGE_TEST_BUDGET_SECONDS` says `<file>,<test>` (a test of the runner
28 * proves a breach without a slow fixture). It only ever tightens: a value
29 * above the constant, or one that is not a positive number, is ignored.
30 */
31 export function budgetsFrom(value: string | undefined): Budgets {
32 const [file, test] = (value ?? "").split(",").map((part) => Number(part.trim()));
33 const pick = (asked: number | undefined, most: number): number =>
34 asked !== undefined && Number.isFinite(asked) && asked > 0 && asked < most ? asked : most;
35 return { file: pick(file, FILE_BUDGET_SECONDS), test: pick(test, TEST_BUDGET_SECONDS) };
36 }
37
38 /** One thing over its budget: a whole file, or one test in it. */
39 export type Breach = { file: string; test?: string; seconds: number; budget: number };
40
41 const ENTITIES: Record<string, string> = { amp: "&", lt: "<", gt: ">", quot: '"', apos: "'" };
42
43 function unescapeXml(text: string): string {
44 return text.replace(/&(amp|lt|gt|quot|apos|#\d{1,7}|#x[0-9a-fA-F]{1,6});/g, (_, name: string) => {
45 if (name.startsWith("#x")) return String.fromCodePoint(Number.parseInt(name.slice(2), 16));
46 if (name.startsWith("#")) return String.fromCodePoint(Number(name.slice(1)));
47 return ENTITIES[name]!;
48 });
49 }
50
51 function attributes(tag: string): Map<string, string> {
52 const found = new Map<string, string>();
53 for (const m of tag.matchAll(/\s([A-Za-z_:][\w:.-]*)="([^"]*)"/g)) found.set(m[1]!, unescapeXml(m[2]!));
54 return found;
55 }
56
57 /**
58 * Every test case of one JUnit report `bun test` wrote: its file (made
59 * relative like `test/a.test.ts`), its name under its innermost `describe`
60 * (`group > name`), and its seconds. A case with no file or no finite time
61 * is skipped, never guessed; a report that is not one yields none.
62 */
63 export function parseJunit(xml: string): TestTime[] {
64 const tests: TestTime[] = [];
65 for (const m of xml.matchAll(/<testcase\b[^>]*>/g)) {
66 const a = attributes(m[0]);
67 const name = a.get("name");
68 const file = a.get("file")?.replace(/^\.\//, "");
69 const time = a.get("time") ?? "";
70 const seconds = Number(time);
71 if (name === undefined || !file || !/^\d+(\.\d+)?(e[-+]?\d+)?$/i.test(time) || !Number.isFinite(seconds)) continue;
72 const group = a.get("classname");
73 tests.push({ file, test: group ? `${group} > ${name}` : name, seconds });
74 }
75 return tests;
76 }
77
78 /**
79 * What is over budget, files in `slow` excepted: each file whose own run
80 * took longer than the file budget, and each test longer than the test
81 * budget, slowest first.
82 */
83 export function breaches(
84 files: readonly FileTime[],
85 tests: readonly TestTime[],
86 slow: ReadonlySet<string>,
87 budgets: Budgets = { file: FILE_BUDGET_SECONDS, test: TEST_BUDGET_SECONDS },
88 ): Breach[] {
89 const over: Breach[] = [
90 ...files
91 .filter((f) => !slow.has(f.file) && f.seconds > budgets.file)
92 .map((f) => ({ file: f.file, seconds: f.seconds, budget: budgets.file })),
93 ...tests
94 .filter((t) => !slow.has(t.file) && t.seconds > budgets.test)
95 .map((t) => ({ file: t.file, test: t.test, seconds: t.seconds, budget: budgets.test })),
96 ];
97 return over.sort((a, b) => b.seconds - a.seconds);
98 }
99
100 const FIX = "make it faster, or name its file in SLOW in scripts/gate.ts with an issue";
101
102 /**
103 * The report lines for `over`, grouped under each file's `path:` header the
104 * way `bun test` writes its own, each breach a `(fail)` line: the shard's
105 * tally then counts and names it, and a fast tier red asks its base about it.
106 */
107 export function breachReport(over: readonly Breach[]): string {
108 const byFile = new Map<string, Breach[]>();
109 for (const b of over) byFile.set(b.file, [...(byFile.get(b.file) ?? []), b]);
110 const lines: string[] = [];
111 for (const [file, list] of byFile) {
112 lines.push(`${file}:`);
113 for (const b of list)
114 lines.push(
115 b.test === undefined
116 ? `(fail) the whole file took ${b.seconds.toFixed(1)} s, over the ${b.budget} s file budget: ${FIX}`
117 : `(fail) ${b.test} took ${b.seconds.toFixed(2)} s, over the ${b.budget} s test budget: ${FIX}`,
118 );
119 }
120 return lines.length === 0 ? "" : `${lines.join("\n")}\n`;
121 }
122
123 const key = (b: Breach): string => (b.test === undefined ? b.file : `${b.file} > ${b.test}`);
124
125 /**
126 * The breaches that stand after a second timing, alone: those of `first`
127 * the re-timed run (`again`, its breaches) is still over on. A re-run that
128 * went red (`undefined`) clears nothing. Each cleared one is named in a line.
129 */
130 export function retimeVerdict(
131 first: readonly Breach[],
132 again: readonly Breach[] | undefined,
133 ): { still: Breach[]; lines: string[] } {
134 if (again === undefined) return { still: [...first], lines: [] };
135 const over = new Map(again.map((b) => [key(b), b]));
136 const still = first.flatMap((b) => over.get(key(b)) ?? []);
137 const cleared = first.filter((b) => !over.has(key(b)));
138 return {
139 still,
140 lines: cleared.length === 0 ? [] : [`test-shards: over budget once, under it timed again alone: ${cleared.map(key).join("; ")}`],
141 };
142 }
143
144 /** One warning line per breach, for a run that names them without failing. */
145 export function breachWarnings(over: readonly Breach[]): string[] {
146 return over.map((b) =>
147 b.test === undefined
148 ? `test-shards: over budget (not enforced here): ${b.file} took ${b.seconds.toFixed(1)} s, budget ${b.budget} s`
149 : `test-shards: over budget (not enforced here): ${b.file} > ${b.test} took ${b.seconds.toFixed(2)} s, budget ${b.budget} s`,
150 );
151 }
152
153 /**
154 * The closing count of a run's breaches, then each one, slowest first:
155 * written after the tally, so a log kept only by its tail still names
156 * every file the budget found over, and `SLOW` can be filled from it (#12088).
157 */
158 export function breachClosing(over: readonly Breach[], budgets: Budgets = { file: FILE_BUDGET_SECONDS, test: TEST_BUDGET_SECONDS }): string[] {
159 const sorted = [...over].sort((a, b) => b.seconds - a.seconds || key(a).localeCompare(key(b)));
160 return [
161 `test-shards: over the budget (${budgets.file} s a file, ${budgets.test} s a test), SLOW aside: ${over.length}`,
162 ...sorted.map((b) =>
163 b.test === undefined
164 ? ` ${b.seconds.toFixed(1).padStart(6)}s ${b.file} (the whole file)`
165 : ` ${b.seconds.toFixed(2).padStart(6)}s ${b.file} > ${b.test}`,
166 ),
167 ];
168 }
169
170 /**
171 * The slowest `n` tests and each one's share of `totalSeconds` (the summed
172 * time of every file the run timed), for the gate's closing summary.
173 */
174 export function slowestTestLines(tests: readonly TestTime[], totalSeconds: number, n = SLOWEST_TESTS): string[] {
175 const top = [...tests]
176 .sort((a, b) => b.seconds - a.seconds || a.file.localeCompare(b.file) || a.test.localeCompare(b.test))
177 .slice(0, n);
178 if (top.length === 0) return [];
179 const share = (s: number): string => (totalSeconds > 0 ? `${((s / totalSeconds) * 100).toFixed(1)}%` : "-");
180 const sum = top.reduce((acc, t) => acc + t.seconds, 0);
181 return [
182 `test-shards: slowest ${top.length} tests, ${share(sum)} of ${totalSeconds.toFixed(1)}s of work:`,
183 ...top.map((t) => ` ${t.seconds.toFixed(2).padStart(6)}s ${share(t.seconds).padStart(6)} ${t.file} > ${t.test}`),
184 ];
185 }
186
187 /**
188 * The per-test table a green full gate writes beside the per-file one:
189 * `{ file: { test: seconds } }`, files and tests in name order, seconds to
190 * the millisecond, so two runs diff line by line.
191 */
192 export function formatTestTimes(tests: readonly TestTime[]): string {
193 const byFile = new Map<string, Map<string, number>>();
194 for (const t of tests) {
195 const inFile = byFile.get(t.file) ?? new Map<string, number>();
196 inFile.set(t.test, Math.round(t.seconds * 1000) / 1000);
197 byFile.set(t.file, inFile);
198 }
199 const out: Record<string, Record<string, number>> = {};
200 for (const file of [...byFile.keys()].sort()) {
201 const inFile = byFile.get(file)!;
202 out[file] = Object.fromEntries([...inFile.keys()].sort().map((name) => [name, inFile.get(name)!]));
203 }
204 return `${JSON.stringify(out, null, 2)}\n`;
205 }
scripts/test-shards.ts +81 −7
@@ -44,6 +44,12 @@
4444 * times to `.forge-cache/test-times.json`, which the forge keeps for the
4545 * next check (`src/checks/cache.ts`).
4646 *
47 * Every run times each test from a JUnit report beside the console one
48 * and holds it to the budget (`scripts/test-budget.ts`, #1242): red on the
49 * whole gate and on a fast tier's own changed test files, named by hand.
50 * A green timed gate also writes each test's time to
51 * `.forge-cache/test-times-tests.json` and ends by naming the five slowest.
52 *
4753 * Files are weighed by how long they took, from `scripts/test-times.json`
4854 * overlaid by `.forge-cache/test-times.json` (a file neither names, or a
4955 * table it refuses, falls back to bytes).
@@ -82,7 +88,8 @@ import {
8288 CRASH_RERUNS,
8389 type ShardResult,
8490 } from "./shards.ts";
85 import { gateFiles, gateRefusal, presentTests } from "./gate.ts";
91 import { gateFiles, gateRefusal, presentTests, SLOW, slowRefusal } from "./gate.ts";
92 import { breaches, breachReport, budgetsFrom, retimeVerdict, breachClosing, breachWarnings, formatTestTimes, parseJunit, slowestTestLines, type Breach, type TestTime } from "./test-budget.ts";
8693 import { cgroupMemory, summaryLines } from "./gate-summary.ts";
8794 import { GATE_FILE, executedFiles, formatImpact, gateListAdds, handedImpact, mergeImpact, parseImpact } from "../src/checks/impact.ts";
8895 import { importsReader, readImpact, scansIn } from "./tier-input.ts";
@@ -104,6 +111,8 @@ const IMPACT_NAME = handed ?? "scripts/test-impact.json";
104111 // What the forge keeps between checks (`src/checks/cache.ts`): the full
105112 // gate's own per-file times, fresher than the committed table.
106113 const CACHED_TIMES = `${CHECK_CACHE}/test-times.json`;
114 // Beside it, each test's time from the same run (#1242).
115 const CACHED_TEST_TIMES = `${CHECK_CACHE}/test-times-tests.json`;
107116
108117 const argv = process.argv.slice(2);
109118 const record = argv.includes("--record");
@@ -264,7 +273,7 @@ const flags = split.flags;
264273 // A stale exclusion costs a whole gate run to find out; say so before
265274 // anything spawns. Explicit files alone are not audited.
266275 if (gate || tier === "fast") {
267 const refusal = gateRefusal(presentTests());
276 const refusal = [...gateRefusal(presentTests()), ...slowRefusal(presentTests())];
268277 if (refusal.length > 0) {
269278 for (const line of refusal) console.error(`test-shards: ${line}`);
270279 process.exit(2);
@@ -477,7 +486,18 @@ let crashReruns = 0;
477486 /** What a live first run shows once it has gone red: held until its end. */
478487 const RED_SIGN = /^(\(fail\)|# Unhandled error|error:)/m;
479488
480 type Timed = ShardResult & { seconds: number };
489 type Timed = ShardResult & { seconds: number; tests: TestTime[]; overBudget: Breach[] };
490
491 // The budget (#1242) is red on the whole gate, for every file SLOW does not
492 // name, and on a fast tier for the test files the pull itself changed: a
493 // pull that writes a slow test is stopped at the pull. A slice run by hand
494 // names what is over and stays green.
495 const SLOW_FILES = new Set(SLOW.map((entry) => entry.file));
496 const BUDGETS = budgetsFrom(process.env["FORGE_TEST_BUDGET_SECONDS"]);
497 const budgetBinds = (file: string): boolean =>
498 (gate && tier === "full") || (tier === "fast" && changed.includes(file.replace(/^\.\//, "")));
499 // A run that already asks for a report keeps it; the budget then reads no tests.
500 const junitAsked = flags.some((flag) => flag === "--reporter" || flag.startsWith("--reporter=") || flag === "--dots");
481501
482502 /**
483503 * One shard. `live` (shards running one at a time) writes the shard's
@@ -534,12 +554,16 @@ async function runShardIn(
534554 const cover = covDir
535555 ? ["--coverage", "--coverage-reporter=lcov", `--coverage-dir=${covDir}`]
536556 : [];
557 const junit = join(home, "junit.xml");
558 const report = junitAsked ? [] : ["--reporter=junit", `--reporter-outfile=${junit}`];
537559 const run = async (
538560 targets: string[],
539561 extra: string[],
540562 through?: (text: string) => void,
541 ): Promise<{ code: number; output: string[] }> => {
542 const child = Bun.spawn(["bun", "test", ...flags, ...extra, ...targets], {
563 ): Promise<{ code: number; output: string[]; seconds: number }> => {
564 rmSync(junit, { force: true });
565 const began = performance.now();
566 const child = Bun.spawn(["bun", "test", ...flags, ...report, ...extra, ...targets], {
543567 stdin: "ignore",
544568 stdout: "pipe",
545569 stderr: "pipe",
@@ -557,7 +581,14 @@ async function runShardIn(
557581 ]);
558582 const code = await child.exited;
559583 children.delete(child);
560 return { code, output };
584 return { code, output, seconds: (performance.now() - began) / 1000 };
585 };
586 const testsOfLastRun = (): TestTime[] => {
587 try {
588 return parseJunit(readFileSync(junit, "utf8"));
589 } catch {
590 return [];
591 }
561592 };
562593 const through = live
563594 ? (text: string): void => {
@@ -597,6 +628,8 @@ async function runShardIn(
597628 }
598629 let code = first.code;
599630 let output = quoted === "" ? first.output : [quoted, ...first.output];
631 let lastSeconds = first.seconds;
632 let tests = testsOfLastRun();
600633 // Kept going, a file red on its own is run once more alone: green then,
601634 // it was a flake, and its first output (the `(fail)` lines) is set aside.
602635 if (code !== 0 && keepGoing && slice.length === 1) {
@@ -606,6 +639,8 @@ async function runShardIn(
606639 mkdirSync(covDir);
607640 }
608641 const again = await run(paths, cover, through);
642 lastSeconds = again.seconds;
643 tests = testsOfLastRun();
609644 if (again.code === 0) {
610645 code = 0;
611646 output = [...again.output, `test-shards: ${FLAKY_ALONE} ${slice[0]}\n`];
@@ -632,6 +667,39 @@ async function runShardIn(
632667 if (verdict.red.length === 0) code = 0;
633668 }
634669 }
670 // Over budget (#1242), judged on a green run: a file alone is timed whole,
671 // every test by the report. What binds is timed once more, alone and
672 // without coverage, and judged by that run, so one busy moment on the box
673 // is not a red; what is still over is a `(fail)` the tally counts.
674 let overBudget: Breach[] = [];
675 if (code === 0) {
676 const fileTimes = slice.length === 1 ? [{ file: slice[0]!.replace(/^\.\//, ""), seconds: lastSeconds }] : [];
677 const over = breaches(fileTimes, tests, SLOW_FILES, BUDGETS);
678 const binding = over.filter((b) => budgetBinds(b.file));
679 const named = breachWarnings(over.filter((b) => !budgetBinds(b.file)));
680 let still = binding;
681 if (binding.length > 0) {
682 const retimed = [...new Set(binding.map((b) => b.file))];
683 const again = await run(retimed.map((file) => `./${file}`), []);
684 const againTests = testsOfLastRun();
685 const judged = retimeVerdict(
686 binding,
687 again.code === 0
688 ? breaches(retimed.length === 1 && slice.length === 1 ? [{ file: retimed[0]!, seconds: again.seconds }] : [], againTests, SLOW_FILES, BUDGETS)
689 : undefined,
690 );
691 still = judged.still;
692 named.push(...judged.lines);
693 }
694 const note = `${named.map((line) => `${line}\n`).join("")}${breachReport(still)}`;
695 if (note !== "") {
696 const text = `${output.join("").endsWith("\n") ? "" : "\n"}${note}`;
697 output.push(text);
698 through?.(text);
699 }
700 overBudget = [...over.filter((b) => !budgetBinds(b.file)), ...still];
701 if (still.length > 0) code = 1;
702 }
635703 // Where the room went, named on the log of a red shard, before its
636704 // directories are removed: the next red says its own cause (#8679).
637705 if (code !== 0) {
@@ -664,6 +732,8 @@ async function runShardIn(
664732 code,
665733 output: text,
666734 seconds: (performance.now() - started) / 1000,
735 tests,
736 overBudget,
667737 };
668738 }
669739
@@ -721,6 +791,7 @@ if (record || timed) {
721791 const target = record ? TIMES : CACHED_TIMES;
722792 if (!record) mkdirSync(CHECK_CACHE, { recursive: true });
723793 writeFileSync(target, formatTimes(fresh));
794 if (!record) writeFileSync(CACHED_TEST_TIMES, formatTestTimes(results.flatMap((result) => result.tests)));
724795 console.log(
725796 `test-shards: wrote ${results.length} times to ${record ? "scripts/test-times.json" : CACHED_TIMES}`,
726797 );
@@ -762,7 +833,10 @@ if (timed)
762833 memory: cgroupMemory(readLimit),
763834 wallSeconds: wall,
764835 times: results.map((result) => ({ file: result.files[0]!, seconds: result.seconds })),
765 }).join("\n")}`,
836 }).join("\n")}\n${slowestTestLines(
837 results.flatMap((result) => result.tests),
838 results.reduce((sum, result) => sum + result.seconds, 0),
839 ).join("\n")}\n${breachClosing(results.flatMap((result) => result.overBudget), BUDGETS).join("\n")}`,
766840 );
767841
768842 /**
test/check-list.test.ts +33 −1
@@ -9,7 +9,7 @@ import { describe, expect, test } from "bun:test";
99 import { mkdirSync, mkdtempSync, readdirSync, readFileSync, rmSync, writeFileSync } from "node:fs";
1010 import { tmpdir } from "node:os";
1111 import { join } from "node:path";
12 import { auditGate, EXCLUDED, gateFiles, gateRefusal, treeGate } from "../scripts/gate.ts";
12 import { auditGate, EXCLUDED, gateFiles, gateRefusal, SLOW, slowRefusal, treeGate } from "../scripts/gate.ts";
1313
1414 const root = new URL("..", import.meta.url).pathname;
1515 const present = readdirSync(`${root}test`)
@@ -23,6 +23,10 @@ describe("the gate's list", () => {
2323 expect(gateRefusal(present)).toEqual([]);
2424 });
2525
26 test("every SLOW entry names a gated file that exists, once, with a reason and an issue (#1242)", () => {
27 expect(slowRefusal(present, SLOW, EXCLUDED)).toEqual([]);
28 });
29
2630 test("the gate is every present test file not excluded", () => {
2731 const out = new Set(EXCLUDED.map((e) => e.file));
2832 expect(gateFiles()).toEqual(present.filter((f) => !out.has(f)));
@@ -105,6 +109,34 @@ describe("gateRefusal", () => {
105109 });
106110 });
107111
112 describe("slowRefusal", () => {
113 const present = ["test/a.test.ts", "test/b.test.ts"];
114 test("a sound list is no refusal", () => {
115 expect(slowRefusal(present, [{ file: "test/a.test.ts", reason: "boots a sandbox", issue: 7 }], [])).toEqual([]);
116 });
117
118 test("a stale, doubled, unreasoned or unowned entry is named, and the last line names the file to fix", () => {
119 const entry = { file: "test/a.test.ts", reason: "", issue: 0 };
120 expect(slowRefusal(present, [entry, entry, { file: "test/gone.test.ts", reason: "x", issue: 1 }], [])).toEqual([
121 "test/a.test.ts is in SLOW with no reason",
122 "test/a.test.ts is in SLOW with no issue number",
123 "test/a.test.ts is in SLOW twice",
124 "test/a.test.ts is in SLOW with no reason",
125 "test/a.test.ts is in SLOW with no issue number",
126 "test/gone.test.ts is in SLOW but does not exist",
127 "test/a.test.ts, test/gone.test.ts: fix its SLOW entry in scripts/gate.ts",
128 ]);
129 });
130
131 test("a file both excluded and slow is refused: an excluded file is never timed", () => {
132 const one = { file: "test/b.test.ts", reason: "slow", issue: 2 };
133 expect(slowRefusal(present, [one], [one])).toEqual([
134 "test/b.test.ts is in both EXCLUDED and SLOW",
135 "test/b.test.ts: fix its SLOW entry in scripts/gate.ts",
136 ]);
137 });
138 });
139
108140 describe("treeGate: the gate an older commit's tree names", () => {
109141 const tree = (gate: string, tests: string[]): string => {
110142 const dir = mkdtempSync(join(tmpdir(), "forge-tree-gate-"));
test/test-budget-run.test.ts added +85
@@ -0,0 +1,85 @@
1 /**
2 * The test budget binds in the gate's runner (#1242): a test over its
3 * budget in a file the pull changed turns the fast tier red with a `(fail)`
4 * line naming the fix, even after it is timed again, and so does the whole
5 * gate; the same file run by hand is named over budget and stays green. One fixture tree, built
6 * once.
7 *
8 * @not-a-tree-scan: it lists only the repository's test names, to make an
9 * audit-clean fixture, and reads nothing else of the tree.
10 */
11 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
12 import { mkdirSync, mkdtempSync, rmSync, writeFileSync } from "node:fs";
13 import { tmpdir } from "node:os";
14 import { join } from "node:path";
15 import { presentTests } from "../scripts/gate.ts";
16
17 const script = new URL("../scripts/test-shards.ts", import.meta.url).pathname;
18 let dir = "";
19
20 const git = (...args: string[]): number =>
21 Bun.spawnSync(["git", "-c", "user.name=t", "-c", "user.email=t@t", "-c", "commit.gpgsign=false", ...args], {
22 cwd: dir,
23 stdout: "ignore",
24 stderr: "ignore",
25 }).exitCode;
26
27 const runner = async (args: string[], env: Record<string, string> = {}): Promise<{ code: number; out: string }> => {
28 const child = Bun.spawn(["bun", script, ...args], {
29 cwd: dir,
30 // The budget tightened so a 60 ms test is over it: no slow fixture.
31 env: { ...process.env, FORGE_CHECK_SHARDS: "1", FORGE_TEST_BUDGET_SECONDS: ",0.02", ...env },
32 stdin: "ignore",
33 stdout: "pipe",
34 stderr: "pipe",
35 });
36 const [out, err] = await Promise.all([new Response(child.stdout).text(), new Response(child.stderr).text()]);
37 return { code: await child.exited, out: out + err };
38 };
39
40 beforeAll(() => {
41 dir = mkdtempSync(join(tmpdir(), "forge-budget-"));
42 mkdirSync(join(dir, "test"));
43 for (const file of presentTests()) writeFileSync(join(dir, file), "");
44 expect(git("init", "-q")).toBe(0);
45 expect(git("add", "-A")).toBe(0);
46 expect(git("commit", "-qm", "base")).toBe(0);
47 writeFileSync(
48 join(dir, "test/zz-budget.test.ts"),
49 `import { expect, test } from "bun:test";
50 test("spins past the budget", () => {
51 const end = performance.now() + 60;
52 while (performance.now() < end) {}
53 expect(true).toBe(true);
54 });
55 `,
56 );
57 expect(git("add", "-A")).toBe(0);
58 expect(git("commit", "-qm", "a slow test")).toBe(0);
59 });
60
61 afterAll(() => rmSync(dir, { recursive: true, force: true }));
62
63 describe("the budget in the runner", () => {
64 test("the fast tier is red on a test over budget in a file the pull changed", async () => {
65 const got = await runner(["--tier", "fast", "--diff", "HEAD~1..HEAD"]);
66 expect(got.out).toContain("test/zz-budget.test.ts:\n(fail) spins past the budget took ");
67 expect(got.out).toContain("over the 0.02 s test budget: make it faster, or name its file in SLOW in scripts/gate.ts");
68 expect(got.out).toContain("1 failed.");
69 expect(got.code).toBe(1);
70 }, 20_000);
71
72 test("the whole gate is red on it too", async () => {
73 const got = await runner(["--gate"], { FORGE_CHECK_ONLY: "test/zz-budget.test.ts" });
74 expect(got.out).toContain("test/zz-budget.test.ts:\n(fail) spins past the budget took ");
75 expect(got.out).toContain("1 failed.");
76 expect(got.code).toBe(1);
77 }, 20_000);
78
79 test("by hand the same file is named over budget and stays green", async () => {
80 const got = await runner(["test/zz-budget.test.ts"]);
81 expect(got.out).toContain("test-shards: over budget (not enforced here): test/zz-budget.test.ts > spins past the budget took ");
82 expect(got.out).not.toContain("(fail)");
83 expect(got.code).toBe(0);
84 }, 20_000);
85 });
test/test-budget.test.ts added +165
@@ -0,0 +1,165 @@
1 /**
2 * The test budget's judgement (`scripts/test-budget.ts`, #1242): a gated
3 * file over its seconds, or one test over its own, is a `(fail)` the shard
4 * tally counts, unless `SLOW` names the file; a breach that is under budget
5 * when timed again alone stands cleared and named.
6 */
7 import { describe, expect, test } from "bun:test";
8 import { failingTests, tally } from "../scripts/shards.ts";
9 import {
10 breaches,
11 breachClosing,
12 breachReport,
13 breachWarnings,
14 budgetsFrom,
15 FILE_BUDGET_SECONDS,
16 formatTestTimes,
17 parseJunit,
18 retimeVerdict,
19 slowestTestLines,
20 TEST_BUDGET_SECONDS,
21 } from "../scripts/test-budget.ts";
22
23 const junit = `<?xml version="1.0" encoding="UTF-8"?>
24 <testsuites name="bun test" tests="3" time="0.5">
25 <testsuite name="test/a.test.ts" file="test/a.test.ts" tests="3" time="0">
26 <testsuite name="group &amp; co" file="test/a.test.ts" tests="2" time="0">
27 <testcase name="says &quot;hi&quot; &lt;soon&gt;" classname="group &amp; co" time="2.5" file="test/a.test.ts" line="3" assertions="1" />
28 <testcase name="quick" classname="group &amp; co" time="0.000925" file="./test/a.test.ts" line="4" assertions="1" />
29 </testsuite>
30 <testcase name="top" classname="" time="1.25" file="test/a.test.ts" line="9" assertions="1">
31 <failure type="AssertionError" />
32 </testcase>
33 <testcase name="no file" time="9" />
34 <testcase name="no time" file="test/a.test.ts" time="" />
35 </testsuite>
36 </testsuites>`;
37
38 describe("parseJunit", () => {
39 test("each case with a file and a time: name under its describe, entities read, ./ dropped", () => {
40 expect(parseJunit(junit)).toEqual([
41 { file: "test/a.test.ts", test: 'group & co > says "hi" <soon>', seconds: 2.5 },
42 { file: "test/a.test.ts", test: "group & co > quick", seconds: 0.000925 },
43 { file: "test/a.test.ts", test: "top", seconds: 1.25 },
44 ]);
45 });
46
47 test("what is not a report yields nothing", () => {
48 expect(parseJunit("")).toEqual([]);
49 expect(parseJunit("not xml <testcase")).toEqual([]);
50 });
51 });
52
53 describe("breaches", () => {
54 const tests = parseJunit(junit);
55 test("a file over the file budget and a test over the test budget, slowest first", () => {
56 expect(breaches([{ file: "test/a.test.ts", seconds: FILE_BUDGET_SECONDS + 1 }, { file: "test/b.test.ts", seconds: 1 }], tests, new Set())).toEqual([
57 { file: "test/a.test.ts", seconds: FILE_BUDGET_SECONDS + 1, budget: FILE_BUDGET_SECONDS },
58 { file: "test/a.test.ts", test: 'group & co > says "hi" <soon>', seconds: 2.5, budget: TEST_BUDGET_SECONDS },
59 ]);
60 });
61
62 test("a file SLOW names is held to neither budget", () => {
63 expect(breaches([{ file: "test/a.test.ts", seconds: 99 }], tests, new Set(["test/a.test.ts"]))).toEqual([]);
64 });
65
66 test("exactly at the budget is within it", () => {
67 expect(breaches([{ file: "test/a.test.ts", seconds: FILE_BUDGET_SECONDS }], [], new Set())).toEqual([]);
68 });
69 });
70
71 describe("budgetsFrom", () => {
72 test("only ever tightens the constants", () => {
73 expect(budgetsFrom(undefined)).toEqual({ file: FILE_BUDGET_SECONDS, test: TEST_BUDGET_SECONDS });
74 expect(budgetsFrom("0.5,0.01")).toEqual({ file: 0.5, test: 0.01 });
75 expect(budgetsFrom("999,999")).toEqual({ file: FILE_BUDGET_SECONDS, test: TEST_BUDGET_SECONDS });
76 expect(budgetsFrom("-1,abc")).toEqual({ file: FILE_BUDGET_SECONDS, test: TEST_BUDGET_SECONDS });
77 expect(budgetsFrom(",0.2")).toEqual({ file: FILE_BUDGET_SECONDS, test: 0.2 });
78 });
79 });
80
81 describe("breachReport", () => {
82 const over = breaches([{ file: "test/a.test.ts", seconds: 30 }], parseJunit(junit), new Set());
83
84 test("reads back as failing tests of the file, the way a red bun test does", () => {
85 const named = failingTests(breachReport(over));
86 expect([...named.keys()]).toEqual(["test/a.test.ts"]);
87 expect(named.get("test/a.test.ts")).toHaveLength(2);
88 expect(named.get("test/a.test.ts")![1]).toStartWith('group & co > says "hi" <soon> took 2.50 s, over the 2 s test budget');
89 });
90
91 test("the shard tally counts each as a failure, and says the fix", () => {
92 const output = `Ran 3 tests across 1 file. [30.00s]\n${breachReport(over)}`;
93 const ending = tally([{ files: ["test/a.test.ts"], code: 1, output }], 30);
94 expect(ending.code).toBe(1);
95 expect(ending.lines.filter((line) => line.startsWith("(fail) "))).toHaveLength(2);
96 expect(ending.lines.join("\n")).toContain("name its file in SLOW in scripts/gate.ts with an issue");
97 });
98
99 test("nothing over is no report, and a warning names without (fail)", () => {
100 expect(breachReport([])).toBe("");
101 expect(breachWarnings(over).every((line) => line.startsWith("test-shards: over budget (not enforced here): "))).toBe(true);
102 });
103 });
104
105 describe("retimeVerdict", () => {
106 const first = [
107 { file: "test/a.test.ts", seconds: 25, budget: 20 },
108 { file: "test/a.test.ts", test: "t", seconds: 3, budget: 2 },
109 ];
110 test("what is over again stands, at its second time; what is under is cleared and named", () => {
111 const got = retimeVerdict(first, [{ file: "test/a.test.ts", test: "t", seconds: 2.4, budget: 2 }]);
112 expect(got.still).toEqual([{ file: "test/a.test.ts", test: "t", seconds: 2.4, budget: 2 }]);
113 expect(got.lines).toEqual(["test-shards: over budget once, under it timed again alone: test/a.test.ts"]);
114 });
115
116 test("a re-run that went red clears nothing; a breach new in the re-run is not added", () => {
117 expect(retimeVerdict(first, undefined)).toEqual({ still: first, lines: [] });
118 expect(retimeVerdict([], [{ file: "test/b.test.ts", seconds: 30, budget: 20 }]).still).toEqual([]);
119 });
120 });
121
122 describe("breachClosing", () => {
123 test("the count, then every breach slowest first, so a log's tail names them all", () => {
124 const lines = breachClosing(
125 [
126 { file: "test/b.test.ts", test: "t", seconds: 2.5, budget: 2 },
127 { file: "test/a.test.ts", seconds: 25, budget: 20 },
128 ],
129 { file: 20, test: 2 },
130 );
131 expect(lines).toEqual([
132 "test-shards: over the budget (20 s a file, 2 s a test), SLOW aside: 2",
133 " 25.0s test/a.test.ts (the whole file)",
134 " 2.50s test/b.test.ts > t",
135 ]);
136 expect(breachClosing([], { file: 20, test: 2 })).toEqual(["test-shards: over the budget (20 s a file, 2 s a test), SLOW aside: 0"]);
137 });
138 });
139
140 describe("slowestTestLines", () => {
141 test("the five slowest with their share of the run's work", () => {
142 const tests = [0.1, 4, 2, 1, 3, 0.5, 0.2].map((seconds, i) => ({ file: "test/a.test.ts", test: `t${i}`, seconds }));
143 const lines = slowestTestLines(tests, 100);
144 expect(lines[0]).toBe("test-shards: slowest 5 tests, 10.5% of 100.0s of work:");
145 expect(lines.slice(1).map((line) => line.trim())).toEqual([
146 "4.00s 4.0% test/a.test.ts > t1",
147 "3.00s 3.0% test/a.test.ts > t4",
148 "2.00s 2.0% test/a.test.ts > t2",
149 "1.00s 1.0% test/a.test.ts > t3",
150 "0.50s 0.5% test/a.test.ts > t5",
151 ]);
152 expect(slowestTestLines([], 100)).toEqual([]);
153 });
154 });
155
156 describe("formatTestTimes", () => {
157 test("file to test to seconds, in name order, to the millisecond", () => {
158 const text = formatTestTimes([
159 { file: "test/b.test.ts", test: "z", seconds: 0.12345 },
160 { file: "test/a.test.ts", test: "y", seconds: 1 },
161 { file: "test/b.test.ts", test: "a", seconds: 0.0004 },
162 ]);
163 expect(text).toBe(`${JSON.stringify({ "test/a.test.ts": { y: 1 }, "test/b.test.ts": { a: 0, z: 0.123 } }, null, 2)}\n`);
164 });
165 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs