test(adapter-utils): make the next sandbox flake diagnosable (#11483)

`execution-target-sandbox` has failed twice in CI and not once in several
hundred local runs. This does not fix it. It makes the next occurrence carry
its own evidence, because a third unreproducible failure would teach nothing.

The observed signature was an empty stdout with exit code 0 - the child exited
cleanly having produced nothing, which is what a lost stdin frame looks like
from the test's side. Three mechanisms were checked and ruled out rather than
assumed: the helper resolving on `exit` rather than `close` (a 200-iteration
probe produced no truncations, and the failure was empty rather than partial);
the wrapper reporting exit before stdout drains (it already listens on
`close`); and frame writes racing (the stream wrapper's `writeEvent` is
synchronous and sequence-numbered).

Two candidates remain and the runtime tree separates them. A stdin queue frame
still present means the host wrote it and the wrapper never consumed it; a
drained queue with no output means it was consumed and the reply was lost on
the way back. The report prints that tree, both proxy streams, the exit code,
and the elapsed time - the last because the bridge and proxy run on 5s budgets
that are generous locally and tight on a runner sharing a box with 19 other
lanes.

Timeouts are deliberately unchanged. Raising them would probably make the
symptom go away, which is the reason not to do it blind.

The first revision capped the tree walk one level above the queue frames, so
"the queue is empty" and "the walk never looked" printed identically - the
distinction the report exists to make. Caught in review. Verifying that the
reporter printed something was not enough; it had to print the thing that
discriminates, which is now checked by planting a frame and forcing the
assertion.

adapter-utils typecheck clean; 44 pass, stable across repeated runs.

Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
This commit is contained in:
Tonio 2026-08-16 10:47:35 -07:00 committed by GitHub
parent add65ba4a2
commit 92047cac46
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
1 changed files with 90 additions and 11 deletions

View File

@ -148,7 +148,22 @@ describe("sandbox adapter execution targets", () => {
throw new Error(message);
}
async function runProxyWithInput(command: string, input: string): Promise<{ stdout: string; stderr: string; code: number | null }> {
type ProxyRunResult = {
stdout: string;
stderr: string;
code: number | null;
/**
* How long the exchange took. The bridge and the proxy both run on 5s
* budgets, which is generous locally and tight on a CI runner sharing a
* box with 19 other lanes. A run that returns fast and empty is a
* different fault from one that nearly hit the ceiling, and the numbers
* are the only way to tell them apart after the fact.
*/
elapsedMs: number;
};
async function runProxyWithInput(command: string, input: string): Promise<ProxyRunResult> {
const startedAt = performance.now();
const child = spawn(command, [], { stdio: ["pipe", "pipe", "pipe"] });
let stdout = "";
let stderr = "";
@ -175,7 +190,65 @@ describe("sandbox adapter execution targets", () => {
resolve(exitCode);
});
});
return { stdout, stderr, code };
return { stdout, stderr, code, elapsedMs: Math.round(performance.now() - startedAt) };
}
/**
* A failure report for a proxy exchange, attached to the assertions below.
*
* `execution-target-sandbox` has failed twice in CI and never once in a few
* hundred local runs, so the next occurrence has to carry its own evidence -
* a second unreproducible failure teaches nothing. The observed signature was
* an empty stdout with exit code 0, meaning the child exited cleanly having
* produced nothing, which is what a lost stdin frame looks like from here.
*
* The runtime tree is the part that discriminates. The stdin queue files are
* written by the host and deleted by the wrapper once parsed, so what remains
* says whether the frame was never written, written and never consumed, or
* consumed normally and the reply lost on the way back.
*/
async function describeProxyRun(result: ProxyRunResult, runtimeRootDir: string): Promise<string> {
const lines = [
`proxy exit=${result.code} elapsedMs=${result.elapsedMs}`,
`proxy stdout=${JSON.stringify(result.stdout)}`,
`proxy stderr=${JSON.stringify(result.stderr)}`,
];
const walk = async (dir: string, depth: number): Promise<void> => {
// Deep enough to reach the queue frames, which are the point. They sit
// at process-sessions/<id>/stdin/<seq>.json — depth 4 from the runtime
// root — so a cap of 3 listed the `stdin/` directory and stopped, making
// "the queue is empty" and "the walk never looked" print identically.
if (depth > 5) return;
let entries;
try {
entries = await readdir(dir, { withFileTypes: true });
} catch (error) {
lines.push(`${" ".repeat(depth)}<unreadable ${dir}: ${(error as Error).message}>`);
return;
}
for (const entry of entries.sort((a, b) => a.name.localeCompare(b.name))) {
const full = path.join(dir, entry.name);
if (entry.isDirectory()) {
lines.push(`${" ".repeat(depth)}${entry.name}/`);
await walk(full, depth + 1);
continue;
}
// Small files are the queue and event frames, and their contents are
// the point. Anything larger is a child script or a log; the size is
// enough to say it exists.
let detail = "";
try {
const raw = await readFile(full, "utf8");
detail = raw.length <= 400 ? ` ${JSON.stringify(raw)}` : ` <${raw.length}B>`;
} catch (error) {
detail = ` <unreadable: ${(error as Error).message}>`;
}
lines.push(`${" ".repeat(depth)}${entry.name}${detail}`);
}
};
lines.push(`runtime tree under ${runtimeRootDir}:`);
await walk(runtimeRootDir, 1);
return lines.join("\n");
}
function combinedStream(
@ -729,9 +802,10 @@ describe("sandbox adapter execution targets", () => {
try {
const result = await runProxyWithInput(bridge!.agentCommand, "hello\n");
expect(result.code).toBe(0);
expect(result.stdout).toBe("out:hello\n");
expect(result.stderr).toBe("err:hello\n");
const report = await describeProxyRun(result, path.posix.join(rootDir, ".paperclip-runtime", "acpx"));
expect(result.code, report).toBe(0);
expect(result.stdout, report).toBe("out:hello\n");
expect(result.stderr, report).toBe("err:hello\n");
} finally {
await bridge?.stop();
}
@ -1026,9 +1100,10 @@ describe("sandbox adapter execution targets", () => {
try {
const result = await runProxyWithInput(bridge!.agentCommand, "hello\n");
expect(result.code).toBe(0);
expect(result.stdout).toBe("out:hello\n");
expect(result.stderr).toBe("err:hello\n");
const report = await describeProxyRun(result, path.posix.join(rootDir, ".paperclip-runtime", "acpx"));
expect(result.code, report).toBe(0);
expect(result.stdout, report).toBe("out:hello\n");
expect(result.stderr, report).toBe("err:hello\n");
} finally {
await bridge?.stop();
}
@ -1087,8 +1162,9 @@ describe("sandbox adapter execution targets", () => {
// frame flows, so it is observable as soon as the handle resolves.
expect(spanNames).toContain("sandbox.agentProcess");
const result = await runProxyWithInput(bridge!.agentCommand, "hello\n");
expect(result.code).toBe(0);
expect(result.stdout).toBe("out:hello\n");
const report = await describeProxyRun(result, path.posix.join(rootDir, ".paperclip-runtime", "acpx"));
expect(result.code, report).toBe(0);
expect(result.stdout, report).toBe("out:hello\n");
} finally {
await bridge?.stop();
}
@ -1480,7 +1556,10 @@ describe("sandbox adapter execution targets", () => {
// Round-trip one input so a stdin-delivery control exec runs and gets
// recorded before the assertions below.
const result = await runProxyWithInput(bridge!.agentCommand, "hello\n");
expect(result.stdout).toBe("out:hello\n");
expect(
result.stdout,
await describeProxyRun(result, path.posix.join(rootDir, ".paperclip-runtime", "acpx")),
).toBe("out:hello\n");
// Exactly one exec runs on the persistent session: the long-lived agent
// command. It streams its output through the session log stream, so it