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

Kill a run past its budget: re-queued once, a card the second time (#1270) #1352

Merged opened this

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

Merged

scout/forge:scout/1271-kill-a-run-past-its-budget-re-queued-onc → main 5 commits fork 3 threads · 3 unresolved

  • Merged. scout/1271-kill-a-run-past-its-budget-re-queued-onc was merged into main as 31c2dce.

Review

Sign in to review this change.
11 files changed +308 −6
README.md +6
@@ -251,6 +251,12 @@ file), and if you named an agent, the sentence became issue #1, assigned.
251251 redeployed on each push and gone when the pull closes. Its data starts as
252252 a copy of production's — copy-on-write where the filesystem can — and
253253 never writes back. Merging moves code and touches no data.
254 - **A run has a budget** (`src/kernel/budgets.ts`): a check past `gate`
255 (60 min) or a reviewer's run past `review` (10 min) is killed with
256 `budget: <what> took <n> min, limit <m>`, queued again once, and failed
257 the second time, which the vitals carry as a need for a day. `gate` is 60
258 min because this repository's own gate takes 18–25 min alone and 45 beside
259 another check; it comes down when the gate does.
254260 - **Every deploy is a run**, and the run is the check on the pull. Turn on
255261 **require checks** and a pull cannot merge until its head is green.
256262 - A **private** app answers only to someone the forge has vouched for
scripts/gate.ts +1
@@ -196,6 +196,7 @@ export const GATE: readonly string[] = [
196196 "test/origins.test.ts",
197197 "test/overlap.test.ts",
198198 "test/outsiders-switch.test.ts",
199 "test/check-budget.test.ts",
199200 "test/check-list.test.ts",
200201 "test/check-tiers.test.ts",
201202 "test/holds.test.ts",
src/checks/service.ts +43 −1
@@ -29,6 +29,7 @@ import {
2929 finishRun,
3030 listActive,
3131 noteRunProgress,
32 overranBefore,
3233 requeueCheck,
3334 REQUEUED_SUMMARY,
3435 sweepAbandonedChecks,
@@ -40,6 +41,7 @@ import { giveHistory } from "./history.ts";
4041 import { readLearned } from "./learned.ts";
4142 import { getIssueById } from "../core/issues.ts";
4243 import { repoDir } from "../git/repos.ts";
44 import { BUDGETS, budgetSummary } from "../kernel/budgets.ts";
4345 import { transact } from "../kernel/db.ts";
4446 import { createLog } from "../kernel/log.ts";
4547 import { holdLease } from "../runs/lease.ts";
@@ -71,6 +73,8 @@ export interface ChecksOptions {
7173 readonly concurrency?: number | undefined;
7274 /** The forge's public URL, told to the check as `FORGE_URL`. */
7375 readonly forgeUrl: string;
76 /** How long a check may run before it is killed. @default BUDGETS.gate */
77 readonly budgetMs?: number | undefined;
7478 }
7579
7680 export interface ChecksHandle {
@@ -355,7 +359,45 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
355359 const write = (line: string): void =>
356360 appendRunLog(app.config.dataDir, run.id, line);
357361 const started = Date.now();
358 const outcome = await check(claimed, repo, write, signal).finally(lease);
362 // The budget: past it the check is aborted, whatever it is doing.
363 const limit = options.budgetMs ?? BUDGETS.gate;
364 const budget = new AbortController();
365 let overran = false;
366 const forward = (): void => budget.abort();
367 signal.addEventListener("abort", forward, { once: true });
368 const clock = setTimeout(() => {
369 overran = true;
370 budget.abort();
371 }, limit);
372 const outcome = await check(claimed, repo, write, budget.signal).finally(
373 () => {
374 clearTimeout(clock);
375 signal.removeEventListener("abort", forward);
376 lease();
377 },
378 );
379 if (overran) {
380 const summary = budgetSummary(
381 "a full gate",
382 Date.now() - started,
383 limit,
384 );
385 write(summary);
386 if (!overranBefore(app.db, claimed)) {
387 const moved = requeueCheck(app.db, run.id, undefined, summary);
388 if (moved) {
389 announceRun(app, moved.again, run.actorId ?? undefined);
390 return;
391 }
392 }
393 // The second overrun: a failure, and the card the vitals carry.
394 const failed = finishRun(app.db, run.id, {
395 state: "failed",
396 summary,
397 });
398 if (failed) announceRun(app, failed);
399 return;
400 }
359401 if (!outcome.ok && stopped && signal.aborted) {
360402 // Cut off by this forge stopping, not by the check: the same check
361403 // goes back on the queue, and the forge that carries on runs it.
src/core/runs.ts +40 −1
@@ -9,6 +9,7 @@
99 */
1010
1111 import type { Database } from "bun:sqlite";
12 import { BUDGET_PREFIX } from "../kernel/budgets.ts";
1213 import { id } from "../kernel/id.ts";
1314
1415 export type RunKind = "deploy" | "agent" | "check";
@@ -399,6 +400,7 @@ export function requeueCheck(
399400 db: Database,
400401 runId: string,
401402 lapsedBefore?: string,
403 summary: string = REQUEUED_SUMMARY,
402404 ): { cancelled: Run; again: Run } | undefined {
403405 return db.transaction(() => {
404406 const changes = db
@@ -408,7 +410,7 @@ export function requeueCheck(
408410 WHERE id = ?1 AND kind = 'check' AND state = 'running'
409411 AND (?3 IS NULL OR heartbeat_at IS NULL OR heartbeat_at < ?3)`,
410412 )
411 .run(runId, REQUEUED_SUMMARY, lapsedBefore ?? null).changes;
413 .run(runId, summary, lapsedBefore ?? null).changes;
412414 if (changes === 0) return undefined;
413415 const cancelled = getRun(db, runId)!;
414416 const again = createRun(db, {
@@ -425,6 +427,43 @@ export function requeueCheck(
425427 })();
426428 }
427429
430 /**
431 * Whether the run before this one in its chain (the attempt just below, same
432 * kind, repository, reason and issue) was killed for its budget: the second
433 * overrun is a failure, not a second retry. The branch and commit are not
434 * compared: a run notes its branch as it works, its queued retry starts bare.
435 */
436 export function overranBefore(db: Database, run: Run): boolean {
437 return (
438 db
439 .query(
440 `SELECT 1 FROM run WHERE kind = ?1 AND repo_id = ?2 AND reason = ?3
441 AND COALESCE(issue_id, '') = ?4 AND attempt = ?5 AND id <> ?6
442 AND state = 'cancelled' AND summary LIKE ?7 || '%' LIMIT 1`,
443 )
444 .get(
445 run.kind,
446 run.repoId,
447 run.reason,
448 run.issueId ?? "",
449 run.attempt - 1,
450 run.id,
451 BUDGET_PREFIX,
452 ) !== null
453 );
454 }
455
456 /** Failed runs the budget killed since `since`: each is a card in the vitals. */
457 export function budgetFailures(db: Database, since: string): Run[] {
458 return db
459 .query<RunRow, [string, string]>(
460 `SELECT * FROM run WHERE state = 'failed' AND summary LIKE ?2 || '%'
461 AND finished_at >= ?1 ORDER BY finished_at DESC LIMIT 20`,
462 )
463 .all(since, BUDGET_PREFIX)
464 .map(toRun);
465 }
466
428467 /** What a sweep of abandoned checks did, run by run. */
429468 export interface AbandonedChecks {
430469 /** Cancelled and queued again: the cancelled run and its retry. */
src/crew/dispatch.ts +3 −1
@@ -898,7 +898,9 @@ function resumeLater(app: App, run: Run, pause: Pause): void {
898898 {
899899 notBefore: pause.resumeAt,
900900 attempt: pause.attempt,
901 summary: `paused on the provider's limit; resumes ${whenText(new Date(pause.resumeAt))}`,
901 summary:
902 pause.summary ??
903 `paused on the provider's limit; resumes ${whenText(new Date(pause.resumeAt))}`,
902904 },
903905 );
904906 log.info("run paused", {
src/crew/runner.ts +36
@@ -51,6 +51,7 @@ import {
5151 finishRun,
5252 lastAgentRun,
5353 noteRunProgress,
54 overranBefore,
5455 type Run,
5556 } from "../core/runs.ts";
5657 import { createToken, deleteToken } from "../core/tokens.ts";
@@ -60,6 +61,7 @@ import { runGitCapture } from "../git/env.ts";
6061 import { looksForEnv } from "../core/looks.ts";
6162 import { aheadCount, resolveOid } from "../git/merge.ts";
6263 import { repoDir } from "../git/repos.ts";
64 import { BUDGETS, budgetSummary } from "../kernel/budgets.ts";
6365 import { createLog, redactValues } from "../kernel/log.ts";
6466 import { err, ok, type Result } from "../kernel/result.ts";
6567 import { holdLease } from "../runs/lease.ts";
@@ -120,6 +122,8 @@ export interface CrewOptions {
120122 /** Spend per run when the agent's own budget is 0. */
121123 readonly budgetUsd: number;
122124 readonly runTimeoutMs: number;
125 /** How long a review run may take. @default BUDGETS.review */
126 readonly reviewBudgetMs?: number | undefined;
123127 /** A `CLAUDE_CONFIG_DIR` for runs, when the operator wants one. */
124128 readonly configDir?: string | undefined;
125129 /** Hosts an agent's shell may reach beyond the forge and the registry. */
@@ -267,6 +271,15 @@ export async function executeAgentRun(
267271 appendRunLog(app.config.dataDir, run.id, line);
268272 announceRun(app, claimed);
269273 const started = Date.now();
274 // A reviewer past its budget is stopped, whatever it is doing.
275 let overran = false;
276 const clock =
277 claimed.reason === "review"
278 ? setTimeout(() => {
279 overran = true;
280 controller.abort();
281 }, options.reviewBudgetMs ?? BUDGETS.review)
282 : undefined;
270283 const meter: Meter = {
271284 tokensIn: 0,
272285 tokensOut: 0,
@@ -292,6 +305,7 @@ export async function executeAgentRun(
292305 summary: `the run failed: ${String(error).slice(0, 200)}`,
293306 };
294307 } finally {
308 clearTimeout(clock);
295309 untrackAgentRun(run.id);
296310 steering.delete(run.id);
297311 lease();
@@ -302,6 +316,26 @@ export async function executeAgentRun(
302316 await reapOrphans(app, run, write);
303317 forgetLandedClone(app, run);
304318 meterUsage(app, claimed, outcome, meter, started);
319 if (overran) {
320 const summary = budgetSummary(
321 "a review run",
322 Date.now() - started,
323 options.reviewBudgetMs ?? BUDGETS.review,
324 );
325 write(summary);
326 if (!overranBefore(app.db, claimed)) {
327 const again = cancelRun(app.db, run.id, summary);

Next: verify resumeLater does not cancel this already-cancelled run again; the test only checks the final states.

328 if (again) announceRun(app, again);
329 return {
330 resumeAt: new Date().toISOString(),
331 attempt: run.attempt + 1,
332 summary: `${summary}; queued again`,
333 };
334 }
335 const failed = finishRun(app.db, run.id, { state: "failed", summary });
336 if (failed) announceRun(app, failed);
337 return undefined;
338 }
305339 if (outcome.state === "paused") {
306340 write(outcome.summary);
307341 noteRunProgress(app.db, run.id, {
@@ -548,6 +582,8 @@ function meterUsage(
548582 export interface Pause {
549583 readonly resumeAt: string;
550584 readonly attempt: number;
585 /** What the queued task says while it waits, when not the provider's limit. */
586 readonly summary?: string | undefined;
551587 }
552588
553589 async function work(
src/kernel/budgets.ts added +31
@@ -0,0 +1,31 @@
1 /**
2 * How long a run may take before it is a failure. One place, plain numbers:
3 * the checks service and the crew read these, and a run past its budget is
4 * killed, queued again once, and on the second overrun failed (#1271).
5 */
6
7 export const BUDGETS = {
8 /**
9 * A check run, in ms. Set from measurement, not from the 15 min the plan
10 * wants: this repository's own gate takes 18–25 min alone and 45 min
11 * beside another check, so 15 would fail every check it has. Lower it
12 * when the gate is sharded under it. There is no fast-tier budget until a
13 * fast tier exists to measure.
14 */
15 gate: 60 * 60_000,
16 /** A reviewer's run on a pull, in ms. */
17 review: 10 * 60_000,
18 } as const;
19
20 /** The summary prefix every budget kill carries; vitals and retries read it. */
21 export const BUDGET_PREFIX = "budget:";
22
23 /** What a run killed past its budget says as its summary. */
24 export function budgetSummary(
25 what: string,
26 tookMs: number,
27 limitMs: number,
28 ): string {
29 const min = (ms: number): number => Math.max(Math.round(ms / 60_000), 1);
30 return `${BUDGET_PREFIX} ${what} took ${min(tookMs)} min, limit ${min(limitMs)}`;
31 }
outdated

Exported but never imported, and src/core/runs.ts repeats budget: as a literal in two queries. Use this constant in budgetSummary and bind it in overranBefore and budgetFailures, or remove it.

src/kernel/vitals.ts +13 −1
@@ -12,7 +12,12 @@ import type { Database } from "bun:sqlite";
1212 import { statfsSync } from "node:fs";
1313 import { freemem, totalmem } from "node:os";
1414 import { recentErrors, type ErrorLine } from "./log.ts";
15 import { leaseLapsed, listRunning, queueDepth } from "../core/runs.ts";
15 import {
16 budgetFailures,
17 leaseLapsed,
18 listRunning,
19 queueDepth,
20 } from "../core/runs.ts";
1621 import { STALE_AFTER_MS } from "../runs/lease.ts";
1722
1823 /** Free disk under this share of the volume is something to say. */
@@ -98,6 +103,13 @@ export function vitals(input: VitalsInput): Vitals {
98103 `${stuck.length} run${stuck.length === 1 ? " is" : "s are"} stuck.`,
99104 );
100105
106 // A run killed twice for its budget is a card, for a day.
107 for (const run of budgetFailures(
108 input.db,
109 new Date(now - 24 * 3_600_000).toISOString(),
110 ))
111 needs.push(`A run was killed twice: ${run.summary}.`);

Next: say which repository/pull and link the run; "A run was killed twice: budget: a full gate took 61 min, limit 60." does not tell a person what to do. Clear it when a later run in the chain passes.

112
101113 const apps = { serving: 0, asleep: 0, previews: 0 };
102114 for (const e of input.envs ?? []) {
103115 if (e.env !== "production") apps.previews++;
test/check-budget.test.ts added +94
@@ -0,0 +1,94 @@
1 /**
2 * A check past its budget is killed, queued again once, and on the second
3 * overrun failed and carried by the vitals as a card (#1271).
4 */
5
6 import { afterAll, beforeAll, expect, test } from "bun:test";
7 import { mkdtemp, rm } from "node:fs/promises";
8 import { tmpdir } from "node:os";
9 import { join } from "node:path";
10 import { createApp, type App } from "../src/app.ts";
11 import { commitToBranch, createRepo } from "../src/actions/repos.ts";
12 import { startChecks, type ChecksHandle } from "../src/checks/service.ts";
13 import { BUDGETS, budgetSummary } from "../src/kernel/budgets.ts";
14 import { vitals } from "../src/kernel/vitals.ts";
15 import { listRuns } from "../src/core/runs.ts";
16 import { createUser } from "../src/core/users.ts";
17
18 process.env["FORGE_CELLS"] = "off";
19
20 let dataDir: string;
21 let app: App;
22 let checks: ChecksHandle;
23
24 beforeAll(async () => {
25 dataDir = await mkdtemp(join(tmpdir(), "forge-budget-"));
26 app = createApp({ dataDir, port: 0 });
27 checks = startChecks(app, {
28 forgeUrl: "http://forge.test",
29 concurrency: 1,
30 budgetMs: 1_500,
31 });
32 });
33
34 afterAll(async () => {
35 await checks.stop();
36 app.close();
37 await rm(dataDir, { recursive: true, force: true });
38 });
39
40 test("the summary names the thing, the time and the limit", () => {
41 expect(budgetSummary("a full gate", 18 * 60_000, BUDGETS.gate)).toBe(
42 "budget: a full gate took 18 min, limit 60",
43 );
44 });
45
46 test("a check past its budget is re-queued once; the second overrun fails it and is a card", async () => {
47 const u = await createUser(app.db, {
48 trusted: true,
49 username: "alice",
50 email: "[email protected]",
51 password: "a-good-passphrase",
52 adminIfFirst: true,
53 });
54 if (!u.ok) throw new Error(u.error);
55 const made = await createRepo(app, u.value, {
56 name: "slow",
57 visibility: "public",
58 });
59 if (!made.ok) throw new Error(String(made.error));
60 const repo = made.value;
61 const pushed = await commitToBranch(app, u.value, repo, {
62 message: "A check that never ends",
63 files: [
64 {
65 path: "forge.json",
66 content: `{"check": {"run": "sleep 30", "install": ""}}\n`,
67 },
68 ],
69 });
70 if (!pushed.ok) throw new Error(JSON.stringify(pushed.error));
71 const oid = pushed.value.commitOid;
72
73 const deadline = Date.now() + 30_000;
74 let runs = listRuns(app.db, repo.id, { kind: "check", limit: 50 });
75 while (
76 Date.now() < deadline &&
77 !runs.some((r) => r.commitOid === oid && r.state === "failed")
78 ) {
79 await Bun.sleep(100);
80 runs = listRuns(app.db, repo.id, { kind: "check", limit: 50 });
81 }
82 const mine = runs.filter((r) => r.commitOid === oid);
83 expect(mine).toHaveLength(2);
84 const first = mine.find((r) => r.attempt === 0)!;
85 const second = mine.find((r) => r.attempt === 1)!;
86 expect(first.state).toBe("cancelled");
87 expect(first.summary).toBe("budget: a full gate took 1 min, limit 1");
88 expect(second.state).toBe("failed");
89 expect(second.summary).toMatch(/^budget: a full gate took \d+ min, limit \d+$/);
90
91 const seen = vitals({ db: app.db, dataDir });
92 expect(seen.ok).toBe(false);
93 expect(seen.needs.some((n) => n.includes("budget: a full gate"))).toBe(true);
94 }, 60_000);
test/crew.test.ts +39
@@ -198,6 +198,7 @@ if grep -q DECLINE-ME "${promptFile}"; then
198198 exit 0
199199 fi
200200 if grep -q "You are the reviewer on this crew" "${promptFile}"; then
201 if grep -q SLOW-REVIEW "${promptFile}"; then exec sleep 60; fi
201202 path=$(grep -o 'api/v1/repos/[^"\\]*/review-states' "${promptFile}" | head -1)
202203 curl -sS -X POST -H "authorization: Bearer $FORGE_TOKEN" -H "content-type: application/json" "\${FORGE_URL%/}/$path" -d '{"state":"changes_requested","body":"Name the fence."}' > "${dataDir}/review.out"
203204 echo '{"type":"result","subtype":"success","is_error":false,"result":"Reviewed.","total_cost_usd":0.004,"num_turns":1,"session_id":"fake-3","terminal_reason":"completed"}'
@@ -222,6 +223,7 @@ echo '{"type":"result","subtype":"success","is_error":false,"result":"Added CREW
222223 concurrency: 1,
223224 budgetUsd: 1,
224225 runTimeoutMs: 60_000,
226 reviewBudgetMs: 4_000,
225227 });
226228 const a = await createUser(app.db, {
227229 trusted: true,
@@ -745,4 +747,41 @@ echo '{"type":"result","subtype":"success","is_error":false,"result":"Added CREW
745747 expect(readFileSync(argsFile, "utf8")).not.toContain("--resume");
746748 expect(listReviews(app.db, issue.id)).toHaveLength(1);
747749 }, 60_000);
750
751 test("a review run past its budget is queued again once; the second overrun fails it", async () => {
752 const made = await createAgent(app, alice, { username: "slowrev" });
753 if (!made.ok) throw new Error(String(made.error));
754 expect(addToCrew(app, alice, repo, "slowrev").ok).toBe(true);
755 setCrewRole(app.db, repo.id, made.value.user.id, "reviewer");
756 const branch = await commitToBranch(app, alice, repo, {
757 branch: "slow-fence",
758 base: "main",
759 message: "A slow fence",
760 files: [{ path: "SLOW.md", content: "slow\n" }],
761 });
762 if (!branch.ok) throw new Error(JSON.stringify(branch.error));
763 const opened = await openPull(app, alice, repo, {
764 title: "SLOW-REVIEW fence",
765 baseBranch: "main",
766 headBranch: "slow-fence",
767 });
768 if (!opened.ok) throw new Error(String(opened.error));
769 const issue = getIssue(app.db, repo.id, opened.value.number)!;
770 expect(queueAgentRun(app, repo, issue, made.value, "review")).toBeDefined();
771
772 const failed = await settled(
773 (r) =>
774 r.reason === "review" && r.issueId === issue.id && r.state === "failed",
775 );
776 expect(failed.summary).toMatch(
777 /^budget: a review run took \d+ min, limit \d+$/,
778 );
779 const reviews = listRuns(app.db, repo.id, { kind: "agent" }).filter(
780 (r) => r.reason === "review" && r.issueId === issue.id,
781 );
782 expect(reviews).toHaveLength(2);
783 expect(reviews.find((r) => r.state === "cancelled")?.summary).toMatch(
784 /^budget: a review run/,
785 );
786 }, 90_000);
748787 });
test/vitals.test.ts +2 −2
@@ -148,8 +148,8 @@ test("the number of queries does not grow with runs", () => {
148148 if (i % 2) app.db.query("UPDATE run SET state='running' WHERE id=?1").run(r.id);
149149 }
150150 expect(count()).toBe(before);
151 // The queue and the running runs.
152 expect(before).toBe(2);
151 // The queue, the running runs, and the runs killed twice for their budget.
152 expect(before).toBe(3);
153153 });
154154
155155 test("errors are counted, bounded, redacted, and a burst is said", async () => {

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs