Fix: bound the captured start-up streams and report a child that exits without closing its pipes

core/test/code_executors/unsafe_local_code_executor_test.ts

@@ -45,19 +45,6 @@ const EXPECTED_POWERSHELL_ARGS = [
   expect.stringMatching(/script\.ps1$/),
 ];
 
-/**
- * `it()` budget (ms) for the cases that spawn a real interpreter rather than
- * the mocked `spawn` used by the `spawn arguments` suite below. The `unit:core`
- * project sets no `testTimeout`, so these inherit Vitest's 5000 ms default,
- * which is not a process-start budget: on Windows the default shell is Windows
- * PowerShell, whose cold start under V8 coverage instrumentation on a loaded CI
- * runner does not reliably fit. The value is above `UnsafeLocalCodeExecutor`'s
- * own 30 s default execution timeout on purpose, so a genuinely stuck
- * interpreter fails with the executor's timeout message instead of an opaque
- * Vitest timeout.
- */
-const REAL_INTERPRETER_TIMEOUT_MS = 40000;
-
 function createMockInvocationContext(): InvocationContext {
   const agent = new LlmAgent({
     name: 'test_agent',
@@ -171,25 +158,21 @@ describe('UnsafeLocalCodeExecutor', () => {
     expect(result.stderr).toBe('');
   });
 
-  it(
-    'should execute shell code and return stdout',
-    async () => {
-      const params: ExecuteCodeParams = {
-        invocationContext,
-        codeExecutionInput: {
-          code: 'echo "Hello, Shell!"',
-          language: CodeExecutionLanguage.SHELL,
-          inputFiles: [],
-        },
-      };
+  it('should execute shell code and return stdout', async () => {
+    const params: ExecuteCodeParams = {
+      invocationContext,
+      codeExecutionInput: {
+        code: 'echo "Hello, Shell!"',
+        language: CodeExecutionLanguage.SHELL,
+        inputFiles: [],
+      },
+    };
 
-      const result = await executor.executeCode(params);
+    const result = await executor.executeCode(params);
 
-      expect(result.stdout).toContain('Hello, Shell!');
-      expect(result.stderr).toBe('');
-    },
-    REAL_INTERPRETER_TIMEOUT_MS,
-  );
+    expect(result.stdout).toContain('Hello, Shell!');
+    expect(result.stderr).toBe('');
+  });
 
   it('should return error for unsupported language', async () => {
     const params: ExecuteCodeParams = {

tests/integration/test_case_utils.ts

@@ -265,6 +265,9 @@ const OUTPUT_EXCERPT_CHARS = 4000;
 /** How long `stop()` waits for a clean exit before escalating to SIGKILL. */
 const PROCESS_EXIT_TIMEOUT_MS = 5000;
 
+/** How long a premature `'exit'` waits for the stdio pipes to reach EOF. */
+const STDIO_FLUSH_GRACE_MS = 250;
+
 /**
  * Returns a TCP port on `host` that the OS has just confirmed is free, by
  * binding port 0, reading the assignment back and releasing it.
@@ -295,16 +298,26 @@ export async function reserveFreePort(host: string): Promise<number> {
 }
 
 /**
- * Keeps only the last {@link OUTPUT_EXCERPT_CHARS} characters of a captured
- * stream: a child that dies noisily writes far more than is useful, and the
- * bytes it wrote last are the ones explaining why.
+ * Appends `chunk` to `buffer`, retaining only the last
+ * {@link OUTPUT_EXCERPT_CHARS} characters.
+ *
+ * Capping on the way in rather than on the way out bounds what a child can make
+ * the harness hold: a server stuck in a log loop writes for the whole readiness
+ * window, and only its last words explain why it never started.
  */
-function excerpt(output: string): string {
-  return output.slice(-OUTPUT_EXCERPT_CHARS) || '(no output captured)';
+export function appendCapped(
+  buffer: string,
+  chunk: string,
+  maxChars = OUTPUT_EXCERPT_CHARS,
+): string {
+  return (buffer + chunk).slice(-maxChars);
 }
 
+/** Stands in for a stream the child never wrote to. */
+const NO_OUTPUT = '(no output captured)';
+
 function formatCapturedOutput(stdout: string, stderr: string): string {
-  return `\nstdout:\n${excerpt(stdout)}\nstderr:\n${excerpt(stderr)}`;
+  return `\nstdout:\n${stdout || NO_OUTPUT}\nstderr:\n${stderr || NO_OUTPUT}`;
 }
 
 /**
@@ -364,11 +377,14 @@ export abstract class BaseTestServer {
       // of the child so its pipes keep draining; a chatty server that filled
       // the 64 KB pipe buffer would otherwise block.
       let capturing = true;
+      let flushGrace: ReturnType<typeof setTimeout> | undefined;
 
       const settle = (error?: Error) => {
         clearTimeout(timer);
+        clearTimeout(flushGrace);
         capturing = false;
         child.off('error', onError);
+        child.off('exit', onExit);
         child.off('close', onClose);
         if (error) {
           reject(error);
@@ -379,7 +395,7 @@ export abstract class BaseTestServer {
 
       const onStdout = (data: Buffer) => {
         if (!capturing) return;
-        stdout += data.toString();
+        stdout = appendCapped(stdout, data.toString());
 
         // Matched against the accumulated output, not this chunk: a banner
         // split across two writes must still complete the handshake.
@@ -389,8 +405,13 @@ export abstract class BaseTestServer {
       };
 
       const onStderr = (data: Buffer) => {
+        const message = data.toString();
+        // Echoed unconditionally: retention stops once the handshake settles,
+        // but a server that starts cleanly and fails later still has to reach
+        // the CI log.
+        console.error(`${serverName} Stderr: ${message}`);
         if (!capturing) return;
-        stderr += data.toString();
+        stderr = appendCapped(stderr, message);
       };
 
       const onError = (error: Error) => {
@@ -418,6 +439,21 @@ export abstract class BaseTestServer {
         );
       };
 
+      // A child that leaves a grandchild holding the inherited stdio pipes --
+      // `go run` does exactly that -- emits 'exit' but never 'close', so the
+      // wait for a drained pipe is bounded and then reported anyway. Reporting
+      // the exit code beats stalling until the readiness timeout claims the
+      // server merely started slowly.
+      const onExit = (
+        code: number | null,
+        signal: ChildProcessWithoutNullStreams['signalCode'],
+      ) => {
+        flushGrace = setTimeout(
+          () => onClose(code, signal),
+          STDIO_FLUSH_GRACE_MS,
+        );
+      };
+
       const timer = setTimeout(() => {
         settle(
           new Error(
@@ -430,6 +466,7 @@ export abstract class BaseTestServer {
       child.stdout.on('data', onStdout);
       child.stderr.on('data', onStderr);
       child.on('error', onError);
+      child.on('exit', onExit);
       child.on('close', onClose);
     });
 

tests/integration/test_case_utils_test.ts

@@ -10,8 +10,12 @@ import {mkdtempSync, readFileSync} from 'node:fs';
 import {createServer, type Server} from 'node:net';
 import {platform, tmpdir} from 'node:os';
 import * as path from 'node:path';
-import {afterEach, describe, expect, it} from 'vitest';
-import {BaseTestServer, reserveFreePort} from './test_case_utils.js';
+import {afterEach, describe, expect, it, vi} from 'vitest';
+import {
+  appendCapped,
+  BaseTestServer,
+  reserveFreePort,
+} from './test_case_utils.js';
 
 const HOST = 'localhost';
 const START_MESSAGE = 'SCRIPTED SERVER STARTED';
@@ -21,6 +25,15 @@ const START_TIMEOUT_MS = 15000;
 const STAY_ALIVE = 'setInterval(() => {}, 1000);';
 /** Mirrors `PROCESS_EXIT_TIMEOUT_MS` in the harness under test. */
 const PROCESS_EXIT_TIMEOUT_MS = 5000;
+/** Mirrors `OUTPUT_EXCERPT_CHARS` in the harness under test. */
+const OUTPUT_EXCERPT_CHARS = 4000;
+/**
+ * Readiness budget for the grandchild case: long enough that reaching it means
+ * the exit was never reported, short enough to fail fast when that regresses.
+ */
+const GRANDCHILD_START_TIMEOUT_MS = 10000;
+/** Children write on their own schedule, so observations are polled. */
+const WAIT_FOR_OPTIONS = {timeout: 5000, interval: 10};
 const IS_WINDOWS = platform() === 'win32';
 
 const spawned: ChildProcessWithoutNullStreams[] = [];
@@ -75,16 +88,14 @@ function hasExited(child: ChildProcessWithoutNullStreams): boolean {
  * Waits for the harness to reach its spawn closure. `startProcess` awaits the
  * port reservation first, so the child handle is not available synchronously.
  */
-async function waitForChild(
+function waitForChild(
   server: ScriptedTestServer,
 ): Promise<ChildProcessWithoutNullStreams> {
-  for (let i = 0; i < 500 && !server.child; i++) {
-    await new Promise((resolve) => setTimeout(resolve, 10));
-  }
-  if (!server.child) {
-    expect.fail('the server never reached its spawn closure');
-  }
-  return server.child;
+  return vi.waitFor(() => {
+    const child = server.child;
+    if (!child) expect.fail('the server never reached its spawn closure');
+    return child;
+  }, WAIT_FOR_OPTIONS);
 }
 
 /** True for the Node error raised when a pid no longer exists. */
@@ -154,6 +165,40 @@ describe('reserveFreePort', () => {
   });
 });
 
+describe('appendCapped', () => {
+  it('appends without truncating below the cap', () => {
+    expect(appendCapped('abc', 'de', 8)).toBe('abcde');
+  });
+
+  it('appends without truncating exactly at the cap', () => {
+    expect(appendCapped('abc', 'de', 5)).toBe('abcde');
+  });
+
+  it('drops the head and keeps the tail once over the cap', () => {
+    expect(appendCapped('abc', 'de', 4)).toBe('bcde');
+  });
+
+  it('keeps only the tail of a chunk that alone exceeds the cap', () => {
+    expect(appendCapped('abc', 'defgh', 3)).toBe('fgh');
+  });
+
+  it('stays capped across repeated appends', () => {
+    let buffer = '';
+    for (let i = 0; i < 100; i++) {
+      buffer = appendCapped(buffer, '0123456789', 15);
+    }
+
+    expect(buffer).toHaveLength(15);
+    expect(buffer.endsWith('0123456789')).toBe(true);
+  });
+
+  it('defaults to the harness excerpt size', () => {
+    const overCap = 'x'.repeat(OUTPUT_EXCERPT_CHARS + 1000);
+
+    expect(appendCapped('', overCap)).toHaveLength(OUTPUT_EXCERPT_CHARS);
+  });
+});
+
 describe('BaseTestServer.startProcess', () => {
   it('reserves the port before the child is spawned', async () => {
     const server = new ScriptedTestServer(
@@ -212,6 +257,38 @@ describe('BaseTestServer.startProcess', () => {
     await expect(attempt).rejects.toThrow('STDOUT-REASON');
   });
 
+  it('reports the exit code when a grandchild holds the pipes open', async () => {
+    // `go run` behaves this way: the built binary inherits the stdio pipes, so
+    // the wrapper can die without them ever reaching EOF and 'close' never
+    // arrives. Waiting for it would report a start-up *timeout* minutes later
+    // instead of the exit code the child already handed us.
+    const pidFile = path.join(
+      mkdtempSync(path.join(tmpdir(), 'adk-harness-')),
+      'grandchild.pid',
+    );
+    grandchildPidFiles.push(pidFile);
+    const server = new ScriptedTestServer(
+      nodeScript(
+        "const gc = require('node:child_process').spawn(process.execPath, " +
+          "['-e', 'setTimeout(() => {}, 60000)'], {stdio: 'inherit'});" +
+          `require('node:fs').writeFileSync(${JSON.stringify(pidFile)}, ` +
+          'String(gc.pid));' +
+          "process.stderr.write('HELD-STDERR\\n', () => " +
+          "process.stdout.write('HELD-STDOUT\\n', () => process.exit(3)));",
+      ),
+    );
+
+    // Far longer than the flush grace, so a rejection this side of it can only
+    // have come from the exit path rather than from the readiness timeout.
+    const attempt = server.start(GRANDCHILD_START_TIMEOUT_MS);
+
+    await expect(attempt).rejects.toThrow(
+      'Scripted exited prematurely with code 3',
+    );
+    await expect(attempt).rejects.toThrow('HELD-STDOUT');
+    await expect(attempt).rejects.toThrow('HELD-STDERR');
+  });
+
   it('reports both streams as empty when the child exits silently', async () => {
     const server = new ScriptedTestServer(nodeScript('process.exit(1);'));
 
@@ -305,6 +382,34 @@ describe('BaseTestServer.startProcess', () => {
     await new Promise<void>((resolve) => child!.once('close', () => resolve()));
     expect(child!.exitCode).toBe(0);
   });
+
+  it('echoes stderr written after the handshake has settled', async () => {
+    // Retention stops at settle, but the echo is what surfaces a server that
+    // starts cleanly and then fails mid-test, so it has to outlive the
+    // handshake.
+    const server = new ScriptedTestServer(
+      nodeScript(
+        `process.stdout.write('${START_MESSAGE}\\n');` +
+          "setTimeout(() => process.stderr.write('MID-TEST-FAILURE\\n'), 50);" +
+          STAY_ALIVE,
+      ),
+    );
+    const echoed = vi.spyOn(console, 'error');
+
+    try {
+      await server.start();
+
+      await vi.waitFor(
+        () =>
+          expect(echoed).toHaveBeenCalledWith(
+            expect.stringContaining('Scripted Stderr: MID-TEST-FAILURE'),
+          ),
+        WAIT_FOR_OPTIONS,
+      );
+    } finally {
+      echoed.mockRestore();
+    }
+  });
 });
 
 describe('BaseTestServer.stop', () => {