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

A shared-red sentinel issue names the pulls that failed the test and quotes the failure, so a builder can reproduce it #8293

Merged opened this

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

Merged

scout/forge:scout/8286-a-shared-red-sentinel-issue-names-the-pu → main 2 commits fork 3 threads · 3 unresolved

  • Merged. scout/8286-a-shared-red-sentinel-issue-names-the-pu was merged into main as 546c64f.

Review

Sign in to review this change.
3 files changed +335 −7
src/checks/shared_red.ts +96
@@ -214,3 +214,99 @@ export function flakeHref(db: Database, t: SharedTest): string {
214214 export function sharedSentence(t: SharedTest): string {
215215 return `${t.repo}: "${t.test}" failed on ${t.pulls} pulls in the last hour — the lane's red, not theirs; they wait for main's next green check, unparked.`;
216216 }
217
218 /** One failed pull check on a shared test: which pull, which run, what base it merged. */
219 export interface SharedRun {
220 readonly runId: string;
221 readonly pull: number;
222 readonly baseOid: string;
223 }
224
225 /** How many of a shared test's failed checks a finding names (#8286). */
226 export const SHARED_RUNS_NAMED = 5;
227
228 /**
229 * The failed pull checks in the window on the test a shared cause names,
230 * newest first, at most {@link SHARED_RUNS_NAMED} (#8286): what a builder
231 * needs to find the log and reproduce the red. Undefined when none is left.
232 */
233 const FAILED_RUNS = `
234 SELECT run.id AS run_id, i.number AS pull, run.base_oid AS base_oid, n.value AS test
235 FROM run
236 JOIN issue i ON i.id = run.issue_id,
237 json_each(CASE WHEN json_valid(run.check_detail) THEN run.check_detail ELSE '{}' END, '$.names') n
238 WHERE run.repo_id = ?1 AND run.id >= ?2 AND run.finished_at >= ?3
239 AND run.kind = 'check' AND run.state = 'failed' AND n.type = 'text'
240 ORDER BY run.id DESC`;

The slice to SHARED_RUNS_NAMED is untested: record six failed pulls and assert only the newest five are named.

241
242 export function sharedRuns(
243 db: Database,
244 cause: string,
245 now: number = Date.now(),
246 ): { test: string; runs: SharedRun[] } | undefined {
247 const repoId = cause.split(":")[1] ?? "";
248 const rows = db
249 .query<{ run_id: string; pull: number; base_oid: string; test: string }, [string, string, string]>(FAILED_RUNS)
250 .all(repoId, idFloor(now - SHARED_WINDOW_MS - QUEUED_SLACK_MS), new Date(now - SHARED_WINDOW_MS).toISOString())
251 .filter((r) => sharedCause({ repoId, test: r.test }) === cause);
252 const first = rows[0];
253 if (first === undefined) return undefined;
254 return {
255 test: first.test,
256 runs: rows.slice(0, SHARED_RUNS_NAMED).map((r) => ({ runId: r.run_id, pull: r.pull, baseOid: r.base_oid })),
257 };
258 }
259
260 /** Main's newest finished check, and whether it failed the named test. */
261 export function mainVerdict(
262 db: Database,
263 repoId: string,
264 test: string,
265 ): { runId: string; commitOid: string; passes: boolean } | undefined {
266 const row = db
267 .query<{ id: string; commit_oid: string; state: string; check_detail: string | null }, [string]>(
268 `SELECT r.id, r.commit_oid, r.state, r.check_detail FROM run r JOIN repo ON repo.id = r.repo_id
269 WHERE r.repo_id = ?1 AND r.kind = 'check' AND r.issue_id IS NULL
270 AND r.env = repo.default_branch AND r.state IN ('ok', 'failed')
271 ORDER BY r.id DESC LIMIT 1`,

The failed state with the named test is the branch a builder cares about most (main is red too, so it is not a pull problem) and it is untested. Add a main run finished failed with checkDetail names including the test, and one failed on another test that must report passes.

272 )
273 .get(repoId);
274 if (row === null) return undefined;
275 let names: unknown = [];
276 try {
277 names = (JSON.parse(row.check_detail ?? "{}") as { names?: unknown }).names ?? [];
278 } catch {
279 names = [];
280 }
281 const failsIt = row.state === "failed" && Array.isArray(names) && names.includes(test);
282 return { runId: row.id, commitOid: row.commit_oid, passes: row.state === "ok" || !failsIt };
283 }
284
285 /** The most lines of a failing test's output a finding quotes. */
286 export const ASSERTION_LINES = 20;
287
288 const RESULT = /^\((?:pass|fail|skip|todo)\) /;
289 const FILE_HEADER = /^\S+\.test\.[cm]?[jt]sx?:$/;
290 /** bun's closing tally: a `(fail)` line under it is the recap, not the report. */
291 const TALLY = /^\s*\d+ (?:pass|fail|skip|todo)$|^\d+ tests? failed:$|^Ran \d+ tests? /;
292
293 /**
294 * What bun printed for one failing test: the lines above its `(fail)` line,
295 * back to the result or file header before them, at most
296 * {@link ASSERTION_LINES}. The newest report wins; bun's recap of `(fail)`
297 * lines under its tally quotes nothing. Empty when no report is in `lines`.
298 */
299 export function assertionLines(lines: readonly string[], test: string): string[] {
300 for (let at = lines.length - 1; at >= 0; at--) {
301 const line = lines[at]!;
302 if (line !== `(fail) ${test}` && !line.startsWith(`(fail) ${test} [`)) continue;
303 let from = at;
304 while (from > 0 && at - from < ASSERTION_LINES && !RESULT.test(lines[from - 1]!) && !FILE_HEADER.test(lines[from - 1]!))
305 from--;
306 const block = lines.slice(from, at);
307 if (block.some((l) => TALLY.test(l))) continue;
308 const quoted = block.filter((l) => l.trim() !== "");
309 if (quoted.length > 0) return quoted;
310 }
311 return [];
312 }
src/crew/sentinel.ts +64 −7
@@ -32,7 +32,15 @@ import { spans } from "../kernel/degraded_history.ts";
3232 import { QUEUE_WAIT_MAX_MS } from "../kernel/vitals.ts";
3333 import { STALE_AFTER_MS } from "../runs/lease.ts";
3434 import { isOutageSummary } from "./network.ts";
35 import { pullsFailedSince, SHARED_PULLS, SHARED_WINDOW_MS } from "../checks/shared_red.ts";
35 import {
36 assertionLines,
37 mainVerdict,
38 pullsFailedSince,
39 SHARED_PULLS,
40 SHARED_WINDOW_MS,
41 sharedRuns,
42 } from "../checks/shared_red.ts";
43 import { readRunLogTail } from "../runs/log.ts";
3644 import { clip } from "../text/clip.ts";
3745
3846 const log = createLog("sentinel");
@@ -367,7 +375,7 @@ export function repeatedErrors(now: number): Finding[] {
367375 * Each cause whose spans total more than ten minutes in the day ending at
368376 * `now`, quoting its sentence. Shorter totals stay in the history.
369377 */
370 export function degradedCauses(db: Database, now: number, forgeRepoId?: string): Finding[] {
378 export function degradedCauses(db: Database, now: number, forgeRepoId?: string, dataDir?: string): Finding[] {
371379 const from = now - DAY_MS;
372380 const byCause = new Map<string, { sentence: string; href: string; first: number; opened: number; ms: number }>();
373381 for (const s of spans(db, from, now)) {
@@ -397,6 +405,7 @@ export function degradedCauses(db: Database, now: number, forgeRepoId?: string):
397405 `first open: ${new Date(d.first).toISOString()}`,
398406 `total: ${minutes} minutes in the day`,
399407 `href: ${d.href}`,
408 ...sharedLines(db, cause, now, forgeRepoId, dataDir),
400409 ],
401410 pillar: "P0 Trust: the forge says when it is not well, and is well again",
402411 lookFor: `\`${cause}\` stays out of the degraded list for a day, or holds under ${DEGRADED_DAY_MS / 60_000} minutes.`,
@@ -436,7 +445,7 @@ export function ownCause(cause: string, forgeRepoId: string | undefined): boolea
436445 * at once, not when the day has added up. The finding shares its key with
437446 * `degradedCauses`, so one cause is one issue.
438447 */
439 export function budgetBreaches(db: Database, now: number, forgeRepoId?: string): Finding[] {
448 export function budgetBreaches(db: Database, now: number, forgeRepoId?: string, dataDir?: string): Finding[] {
440449 const out: Finding[] = [];
441450 for (const s of spans(db, now - DAY_MS, now)) {
442451 if (s.closedAt !== null || !BREACH_CAUSE.test(s.cause) || !ownCause(s.cause, forgeRepoId)) continue;
@@ -449,6 +458,7 @@ export function budgetBreaches(db: Database, now: number, forgeRepoId?: string):
449458 `since: ${new Date(s.openedAt).toISOString()}`,
450459 `href: ${s.href}`,
451460 ...runLogLines(db, s.cause),
461 ...sharedLines(db, s.cause, now, forgeRepoId, dataDir),
452462 ],
453463 pillar: "P0 Trust: the forge says when it is not well, and is well again",
454464 lookFor: `\`${s.cause}\` is gone from the degraded list and the cause is fixed, not waited out.`,
@@ -476,16 +486,63 @@ function runLogLines(db: Database, cause: string): string[] {
476486 return run === null ? [] : [`run ${id}: ${run.state}${run.summary ? `, ${oneLine(run.summary)}` : ""}`];
477487 }
478488
489 /** How many log lines a shared finding reads from the end of its newest run's log: never the whole file. */
490 const SHARED_LOG_TAIL = 400;
491
492 /**
493 * What a builder needs to reproduce a `shared:` cause (#8286): the pulls
494 * and runs that failed its test, newest first, the base the newest merged,
495 * the newest one's assertion lines from the tail of its log, and whether
496 * main's newest check passes the test. A private repository's pulls and log
497 * lines stay out of a finding filed anywhere but in that repository.
498 */
499 function sharedLines(
500 db: Database,
501 cause: string,
502 now: number,
503 forgeRepoId: string | undefined,
504 dataDir: string | undefined,
505 ): string[] {
506 if (!cause.startsWith("shared:")) return [];
507 const repoId = cause.split(":")[1] ?? "";
508 const repo = db
509 .query<{ visibility: string }, [string]>("SELECT visibility FROM repo WHERE id = ?1")
510 .get(repoId);
511 if (repo === null || (repo.visibility !== "public" && repoId !== forgeRepoId)) return [];
512 const found = sharedRuns(db, cause, now);
513 if (found === undefined) return [];
514 const [newest] = found.runs;
515 const out = [
516 `test: ${oneLine(found.test)}`,
517 ...found.runs.map((r) => `failed: pull #${r.pull}, check run ${r.runId}`),
518 ];
519 if (newest !== undefined) {
520 out.push(`base: ${newest.baseOid || "none recorded"} (run ${newest.runId})`);

The none recorded fallback for an empty base_oid has no test. Add a run without setRunBase and assert the line.

521 const quoted =
522 dataDir === undefined ? [] : assertionLines(readRunLogTail(dataDir, newest.runId, SHARED_LOG_TAIL).lines, found.test);
523 out.push(...quoted.map((l) => `log: ${clip(oneLine(l), QUOTE_MAX)}`));
524 }
525 const main = mainVerdict(db, repoId, found.test);
526 out.push(
527 main === undefined
528 ? "main: no check of main recorded"
529 : main.passes
530 ? `main: passes on main's newest check, run ${main.runId} at ${main.commitOid}`
531 : `main: fails on main's newest check too, run ${main.runId} at ${main.commitOid}`,
532 );
533 return out;
534 }
535
479536 /** Everything the sentinel reads, in one pass. */
480 export function findFaults(db: Database, now = Date.now(), forgeRepoId?: string): Finding[] {
537 export function findFaults(db: Database, now = Date.now(), forgeRepoId?: string, dataDir?: string): Finding[] {
481538 const found = [
482 ...budgetBreaches(db, now, forgeRepoId),
539 ...budgetBreaches(db, now, forgeRepoId, dataDir),
483540 ...heldSlots(db, now),
484541 ...strayTriggers(db),
485542 ...ledgerStreaks(db, now),
486543 ...runStreaks(db),
487544 ...repeatedErrors(now),
488 ...degradedCauses(db, now, forgeRepoId),
545 ...degradedCauses(db, now, forgeRepoId, dataDir),
489546 ];
490547 const keys = new Set<string>();
491548 return found
@@ -746,7 +803,7 @@ export function hunt(
746803 let commented = 0;
747804 const [owner = "", name = ""] = repoPath.split("/");
748805 const repo = getRepo(app.db, owner, name);
749 const findings = findFaults(app.db, now, repo?.id);
806 const findings = findFaults(app.db, now, repo?.id, app.config.dataDir);
750807 const actor = sentinelActor(app.db);
751808 if (repo !== undefined && actor !== undefined) {
752809 for (const f of findings) {
test/sentinel-shared-evidence.test.ts added +175
@@ -0,0 +1,175 @@
1 /**
2 * A shared-red finding a builder can reproduce (#8286): it names the pulls
3 * and check runs that failed the test, quotes the newest run's assertion
4 * lines from the tail of its log, carries the base that run merged, and says
5 * whether main's newest check passes. A private repository's pulls and log
6 * lines never reach a finding filed elsewhere.
7 */
8 import { beforeEach, describe, expect, test } from "bun:test";
9 import type { Database } from "bun:sqlite";
10 import { mkdirSync, mkdtempSync, writeFileSync } from "node:fs";
11 import { tmpdir } from "node:os";
12 import { join } from "node:path";
13 import { migrations } from "../src/core/schema.ts";
14 import { openDb } from "../src/kernel/db.ts";
15 import { claimRun, createRun, finishRun, setRunBase, type Run } from "../src/core/runs.ts";
16 import { assertionLines, sharedCause } from "../src/checks/shared_red.ts";
17 import { budgetBreaches, degradedCauses } from "../src/crew/sentinel.ts";
18 import { runLogPath } from "../src/runs/log.ts";
19
20 const TEST = "board > a card keeps its place";
21 let db: Database;
22 let dataDir: string;
23
24 beforeEach(() => {
25 db = openDb(":memory:", migrations);
26 dataDir = mkdtempSync(join(tmpdir(), "shared-evidence-"));
27 mkdirSync(join(dataDir, "runs"));
28 db.run("INSERT INTO user (id, username, email, password_hash) VALUES ('u1', 'trevato', 't@x', '')");
29 db.run("INSERT INTO repo (id, owner_id, name, visibility) VALUES ('r1', 'u1', 'forge', 'public')");
30 for (const n of [41, 42, 43, 44, 45, 46])
31 db.run(`INSERT INTO issue (id, repo_id, number, kind, title, author_id) VALUES ('i${n}', 'r1', ${n}, 'pull', 'p', 'u1')`);
32 });
33
34 const red = (issueId: string, base: string, log: string[]): Run => {
35 const run = createRun(db, { repoId: "r1", kind: "check", env: `pull-${issueId}`, issueId, commitOid: "a".repeat(40), reason: "push" });
36 claimRun(db, run.id);
37 if (base !== "") setRunBase(db, run.id, base);
38 writeFileSync(runLogPath(dataDir, run.id), log.join("\n") + "\n");
39 return finishRun(db, run.id, { state: "failed", summary: "check failed", checkDetail: { passed: 9, failed: 1, names: [TEST] } })!;
40 };
41
42 const logOf = (said: string): string[] => [
43 "bun test v1.3.14",
44 "test/board.test.ts:",
45 "(pass) board > renders [1.00ms]",
46 `error: expect(received).toBe(expected)`,
47 `Expected: "${said}"`,
48 `Received: "moved"`,
49 " at <anonymous> (test/board.test.ts:12:5)",
50 `(fail) ${TEST} [3.00ms]`,
51 "",
52 " 9 pass",
53 " 1 fail",
54 "Ran 10 tests across 1 file. [1.00s]",
55 "1 tests failed:",
56 `(fail) ${TEST} [3.00ms]`,
57 ];
58
59 function recordThree(): Run[] {
60 return [
61 red("i41", "b".repeat(40), logOf("first")),
62 red("i42", "c".repeat(40), logOf("second")),
63 red("i43", "d".repeat(40), logOf("third")),
64 ];
65 }
66
67 const open = (now: number) =>
68 db.run("INSERT INTO degraded_span (cause, sentence, href, opened_at) VALUES (?1, 's', '/x', ?2)", [
69 sharedCause({ repoId: "r1", test: TEST }),
70 now - 20 * 60_000,
71 ]);
72
73 describe("a shared-red finding names its pulls and quotes the failure (#8286)", () => {
74 test("three failed checks: the pulls, their runs newest first, the newest's lines and base", () => {
75 const runs = recordThree();
76 const now = Date.now();
77 open(now);
78 const [found] = budgetBreaches(db, now, "r1", dataDir);
79 const ev = found!.evidence;
80 expect(ev).toContain(`test: ${TEST}`);
81 const failed = ev.filter((l) => l.startsWith("failed: "));
82 expect(failed).toEqual([
83 `failed: pull #43, check run ${runs[2]!.id}`,
84 `failed: pull #42, check run ${runs[1]!.id}`,
85 `failed: pull #41, check run ${runs[0]!.id}`,
86 ]);
87 expect(ev).toContain(`base: ${"d".repeat(40)} (run ${runs[2]!.id})`);
88 expect(ev.filter((l) => l.startsWith("log: "))).toEqual([
89 "log: error: expect(received).toBe(expected)",
90 'log: Expected: "third"',
91 'log: Received: "moved"',
92 "log: at <anonymous> (test/board.test.ts:12:5)",
93 ]);
94 expect(ev).toContain("main: no check of main recorded");
95 // The day's degraded finding for the same cause carries the same evidence.
96 expect(degradedCauses(db, now, "r1", dataDir)[0]!.evidence.filter((l) => l.startsWith("failed: "))).toEqual(failed);
97 });
98
99 test("it says whether main's newest check passes the test", () => {
100 recordThree();
101 const main = createRun(db, { repoId: "r1", kind: "check", env: "main", commitOid: "e".repeat(40), reason: "push" });
102 claimRun(db, main.id);
103 finishRun(db, main.id, { state: "ok", summary: "check passed" });
104 const now = Date.now();
105 open(now);
106 expect(budgetBreaches(db, now, "r1", dataDir)[0]!.evidence).toContain(
107 `main: passes on main's newest check, run ${main.id} at ${"e".repeat(40)}`,
108 );
109 });
110
111 const mainCheck = (state: "ok" | "failed", names: string[] = []): Run => {
112 const main = createRun(db, { repoId: "r1", kind: "check", env: "main", commitOid: "e".repeat(40), reason: "push" });
113 claimRun(db, main.id);
114 return finishRun(db, main.id, {
115 state,
116 summary: state === "ok" ? "check passed" : "check failed",
117 ...(state === "failed" ? { checkDetail: { passed: 9, failed: names.length, names } } : {}),
118 })!;
119 };
120
121 test("main red on the same test reads as failing on main too", () => {
122 recordThree();
123 const main = mainCheck("failed", [TEST]);
124 const now = Date.now();
125 open(now);
126 expect(budgetBreaches(db, now, "r1", dataDir)[0]!.evidence).toContain(
127 `main: fails on main's newest check too, run ${main.id} at ${"e".repeat(40)}`,
128 );
129 });
130
131 test("main red on another test still passes this one", () => {
132 recordThree();
133 const main = mainCheck("failed", ["some > other test"]);
134 const now = Date.now();
135 open(now);
136 expect(budgetBreaches(db, now, "r1", dataDir)[0]!.evidence).toContain(
137 `main: passes on main's newest check, run ${main.id} at ${"e".repeat(40)}`,
138 );
139 });
140
141 test("six failed pulls: only the newest five are named", () => {
142 const runs = [41, 42, 43, 44, 45, 46].map((n) => red(`i${n}`, "b".repeat(40), logOf(`${n}`)));
143 const now = Date.now();
144 open(now);
145 const failed = budgetBreaches(db, now, "r1", dataDir)[0]!.evidence.filter((l) => l.startsWith("failed: "));
146 expect(failed).toEqual(runs.slice(1).reverse().map((r, i) => `failed: pull #${46 - i}, check run ${r.id}`));
147 });
148
149 test("a run that merged no base says none was recorded", () => {
150 recordThree();
151 const last = red("i44", "", logOf("bare"));
152 const now = Date.now();
153 open(now);
154 expect(budgetBreaches(db, now, "r1", dataDir)[0]!.evidence).toContain(`base: none recorded (run ${last.id})`);
155 });
156
157 test("a private repository's pulls and log lines stay out of a finding filed elsewhere", () => {
158 db.run("UPDATE repo SET visibility = 'private' WHERE id = 'r1'");
159 recordThree();
160 const now = Date.now();
161 open(now);
162 const [elsewhere] = budgetBreaches(db, now, undefined, dataDir);
163 expect(elsewhere!.evidence.some((l) => /^(failed|log|base|test): /.test(l))).toBe(false);
164 // Filed in that same repository, its own readers see it.
165 expect(budgetBreaches(db, now, "r1", dataDir)[0]!.evidence.some((l) => l.startsWith("failed: "))).toBe(true);
166 });
167
168 test("the quote stops at twenty lines and skips bun's recap", () => {
169 const long = ["x.test.ts:", ...Array.from({ length: 30 }, (_, i) => `line ${i}`), `(fail) ${TEST}`, " 0 pass", " 1 fail", "1 tests failed:", `(fail) ${TEST}`];
170 const quoted = assertionLines(long, TEST);
171 expect(quoted).toHaveLength(20);
172 expect(quoted.at(-1)).toBe("line 29");
173 expect(assertionLines(["1 tests failed:", `(fail) ${TEST}`], TEST)).toEqual([]);
174 });
175 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs