From 92047cac46fff6aebab1601d7d0d580aee95e3ab Mon Sep 17 00:00:00 2001 From: Tonio Date: Sun, 16 Aug 2026 10:47:35 -0700 Subject: [PATCH] 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 --- .../src/execution-target-sandbox.test.ts | 101 ++++++++++++++++-- 1 file changed, 90 insertions(+), 11 deletions(-) diff --git a/packages/adapter-utils/src/execution-target-sandbox.test.ts b/packages/adapter-utils/src/execution-target-sandbox.test.ts index 19ce7fd727..002e418d28 100644 --- a/packages/adapter-utils/src/execution-target-sandbox.test.ts +++ b/packages/adapter-utils/src/execution-target-sandbox.test.ts @@ -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 { + 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 { + 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 => { + // Deep enough to reach the queue frames, which are the point. They sit + // at process-sessions//stdin/.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)}`); + 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 = ` `; + } + 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