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