From b7e86b5ba4f98a74644482c07109f612f3d49e29 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 17:04:41 -0400 Subject: [PATCH 1/9] Instrument Node in-process test stalls Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- .github/workflows/nodejs-sdk-tests.yml | 1 + nodejs/src/client.ts | 32 +++++++++++++++++++++++ nodejs/src/ffiRuntimeHost.ts | 21 +++++++++++++++ nodejs/src/session.ts | 16 ++++++++++++ nodejs/test/e2e/harness/sdkTestContext.ts | 27 +++++++++++++++---- 5 files changed, 92 insertions(+), 5 deletions(-) diff --git a/.github/workflows/nodejs-sdk-tests.yml b/.github/workflows/nodejs-sdk-tests.yml index 647345e0ea..f5a72a94d0 100644 --- a/.github/workflows/nodejs-sdk-tests.yml +++ b/.github/workflows/nodejs-sdk-tests.yml @@ -80,6 +80,7 @@ jobs: if: matrix.transport == 'inprocess' run: | echo "COPILOT_SDK_DEFAULT_CONNECTION=inprocess" >> "$GITHUB_ENV" + echo "COPILOT_SDK_TEST_DIAGNOSTICS=1" >> "$GITHUB_ENV" - name: Run Node.js SDK tests env: diff --git a/nodejs/src/client.ts b/nodejs/src/client.ts index 65784569cc..2c6b566fec 100644 --- a/nodejs/src/client.ts +++ b/nodejs/src/client.ts @@ -121,6 +121,14 @@ async function withTimeout(promise: Promise, timeoutMs: number, message: s } } +function logTestDiagnostic(message: string, startMs?: number): void { + if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { + return; + } + const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; + process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); +} + async function waitForChildExit(child: ChildProcess, timeoutMs: number): Promise { if (child.exitCode != null || child.signalCode != null) { return true; @@ -877,21 +885,26 @@ export class CopilotClient { return; } + const startMs = Date.now(); + logTestDiagnostic(`client.start begin transport=${this.connectionConfig.kind}`); this.state = "connecting"; try { // Only start CLI server process if not connecting to external server if (this.connectionConfig.kind === "inprocess") { await this.startInProcessFfi(); + logTestDiagnostic("client.start FFI host ready", startMs); } else if (!this.isExternalServer) { await this.startCLIServer(); } // Connect to the server await this.connectToServer(); + logTestDiagnostic("client.start JSON-RPC connected", startMs); // Verify protocol version compatibility await this.verifyProtocolVersion(); + logTestDiagnostic("client.start protocol verified", startMs); // If a session filesystem provider was configured, register it if (this.sessionFsConfig) { @@ -911,8 +924,10 @@ export class CopilotClient { } this.state = "connected"; + logTestDiagnostic("client.start complete", startMs); } catch (error) { this.state = "error"; + logTestDiagnostic("client.start failed", startMs); throw error; } } @@ -942,10 +957,12 @@ export class CopilotClient { * ``` */ async stop(): Promise { + const stopMs = Date.now(); const errors: Error[] = []; // Disconnect all active sessions with retry logic const activeSessions = [...this.sessions.values()]; + logTestDiagnostic(`client.stop begin sessions=${activeSessions.length}`); // TEMPORARY: over the in-process (FFI) transport the runtime shares this // process, so a turn still running when the runtime disposes the session // can leave that session's SQLite session.db handle open — it isn't @@ -959,6 +976,7 @@ export class CopilotClient { // may still resume. Remove once the runtime cleans up fully on shutdown. if (this.connectionConfig.kind === "inprocess") { await Promise.allSettled(activeSessions.map((session) => session.abort())); + logTestDiagnostic("client.stop session aborts settled", stopMs); } for (const session of activeSessions) { const sessionId = session.sessionId; @@ -989,6 +1007,7 @@ export class CopilotClient { ); } } + logTestDiagnostic("client.stop session disconnects complete", stopMs); for (const session of activeSessions) { session._markDisconnected(); } @@ -1023,6 +1042,7 @@ export class CopilotClient { ); } } + logTestDiagnostic("client.stop runtime shutdown stage complete", stopMs); // Close connection. Suppress writer failures first: tearing down the // transport can reject an in-flight server→client response write with @@ -1046,6 +1066,7 @@ export class CopilotClient { this._rpc = null; this._internalRpc = null; } + logTestDiagnostic("client.stop JSON-RPC disposed", stopMs); // Clear models cache this.modelsCache = null; @@ -1104,7 +1125,9 @@ export class CopilotClient { const host = this.ffiHost; this.ffiHost = null; try { + logTestDiagnostic("client.stop FFI host dispose begin", stopMs); host.dispose(); + logTestDiagnostic("client.stop FFI host dispose complete", stopMs); } catch (error) { errors.push( new Error( @@ -1122,6 +1145,7 @@ export class CopilotClient { this.runtimePort = null; this.stderrBuffer = ""; this.processExitPromise = null; + logTestDiagnostic(`client.stop complete errors=${errors.length}`, stopMs); return errors; } @@ -1416,8 +1440,11 @@ export class CopilotClient { } async createSession(config: SessionConfig): Promise { + const createMs = Date.now(); + logTestDiagnostic(`client.createSession begin connected=${this.connection !== null}`); if (!this.connection) { await this.start(); + logTestDiagnostic("client.createSession client started", createMs); } config = { ...this.configDefaultsForMode(), ...config }; @@ -1588,6 +1615,7 @@ export class CopilotClient { expAssignments: config.expAssignments, enableManagedSettings: config.enableManagedSettings, }); + logTestDiagnostic("client.createSession RPC complete", createMs); const { sessionId: returnedSessionId, @@ -1629,6 +1657,7 @@ export class CopilotClient { throw e; } + logTestDiagnostic("client.createSession complete", createMs); return session; } @@ -2560,6 +2589,8 @@ export class CopilotClient { /** Starts the in-process FFI runtime with SDK-managed typed options. */ private async startInProcessFfi(): Promise { + const startMs = Date.now(); + logTestDiagnostic("client.startInProcessFfi begin"); const entrypoint = this.resolveCliPathForFfi(); // Load the FFI host lazily so the native `koffi` addon (and its // platform-specific `koffi.node`) is only loaded on the in-process path; @@ -2603,6 +2634,7 @@ export class CopilotClient { ); this.ffiHost = host; await host.start(); + logTestDiagnostic("client.startInProcessFfi complete", startMs); } /** diff --git a/nodejs/src/ffiRuntimeHost.ts b/nodejs/src/ffiRuntimeHost.ts index a92aa1589a..790e20f5b1 100644 --- a/nodejs/src/ffiRuntimeHost.ts +++ b/nodejs/src/ffiRuntimeHost.ts @@ -28,6 +28,14 @@ const SYMBOL_PREFIX = "copilot_runtime_"; // connection is open (see start()); the exact interval is irrelevant. const KEEP_ALIVE_INTERVAL_MS = 1 << 30; +function logTestDiagnostic(message: string, startMs?: number): void { + if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { + return; + } + const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; + process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); +} + type KoffiFunction = ReturnType["func"]>; type KoffiType = ReturnType; type KoffiRegisteredCallback = ReturnType; @@ -186,6 +194,8 @@ export class FfiRuntimeHost { * waits for readiness, and opens the FFI JSON-RPC connection. */ async start(): Promise { + const startMs = Date.now(); + logTestDiagnostic("ffi.start begin"); const argvJson = buildArgvJson(this.cliEntrypoint, this.args); const envJson = buildEnvJson(this.environment); @@ -216,6 +226,7 @@ export class FfiRuntimeHost { `copilot_runtime_host_start failed (library '${this.libraryPath}', entrypoint '${this.cliEntrypoint}').` ); } + logTestDiagnostic("ffi.start hostStart complete", startMs); this.outboundCallback = koffi.register( (_userData: unknown, bytesPtr: unknown, bytesLen: number | bigint) => @@ -240,6 +251,7 @@ export class FfiRuntimeHost { this.serverId = 0; throw new Error("copilot_runtime_connection_open failed."); } + logTestDiagnostic("ffi.start connectionOpen complete", startMs); // The in-process transport has no socket/pipe handle to keep the Node event loop // alive while the SDK is idle awaiting a server→client frame. koffi delivers the @@ -311,6 +323,10 @@ export class FfiRuntimeHost { return; } this.disposed = true; + const disposeMs = Date.now(); + logTestDiagnostic( + `ffi.dispose begin server=${this.serverId !== 0} connection=${this.connectionId !== 0}` + ); if (this.keepAliveTimer !== undefined) { clearInterval(this.keepAliveTimer); @@ -319,8 +335,10 @@ export class FfiRuntimeHost { try { if (this.connectionId) { + logTestDiagnostic("ffi.dispose connectionClose begin", disposeMs); this.lib.connectionClose(this.connectionId); this.connectionId = 0; + logTestDiagnostic("ffi.dispose connectionClose complete", disposeMs); } } catch { // Ignore teardown failures. @@ -328,8 +346,10 @@ export class FfiRuntimeHost { try { if (this.serverId) { + logTestDiagnostic("ffi.dispose hostShutdown begin", disposeMs); this.lib.hostShutdown(this.serverId); this.serverId = 0; + logTestDiagnostic("ffi.dispose hostShutdown complete", disposeMs); } } catch { // Ignore teardown failures. @@ -337,5 +357,6 @@ export class FfiRuntimeHost { this.receiveStream.end(); this.unregisterCallback(); + logTestDiagnostic("ffi.dispose complete", disposeMs); } } diff --git a/nodejs/src/session.ts b/nodejs/src/session.ts index 1f71209de8..a6c7d8291a 100644 --- a/nodejs/src/session.ts +++ b/nodejs/src/session.ts @@ -61,6 +61,14 @@ import type { UserInputResponse, } from "./types.js"; +function logTestDiagnostic(message: string, startMs?: number): void { + if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { + return; + } + const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; + process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); +} + /** * Convert a raw hook input received over the wire into its public-facing shape. * This deserializes the numeric Unix-ms `timestamp` field on BaseHookInput @@ -292,6 +300,8 @@ export class CopilotSession { optionsOrPrompt: MessageOptions | string, timeout?: number ): Promise { + const sendMs = Date.now(); + logTestDiagnostic(`session.sendAndWait begin session=${this.sessionId}`); const options: MessageOptions = typeof optionsOrPrompt === "string" ? { prompt: optionsOrPrompt } : optionsOrPrompt; const effectiveTimeout = timeout ?? 60_000; @@ -322,6 +332,10 @@ export class CopilotSession { let timeoutId: ReturnType | undefined; try { await this.send(options); + logTestDiagnostic( + `session.sendAndWait send complete session=${this.sessionId}`, + sendMs + ); const timeoutPromise = new Promise((_, reject) => { timeoutId = setTimeout( @@ -335,6 +349,7 @@ export class CopilotSession { ); }); await Promise.race([idlePromise, timeoutPromise]); + logTestDiagnostic(`session.sendAndWait idle session=${this.sessionId}`, sendMs); return lastAssistantMessage; } finally { @@ -342,6 +357,7 @@ export class CopilotSession { clearTimeout(timeoutId); } unsubscribe(); + logTestDiagnostic(`session.sendAndWait complete session=${this.sessionId}`, sendMs); } } diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index 624450e47c..12a7781bac 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -16,6 +16,21 @@ import { formatError, retry } from "./sdkTestHelper"; export const isCI = process.env.GITHUB_ACTIONS === "true"; export const DEFAULT_GITHUB_TOKEN = "fake-token-for-e2e-tests"; +async function runDiagnosticPhase(name: string, action: () => Promise): Promise { + if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { + return action(); + } + const startMs = Date.now(); + console.error(`[sdk-test-diagnostic pid=${process.pid}] ${name} begin`); + try { + return await action(); + } finally { + console.error( + `[sdk-test-diagnostic pid=${process.pid}] ${name} complete elapsed=${Date.now() - startMs}ms` + ); + } +} + /** * True when the E2E suite is running over the in-process (FFI) transport * (COPILOT_SDK_DEFAULT_CONNECTION=inprocess). Use with `it.skipIf` / `describe.skipIf` @@ -291,11 +306,13 @@ export async function createSdkTestContext({ }); afterAll(async () => { - await copilotClient.stop(); - await openAiEndpoint.stop(anyTestFailed); - await rmDir("remove e2e test copilotHomeDir", copilotHomeDir); - await rmDir("remove e2e test homeDir", homeDir); - await rmDir("remove e2e test workDir", workDir); + await runDiagnosticPhase("client.stop", () => copilotClient.stop()); + await runDiagnosticPhase("proxy.stop", () => openAiEndpoint.stop(anyTestFailed)); + await runDiagnosticPhase("remove copilotHomeDir", () => + rmDir("remove e2e test copilotHomeDir", copilotHomeDir) + ); + await runDiagnosticPhase("remove homeDir", () => rmDir("remove e2e test homeDir", homeDir)); + await runDiagnosticPhase("remove workDir", () => rmDir("remove e2e test workDir", workDir)); }); return harness; From 2add01567130f4b617adb22717175fd4b5707b6c Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 17:30:15 -0400 Subject: [PATCH 2/9] Trace runtime and proxy during Node stalls Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- nodejs/test/e2e/harness/sdkTestContext.ts | 3 ++- test/harness/capturingHttpProxy.ts | 17 +++++++++++++++++ 2 files changed, 19 insertions(+), 1 deletion(-) diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index 12a7781bac..e2e5206b3f 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -230,7 +230,8 @@ export async function createSdkTestContext({ // beforeEach below), so the worker inherits it; passing a per-client env here // would have no effect (and is rejected by the in-process transport). env: effectiveInProcess ? undefined : mergedEnv, - logLevel: logLevel || "error", + logLevel: + process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1" ? "debug" : (logLevel ?? "error"), connection: effectiveConnection, gitHubToken: authTokenToUse, ...rest, diff --git a/test/harness/capturingHttpProxy.ts b/test/harness/capturingHttpProxy.ts index edccca4ead..4a9f376524 100644 --- a/test/harness/capturingHttpProxy.ts +++ b/test/harness/capturingHttpProxy.ts @@ -32,6 +32,13 @@ export class CapturingHttpProxy { req.on("end", () => { const body = Buffer.concat(chunks).toString("utf8"); const startTime = Date.now(); + const diagnosticsEnabled = + process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1"; + if (diagnosticsEnabled) { + console.error( + `[proxy-diagnostic pid=${process.pid}] request begin ${req.method || "GET"} ${req.url || "/"}`, + ); + } const capturedRequest: CapturedRequest = { method: req.method || "GET", @@ -86,6 +93,11 @@ export class CapturingHttpProxy { }; exchange.durationMs = endTime - startTime; + if (diagnosticsEnabled) { + console.error( + `[proxy-diagnostic pid=${process.pid}] request complete ${capturedRequest.method} ${capturedRequest.url} status=${responseStatusCode || 500} elapsed=${exchange.durationMs}ms`, + ); + } res.end(); }, @@ -105,6 +117,11 @@ export class CapturingHttpProxy { }; exchange.durationMs = endTime - startTime; + if (diagnosticsEnabled) { + console.error( + `[proxy-diagnostic pid=${process.pid}] request error ${capturedRequest.method} ${capturedRequest.url} elapsed=${exchange.durationMs}ms`, + ); + } res.writeHead(exchange.response.statusCode, errorHeaders); res.end("Proxy error"); From 9f19df2a8dd9e759a57281286332000ebebbfb7b Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 17:59:45 -0400 Subject: [PATCH 3/9] Create focused Windows in-process stress run Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- .github/workflows/nodejs-sdk-tests.yml | 11 ++++++++--- nodejs/test/e2e/harness/sdkTestContext.ts | 3 +-- 2 files changed, 9 insertions(+), 5 deletions(-) diff --git a/.github/workflows/nodejs-sdk-tests.yml b/.github/workflows/nodejs-sdk-tests.yml index f5a72a94d0..496094de0a 100644 --- a/.github/workflows/nodejs-sdk-tests.yml +++ b/.github/workflows/nodejs-sdk-tests.yml @@ -38,8 +38,8 @@ jobs: strategy: fail-fast: false matrix: - os: [ubuntu-latest, macos-latest, windows-latest] - transport: ["default", "inprocess"] + os: [windows-latest] + transport: ["inprocess"] runs-on: ${{ matrix.os }} defaults: run: @@ -85,4 +85,9 @@ jobs: - name: Run Node.js SDK tests env: COPILOT_HMAC_KEY: ${{ secrets.COPILOT_DEVELOPER_CLI_INTEGRATION_HMAC_KEY }} - run: npm test + run: >- + npm test -- + test/e2e/builtin_tools.e2e.test.ts + test/e2e/hooks.e2e.test.ts + test/e2e/agent_and_compact_rpc.e2e.test.ts + test/e2e/session.e2e.test.ts diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index e2e5206b3f..9b05f3c5a8 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -230,8 +230,7 @@ export async function createSdkTestContext({ // beforeEach below), so the worker inherits it; passing a per-client env here // would have no effect (and is rejected by the in-process transport). env: effectiveInProcess ? undefined : mergedEnv, - logLevel: - process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1" ? "debug" : (logLevel ?? "error"), + logLevel: logLevel ?? "error", connection: effectiveConnection, gitHubToken: authTokenToUse, ...rest, From 57d13046587e3283c85aa74365409633fdd19cd4 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 18:04:50 -0400 Subject: [PATCH 4/9] Measure Windows test resource pressure Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- .github/workflows/nodejs-sdk-tests.yml | 19 +++++++++++++------ 1 file changed, 13 insertions(+), 6 deletions(-) diff --git a/.github/workflows/nodejs-sdk-tests.yml b/.github/workflows/nodejs-sdk-tests.yml index 496094de0a..1385fe2979 100644 --- a/.github/workflows/nodejs-sdk-tests.yml +++ b/.github/workflows/nodejs-sdk-tests.yml @@ -85,9 +85,16 @@ jobs: - name: Run Node.js SDK tests env: COPILOT_HMAC_KEY: ${{ secrets.COPILOT_DEVELOPER_CLI_INTEGRATION_HMAC_KEY }} - run: >- - npm test -- - test/e2e/builtin_tools.e2e.test.ts - test/e2e/hooks.e2e.test.ts - test/e2e/agent_and_compact_rpc.e2e.test.ts - test/e2e/session.e2e.test.ts + run: | + pwsh.exe -NoProfile -Command ' + while ($true) { + $cpu = [math]::Round((Get-Counter "\Processor(_Total)\% Processor Time").CounterSamples.CookedValue) + $memory = [math]::Round((Get-Counter "\Memory\Available MBytes").CounterSamples.CookedValue) + $nodeCount = @(Get-Process -Name node -ErrorAction SilentlyContinue).Count + Write-Host "[resource-diagnostic] $(Get-Date -Format o) cpu=$cpu availableMb=$memory nodeProcesses=$nodeCount" + Start-Sleep -Seconds 5 + } + ' & + monitor_pid=$! + trap 'kill "$monitor_pid"' EXIT + npm test From d4c997a82bca17d6ad2af862888cbe1a7c6a4b91 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 18:26:32 -0400 Subject: [PATCH 5/9] Preserve runtime diagnostics on failure Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- .github/workflows/nodejs-sdk-tests.yml | 43 ++++++++++++++++------- nodejs/test/e2e/harness/sdkTestContext.ts | 14 +++++--- 2 files changed, 40 insertions(+), 17 deletions(-) diff --git a/.github/workflows/nodejs-sdk-tests.yml b/.github/workflows/nodejs-sdk-tests.yml index 1385fe2979..410618d26d 100644 --- a/.github/workflows/nodejs-sdk-tests.yml +++ b/.github/workflows/nodejs-sdk-tests.yml @@ -10,19 +10,19 @@ on: pull_request: types: [opened, synchronize, reopened, ready_for_review] paths: - - 'nodejs/**' - - 'test/**' - - '.github/workflows/nodejs-sdk-tests.yml' - - '!nodejs/scripts/**' - - '!**/*.md' - - '!**/LICENSE*' - - '!**/.gitignore' - - '!**/.editorconfig' - - '!**/*.png' - - '!**/*.jpg' - - '!**/*.jpeg' - - '!**/*.gif' - - '!**/*.svg' + - "nodejs/**" + - "test/**" + - ".github/workflows/nodejs-sdk-tests.yml" + - "!nodejs/scripts/**" + - "!**/*.md" + - "!**/LICENSE*" + - "!**/.gitignore" + - "!**/.editorconfig" + - "!**/*.png" + - "!**/*.jpg" + - "!**/*.jpeg" + - "!**/*.gif" + - "!**/*.svg" workflow_dispatch: merge_group: @@ -85,6 +85,7 @@ jobs: - name: Run Node.js SDK tests env: COPILOT_HMAC_KEY: ${{ secrets.COPILOT_DEVELOPER_CLI_INTEGRATION_HMAC_KEY }} + COPILOT_SDK_PRESERVE_TEST_HOME: "1" run: | pwsh.exe -NoProfile -Command ' while ($true) { @@ -98,3 +99,19 @@ jobs: monitor_pid=$! trap 'kill "$monitor_pid"' EXIT npm test + + - name: Collect runtime diagnostics + if: failure() + shell: pwsh + run: | + $paths = Get-ChildItem $env:TEMP -Directory -Filter "copilot-test-home-*" + if ($paths) { + Compress-Archive -Path $paths.FullName -DestinationPath runtime-diagnostics.zip + } + + - name: Upload runtime diagnostics + if: failure() + uses: actions/upload-artifact@v4 + with: + name: nodejs-runtime-diagnostics + path: nodejs/runtime-diagnostics.zip diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index 9b05f3c5a8..c280ee903c 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -230,7 +230,9 @@ export async function createSdkTestContext({ // beforeEach below), so the worker inherits it; passing a per-client env here // would have no effect (and is rejected by the in-process transport). env: effectiveInProcess ? undefined : mergedEnv, - logLevel: logLevel ?? "error", + logLevel: + logLevel ?? + (process.env.COPILOT_SDK_PRESERVE_TEST_HOME === "1" ? "debug" : "error"), connection: effectiveConnection, gitHubToken: authTokenToUse, ...rest, @@ -308,9 +310,13 @@ export async function createSdkTestContext({ afterAll(async () => { await runDiagnosticPhase("client.stop", () => copilotClient.stop()); await runDiagnosticPhase("proxy.stop", () => openAiEndpoint.stop(anyTestFailed)); - await runDiagnosticPhase("remove copilotHomeDir", () => - rmDir("remove e2e test copilotHomeDir", copilotHomeDir) - ); + if (anyTestFailed && process.env.COPILOT_SDK_PRESERVE_TEST_HOME === "1") { + console.error(`[sdk-test-diagnostic pid=${process.pid}] preserved ${copilotHomeDir}`); + } else { + await runDiagnosticPhase("remove copilotHomeDir", () => + rmDir("remove e2e test copilotHomeDir", copilotHomeDir) + ); + } await runDiagnosticPhase("remove homeDir", () => rmDir("remove e2e test homeDir", homeDir)); await runDiagnosticPhase("remove workDir", () => rmDir("remove e2e test workDir", workDir)); }); From 977de35fb27116ce346611f883f5e7e025dde333 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 18:39:18 -0400 Subject: [PATCH 6/9] Trace Windows session database locks Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- nodejs/test/e2e/harness/sdkTestContext.ts | 34 ++++++++++++++++++++++- 1 file changed, 33 insertions(+), 1 deletion(-) diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index c280ee903c..2e786182a7 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -6,6 +6,7 @@ import fs, { realpathSync } from "fs"; import { rm } from "fs/promises"; import os from "os"; import { basename, dirname, join, resolve } from "path"; +import { execFileSync } from "node:child_process"; import { rimraf } from "rimraf"; import { fileURLToPath } from "url"; import { afterAll, afterEach, beforeEach, onTestFailed, TestContext } from "vitest"; @@ -349,8 +350,39 @@ async function rmDir(message: string, path: string): Promise { // be removed (e.g. CLI background writer racing with cleanup), warn and // continue rather than failing the whole test run — the OS / CI runner // will reclaim the temp dir on shutdown. + let reportedLock = false; try { - await retry(message, () => rm(path, { recursive: true, force: true }), 30, 1000); + await retry( + message, + async () => { + try { + await rm(path, { recursive: true, force: true }); + } catch (error) { + if ( + !reportedLock && + process.platform === "win32" && + process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1" + ) { + reportedLock = true; + const processes = execFileSync( + "powershell.exe", + [ + "-NoProfile", + "-Command", + "Get-CimInstance Win32_Process | Where-Object { $_.Name -in @('node.exe', 'cmd.exe', 'copilot.exe') } | Select-Object ProcessId, ParentProcessId, CreationDate, Name, CommandLine | ConvertTo-Json -Compress", + ], + { encoding: "utf8" } + ); + console.error( + `[sdk-test-diagnostic pid=${process.pid}] remove failed path=${path} error=${formatError(error)} processes=${processes.trim()}` + ); + } + throw error; + } + }, + 30, + 1000 + ); } catch (error) { console.warn( `WARN: ${message} failed; leaving temp dir for OS cleanup: ${formatError(error)}` From a4f17fbdc622756230ac21f07541daf6ea6d05b8 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 19:05:46 -0400 Subject: [PATCH 7/9] Avoid perturbing runtime lock timing Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- nodejs/test/e2e/harness/sdkTestContext.ts | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index 2e786182a7..6b837eb8fd 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -231,9 +231,7 @@ export async function createSdkTestContext({ // beforeEach below), so the worker inherits it; passing a per-client env here // would have no effect (and is rejected by the in-process transport). env: effectiveInProcess ? undefined : mergedEnv, - logLevel: - logLevel ?? - (process.env.COPILOT_SDK_PRESERVE_TEST_HOME === "1" ? "debug" : "error"), + logLevel: logLevel ?? "error", connection: effectiveConnection, gitHubToken: authTokenToUse, ...rest, From 5e60dadac2ee55f0810be1f2ad04385ffa38ef07 Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 19:26:37 -0400 Subject: [PATCH 8/9] Avoid Windows in-process teardown deadlock Do not retry removal of the in-process runtime's session home while its Vitest worker still owns a locked session database. Retrying until the hook timeout prevents the worker from exiting and releasing the lock. Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- .github/workflows/nodejs-sdk-tests.yml | 62 +++++-------------- nodejs/src/client.ts | 32 ---------- nodejs/src/ffiRuntimeHost.ts | 21 ------- nodejs/src/session.ts | 16 ----- nodejs/test/e2e/harness/sdkTestContext.ts | 75 +++++------------------ test/harness/capturingHttpProxy.ts | 17 ----- 6 files changed, 30 insertions(+), 193 deletions(-) diff --git a/.github/workflows/nodejs-sdk-tests.yml b/.github/workflows/nodejs-sdk-tests.yml index 410618d26d..647345e0ea 100644 --- a/.github/workflows/nodejs-sdk-tests.yml +++ b/.github/workflows/nodejs-sdk-tests.yml @@ -10,19 +10,19 @@ on: pull_request: types: [opened, synchronize, reopened, ready_for_review] paths: - - "nodejs/**" - - "test/**" - - ".github/workflows/nodejs-sdk-tests.yml" - - "!nodejs/scripts/**" - - "!**/*.md" - - "!**/LICENSE*" - - "!**/.gitignore" - - "!**/.editorconfig" - - "!**/*.png" - - "!**/*.jpg" - - "!**/*.jpeg" - - "!**/*.gif" - - "!**/*.svg" + - 'nodejs/**' + - 'test/**' + - '.github/workflows/nodejs-sdk-tests.yml' + - '!nodejs/scripts/**' + - '!**/*.md' + - '!**/LICENSE*' + - '!**/.gitignore' + - '!**/.editorconfig' + - '!**/*.png' + - '!**/*.jpg' + - '!**/*.jpeg' + - '!**/*.gif' + - '!**/*.svg' workflow_dispatch: merge_group: @@ -38,8 +38,8 @@ jobs: strategy: fail-fast: false matrix: - os: [windows-latest] - transport: ["inprocess"] + os: [ubuntu-latest, macos-latest, windows-latest] + transport: ["default", "inprocess"] runs-on: ${{ matrix.os }} defaults: run: @@ -80,38 +80,8 @@ jobs: if: matrix.transport == 'inprocess' run: | echo "COPILOT_SDK_DEFAULT_CONNECTION=inprocess" >> "$GITHUB_ENV" - echo "COPILOT_SDK_TEST_DIAGNOSTICS=1" >> "$GITHUB_ENV" - name: Run Node.js SDK tests env: COPILOT_HMAC_KEY: ${{ secrets.COPILOT_DEVELOPER_CLI_INTEGRATION_HMAC_KEY }} - COPILOT_SDK_PRESERVE_TEST_HOME: "1" - run: | - pwsh.exe -NoProfile -Command ' - while ($true) { - $cpu = [math]::Round((Get-Counter "\Processor(_Total)\% Processor Time").CounterSamples.CookedValue) - $memory = [math]::Round((Get-Counter "\Memory\Available MBytes").CounterSamples.CookedValue) - $nodeCount = @(Get-Process -Name node -ErrorAction SilentlyContinue).Count - Write-Host "[resource-diagnostic] $(Get-Date -Format o) cpu=$cpu availableMb=$memory nodeProcesses=$nodeCount" - Start-Sleep -Seconds 5 - } - ' & - monitor_pid=$! - trap 'kill "$monitor_pid"' EXIT - npm test - - - name: Collect runtime diagnostics - if: failure() - shell: pwsh - run: | - $paths = Get-ChildItem $env:TEMP -Directory -Filter "copilot-test-home-*" - if ($paths) { - Compress-Archive -Path $paths.FullName -DestinationPath runtime-diagnostics.zip - } - - - name: Upload runtime diagnostics - if: failure() - uses: actions/upload-artifact@v4 - with: - name: nodejs-runtime-diagnostics - path: nodejs/runtime-diagnostics.zip + run: npm test diff --git a/nodejs/src/client.ts b/nodejs/src/client.ts index 2c6b566fec..65784569cc 100644 --- a/nodejs/src/client.ts +++ b/nodejs/src/client.ts @@ -121,14 +121,6 @@ async function withTimeout(promise: Promise, timeoutMs: number, message: s } } -function logTestDiagnostic(message: string, startMs?: number): void { - if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { - return; - } - const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; - process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); -} - async function waitForChildExit(child: ChildProcess, timeoutMs: number): Promise { if (child.exitCode != null || child.signalCode != null) { return true; @@ -885,26 +877,21 @@ export class CopilotClient { return; } - const startMs = Date.now(); - logTestDiagnostic(`client.start begin transport=${this.connectionConfig.kind}`); this.state = "connecting"; try { // Only start CLI server process if not connecting to external server if (this.connectionConfig.kind === "inprocess") { await this.startInProcessFfi(); - logTestDiagnostic("client.start FFI host ready", startMs); } else if (!this.isExternalServer) { await this.startCLIServer(); } // Connect to the server await this.connectToServer(); - logTestDiagnostic("client.start JSON-RPC connected", startMs); // Verify protocol version compatibility await this.verifyProtocolVersion(); - logTestDiagnostic("client.start protocol verified", startMs); // If a session filesystem provider was configured, register it if (this.sessionFsConfig) { @@ -924,10 +911,8 @@ export class CopilotClient { } this.state = "connected"; - logTestDiagnostic("client.start complete", startMs); } catch (error) { this.state = "error"; - logTestDiagnostic("client.start failed", startMs); throw error; } } @@ -957,12 +942,10 @@ export class CopilotClient { * ``` */ async stop(): Promise { - const stopMs = Date.now(); const errors: Error[] = []; // Disconnect all active sessions with retry logic const activeSessions = [...this.sessions.values()]; - logTestDiagnostic(`client.stop begin sessions=${activeSessions.length}`); // TEMPORARY: over the in-process (FFI) transport the runtime shares this // process, so a turn still running when the runtime disposes the session // can leave that session's SQLite session.db handle open — it isn't @@ -976,7 +959,6 @@ export class CopilotClient { // may still resume. Remove once the runtime cleans up fully on shutdown. if (this.connectionConfig.kind === "inprocess") { await Promise.allSettled(activeSessions.map((session) => session.abort())); - logTestDiagnostic("client.stop session aborts settled", stopMs); } for (const session of activeSessions) { const sessionId = session.sessionId; @@ -1007,7 +989,6 @@ export class CopilotClient { ); } } - logTestDiagnostic("client.stop session disconnects complete", stopMs); for (const session of activeSessions) { session._markDisconnected(); } @@ -1042,7 +1023,6 @@ export class CopilotClient { ); } } - logTestDiagnostic("client.stop runtime shutdown stage complete", stopMs); // Close connection. Suppress writer failures first: tearing down the // transport can reject an in-flight server→client response write with @@ -1066,7 +1046,6 @@ export class CopilotClient { this._rpc = null; this._internalRpc = null; } - logTestDiagnostic("client.stop JSON-RPC disposed", stopMs); // Clear models cache this.modelsCache = null; @@ -1125,9 +1104,7 @@ export class CopilotClient { const host = this.ffiHost; this.ffiHost = null; try { - logTestDiagnostic("client.stop FFI host dispose begin", stopMs); host.dispose(); - logTestDiagnostic("client.stop FFI host dispose complete", stopMs); } catch (error) { errors.push( new Error( @@ -1145,7 +1122,6 @@ export class CopilotClient { this.runtimePort = null; this.stderrBuffer = ""; this.processExitPromise = null; - logTestDiagnostic(`client.stop complete errors=${errors.length}`, stopMs); return errors; } @@ -1440,11 +1416,8 @@ export class CopilotClient { } async createSession(config: SessionConfig): Promise { - const createMs = Date.now(); - logTestDiagnostic(`client.createSession begin connected=${this.connection !== null}`); if (!this.connection) { await this.start(); - logTestDiagnostic("client.createSession client started", createMs); } config = { ...this.configDefaultsForMode(), ...config }; @@ -1615,7 +1588,6 @@ export class CopilotClient { expAssignments: config.expAssignments, enableManagedSettings: config.enableManagedSettings, }); - logTestDiagnostic("client.createSession RPC complete", createMs); const { sessionId: returnedSessionId, @@ -1657,7 +1629,6 @@ export class CopilotClient { throw e; } - logTestDiagnostic("client.createSession complete", createMs); return session; } @@ -2589,8 +2560,6 @@ export class CopilotClient { /** Starts the in-process FFI runtime with SDK-managed typed options. */ private async startInProcessFfi(): Promise { - const startMs = Date.now(); - logTestDiagnostic("client.startInProcessFfi begin"); const entrypoint = this.resolveCliPathForFfi(); // Load the FFI host lazily so the native `koffi` addon (and its // platform-specific `koffi.node`) is only loaded on the in-process path; @@ -2634,7 +2603,6 @@ export class CopilotClient { ); this.ffiHost = host; await host.start(); - logTestDiagnostic("client.startInProcessFfi complete", startMs); } /** diff --git a/nodejs/src/ffiRuntimeHost.ts b/nodejs/src/ffiRuntimeHost.ts index 790e20f5b1..a92aa1589a 100644 --- a/nodejs/src/ffiRuntimeHost.ts +++ b/nodejs/src/ffiRuntimeHost.ts @@ -28,14 +28,6 @@ const SYMBOL_PREFIX = "copilot_runtime_"; // connection is open (see start()); the exact interval is irrelevant. const KEEP_ALIVE_INTERVAL_MS = 1 << 30; -function logTestDiagnostic(message: string, startMs?: number): void { - if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { - return; - } - const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; - process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); -} - type KoffiFunction = ReturnType["func"]>; type KoffiType = ReturnType; type KoffiRegisteredCallback = ReturnType; @@ -194,8 +186,6 @@ export class FfiRuntimeHost { * waits for readiness, and opens the FFI JSON-RPC connection. */ async start(): Promise { - const startMs = Date.now(); - logTestDiagnostic("ffi.start begin"); const argvJson = buildArgvJson(this.cliEntrypoint, this.args); const envJson = buildEnvJson(this.environment); @@ -226,7 +216,6 @@ export class FfiRuntimeHost { `copilot_runtime_host_start failed (library '${this.libraryPath}', entrypoint '${this.cliEntrypoint}').` ); } - logTestDiagnostic("ffi.start hostStart complete", startMs); this.outboundCallback = koffi.register( (_userData: unknown, bytesPtr: unknown, bytesLen: number | bigint) => @@ -251,7 +240,6 @@ export class FfiRuntimeHost { this.serverId = 0; throw new Error("copilot_runtime_connection_open failed."); } - logTestDiagnostic("ffi.start connectionOpen complete", startMs); // The in-process transport has no socket/pipe handle to keep the Node event loop // alive while the SDK is idle awaiting a server→client frame. koffi delivers the @@ -323,10 +311,6 @@ export class FfiRuntimeHost { return; } this.disposed = true; - const disposeMs = Date.now(); - logTestDiagnostic( - `ffi.dispose begin server=${this.serverId !== 0} connection=${this.connectionId !== 0}` - ); if (this.keepAliveTimer !== undefined) { clearInterval(this.keepAliveTimer); @@ -335,10 +319,8 @@ export class FfiRuntimeHost { try { if (this.connectionId) { - logTestDiagnostic("ffi.dispose connectionClose begin", disposeMs); this.lib.connectionClose(this.connectionId); this.connectionId = 0; - logTestDiagnostic("ffi.dispose connectionClose complete", disposeMs); } } catch { // Ignore teardown failures. @@ -346,10 +328,8 @@ export class FfiRuntimeHost { try { if (this.serverId) { - logTestDiagnostic("ffi.dispose hostShutdown begin", disposeMs); this.lib.hostShutdown(this.serverId); this.serverId = 0; - logTestDiagnostic("ffi.dispose hostShutdown complete", disposeMs); } } catch { // Ignore teardown failures. @@ -357,6 +337,5 @@ export class FfiRuntimeHost { this.receiveStream.end(); this.unregisterCallback(); - logTestDiagnostic("ffi.dispose complete", disposeMs); } } diff --git a/nodejs/src/session.ts b/nodejs/src/session.ts index a6c7d8291a..1f71209de8 100644 --- a/nodejs/src/session.ts +++ b/nodejs/src/session.ts @@ -61,14 +61,6 @@ import type { UserInputResponse, } from "./types.js"; -function logTestDiagnostic(message: string, startMs?: number): void { - if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { - return; - } - const elapsed = startMs === undefined ? "" : ` elapsed=${Date.now() - startMs}ms`; - process.stderr.write(`[copilot-sdk-diagnostic pid=${process.pid}] ${message}${elapsed}\n`); -} - /** * Convert a raw hook input received over the wire into its public-facing shape. * This deserializes the numeric Unix-ms `timestamp` field on BaseHookInput @@ -300,8 +292,6 @@ export class CopilotSession { optionsOrPrompt: MessageOptions | string, timeout?: number ): Promise { - const sendMs = Date.now(); - logTestDiagnostic(`session.sendAndWait begin session=${this.sessionId}`); const options: MessageOptions = typeof optionsOrPrompt === "string" ? { prompt: optionsOrPrompt } : optionsOrPrompt; const effectiveTimeout = timeout ?? 60_000; @@ -332,10 +322,6 @@ export class CopilotSession { let timeoutId: ReturnType | undefined; try { await this.send(options); - logTestDiagnostic( - `session.sendAndWait send complete session=${this.sessionId}`, - sendMs - ); const timeoutPromise = new Promise((_, reject) => { timeoutId = setTimeout( @@ -349,7 +335,6 @@ export class CopilotSession { ); }); await Promise.race([idlePromise, timeoutPromise]); - logTestDiagnostic(`session.sendAndWait idle session=${this.sessionId}`, sendMs); return lastAssistantMessage; } finally { @@ -357,7 +342,6 @@ export class CopilotSession { clearTimeout(timeoutId); } unsubscribe(); - logTestDiagnostic(`session.sendAndWait complete session=${this.sessionId}`, sendMs); } } diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index 6b837eb8fd..f2dd607edb 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -6,7 +6,6 @@ import fs, { realpathSync } from "fs"; import { rm } from "fs/promises"; import os from "os"; import { basename, dirname, join, resolve } from "path"; -import { execFileSync } from "node:child_process"; import { rimraf } from "rimraf"; import { fileURLToPath } from "url"; import { afterAll, afterEach, beforeEach, onTestFailed, TestContext } from "vitest"; @@ -17,21 +16,6 @@ import { formatError, retry } from "./sdkTestHelper"; export const isCI = process.env.GITHUB_ACTIONS === "true"; export const DEFAULT_GITHUB_TOKEN = "fake-token-for-e2e-tests"; -async function runDiagnosticPhase(name: string, action: () => Promise): Promise { - if (process.env.COPILOT_SDK_TEST_DIAGNOSTICS !== "1") { - return action(); - } - const startMs = Date.now(); - console.error(`[sdk-test-diagnostic pid=${process.pid}] ${name} begin`); - try { - return await action(); - } finally { - console.error( - `[sdk-test-diagnostic pid=${process.pid}] ${name} complete elapsed=${Date.now() - startMs}ms` - ); - } -} - /** * True when the E2E suite is running over the in-process (FFI) transport * (COPILOT_SDK_DEFAULT_CONNECTION=inprocess). Use with `it.skipIf` / `describe.skipIf` @@ -231,7 +215,7 @@ export async function createSdkTestContext({ // beforeEach below), so the worker inherits it; passing a per-client env here // would have no effect (and is rejected by the in-process transport). env: effectiveInProcess ? undefined : mergedEnv, - logLevel: logLevel ?? "error", + logLevel: logLevel || "error", connection: effectiveConnection, gitHubToken: authTokenToUse, ...rest, @@ -307,17 +291,17 @@ export async function createSdkTestContext({ }); afterAll(async () => { - await runDiagnosticPhase("client.stop", () => copilotClient.stop()); - await runDiagnosticPhase("proxy.stop", () => openAiEndpoint.stop(anyTestFailed)); - if (anyTestFailed && process.env.COPILOT_SDK_PRESERVE_TEST_HOME === "1") { - console.error(`[sdk-test-diagnostic pid=${process.pid}] preserved ${copilotHomeDir}`); - } else { - await runDiagnosticPhase("remove copilotHomeDir", () => - rmDir("remove e2e test copilotHomeDir", copilotHomeDir) - ); - } - await runDiagnosticPhase("remove homeDir", () => rmDir("remove e2e test homeDir", homeDir)); - await runDiagnosticPhase("remove workDir", () => rmDir("remove e2e test workDir", workDir)); + await copilotClient.stop(); + await openAiEndpoint.stop(anyTestFailed); + // On Windows, the in-process runtime can keep session.db locked until this + // Vitest worker exits. Retrying here prevents that exit and deadlocks teardown. + await rmDir( + "remove e2e test copilotHomeDir", + copilotHomeDir, + isInProcess && process.platform === "win32" ? 1 : 30 + ); + await rmDir("remove e2e test homeDir", homeDir); + await rmDir("remove e2e test workDir", workDir); }); return harness; @@ -342,45 +326,14 @@ function getTrafficCapturePath(testContext: TestContext): string { return join(SNAPSHOTS_DIR, testFileName, `${taskNameAsFilename}.yaml`); } -async function rmDir(message: string, path: string): Promise { +async function rmDir(message: string, path: string, maxTries = 30): Promise { // Use longer retries to tolerate Windows holding SQLite session-store.db // open briefly after the CLI subprocess exits. If the temp dir still can't // be removed (e.g. CLI background writer racing with cleanup), warn and // continue rather than failing the whole test run — the OS / CI runner // will reclaim the temp dir on shutdown. - let reportedLock = false; try { - await retry( - message, - async () => { - try { - await rm(path, { recursive: true, force: true }); - } catch (error) { - if ( - !reportedLock && - process.platform === "win32" && - process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1" - ) { - reportedLock = true; - const processes = execFileSync( - "powershell.exe", - [ - "-NoProfile", - "-Command", - "Get-CimInstance Win32_Process | Where-Object { $_.Name -in @('node.exe', 'cmd.exe', 'copilot.exe') } | Select-Object ProcessId, ParentProcessId, CreationDate, Name, CommandLine | ConvertTo-Json -Compress", - ], - { encoding: "utf8" } - ); - console.error( - `[sdk-test-diagnostic pid=${process.pid}] remove failed path=${path} error=${formatError(error)} processes=${processes.trim()}` - ); - } - throw error; - } - }, - 30, - 1000 - ); + await retry(message, () => rm(path, { recursive: true, force: true }), maxTries, 1000); } catch (error) { console.warn( `WARN: ${message} failed; leaving temp dir for OS cleanup: ${formatError(error)}` diff --git a/test/harness/capturingHttpProxy.ts b/test/harness/capturingHttpProxy.ts index 4a9f376524..edccca4ead 100644 --- a/test/harness/capturingHttpProxy.ts +++ b/test/harness/capturingHttpProxy.ts @@ -32,13 +32,6 @@ export class CapturingHttpProxy { req.on("end", () => { const body = Buffer.concat(chunks).toString("utf8"); const startTime = Date.now(); - const diagnosticsEnabled = - process.env.COPILOT_SDK_TEST_DIAGNOSTICS === "1"; - if (diagnosticsEnabled) { - console.error( - `[proxy-diagnostic pid=${process.pid}] request begin ${req.method || "GET"} ${req.url || "/"}`, - ); - } const capturedRequest: CapturedRequest = { method: req.method || "GET", @@ -93,11 +86,6 @@ export class CapturingHttpProxy { }; exchange.durationMs = endTime - startTime; - if (diagnosticsEnabled) { - console.error( - `[proxy-diagnostic pid=${process.pid}] request complete ${capturedRequest.method} ${capturedRequest.url} status=${responseStatusCode || 500} elapsed=${exchange.durationMs}ms`, - ); - } res.end(); }, @@ -117,11 +105,6 @@ export class CapturingHttpProxy { }; exchange.durationMs = endTime - startTime; - if (diagnosticsEnabled) { - console.error( - `[proxy-diagnostic pid=${process.pid}] request error ${capturedRequest.method} ${capturedRequest.url} elapsed=${exchange.durationMs}ms`, - ); - } res.writeHead(exchange.response.statusCode, errorHeaders); res.end("Proxy error"); From 9dc2c289e7867c414ed63ac7f9397090ae4364ac Mon Sep 17 00:00:00 2001 From: Stephen Toub Date: Wed, 15 Jul 2026 20:57:12 -0400 Subject: [PATCH 9/9] Clarify Windows teardown deadlock Co-authored-by: Copilot App <223556219+Copilot@users.noreply.github.com> Copilot-Session: 6e902b9a-5527-4a32-a5a3-e0bf5bfef3f7 --- nodejs/test/e2e/harness/sdkTestContext.ts | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/nodejs/test/e2e/harness/sdkTestContext.ts b/nodejs/test/e2e/harness/sdkTestContext.ts index f2dd607edb..bf62db4826 100644 --- a/nodejs/test/e2e/harness/sdkTestContext.ts +++ b/nodejs/test/e2e/harness/sdkTestContext.ts @@ -293,8 +293,10 @@ export async function createSdkTestContext({ afterAll(async () => { await copilotClient.stop(); await openAiEndpoint.stop(anyTestFailed); - // On Windows, the in-process runtime can keep session.db locked until this - // Vitest worker exits. Retrying here prevents that exit and deadlocks teardown. + // On Windows, this Vitest worker can retain the in-process runtime's session.db + // lock until the worker exits. Retrying from its afterAll hook cannot succeed: + // the hook waits for the lock, while the lock cannot clear until the hook returns + // and lets the worker exit. await rmDir( "remove e2e test copilotHomeDir", copilotHomeDir,