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

A full-suite red report quotes the failing assertion and the lines around it, and says how to reproduce it #12304

Merged opened this

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

Merged

scout/forge:scout/12295-a-full-suite-red-report-quotes-the-faili → main 3 commits fork

  • Merged. scout/12295-a-full-suite-red-report-quotes-the-faili was merged into main as c1f25a9.

Review

Sign in to review this change.
3 files changed +290 −6
src/checks/report.ts +184 −4
@@ -15,6 +15,8 @@ import { getRepo, type Repo } from "../core/repos.ts";
1515 import { ownRepoPath } from "../kernel/own_repo.ts";
1616 import type { CheckDetail, Run } from "../core/runs.ts";
1717 import { failedTests, fileIssueOnce } from "./flake.ts";
18 import { isSummaryLine } from "./bun-test.ts";
19 import { safeFile } from "./verify.ts";
1820
1921 /** The label every report issue carries. */
2022 export const REPORT_LABEL = "full-suite";
@@ -28,20 +30,197 @@ export const reportTitle = (file: string): string => `Full suite red: ${file}`;
2830 /** How every report issue's body opens: with the label and title, what tells it from one a person wrote. */
2931 const FILED_BY = "_Filed by the scheduled full-suite report, not written by a person.";
3032
31 /** A red verification's detail with the failing tests under its failing files (at most {@link MAX_FAILURES}). */
33 /** The most lines of one failing test's own output the report quotes (#12295). */
34 export const EXCERPT_LINES = 30;
35 /** The longest line the report quotes; the rest is cut. */
36 export const LINE_MAX = 200;
37 /**
38 * The most failing tests a run quotes, and the most one file's issue quotes: with the caps above,
39 * an issue stays a few kilobytes.
40 */
41 const QUOTED = 10;
42 const QUOTED_PER_FILE = 3;
43 /** How the report's second command reruns a file to catch a flake (#12295). */
44 export const RERUN = "--rerun-each 10";
45 /** The most files of a shard the report names in its command. */
46 const SLICE_MAX = 20;
47
48 const HEADER = /^(\S+\.test\.[cm]?[jt]sx?):$/;
49 const RESULT = /^\((pass|fail|skip|todo)\) /;
50 const SHARD = /^── shard (\d+\/\d+)(?: \([^)]*\))?: (.*)$/;
51 const AT_A_TIME = /^test-shards: .*?\b(\d+) at a time\b/;
52 const IN_SHARDS = /^test-shards: \d+ files in (\d+) shards?\b/;
53 const SERIAL = /^test-shards: \d+ files serial\b/;
54 // eslint-disable-next-line no-control-regex
55 const ANSI = /\u001b\[[0-9;?]*[A-Za-z]/g;
56 // eslint-disable-next-line no-control-regex
57 const CONTROL = /[\u0000-\u0008\u000b-\u001f\u007f-\u009f]/g;
58
59 /**
60 * One log line as the report may quote it: no colour codes or control characters, tabs as spaces,
61 * at most {@link LINE_MAX} long.
62 */
63 function clean(line: string): string {
64 const plain = line.replace(ANSI, "").replace(/\t/g, " ").replace(CONTROL, "").trimEnd();
65 return plain.length > LINE_MAX ? `${plain.slice(0, LINE_MAX - 1)}…` : plain;
66 }
67
68 /**
69 * The lines of a test's own output worth quoting: from a few before its first `error:` (bun's
70 * source excerpt), at most {@link EXCERPT_LINES}.
71 */
72 function excerptOf(block: readonly string[]): string[] {
73 if (block.length <= EXCERPT_LINES) return [...block];
74 const error = block.findIndex((l) => l.startsWith("error:"));
75 const from = error < 0 ? block.length - EXCERPT_LINES : Math.min(Math.max(0, error - 8), block.length - EXCERPT_LINES);
76 return block.slice(from, from + EXCERPT_LINES);
77 }
78
79 /**
80 * What the log says of each quoted failure, of each failing file's shard, and of how the suite ran.
81 */
82 function quoted(lines: readonly string[], files: readonly string[], names: readonly { file: string; name: string }[]) {
83 const wanted = new Set(names.map((n) => `${n.file}\0${n.name}`));
84 const quotes = new Map<string, { assertion?: string; excerpt: string[] }>();
85 const perFile = new Map<string, number>();
86 const shards = new Map<string, { shard: string; slice: string[] }>();
87 let concurrency: string | undefined;
88 let shard: { shard: string; slice: string[] } | undefined;
89 let file: string | undefined;
90 let block: string[] = [];
91 // The window around a test's first `error:` line, kept whole however much it prints after.
92 let pinned: string[] | undefined;
93 let cut = false;
94 const reset = (): void => {
95 block = [];
96 pinned = undefined;
97 cut = false;
98 };
99 for (const raw of lines) {
100 const line = clean(raw);
101 if (concurrency === undefined) {
102 const files = AT_A_TIME.exec(line)?.[1];
103 const side = IN_SHARDS.exec(line)?.[1];
104 if (files !== undefined) concurrency = `${files} files at a time`;
105 else if (side !== undefined) concurrency = `${side} shards side by side`;
106 else if (SERIAL.test(line)) concurrency = "one file at a time";
107 }
108 const head = SHARD.exec(line);
109 if (head !== null) {
110 shard = { shard: head[1]!, slice: head[2]!.split(" ").map((f) => f.replace(/^\.\//, "")).filter(safeFile) };
111 continue;
112 }
113 const header = HEADER.exec(line);
114 if (header !== null) {
115 file = header[1]!.replace(/^\.\//, "");
116 reset();
117 if (shard !== undefined && files.includes(file) && !shards.has(file)) shards.set(file, shard);
118 continue;
119 }
120 if (isSummaryLine(line)) {
121 file = undefined;
122 reset();
123 continue;
124 }
125 if (file === undefined) continue;
126 const result = RESULT.exec(line);
127 if (result === null) {
128 if (pinned === undefined && line.startsWith("error:")) pinned = [...block.slice(-8), line];
129 else if (pinned !== undefined && pinned.length < EXCERPT_LINES) pinned.push(line);
130 block.push(line);
131 // Only a window can be quoted: a test that prints ten thousand lines keeps a bounded block.
132 if (block.length > EXCERPT_LINES * 4) {
133 block = block.slice(-EXCERPT_LINES * 2);
134 cut = true;
135 }
136 continue;
137 }
138 const name = result[1] === "fail" ? (line.match(/^\(fail\) (.+?)(?: \[[0-9.]+m?s\])?(?: \[shard [0-9]+\])?$/)?.[1] ?? "") : "";
139 const key = `${file}\0${name}`;
140 const count = perFile.get(file) ?? 0;
141 if (block.length > 0 && wanted.has(key) && !quotes.has(key) && quotes.size < QUOTED && count < QUOTED_PER_FILE) {
142 const assertion = (pinned ?? block).find((l) => l.startsWith("error:"));
143 const excerpt =
144 cut && pinned !== undefined
145 ? [...pinned.slice(0, EXCERPT_LINES - 2), "…", line]
146 : excerptOf([...block, line]);
147 quotes.set(key, { ...(assertion === undefined ? {} : { assertion }), excerpt });
148 perFile.set(file, count + 1);
149 }
150 reset();
151 }
152 return { quotes, shards, concurrency };
153 }
154
155 /**
156 * A red verification's detail with the failing tests under its failing files (at most {@link
157 * MAX_FAILURES}), the first few quoted from the log (#12295).
158 */
32159 export function redDetail(
33160 detail: CheckDetail | undefined,
34161 files: readonly string[],
35162 lines: readonly string[],
36163 ): CheckDetail | undefined {
37164 if (files.length === 0) return detail;
165 const failing = failedTests(lines).filter((t) => files.includes(t.file)).slice(0, MAX_FAILURES);
166 const said = quoted(lines, files, failing);
38167 return {
39168 ...(detail ?? { passed: 0, failed: files.length, names: [] }),
40169 files,
41 failures: failedTests(lines).filter((t) => files.includes(t.file)).slice(0, MAX_FAILURES),
170 failures: failing.map((t) => ({ ...t, ...said.quotes.get(`${t.file}\0${t.name}`) })),
171 ...(said.shards.size === 0
172 ? {}
173 : { shards: [...said.shards].map(([file, s]) => ({ file, shard: s.shard, slice: s.slice.slice(0, SLICE_MAX + 1) })) }),
174 ...(said.concurrency === undefined ? {} : { concurrency: said.concurrency }),
42175 };
43176 }
44177
178 /**
179 * `text` as a code span or block that nothing in it can close: the fence is longer than any run of
180 * backticks inside.
181 */
182 function fence(text: string): string {
183 const longest = Math.max(0, ...(text.match(/`+/g) ?? []).map((run) => run.length));
184 return "`".repeat(Math.max(3, longest + 1));
185 }
186
187 /**
188 * What a report says of one failing file: each quoted failure, then how to reproduce it (#12295).
189 */
190 export function redBody(detail: CheckDetail | null | undefined, file: string): string {
191 const quotes = (detail?.failures ?? []).filter((f) => f.file === file && f.excerpt !== undefined);
192 const parts: string[] = [];
193 for (const q of quotes) {
194 const output = q.excerpt!.join("\n");
195 const f = fence(output);
196 const head = q.assertion === undefined ? "" : `: ${inline(q.assertion)}`;
197 parts.push(`${inline(q.name)} failed${head}\n\n${f}text\n${output}\n${f}`);
198 }
199 const shard = detail?.shards?.find((s) => s.file === file);
200 const repro = [`bun test ./${file}`, `bun test ./${file} ${RERUN}`];
201 if (shard !== undefined && shard.slice.length > 1 && shard.slice.length <= SLICE_MAX)
202 repro.push(`bun test ${shard.slice.map((f) => `./${f}`).join(" ")}`);
203 const ran = [
204 shard === undefined ? undefined : `in shard ${shard.shard}`,
205 shard !== undefined && shard.slice.length > 1 ? `beside ${shard.slice.length - 1} other file${shard.slice.length === 2 ? "" : "s"}` : undefined,
206 detail?.concurrency,
207 ].filter((s) => s !== undefined);
208 parts.push(
209 `To reproduce:\n\n\`\`\`sh\n${repro.join("\n")}\n\`\`\`\n\n` +
210 (ran.length === 0
211 ? "The run's log did not say which shard it ran in."
212 : `The full suite ran it ${ran.join(", ")}${repro.length > 2 ? " (the last command runs that shard as one `bun test`)" : ""}.`),
213 );
214 return parts.join("\n\n");
215 }
216
217 /** `text` as one inline code span, whatever backticks it holds. */
218 function inline(text: string): string {
219 const longest = Math.max(0, ...(text.match(/`+/g) ?? []).map((run) => run.length));
220 const tick = "`".repeat(longest + 1);
221 return `${tick} ${text} ${tick}`;
222 }
223
45224 function labelOf(app: App, repo: Repo): Label | undefined {
46225 const made = createLabel(app.db, repo.id, REPORT_LABEL, REPORT_COLOR);
47226 return made.ok ? made.value : getLabel(app.db, repo.id, REPORT_LABEL);
@@ -60,12 +239,13 @@ export function reportRed(app: App, repo: Repo, run: Run): string[] {
60239 const more = names.length > NAMED ? `\n- and ${names.length - NAMED} more` : "";
61240 const where = `check run ${run.id}, ${run.commitOid.slice(0, 7)}`;
62241 const title = reportTitle(file);
242 const told = redBody(run.checkDetail, file);
63243 const filed = fileIssueOnce(app.db, app.bus, repo, {
64244 title,
65245 body:
66246 `${FILED_BY} It holds no pull, batch or release._\n\n` +
67247 `\`${file}\` failed in the full suite on ${repo.defaultBranch} (${where}).` +
68 `${said}${more}\n\nFiles: ${file}`,
248 `${said}${more}\n\n${told}\n\nFiles: ${file}`,
69249 ...(label === undefined ? {} : { labelId: label.id }),
70250 });
71251 if (filed.number === 0) lines.push(`report: ${file} not filed`);
@@ -78,7 +258,7 @@ export function reportRed(app: App, repo: Repo, run: Run): string[] {
78258 addComment(app.db, {
79259 issueId: open.id,
80260 authorId: repo.ownerId,
81 body: `Still red in the full suite (${where}).${said}${more}`,
261 body: `Still red in the full suite (${where}).${said}${more}\n\n${told}`,
82262 });
83263 lines.push(`report: added to #${filed.number} for ${file}`);
84264 }
src/core/runs.ts +15 −1
@@ -47,7 +47,21 @@ export interface CheckDetail {
4747 /** The test files the failures printed under, when a verification after landing failed (#7786). */
4848 readonly files?: readonly string[];
4949 /** The failing tests under those files, at most forty, for the report that files them (#7780). */
50 readonly failures?: readonly { readonly file: string; readonly name: string }[];
50 readonly failures?: readonly {
51 readonly file: string;
52 readonly name: string;
53 /** The `error:` line bun printed for it, cut from the run's own log (#12295). */
54 readonly assertion?: string;
55 /** Up to thirty lines of its own output, ending at its `(fail)` line (#12295). */
56 readonly excerpt?: readonly string[];
57 }[];
58 /**
59 * Where each failing file ran in the full suite: its shard and the files beside it in that shard
60 * (#12295).
61 */
62 readonly shards?: readonly { readonly file: string; readonly shard: string; readonly slice: readonly string[] }[];
63 /** How many files or shards the full suite ran side by side, as its banner said (#12295). */
64 readonly concurrency?: string;
5165 /** The check machine's free disk share (0..1) when a red finished (#5453). */
5266 readonly diskFree?: number;
5367 /** `temp_full`: a shard ran out of temp space, the environment's fault, not the change's (#8679). */
test/full-suite-report.test.ts +91 −1
@@ -11,7 +11,7 @@ import { join } from "node:path";
1111 import { createApp, type App } from "../src/app.ts";
1212 import { createRepo } from "../src/actions/repos.ts";
1313 import { flowLines } from "../src/tui/screens/flow.ts";
14 import { MAX_FAILURES, redDetail, reportGreen, reportRed, reportTitle, REPORT_LABEL } from "../src/checks/report.ts";
14 import { RERUN, EXCERPT_LINES, LINE_MAX, MAX_FAILURES, redBody, redDetail, reportGreen, reportRed, reportTitle, REPORT_LABEL } from "../src/checks/report.ts";
1515 import { failedTests } from "../src/checks/flake.ts";
1616 import { heldByRed, redMain } from "../src/checks/red_main.ts";
1717 import { failedFiles, passedFiles, VERIFY_ENV } from "../src/checks/verify.ts";
@@ -279,6 +279,96 @@ describe("the report", () => {
279279 expect(issueFor("test/a.test.ts").state).toBe("open");
280280 });
281281
282 /**
283 * A verification's log as test-shards prints it: banner, a shard header, bun's output for that
284 * shard (#12295).
285 */
286 const SHARD_LOG = [
287 "test-shards: measuring 120 files under coverage, one bun test each, 4 at a time",
288 "",
289 "── shard 7/120 (exit 1, 3.1s): test/z.test.ts test/a.test.ts",
290 "bun test v1.3.14 (0d9b296a)",
291 "test/a.test.ts:",
292 "(pass) a > ok [0.20ms]",
293 "noise before the error",
294 "4 | test(\"one\", () => {",
295 "5 | expect(\"<b>`x`</b>```\").toBe(2);",
296 "error: expect(received).toBe(expected)",
297 "Expected: 2",
298 "Received: \"<b>`x`</b>```\"",
299 " at <anonymous> (test/a.test.ts:5:3)",
300 "(fail) a > one [0.11ms]",
301 "",
302 "1 tests failed:",
303 "(fail) a > one [0.11ms]",
304 " 1 pass",
305 " 1 fail",
306 "Ran 2 tests across 2 files. [38.00ms]",
307 ];
308
309 const redFrom = (log: readonly string[], commit: string): Run => {
310 const run = createRun(app.db, { repoId: repo.id, kind: "check", env: VERIFY_ENV, commitOid: commit, reason: "schedule" });
311 const detail = redDetail({ passed: 1, failed: 1, names: ["a > one"] }, ["test/a.test.ts"], log);
312 app.db
313 .query("UPDATE run SET state = 'failed', check_detail = ?2, finished_at = ?3 WHERE id = ?1")
314 .run(run.id, JSON.stringify(detail), new Date().toISOString());
315 return getRun(app.db, run.id)!;
316 };
317
318 test("the issue quotes the failing assertion and its output, fenced so nothing in it closes the block (#12295)", () => {
319 reportRed(app, repo, redFrom(SHARD_LOG, "a".repeat(40)));
320 const body = reports()[0]!.body;
321 expect(body).toContain("error: expect(received).toBe(expected)");
322 expect(body).toContain("noise before the error\n4 | test(");
323 expect(body).toContain("Received: \"<b>`x`</b>```\"");
324 expect(body).toContain("````text\n");
325 expect(body).not.toContain("(pass) a > ok");
326 expect(body.indexOf("error:")).toBeLessThan(body.indexOf("Files: test/a.test.ts"));
327 });
328
329 test("the issue says how to reproduce it: the file, ten reruns, and the shard and concurrency it ran under (#12295)", () => {
330 reportRed(app, repo, redFrom(SHARD_LOG, "a".repeat(40)));
331 const body = reports()[0]!.body;
332 expect(body).toContain("bun test ./test/a.test.ts\n");
333 expect(body).toContain(`bun test ./test/a.test.ts ${RERUN}\n`);
334 expect(body).toContain("bun test ./test/z.test.ts ./test/a.test.ts\n");
335 expect(body).toContain("in shard 7/120, beside 1 other file, 4 files at a time");
336 });
337
338 test("each Still red comment carries the excerpt and the commands too (#12295)", () => {
339 reportRed(app, repo, redFrom(SHARD_LOG, "a".repeat(40)));
340 reportRed(app, repo, redFrom(SHARD_LOG, "b".repeat(40)));
341 const [comment] = listComments(app.db, reports()[0]!.id);
342 expect(comment!.body).toStartWith("Still red in the full suite");
343 expect(comment!.body).toContain("error: expect(received).toBe(expected)");
344 expect(comment!.body).toContain(`bun test ./test/a.test.ts ${RERUN}`);
345 });
346
347 test("a ten-thousand-line test output is cut to the line limit, around its error (#12295)", () => {
348 const noise = Array.from({ length: 10_000 }, (_, i) => `log ${i} ${"x".repeat(500)}`);
349 const log = ["test/a.test.ts:", ...noise, "error: boom", ...noise.slice(0, 5000), "(fail) a > one", "1 tests failed:"];
350 const detail = redDetail(undefined, ["test/a.test.ts"], log)!;
351 const [quote] = detail.failures!;
352 expect(quote!.excerpt!.length).toBeLessThanOrEqual(EXCERPT_LINES);
353 expect(quote!.excerpt!.every((l) => l.length <= LINE_MAX)).toBe(true);
354 expect(quote!.assertion).toBe("error: boom");
355 const body = redBody(detail, "test/a.test.ts");
356 expect(body.length).toBeLessThan(10_000);
357 expect(body).toContain(`bun test ./test/a.test.ts ${RERUN}`);
358 });
359
360 test("a failure that printed nothing is named, not quoted with its bare (fail) line", () => {
361 const detail = redDetail(undefined, ["test/a.test.ts"], ["test/a.test.ts:", "(fail) a > one", "1 tests failed:"])!;
362 expect(detail.failures).toEqual([{ file: "test/a.test.ts", name: "a > one" }]);
363 expect(redBody(detail, "test/a.test.ts")).not.toContain("```text");
364 });
365
366 test("a log with no shard banner still says how to reproduce, and that the shard is unknown", () => {
367 const body = redBody(redDetail(undefined, ["test/a.test.ts"], SHARD_LOG.slice(3)), "test/a.test.ts");
368 expect(body).toContain(`bun test ./test/a.test.ts ${RERUN}`);
369 expect(body).toContain("did not say which shard");
370 });
371
282372 test("the issue says only what the run recorded", () => {
283373 reportRed(app, repo, red(VERIFY_ENV, "a".repeat(40)));
284374 expect(reports()[0]!.body).not.toContain("run alone");

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs