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

finishing.ts says why it skips each approved, conflicted pull (log line + tick field): 21 have waited 3 h with nothing queued #6239

Merged opened this in answer to

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

Merged

mason/forge:mason/6237-finishing-ts-says-why-it-skips-each-appr → main 2 commits fork 2 threads · 2 unresolved

  • Merged. mason/6237-finishing-ts-says-why-it-skips-each-appr was merged into main as 8ba5ee0.

Review

Sign in to review this change.
6 files changed +214 −23
docs/PLANNING.md +2 −1
@@ -425,7 +425,8 @@ asked, under **Settings → Autonomy**:
425425 to a pull with changes requested, then to a new issue, and one whose
426426 two updates ended without a push is handed to the person who turned
427427 autonomy on — assigned to them, not closed (`crew/finishing.ts`; the
428 tick line says `finishing=N` and `conflict="N waiting"`). The planner's next pass splits or rewrites a parked
428 tick line says `finishing="queued Q, in flight F, skipped S: <why>×k"`,
429 and each skipped pull is logged once per reason as `finishing: skip pull=N why="…"`). The planner's next pass splits or rewrites a parked
429430 issue, and one parked twice is handed to the planner (below). The planner
430431 keeps a standing reserve of startable work — two issues per builder
431432 slot, never fewer than three — and is asked whenever fewer than that can
src/crew/autonomy.ts +3 −2
@@ -1288,8 +1288,9 @@ export async function autonomyTick(
12881288 ...flowVitals(app.db, now),
12891289 active: status.active,
12901290 slots: status.slots,
1291 // Approved pulls being brought up to date, those still waiting (#3682),
1292 // and the lane for rebases: conflicted N, rebasing M, room R (#6140).
1291 // Approved conflicted pulls: queued, in flight, and why each other is
1292 // skipped (#3682, #6237); and the lane for rebases: conflicted N,
1293 // rebasing M, room R (#6140).
12931294 ...finishFields(finishing, readConflictLane(app.db)),
12941295 ...(requested.length === 0
12951296 ? {}
src/crew/finishing.ts +44 −15
@@ -25,6 +25,11 @@
2525 * whoever turned autonomy on, so it is on their review list, with the
2626 * conflict named. Never retried forever, and never closed: the work was
2727 * approved.
28 * - Held, it is left as it is, and counted conflicted on the lane.
29 *
30 * Each one not brought up to date is logged once per reason as
31 * `finishing: skip pull=N why="…"`, and the tick line tallies them:
32 * `finishing="queued Q, in flight F, skipped S: <why>×k, …"` (#6237).
2833 *
2934 * Changes requested come after (`requested.ts`), then new issues
3035 * (`driveRepo`). The conflict sweep and the green sweep leave approved
@@ -66,31 +71,49 @@ export type FinishMove =
6671 | { readonly pull: number; readonly did: "handed to a person"; readonly to: string }
6772 | { readonly pull: number; readonly did: "not moved"; readonly why: string };
6873
74 const notMoved = (pull: Pull, why: string): FinishMove => ({ pull: pull.number, did: "not moved", why });
75
6976 /** Whether the pull's head carries an approval and no change requested: what lands once it merges. */
7077 export function approvedOnHead(db: Database, pull: Pull): boolean {
7178 const seen = reviewSummary(db, pull.id, pull.headOid);
7279 return seen.approvals > 0 && seen.changesRequested === 0;
7380 }
7481
82 /** Why a pull was not brought up to date this tick: the not-moved reason, or the hand-over. */
83 function skipWhy(move: FinishMove): string | undefined {
84 if (move.did === "not moved") return move.why;
85 if (move.did === "handed to a person") return "handed to a person";
86 return undefined;
87 }
88
7589 /**
76 * The tick line's numbers: pulls being brought up to date, the rest still
77 * waiting, and, given the lane, `conflicted N, rebasing M, room R` — this
90 * The tick line's words: `queued Q, in flight F, skipped S: <why>×k, …` —
91 * every approved conflicted pull, and why each skipped one was (#6237) —
92 * and, given the lane, `conflicted N, rebasing M, room R`: this
7893 * repository's approved conflicted pulls against the forge-wide lane
79 * (#6140) — whenever any is conflicted or rebasing.
94 * (#6140), whenever any is conflicted or rebasing.
8095 */
8196 export function finishFields(
8297 moves: readonly FinishMove[],
8398 lane?: ConflictLane,
84 ): { finishing?: number; conflict?: string; lane?: string } {
85 const finishing = moves.filter((m) => m.did === "queued update" || m.did === "in flight").length;
86 const waiting = moves.length - finishing;
99 ): { finishing?: string; lane?: string } {
100 const queued = moves.filter((m) => m.did === "queued update").length;
101 const inFlight = moves.filter((m) => m.did === "in flight").length;
102 const whys = new Map<string, number>();
103 for (const move of moves) {
104 const why = skipWhy(move);
105 if (why !== undefined) whys.set(why, (whys.get(why) ?? 0) + 1);
106 }
107 const skipped = moves.length - queued - inFlight;
108 const reasons = [...whys].map(([why, k]) => `${why}×${k}`).join(", ");
87109 const words =
88110 lane === undefined
89111 ? null
90112 : rebaseLaneSays({ conflicted: moves.length, rebasing: lane.runs + lane.checks, room: lane.room });
91113 return {
92 ...(finishing === 0 ? {} : { finishing }),
93 ...(waiting === 0 ? {} : { conflict: `${waiting} waiting` }),
114 ...(moves.length === 0
115 ? {}
116 : { finishing: `queued ${queued}, in flight ${inFlight}, skipped ${skipped}${skipped === 0 ? "" : `: ${reasons}`}` }),
94117 ...(words === null ? {} : { lane: words }),
95118 };
96119 }
@@ -140,13 +163,18 @@ export async function finishApproved(app: App, repo: Repo, free: number): Promis
140163 if (run.actorId !== null) load.set(run.actorId, (load.get(run.actorId) ?? 0) + 1);
141164 for (const pull of open.sort((a, b) => a.number - b.number)) {
142165 if (!pull.authorIsAgent || pull.mergedAt !== null) continue;
143 if (getHold(app.db, pull.id) !== undefined) continue;
144166 if (!approvedOnHead(app.db, pull)) continue;
145167 const files = await conflictOf(app, repo, pull);
146168 if (files === undefined) continue;
169 // From here every pull is approved and conflicted: one not brought up
170 // to date says why, on its own line and on the tick line (#6237).
147171 const issue = getIssueById(app.db, pull.id);
148172 if (!issue || issue.state !== "open") continue;
149 const move = finishOne(app, repo, pull, issue, files, builders, load, slots, room);
173 const hold = getHold(app.db, pull.id);
174 const move =
175 hold !== undefined
176 ? notMoved(pull, `held by ${hold.heldByName}`)
177 : finishOne(app, repo, pull, issue, files, builders, load, slots, room);
150178 if (move.did === "queued update") {
outdated

Unreachable per the PR text, and untested. Remove it, or test it.

151179 slots--;
152180 room--;
@@ -180,7 +208,7 @@ function finishOne(
180208 slots: number,
181209 room: number,
182210 ): FinishMove {
183 const not = (why: string): FinishMove => ({ pull: pull.number, did: "not moved", why });
211 const not = (why: string): FinishMove => notMoved(pull, why);
184212 if (activeRunFor(app.db, "agent", pull.id) !== undefined) return { pull: pull.number, did: "in flight" };
185213 // A person's name on it is a person holding it — after a hand-over too.
186214 if (issue.assigneeId !== null && getAgent(app.db, issue.assigneeId) === undefined)
@@ -256,7 +284,7 @@ function failedUpdates(app: App, issue: Issue, builder: Agent): number {
256284
257285 /** Two updates failed: the pull is the person's who turned autonomy on, with the conflict named. */
258286 function handOver(app: App, repo: Repo, pull: Pull, issue: Issue, files: readonly string[]): FinishMove {
259 const not = (why: string): FinishMove => ({ pull: pull.number, did: "not moved", why });
287 const not = (why: string): FinishMove => notMoved(pull, why);
260288 const by = getUserById(app.db, repo.autonomyBy!);
261289 if (by === undefined) return not("nobody to hand it to");
262290 const assigned = assignIssue(app, by, repo, issue, by);
@@ -280,12 +308,13 @@ function handOver(app: App, repo: Repo, pull: Pull, issue: Issue, files: readonl
280308 const said = new Map<string, string>();
281309
282310 function say(repo: Repo, pull: Pull, move: FinishMove): void {
283 const where = { repo: `${repo.ownerName}/${repo.name}`, pull: pull.number };
311 const where = `${repo.ownerName}/${repo.name}`;
284312 const key = `${repo.id}:${pull.number}`;
285313 if (move.did === "queued update") {
286314 said.delete(key);
287315 log.info("approved pull conflicts: brought up to date first", {
288 ...where,
316 repo: where,
317 pull: pull.number,
289318 builder: move.builder,
290319 ...(move.for === undefined ? {} : { for: move.for }),
291320 });
@@ -295,5 +324,5 @@ function say(repo: Repo, pull: Pull, move: FinishMove): void {
295324 const line = `${pull.headOid}:${move.why}`;
296325 if (said.get(key) === line) return;
297326 said.set(key, line);
298 log.info(`approved pull conflicts: not moved, ${move.why}`, where);
327 log.info("finishing: skip", { pull: pull.number, why: move.why, repo: where });
299328 }
test/finishing-skips.test.ts added +154
@@ -0,0 +1,154 @@
1 /**
2 * The finishing pass says why it skips each approved, conflicted pull
3 * (#6237): one `finishing: skip pull=N why="…"` line per pull, said again
4 * only when the reason changes, and the tick line's
5 * `finishing="queued Q, in flight F, skipped S: <why>×k"`.
6 */
7 import { afterAll, beforeAll, expect, spyOn, test } from "bun:test";
8 import { mkdtemp, rm } from "node:fs/promises";
9 import { tmpdir } from "node:os";
10 import { join } from "node:path";
11 import { createApp, type App } from "../src/app.ts";
12 import { addToCrew, createAgent } from "../src/actions/crew.ts";
13 import { openPull } from "../src/actions/pulls.ts";
14 import { commitToBranch, createRepo } from "../src/actions/repos.ts";
15 import { setCrewRole } from "../src/core/agents.ts";
16 import { setCapacity } from "../src/core/capacity.ts";
17 import { setHold } from "../src/core/holds.ts";
18 import type { Pull } from "../src/core/pulls.ts";
19 import { getRepoById, type Repo } from "../src/core/repos.ts";
20 import { submitReview } from "../src/core/reviews.ts";
21 import { createRun, listRuns } from "../src/core/runs.ts";
22 import { createUser, getUserByName, type User } from "../src/core/users.ts";
23 import { finishApproved, finishFields, type FinishMove } from "../src/crew/finishing.ts";
24 import { NO_BUILDER_ON_CREW, WAITS_FOR_BUILDER_SLOT } from "../src/crew/words.ts";
25 import { conflictedPulls } from "../src/flow/conflicted.ts";
26
27 let dataDir: string;
28 let app: App;
29 let alice: User;
30 let repo: Repo;
31 const pulls: Pull[] = [];
32
33 /** One finishing pass with `free` slots, its moves and the skip lines it logged. */
34 async function pass(free: number): Promise<{ moves: FinishMove[]; skips: string[] }> {
35 const lines: string[] = [];
36 const spy = spyOn(console, "info").mockImplementation((line: unknown) => {
37 lines.push(String(line));
38 });
39 try {
40 const moves = await finishApproved(app, getRepoById(app.db, repo.id)!, free);
41 return { moves, skips: lines.filter((l) => l.includes("finishing: skip")) };
42 } finally {
43 spy.mockRestore();
44 }
45 }
46
47 const skipOf = (skips: readonly string[], n: number) => skips.filter((l) => l.includes(`pull=${n} `));
48
49 beforeAll(async () => {
50 dataDir = await mkdtemp(join(tmpdir(), "forge-finishing-skips-"));
51 app = createApp({ dataDir, port: 0 });
52 const a = await createUser(app.db, {
53 origin: "seed",
54 trusted: true,
55 username: "alice",
56 email: "[email protected]",
57 password: "a-good-passphrase",
58 adminIfFirst: true,
59 });
60 if (!a.ok) throw new Error(a.error);
61 alice = a.value;
62 const made = await createRepo(app, alice, { name: "engine", visibility: "private" });
63 if (!made.ok) throw new Error(String(made.error));
64 repo = made.value;
65 const seeded = await commitToBranch(app, alice, repo, {
66 message: "Start",
67 files: [{ path: "shared.ts", content: "export const shared = 0;\n" }],
68 });
69 if (!seeded.ok) throw new Error(JSON.stringify(seeded.error));
70 for (const name of ["mason", "quill"]) {
71 const agent = await createAgent(app, alice, { username: name });
72 if (!agent.ok) throw new Error(String(agent.error));
73 expect(addToCrew(app, alice, repo, name).ok).toBe(true);
74 }
75 const mason = getUserByName(app.db, "mason")!;
76 const quill = getUserByName(app.db, "quill")!;
77 setCrewRole(app.db, repo.id, quill.id, "reviewer");
78 for (const n of [1, 2, 3]) {
79 const branch = await commitToBranch(app, alice, repo, {
80 branch: `feature/${n}`,
81 base: "main",
82 message: `Shared, branch ${n}'s way`,
83 files: [{ path: "shared.ts", content: `export const shared = ${n};\n` }],
84 });
85 if (!branch.ok) throw new Error(JSON.stringify(branch.error));
86 const opened = await openPull(app, mason, repo, {
87 title: `Shared the way of ${n}`,
88 body: "",
89 baseBranch: "main",
90 headBranch: `feature/${n}`,
91 });
92 if (!opened.ok) throw new Error(String(opened.error));
93 pulls.push(opened.value);
94 const approved = submitReview(app.db, {
95 issueId: opened.value.id,
96 authorId: quill.id,
97 state: "approved",
98 commitOid: opened.value.headOid,
99 });
100 if (!approved.ok) throw new Error(approved.error);
101 }
102 const moved = await commitToBranch(app, alice, repo, {
103 branch: "main",
104 message: "Shared, main's way",
105 files: [{ path: "shared.ts", content: "export const shared = 'main';\n" }],
106 });
107 if (!moved.ok) throw new Error(JSON.stringify(moved.error));
108 // #1 is held, #2 is a person's, #3 is the crew's to bring up to date.
109 setHold(app.db, pulls[0]!.id, alice.id, "not yet");
110 app.db.query("UPDATE issue SET assignee_id = ?2 WHERE id = ?1").run(pulls[1]!.id, alice.id);
111 app.db
112 .query("UPDATE repo SET autonomy = 'autonomous', autonomy_by = ?2, autonomy_slots = 1 WHERE id = ?1")
113 .run(repo.id, alice.id);
114 });
115
116 afterAll(async () => {
117 app.close();
118 await rm(dataDir, { recursive: true, force: true });
119 });
120
121 test("each skipped pull is logged with its reason, and the tick line tallies them", async () => {
122 const { moves, skips } = await pass(0);
123 expect(skips).toHaveLength(3);
124 expect(skipOf(skips, 1)[0]).toContain('finishing: skip pull=1 why="held by alice"');
125 expect(skipOf(skips, 2)[0]).toContain('finishing: skip pull=2 why="a person has it"');
126 expect(skipOf(skips, 3)[0]).toContain(`finishing: skip pull=3 why=${JSON.stringify(WAITS_FOR_BUILDER_SLOT)}`);
127 expect(finishFields(moves).finishing).toBe(
outdated

Also assert the lane's conflicted count includes the held pull (behaviour change).

128 `queued 0, in flight 0, skipped 3: held by alice×1, a person has it×1, ${WAITS_FOR_BUILDER_SLOT}×1`,
129 );
130 // The held pull is still approved and conflicted: the lane counts it.
131 expect(finishFields(moves, { runs: 0, checks: 0, room: 1 }).lane).toBe("conflicted 3, rebasing 0, room 1");
132 expect(conflictedPulls(app.db).map((p) => p.number)).toContain(1);
133 });
134
135 test("said once per pull: a pass with the same reasons logs nothing", async () => {
136 const { moves, skips } = await pass(0);
137 expect(moves).toHaveLength(3);
138 expect(skips).toEqual([]);
139 });
140
141 test("a changed reason is said again, for that pull only", async () => {
142 // One check at a time, and a rebase already in it: no room in the lane.
143 setCapacity(app.db, "checks.concurrency", "1", alice.id);
144 createRun(app.db, { repoId: repo.id, kind: "agent", issueId: pulls[0]!.id, reason: "conflict" });
145 const full = await pass(1);
146 expect(full.skips).toHaveLength(1);
147 expect(full.skips[0]).toContain('finishing: skip pull=3 why="waits for room in the check lane"');
148 expect(listRuns(app.db, repo.id, { kind: "agent" }).filter((r) => r.issueId === pulls[2]!.id)).toHaveLength(0);
149
150 setCrewRole(app.db, repo.id, getUserByName(app.db, "mason")!.id, "reviewer");
151 const none = await pass(1);
152 expect(none.skips).toHaveLength(1);
153 expect(none.skips[0]).toContain(`finishing: skip pull=3 why=${JSON.stringify(NO_BUILDER_ON_CREW)}`);
154 });
test/finishing.test.ts +7 −4
@@ -138,7 +138,7 @@ test("with one slot, the approved conflicted pull is brought up to date before t
138138 expect(picked()).toHaveLength(0);
139139 expect(getIssueById(app.db, ready.id)!.assigneeId).toBeNull();
140140 expect(line).toContain("did=full");
141 expect(line).toContain("finishing=1");
141 expect(line).toContain('finishing="queued 1, in flight 0, skipped 0"');
142142 // In flight: the next tick queues no second, and still picks nothing.
143143 await tick();
144144 expect(conflicts()).toHaveLength(1);
@@ -161,7 +161,7 @@ test("two updates that end without a push hand the pull to a person, open and on
161161 const notes = listComments(app.db, pull.id).filter((c) => c.body.startsWith(HANDOVER_NOTE));
162162 expect(notes).toHaveLength(1);
163163 expect(notes[0]!.body).toContain("shared.ts");
164 expect(line).toContain('conflict="1 waiting"');
164 expect(line).toContain('finishing="queued 0, in flight 0, skipped 1: handed to a person×1"');
165165 // The slot it no longer needs goes to the ready issue.
166166 expect(getIssueById(app.db, ready.id)!.assigneeId).toBe(mason.id);
167167
@@ -181,7 +181,7 @@ test("two updates that end without a push hand the pull to a person, open and on
181181 expect(asks).toContain("Shared the branch&#39;s way");
182182 });
183183
184 test("the tick line's fields: finishing counts what moves, conflict what waits", () => {
184 test("the tick line's field: finishing counts what moves, and tallies why the rest wait", () => {
185185 expect(finishFields([])).toEqual({});
186186 expect(
187187 finishFields([
@@ -189,6 +189,9 @@ test("the tick line's fields: finishing counts what moves, conflict what waits",
189189 { pull: 2, did: "in flight" },
190190 { pull: 3, did: "not moved", why: "waits for a builder slot" },
191191 { pull: 4, did: "handed to a person", to: "alice" },
192 { pull: 5, did: "not moved", why: "waits for a builder slot" },
192193 ]),
193 ).toEqual({ finishing: 2, conflict: "2 waiting" });
194 ).toEqual({
195 finishing: "queued 1, in flight 1, skipped 3: waits for a builder slot×2, handed to a person×1",
196 });
194197 });
test/rebase-lane.test.ts +4 −1
@@ -175,7 +175,10 @@ describe("the lane reads as conflicted N, rebasing M, room R", () => {
175175 ],
176176 { runs: 1, checks: 2, room: 0 },
177177 );
178 expect(fields).toEqual({ finishing: 1, conflict: "1 waiting", lane: "conflicted 2, rebasing 3, room 0" });
178 expect(fields).toEqual({
179 finishing: "queued 1, in flight 0, skipped 1: waits for room in the check lane×1",
180 lane: "conflicted 2, rebasing 3, room 0",
181 });
179182 expect(finishFields([])).toEqual({});
180183 });
181184

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs