trevato/forge

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

More
Forks1g fMapg aRunsg rEventsFlows

A cancelled run leaves no process behind: a test cancels a run mid-command and finds its whole process group gone #11249

Merged masoncrew opened this

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

ConversationFiles
Merged

mason/forge:mason/11229-a-cancelled-run-leaves-no-process-behind → main 1 commit fork

  • Merged. mason/11229-a-cancelled-run-leaves-no-process-behind was merged into main as 9bc1f0f.

Review

Sign in to review this change.
7 files changed +155 −5
src/actions/runs.ts +2 −1
@@ -39,6 +39,7 @@ import { err, ok, type Result } from "../kernel/result.ts";
3939 import { readRunLog, readRunLogTail, runLogPath } from "../runs/log.ts";
4040 import { shownStates, type ShownState } from "../runs/state.ts";
4141 import { firstErrorLine } from "../runs/error_line.ts";
42 import { cancelledBy } from "../runs/cancelled.ts";
4243 import { requireReader, requireWriter, type AccessError } from "./access.ts";
4344
4445 /** What a run event carries: enough for a surface to render the card. */
@@ -350,7 +351,7 @@ export function cancelRepoRun(
350351 const cancelled = markCancelled(
351352 app.db,
352353 runId,
353 `cancelled by ${writer.value.username}`,
354 cancelledBy(writer.value.username),
354355 );
355356 if (!cancelled) return err("finished");
356357 // The row says cancelled first, so the run's own end leaves it so; the
src/checks/service.ts +5 −2
@@ -88,6 +88,7 @@ import { transact } from "../kernel/db.ts";
8888 import { createLog } from "../kernel/log.ts";
8989 import { holdLease, STALE_AFTER_MS } from "../runs/lease.ts";
9090 import { appendRunLog } from "../runs/log.ts";
91 import { cancelledLine } from "../runs/cancelled.ts";
9192 import { trackRun, untrackRun } from "../runs/stoppable.ts";
9293 import { runningLimitSentence, runningRuns } from "../settings/quotas.ts";
9394 import { exportTree, readFileAt } from "../apps/checkout.ts";
@@ -826,8 +827,10 @@ export function startChecks(app: App, options: ChecksOptions): ChecksHandle {
826827 }
827828 // Ended from outside while it ran: its pull landed or closed, and
828829 // the row says so. That is not this check failing.
829 if (!outcome.ok && getRun(app.db, run.id)?.state === "cancelled") {
830 write(`superseded: ${getRun(app.db, run.id)?.summary ?? "cancelled"}`);
830 // A person's cancel ends the log with who cancelled it (#11229).
831 const row = getRun(app.db, run.id);
832 if (!outcome.ok && row?.state === "cancelled") {
833 write(cancelledLine(row) ?? `superseded: ${row.summary}`);
831834 return;
832835 }
833836 if (!outcome.ok && stopped && signal.aborted) {
src/crew/runner.ts +9 −2
@@ -88,6 +88,7 @@ import {
8888 checkSummary,
8989 claimRun,
9090 finishRun,
91 getRun,
9192 lastAgentRun,
9293 noteRunProgress,
9394 setRunBase,
@@ -121,6 +122,7 @@ import { createLog, redactValues } from "../kernel/log.ts";
121122 import { err, ok, type Result } from "../kernel/result.ts";
122123 import { holdLease } from "../runs/lease.ts";
123124 import { appendRunLog, readRunLog } from "../runs/log.ts";
125 import { cancelledLine } from "../runs/cancelled.ts";
124126 import {
125127 branchFor,
126128 issueOfBranch,
@@ -409,16 +411,21 @@ export async function executeAgentRun(
409411 try {
410412 return await runClaimed(app, run, options, watch, began);
411413 } finally {
412 // The log's last line, on every path that started: where the time went.
414 // The log's last line, on every path that started: where the time went
415 // (and after it, for a run a person cancelled, who did).
413416 // A step an early return cut short still owns the time it held.
414417 if (began.inHarness) watch.lap("harness");
415418 if (began.inWrapUp) watch.lap("wrap-up");
416 if (began.claimed)
419 if (began.claimed) {
417420 appendRunLog(
418421 app.config.dataDir,
419422 run.id,
420423 watch.line("run ended", "the run started"),
421424 );
425 // A run a person cancelled says so, and who, after it (#11229).
426 const cancelled = cancelledLine(getRun(app.db, run.id));
427 if (cancelled !== undefined) appendRunLog(app.config.dataDir, run.id, cancelled);
428 }
422429 }
423430 }
424431
src/runs/cancelled.ts added +25
@@ -0,0 +1,25 @@
1 /**
2 * A person's cancel, in words (#11229). `cancelRepoRun` marks the row with
3 * `cancelledBy(name)`; the worker that was running it, once it has wound
4 * down, ends the run's log with that same line, so the log's last word says
5 * the run was cancelled and by whom. A run cancelled any other way (its
6 * pull landed, a budget, a restart) keeps the summary its own path writes.
7 */
8
9 const PREFIX = "cancelled by ";
10
11 /** The summary and the log's last line for a run `username` cancelled. */
12 export const cancelledBy = (username: string): string => `${PREFIX}${username}`;
13
14 /**
15 * The line a worker ends a run's log with, given the row it finds when its
16 * work is over: the row's summary when a person cancelled it, else nothing.
17 */
18 export function cancelledLine(
19 row: { readonly state: string; readonly summary: string } | undefined,
20 ): string | undefined {
21 if (row === undefined || row.state !== "cancelled") return undefined;
22 return row.summary.startsWith(PREFIX) && row.summary.length > PREFIX.length
23 ? row.summary
24 : undefined;
25 }
test/crew-cancel-by.test.ts added +104
@@ -0,0 +1,104 @@
1 /**
2 * A cancel is a cancel (#11229). A person cancels an agent run through the
3 * action every surface calls (`cancelRepoRun`) while the agent's command has
4 * forked a child and that child a grandchild. Within 2 s none of the three
5 * is alive, and the run's log ends with one line saying it was cancelled,
6 * and by whom.
7 */
8 import { afterAll, beforeAll, describe, expect, test } from "bun:test";
9 import { existsSync, readFileSync } from "node:fs";
10 import { join } from "node:path";
11 import { assignIssue, openIssue } from "../src/actions/issues.ts";
12 import { cancelRepoRun } from "../src/actions/runs.ts";
13 import { getRun, listRuns } from "../src/core/runs.ts";
14 import { readRunLog } from "../src/runs/log.ts";
15 import { cancelledBy, cancelledLine } from "../src/runs/cancelled.ts";
16 import { startStandInCrew, stopStandInCrew, type StandInCrew } from "./helpers/crew-standin.ts";
17
18 describe("cancelledLine", () => {
19 test("is the row's summary when a person cancelled it, else nothing", () => {
20 expect(cancelledBy("alice")).toBe("cancelled by alice");
21 expect(cancelledLine({ state: "cancelled", summary: "cancelled by alice" })).toBe("cancelled by alice");
22 expect(cancelledLine({ state: "cancelled", summary: "the pull landed" })).toBeUndefined();
23 expect(cancelledLine({ state: "cancelled", summary: "cancelled by " })).toBeUndefined();
24 expect(cancelledLine({ state: "failed", summary: "cancelled by alice" })).toBeUndefined();
25 expect(cancelledLine(undefined)).toBeUndefined();
26 });
27 });
28
29 /** Alive and not a zombie a parent has yet to reap. */
30 function alive(pid: number): boolean {
31 let stat: string;
32 try {
33 stat = readFileSync(`/proc/${pid}/stat`, "utf8");
34 } catch {
35 return false;
36 }
37 const state = stat.slice(stat.lastIndexOf(")") + 2)[0];
38 return state !== "Z" && state !== "X";
39 }
40
41 /** Polls, never a fixed sleep: true once `done` holds, false at the deadline. */
42 async function within(ms: number, done: () => boolean): Promise<boolean> {
43 const deadline = Date.now() + ms;
44 while (!done() && Date.now() < deadline) await Bun.sleep(20);
45 return done();
46 }
47
48 async function pidIn(file: string, ms: number): Promise<number> {
49 const named = (): number => (existsSync(file) ? Number(readFileSync(file, "utf8").trim()) : 0);
50 await within(ms, () => Number.isInteger(named()) && named() > 1);
51 const pid = named();
52 if (!Number.isInteger(pid) || pid <= 1) throw new Error(`${file} never named a pid`);
53 return pid;
54 }
55
56 describe.skipIf(process.platform !== "linux")("an agent run a person cancels", () => {
57 let standIn: StandInCrew;
58 const started: number[] = [];
59
60 beforeAll(async () => {
61 standIn = await startStandInCrew();
62 }, 30_000);
63
64 afterAll(async () => {
65 for (const pid of started)
66 try {
67 process.kill(pid, "SIGKILL");
68 } catch {
69 // gone, as it should be
70 }
71 await stopStandInCrew(standIn);
72 });
73
74 test("leaves no process behind within 2 s, and its log ends saying who cancelled it", async () => {
75 const { app, alice, bot, repo, dataDir } = standIn;
76 const issue = openIssue(app, alice, repo, { title: "Grow a tree", body: "SPAWN-TREE and wait." });
77 if (!issue.ok) throw new Error(String(issue.error));
78 expect(assignIssue(app, alice, repo, issue.value, bot).ok).toBe(true);
79
80 const pids = [
81 await pidIn(join(dataDir, "tree.grand"), 30_000),
82 await pidIn(join(dataDir, "tree.child"), 1_000),
83 await pidIn(join(dataDir, "tree.agent"), 1_000),
84 ];
85 started.push(...pids);
86 expect(pids.every(alive)).toBe(true);
87
88 const run = listRuns(app.db, repo.id, { kind: "agent" }).find((r) => r.issueId === issue.value.id);
89 if (run === undefined) throw new Error("no agent run");
90 expect(run.state).toBe("running");
91
92 const cancelled = cancelRepoRun(app, alice, repo, run.id);
93 expect(cancelled.ok).toBe(true);
94 expect(await within(2_000, () => pids.every((pid) => !alive(pid)))).toBe(true);
95
96 // The runner winds down and ends the log; the row keeps what the cancel wrote.
97 const lines = (): string[] => readRunLog(dataDir, run.id).lines;
98 expect(await within(15_000, () => lines().includes("cancelled by alice"))).toBe(true);
99 expect(getRun(app.db, run.id)?.state).toBe("cancelled");
100 expect(getRun(app.db, run.id)?.summary).toBe("cancelled by alice");
101 expect(lines().filter((l) => l === "cancelled by alice")).toHaveLength(1);
102 expect(lines().at(-1)).toBe("cancelled by alice");
103 }, 60_000);
104 });
test/helpers/crew-standin.ts +6
@@ -69,6 +69,12 @@ if [ "$1" = "--version" ]; then echo "2.1.0 (fake)"; exit 0; fi
6969 printf '%s\\n' "$@" > "${argsFile}"
7070 IFS= read -r first; printf '%s\\n' "$first" > "${promptFile}"
7171 echo '{"type":"system","subtype":"init","session_id":"fake-1","model":"fake"}'
72 if grep -q SPAWN-TREE "${promptFile}"; then
73 echo $$ > "${dataDir}/tree.agent"
74 sh -c 'echo $$ > "${dataDir}/tree.child"; sleep 300 & echo $! > "${dataDir}/tree.grand.tmp"; mv "${dataDir}/tree.grand.tmp" "${dataDir}/tree.grand"; wait' &
75 sleep 300
76 exit 0
77 fi
7278 if grep -q LIMIT-ME "${promptFile}" && [ ! -f PAUSED.md ]; then
7379 echo "half-done" > PAUSED.md
7480 echo '{"type":"result","subtype":"error_during_execution","is_error":true,"result":"You\u2019ve hit your session limit \u00b7 resets 7:20am (UTC)","total_cost_usd":0.02,"num_turns":2,"session_id":"fake-1","terminal_reason":"api_error"}'
test/run-cancel-tree.test.ts +4
@@ -167,6 +167,10 @@ describe.skipIf(process.platform !== "linux")("a cancelled check", () => {
167167 const ended = readRunLog(dataDir, run.id).lines.filter((l) => l.startsWith("cancel ended "));
168168 expect(ended).toHaveLength(1);
169169 expect(Number(/^cancel ended (\d+) process/.exec(ended[0]!)?.[1])).toBeGreaterThanOrEqual(pids.length);
170 // And it ends with one line saying it was cancelled, and by whom (#11229).
171 const lines = readRunLog(dataDir, run.id).lines;
172 expect(lines.filter((l) => l === "cancelled by alice")).toHaveLength(1);
173 expect(lines.at(-1)).toBe("cancelled by alice");
170174 }, 45_000);
171175 });
172176

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs