Skip to content
Merged
131 changes: 131 additions & 0 deletions actions/setup/js/copilot_sdk_driver.test.cjs
Original file line number Diff line number Diff line change
Expand Up @@ -87,6 +87,67 @@ describe("copilot_sdk_driver.cjs", () => {
}
});

it("clears cleanup timeout deadlines when cleanup settles promptly", async () => {
const disconnect = vi.fn().mockResolvedValue(undefined);
const stop = vi.fn().mockResolvedValue(undefined);
let onEvent = () => {};
const session = {
sessionId: "session-cleanup-timeouts-cleared",
on: handler => {
onEvent = handler;
},
sendAndWait: vi.fn().mockImplementation(async () => {
onEvent({
type: "assistant.message",
ephemeral: false,
timestamp: new Date().toISOString(),
data: { content: "done" },
});
return { data: { content: "done" } };
}),
disconnect,
};
class FakeCopilotClient {
start = vi.fn().mockResolvedValue(undefined);
createSession = vi.fn().mockResolvedValue(session);
stop = stop;
}

const realSetTimeout = global.setTimeout;
const realClearTimeout = global.clearTimeout;
const cleanupTimeoutHandles = new Set();
const clearedCleanupTimeoutHandles = new Set();
const setTimeoutSpy = vi.spyOn(global, "setTimeout").mockImplementation((fn, delay, ...args) => {
const handle = realSetTimeout(fn, delay, ...args);
if (delay === 5_000) cleanupTimeoutHandles.add(handle);
return handle;
});
const clearTimeoutSpy = vi.spyOn(global, "clearTimeout").mockImplementation(handle => {
if (cleanupTimeoutHandles.has(handle)) clearedCleanupTimeoutHandles.add(handle);
return realClearTimeout(handle);
});

try {
const result = await runWithCopilotSDK({
sdkUri: "http://127.0.0.1:3002",
prompt: "test prompt",
logger: () => {},
sdkModule: {
CopilotClient: FakeCopilotClient,
RuntimeConnection: { forUri: vi.fn(() => ({})) },
approveAll: () => "allow",
},
});

expect(result.exitCode).toBe(0);
expect(cleanupTimeoutHandles.size).toBe(2);
expect(clearedCleanupTimeoutHandles.size).toBe(2);
} finally {
setTimeoutSpy.mockRestore();
clearTimeoutSpy.mockRestore();
}
});

it("disconnects session and stops client on send failure", async () => {
const disconnect = vi.fn().mockResolvedValue(undefined);
const stop = vi.fn().mockResolvedValue(undefined);
Expand Down Expand Up @@ -413,6 +474,76 @@ describe("copilot_sdk_driver.cjs", () => {
}
});

it("cleanup timeout prevents hang when client.stop() never resolves", async () => {
// Regression: when the SDK server is unresponsive, client.stop() in the
// finally block can hang indefinitely, causing the process to be killed by
// the step timeout instead of exiting cleanly with success.
// The 5-second cleanup timeout must bound the hang and allow the function
// to return with exitCode 0 within a reasonable wall-clock budget.
let onEvent = () => {};
let resolveDisconnect;
const disconnectCalled = new Promise(resolve => {
resolveDisconnect = resolve;
});
const disconnectWithSignal = vi.fn().mockImplementation(() => {
resolveDisconnect();
return Promise.resolve(undefined);
});
// stop() never resolves — simulates a hung SDK server.
const hangingStop = vi.fn().mockReturnValue(new Promise(() => {}));

const session = {
sessionId: "session-cleanup-timeout",
on: handler => {
onEvent = handler;
},
sendAndWait: vi.fn().mockImplementation(async () => {
onEvent({
type: "assistant.message",
ephemeral: false,
timestamp: new Date().toISOString(),
data: { content: "work done" },
});
await disconnectCalled;
throw new Error("transport disconnected");
}),
disconnect: disconnectWithSignal,
};
class FakeCopilotClient {
start = vi.fn().mockResolvedValue(undefined);
createSession = vi.fn().mockResolvedValue(session);
stop = hangingStop;
}

const prevIdleMs = process.env.GH_AW_SDK_IDLE_MS;
process.env.GH_AW_SDK_IDLE_MS = "20";
try {
const start = Date.now();
const result = await runWithCopilotSDK({
sdkUri: "http://127.0.0.1:3002",
prompt: "test prompt",
logger: () => {},
sdkModule: {
CopilotClient: FakeCopilotClient,
RuntimeConnection: { forUri: vi.fn(() => ({})) },
approveAll: () => "allow",
},
});
const elapsed = Date.now() - start;

expect(result.exitCode).toBe(0);
expect(result.hasOutput).toBe(true);
expect(result.output).toContain("work done");
// stop() was called but hung — the cleanup timeout must have unblocked.
expect(hangingStop).toHaveBeenCalledTimes(1);
// Should complete well within 10 seconds (5s cleanup timeout + overhead).
expect(elapsed).toBeLessThan(10_000);
} finally {
if (prevIdleMs === undefined) delete process.env.GH_AW_SDK_IDLE_MS;
else process.env.GH_AW_SDK_IDLE_MS = prevIdleMs;
}
});

it("post-completion watchdog does not fire when tool calls are still pending", async () => {
// When a new tool call starts after the watchdog would have been armed,
// the watchdog must be disarmed so it does not fire while work is in progress.
Expand Down
48 changes: 44 additions & 4 deletions actions/setup/js/copilot_sdk_session.cjs
Original file line number Diff line number Diff line change
Expand Up @@ -50,14 +50,19 @@ const SDK_SEND_TIMEOUT_MS_DEFAULT = 10 * 60 * 1000;
// Keep in sync with SDK_SESSION_IDLE_TIMEOUT_PATTERN in copilot_harness.cjs.
const SDK_IDLE_TIMEOUT_PATTERN = /Timeout after \d+ms waiting for session\.idle/;

// Default idle period for the post-completion watchdog: 5 minutes.
// Default idle period for the post-completion watchdog: 30 seconds.
// When the agent has produced output and all tracked tool calls have completed,
// the driver arms a watchdog timer. If no new SDK events arrive within this
// window, the driver force-disconnects the session and treats it as a successful
// completion — covering the SDK driver bug where sendAndWait never resolves after
// the final tool result is returned.
// 30 s is chosen to be well under typical step timeouts (≥ 5 min) while still
// being long enough to avoid false-positives during legitimate LLM inference gaps
// (the session.on handler disarms the watchdog on every assistant.turn_start event,
// so the timer only fires when the session is truly quiescent: output collected,
// no tool calls in flight, and no active inference turn).
// Override via the GH_AW_SDK_IDLE_MS environment variable.
const SDK_POST_COMPLETION_IDLE_MS_DEFAULT = 5 * 60 * 1000;
const SDK_POST_COMPLETION_IDLE_MS_DEFAULT = 30 * 1000;

/**
* Extract the prompt text from a resolved args array.
Expand Down Expand Up @@ -479,16 +484,51 @@ async function runWithCopilotSDK({ sdkUri, prompt, logger, attempt = 0, model, c
if (stream) {
await new Promise(resolve => stream.end(resolve));
}
// Timeout budget for each cleanup operation. Prevents the driver from
// hanging indefinitely when the server is unresponsive after sendAndWait
// times out or the watchdog force-disconnects the session.
// The helper resolves normally on success and also on timeout (signalling
// timeout via the returned boolean) so the caller can log a warning.
const CLEANUP_TIMEOUT_MS = 5_000;
/**
* Race a cleanup promise against a fixed deadline.
* Resolves to true when the promise settled in time, false on timeout.
* @param {Promise<unknown>} p
* @returns {Promise<boolean>}
*/
const withCleanupTimeout = p => {
let timeoutId = null;
const deadline = new Promise(resolve => {
timeoutId = setTimeout(() => {
timeoutId = null;
resolve(false);
}, CLEANUP_TIMEOUT_MS);
if (typeof timeoutId?.unref === "function") timeoutId.unref();
});
return Promise.race([
p.then(
() => true,
() => true
),
deadline,
]).then(settled => {
if (timeoutId) clearTimeout(timeoutId);
if (!settled) {
log(`warning: cleanup operation timed out after ${CLEANUP_TIMEOUT_MS}ms`);
}
return settled;
});
};
if (session) {
try {
await session.disconnect();
await withCleanupTimeout(session.disconnect());
} catch {
// best-effort cleanup
}
}
if (clientStarted) {
try {
await client.stop();
await withCleanupTimeout(client.stop());
} catch {
// best-effort cleanup
}
Expand Down
Loading