fix: drain stdout before resolving when a child holds the pipe past exit (#5753)
This commit is contained in:
@@ -289,6 +289,7 @@ export function createBashToolDefinition(
|
||||
const resolvedCommand = commandPrefix ? `${commandPrefix}\n${command}` : command;
|
||||
const spawnContext = resolveSpawnContext(resolvedCommand, cwd, spawnHook);
|
||||
const output = new OutputAccumulator({ tempFilePrefix: "pi-bash" });
|
||||
let acceptingOutput = true;
|
||||
let updateTimer: NodeJS.Timeout | undefined;
|
||||
let updateDirty = false;
|
||||
let lastUpdateAt = 0;
|
||||
@@ -334,11 +335,13 @@ export function createBashToolDefinition(
|
||||
}
|
||||
|
||||
const handleData = (data: Buffer) => {
|
||||
if (!acceptingOutput) return;
|
||||
output.append(data);
|
||||
scheduleOutputUpdate();
|
||||
};
|
||||
|
||||
const finishOutput = async () => {
|
||||
acceptingOutput = false;
|
||||
output.finish();
|
||||
clearUpdateTimer();
|
||||
emitOutputUpdate();
|
||||
|
||||
@@ -38,10 +38,13 @@ export function spawnProcessSync(
|
||||
/**
|
||||
* Wait for a child process to terminate without hanging on inherited stdio handles.
|
||||
*
|
||||
* On Windows, daemonized descendants can inherit the child's stdout/stderr pipe
|
||||
* handles. In that case the child emits `exit`, but `close` can hang forever even
|
||||
* though the original process is already gone. We wait briefly for stdio to end,
|
||||
* then forcibly stop tracking the inherited handles.
|
||||
* A short-lived child can `exit` while a detached descendant keeps its stdout/stderr
|
||||
* pipe open. We must not resolve and destroy the streams on a fixed deadline measured
|
||||
* from `exit`, or output still being written past that deadline is silently lost
|
||||
* (earendil-works/pi#5303). Instead, after `exit` we wait for the pipes to fall idle:
|
||||
* the grace timer is re-armed on every chunk, so an actively writing descendant keeps
|
||||
* us reading, while a quiet inherited handle (e.g. a Windows daemonized descendant
|
||||
* that never lets `close` fire) still releases us after the grace elapses.
|
||||
*/
|
||||
export function waitForChildProcess(child: ChildProcess): Promise<number | null> {
|
||||
return new Promise((resolve, reject) => {
|
||||
@@ -62,6 +65,8 @@ export function waitForChildProcess(child: ChildProcess): Promise<number | null>
|
||||
child.removeListener("close", onClose);
|
||||
child.stdout?.removeListener("end", onStdoutEnd);
|
||||
child.stderr?.removeListener("end", onStderrEnd);
|
||||
child.stdout?.removeListener("data", onData);
|
||||
child.stderr?.removeListener("data", onData);
|
||||
};
|
||||
|
||||
const finalize = (code: number | null) => {
|
||||
@@ -80,6 +85,17 @@ export function waitForChildProcess(child: ChildProcess): Promise<number | null>
|
||||
}
|
||||
};
|
||||
|
||||
const armIdleTimer = () => {
|
||||
if (postExitTimer) clearTimeout(postExitTimer);
|
||||
postExitTimer = setTimeout(() => finalize(exitCode), EXIT_STDIO_GRACE_MS);
|
||||
};
|
||||
|
||||
const onData = () => {
|
||||
// Output is still arriving after exit; defer finalizing so we don't
|
||||
// destroy the stream mid-write and truncate the tail.
|
||||
if (exited && !settled) armIdleTimer();
|
||||
};
|
||||
|
||||
const onStdoutEnd = () => {
|
||||
stdoutEnded = true;
|
||||
maybeFinalizeAfterExit();
|
||||
@@ -102,7 +118,7 @@ export function waitForChildProcess(child: ChildProcess): Promise<number | null>
|
||||
exitCode = code;
|
||||
maybeFinalizeAfterExit();
|
||||
if (!settled) {
|
||||
postExitTimer = setTimeout(() => finalize(code), EXIT_STDIO_GRACE_MS);
|
||||
armIdleTimer();
|
||||
}
|
||||
};
|
||||
|
||||
@@ -112,6 +128,8 @@ export function waitForChildProcess(child: ChildProcess): Promise<number | null>
|
||||
|
||||
child.stdout?.once("end", onStdoutEnd);
|
||||
child.stderr?.once("end", onStderrEnd);
|
||||
child.stdout?.on("data", onData);
|
||||
child.stderr?.on("data", onData);
|
||||
child.once("error", onError);
|
||||
child.once("exit", onExit);
|
||||
child.once("close", onClose);
|
||||
|
||||
@@ -0,0 +1,29 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { type BashOperations, createBashTool } from "../../../src/core/tools/bash.ts";
|
||||
|
||||
function getTextOutput(result: { content?: Array<{ type: string; text?: string }> }): string {
|
||||
return (
|
||||
result.content
|
||||
?.filter((block) => block.type === "text")
|
||||
.map((block) => block.text ?? "")
|
||||
.join("\n") ?? ""
|
||||
);
|
||||
}
|
||||
|
||||
describe("regression #5208: late bash output callbacks", () => {
|
||||
it("ignores output callbacks after bash operations resolve", async () => {
|
||||
const operations: BashOperations = {
|
||||
exec: async (_command, _cwd, { onData }) => {
|
||||
onData(Buffer.from("before\n", "utf-8"));
|
||||
setTimeout(() => onData(Buffer.from("late\n", "utf-8")), 0);
|
||||
return { exitCode: 0 };
|
||||
},
|
||||
};
|
||||
const bash = createBashTool(process.cwd(), { operations });
|
||||
|
||||
const result = await bash.execute("test-call-late-output", { command: "late-output" });
|
||||
await new Promise((resolve) => setTimeout(resolve, 20));
|
||||
|
||||
expect(getTextOutput(result).trim()).toBe("before");
|
||||
});
|
||||
});
|
||||
@@ -0,0 +1,79 @@
|
||||
import type { ChildProcessByStdio } from "node:child_process";
|
||||
import type { Readable } from "node:stream";
|
||||
import { afterEach, describe, expect, it } from "vitest";
|
||||
import { spawnProcess, waitForChildProcess } from "../../../src/utils/child-process.ts";
|
||||
|
||||
/**
|
||||
* Regression test for https://github.com/earendil-works/pi/issues/5303
|
||||
*
|
||||
* waitForChildProcess armed a fixed 100ms timer on `exit` and destroyed the
|
||||
* stdio streams when it fired. When a short-lived detached descendant kept the
|
||||
* stdout pipe open, `close` never fired, so that timer was the only thing that
|
||||
* resolved the wait, and any output written more than 100ms after exit was
|
||||
* binned. In practice every git commit whose pre-commit hook runs lint-staged
|
||||
* came back truncated mid-listr2 output, read by the model as a hang.
|
||||
*
|
||||
* The fix re-arms the grace on each chunk, so an actively writing pipe keeps us
|
||||
* reading while a genuinely idle held-open handle still releases after the
|
||||
* grace elapses. Both behaviours are covered below.
|
||||
*/
|
||||
describe.skipIf(process.platform === "win32")("issue #5303 bash output truncation past exit", () => {
|
||||
let child: ChildProcessByStdio<null, Readable, Readable> | undefined;
|
||||
|
||||
afterEach(() => {
|
||||
if (child?.pid) {
|
||||
try {
|
||||
process.kill(-child.pid, "SIGKILL");
|
||||
} catch {
|
||||
// Already gone.
|
||||
}
|
||||
}
|
||||
child = undefined;
|
||||
});
|
||||
|
||||
it("captures output emitted after exit while a detached child holds stdout open", async () => {
|
||||
// The shell exits immediately, but a backgrounded subshell keeps the stdout
|
||||
// pipe open and emits ticks every 50ms, the last well past the 100ms grace.
|
||||
const command = 'printf "HEAD\\n"; ( for i in 1 2 3 4 5 6; do sleep 0.05; printf "TICK$i\\n"; done ) &';
|
||||
child = spawnProcess("/bin/sh", ["-c", command], {
|
||||
stdio: ["ignore", "pipe", "pipe"],
|
||||
detached: true,
|
||||
}) as ChildProcessByStdio<null, Readable, Readable>;
|
||||
|
||||
let output = "";
|
||||
child.stdout.on("data", (chunk: Buffer) => {
|
||||
output += chunk.toString();
|
||||
});
|
||||
|
||||
const exitCode = await waitForChildProcess(child);
|
||||
|
||||
expect(exitCode).toBe(0);
|
||||
expect(output).toContain("HEAD");
|
||||
expect(output).toContain("TICK6");
|
||||
});
|
||||
|
||||
it("resolves promptly when a detached child holds stdout open but stays quiet", async () => {
|
||||
// The shell exits, but a backgrounded sleeper inherits the stdout pipe and
|
||||
// keeps it open for a long time without writing. `close` never fires, so we
|
||||
// must still release via the idle grace rather than hang on the open handle.
|
||||
const command = 'printf "DONE\\n"; ( sleep 30 ) &';
|
||||
child = spawnProcess("/bin/sh", ["-c", command], {
|
||||
stdio: ["ignore", "pipe", "pipe"],
|
||||
detached: true,
|
||||
}) as ChildProcessByStdio<null, Readable, Readable>;
|
||||
|
||||
let output = "";
|
||||
child.stdout.on("data", (chunk: Buffer) => {
|
||||
output += chunk.toString();
|
||||
});
|
||||
|
||||
const start = Date.now();
|
||||
const exitCode = await waitForChildProcess(child);
|
||||
const elapsed = Date.now() - start;
|
||||
|
||||
expect(exitCode).toBe(0);
|
||||
expect(output).toContain("DONE");
|
||||
// Must not wait for the 30s sleeper; the idle grace releases us in well under a second.
|
||||
expect(elapsed).toBeLessThan(2000);
|
||||
});
|
||||
});
|
||||
Reference in New Issue
Block a user