From 00e2da197408044156b17412f40321c98b9ef29d Mon Sep 17 00:00:00 2001 From: JF Date: Sat, 22 Aug 2026 16:24:45 -0400 Subject: [PATCH] fix(proxy): eliminate dangling rejections behind the seed-1038859894 flake (#420) The Windows randomized unit sweep intermittently logged unhandled rejections around proxy-manager.start.test.ts: rejections created in one test surfaced at a later real-tick boundary and were attributed to whichever shuffled test ran next. Replaying the seed reproduced the warnings 2-in-5 on the original code; after this change 8/8 replays run with zero unhandled-rejection lines. Source fixes (behavior-preserving): - ProxyManager.sendDapRequest: the ~35s parent backstop timer is now stored on the pending entry, cleared at every settle point, unref'd, and no longer created after a failed send - previously every settled request left a live timer holding its rejector. - ProxyManager.start: listeners installed on the proxy process are tracked and detached on any start() failure (including the sendInitWithRetry throw path that bypassed the wait-promise cleanup), so a stale process can no longer drive handleProxyExit rejections into a later test; the 30s init timeout now runs its local cleanup before rejecting; the missing-pid throw no longer leaves the manager stuck on the 'Proxy already running' guard. - sendInitWithRetry removes its persistent init-received listener on success, not only on timeout. - stop() removes its once('exit') listener in the force-kill and already-exited branches. - DapProxyWorker: the async onInitialized event listener is fire-and-forget, so it now contains and logs failures instead of leaking them as unhandled rejections. Test hygiene: - proxy-manager.start.test.ts gets a top-level afterEach (real timers, removeAllListeners on both sides, macrotask flush) and all create->advance->expect orderings now attach the .rejects expectation BEFORE driving the rejection; same fix in proxy-manager-message-handling.test.ts and go-initialized-fallback.test.ts; the force-kill test wraps its fake timers in try/finally. - flake-hunt.mjs failure summary now includes --sequence.shuffle.tests so the printed reproduce line actually reproduces. Closes #420 Co-Authored-By: Claude Fable 5 --- scripts/flake-hunt.mjs | 4 +- src/proxy/dap-proxy-worker.ts | 43 ++-- src/proxy/proxy-manager.ts | 172 ++++++++++---- tests/proxy/dap-proxy-worker.test.ts | 30 +++ tests/proxy/go-initialized-fallback.test.ts | 18 +- .../proxy-manager-message-handling.test.ts | 11 +- tests/unit/proxy/proxy-manager.start.test.ts | 222 +++++++++++++++--- 7 files changed, 397 insertions(+), 103 deletions(-) diff --git a/scripts/flake-hunt.mjs b/scripts/flake-hunt.mjs index 6860e73a..3124a79a 100644 --- a/scripts/flake-hunt.mjs +++ b/scripts/flake-hunt.mjs @@ -65,7 +65,9 @@ if (failures.length === 0) { } else { console.error(`[flake-hunt] ✗ ${failures.length}/${RUNS} run(s) failed. Reproduce with:`); for (const seed of failures) { - console.error(` vitest run --project ${PROJECT} --sequence.seed=${seed}`); + // Keep --sequence.shuffle.tests: the committed config shuffles files only, + // so omitting it would not reproduce a within-file ordering failure. + console.error(` vitest run --project ${PROJECT} --sequence.seed=${seed} --sequence.shuffle.tests`); } process.exit(1); } diff --git a/src/proxy/dap-proxy-worker.ts b/src/proxy/dap-proxy-worker.ts index 310fe8f7..4baa3239 100644 --- a/src/proxy/dap-proxy-worker.ts +++ b/src/proxy/dap-proxy-worker.ts @@ -667,27 +667,34 @@ export class DapProxyWorker { this.connectionManager.setupEventHandlers(this.dapClient, { onInitialized: async () => { - // Update adapter state - if (this.adapterPolicy.updateStateOnEvent) { - this.adapterPolicy.updateStateOnEvent('initialized', {}, this.adapterState); - } + // Nothing awaits this listener — a rejection escaping it has no + // handler and surfaces as an unhandled rejection (issue #420), so + // failures are contained and logged here. + try { + // Update adapter state + if (this.adapterPolicy.updateStateOnEvent) { + this.adapterPolicy.updateStateOnEvent('initialized', {}, this.adapterState); + } - if (this.adapterPolicy.requiresCommandQueueing()) { - this.logger!.info(`[Worker] DAP "initialized" (${this.adapterPolicy.name}) received; forwarding event and draining queue.`); - this.sendDapEvent('initialized', {}); - await this.drainCommandQueue(); - } else { - // If we're deferring initialized handling (e.g., to send launch/attach first), - // mark the event as pending and resolve the promise to signal it arrived - if (this.deferInitializedHandling) { - this.logger!.info('[Worker] DAP "initialized" event received but deferred until after launch/attach'); - this.initializedEventPending = true; - if (this.initializedEventResolver) { - this.initializedEventResolver(); - } + if (this.adapterPolicy.requiresCommandQueueing()) { + this.logger!.info(`[Worker] DAP "initialized" (${this.adapterPolicy.name}) received; forwarding event and draining queue.`); + this.sendDapEvent('initialized', {}); + await this.drainCommandQueue(); } else { - await this.handleInitializedEvent(); + // If we're deferring initialized handling (e.g., to send launch/attach first), + // mark the event as pending and resolve the promise to signal it arrived + if (this.deferInitializedHandling) { + this.logger!.info('[Worker] DAP "initialized" event received but deferred until after launch/attach'); + this.initializedEventPending = true; + if (this.initializedEventResolver) { + this.initializedEventResolver(); + } + } else { + await this.handleInitializedEvent(); + } } + } catch (error) { + this.logger!.error('[Worker] Error handling DAP "initialized" event:', error); } }, onOutput: (body) => { diff --git a/src/proxy/proxy-manager.ts b/src/proxy/proxy-manager.ts index 37c6fc49..7b347b16 100644 --- a/src/proxy/proxy-manager.ts +++ b/src/proxy/proxy-manager.ts @@ -107,6 +107,14 @@ interface ProxyRuntimeEnvironment { cwd: () => string; } +/** Minimal emitter surface shared by IProxyProcess and its stderr stream. */ +interface RemovableEmitter { + // eslint-disable-next-line @typescript-eslint/no-explicit-any + on(event: string, listener: (...args: any[]) => void): unknown; + // eslint-disable-next-line @typescript-eslint/no-explicit-any + removeListener(event: string, listener: (...args: any[]) => void): unknown; +} + const DEFAULT_RUNTIME_ENVIRONMENT: ProxyRuntimeEnvironment = { moduleUrl: import.meta.url, cwd: () => process.cwd() @@ -123,6 +131,8 @@ export class ProxyManager extends EventEmitter implements IProxyManager { resolve: (response: DebugProtocol.Response) => void; reject: (error: Error) => void; command: string; + /** Parent-side backstop timer; must be cleared wherever the entry settles (issue #420). */ + timer?: NodeJS.Timeout; }>(); private isInitialized = false; private isStopped = false; @@ -155,6 +165,18 @@ export class ProxyManager extends EventEmitter implements IProxyManager { private activeLaunchBarrierRequestId: string | null = null; private proxyMessageCounter = 0; private exitEmitted = false; + /** + * Listeners installed on the proxy process (and its stderr stream) by + * setupEventHandlers, tracked so a failed start() can detach them — a stale + * process driving handleProxyExit after start() already rejected would fire + * rejections with nobody listening (issue #420). + */ + private trackedProxyListeners: Array<{ + emitter: RemovableEmitter; + event: string; + // eslint-disable-next-line @typescript-eslint/no-explicit-any + listener: (...args: any[]) => void; + }> = []; constructor( private adapter: IDebugAdapter | null, // Optional adapter for language-agnostic support @@ -212,6 +234,9 @@ export class ProxyManager extends EventEmitter implements IProxyManager { } if (!this.proxyProcess || typeof this.proxyProcess.pid === 'undefined') { + // Clear the handle so this manager is not permanently stuck on the + // 'Proxy already running' guard above (issue #420). + this.proxyProcess = null; throw new Error('Proxy process is invalid or PID is missing'); } @@ -256,12 +281,27 @@ export class ProxyManager extends EventEmitter implements IProxyManager { } : null }); + // From here on, any failure must detach the listeners just installed on + // the proxy process: start()'s caller discards this manager on failure, + // and a stale process handle still wired to handleProxyExit would reject + // pending requests into a void (issue #420). + try { + await this.startInitializationSequence(initCommand); + } catch (error) { + this.detachProxyEventHandlers(); + throw error; + } + } + + /** Send init (with retry) and await readiness; extracted so start() can detach on any failure. */ + private async startInitializationSequence(initCommand: object): Promise { // Send init command with retry logic await this.sendInitWithRetry(initCommand); // Wait for initialization or dry run completion return new Promise((resolve, reject) => { const timeout = setTimeout(() => { + cleanup(); reject(new Error(ErrorMessages.proxyInitTimeout(30))); }, 30000); @@ -365,22 +405,28 @@ export class ProxyManager extends EventEmitter implements IProxyManager { // Wait for graceful exit or force kill after timeout return new Promise((resolve) => { + const onExit = () => { + clearTimeout(timeout); + resolve(); + }; + const timeout = setTimeout(() => { this.logger.warn(`[ProxyManager] Timeout waiting for proxy exit. Force killing.`); if (!process.killed) { process.kill('SIGKILL'); } + // Detach the once-listener: it never fired, and leaving it would + // accumulate a dead handler on the process object (issue #420). + process.removeListener('exit', onExit); resolve(); }, 5000); - process.once('exit', () => { - clearTimeout(timeout); - resolve(); - }); + process.once('exit', onExit); // If already killed/exited, resolve immediately if (process.killed || process.exitCode !== null) { clearTimeout(timeout); + process.removeListener('exit', onExit); resolve(); } }); @@ -461,10 +507,33 @@ export class ProxyManager extends EventEmitter implements IProxyManager { } return new Promise((resolve, reject) => { + // Timeout handler. The worker/socket timeout (timeoutMs, default 30s) + // fires first and produces the actionable error; this parent timer is a + // backstop that only fires if the worker never responds at all. The + // handle is stored on the pending entry and cleared wherever the entry + // settles — a fired-but-uncleared backstop would otherwise reject with + // nobody listening long after the caller has moved on (issue #420). + const effectiveTimeoutMs = + (options?.timeoutMs ?? this.defaultDapRequestTimeoutMs) + this.dapParentMarginMs; + const timer = setTimeout(() => { + if (this.pendingDapRequests.has(requestId)) { + this.pendingDapRequests.delete(requestId); + if (this.dapState) { + this.dapState = removePendingRequest(this.dapState, requestId); + } + if (this.activeLaunchBarrier && this.activeLaunchBarrierRequestId === requestId) { + this.clearActiveLaunchBarrier(); + } + reject(new Error(ErrorMessages.dapRequestTimeout(command, Math.round(effectiveTimeoutMs / 1000)))); + } + }, effectiveTimeoutMs); + timer.unref?.(); + this.pendingDapRequests.set(requestId, { resolve: resolve as (value: DebugProtocol.Response) => void, reject, - command + command, + timer }); // Mirror into functional core for observability (seq is placeholder; ProxyManager remains authoritative) @@ -480,30 +549,13 @@ export class ProxyManager extends EventEmitter implements IProxyManager { try { this.sendCommand(commandToSend); } catch (error) { + clearTimeout(timer); this.pendingDapRequests.delete(requestId); if (barrier) { this.clearActiveLaunchBarrier(barrier); } reject(error); } - - // Timeout handler. The worker/socket timeout (timeoutMs, default 30s) - // fires first and produces the actionable error; this parent timer is a - // backstop that only fires if the worker never responds at all. - const effectiveTimeoutMs = - (options?.timeoutMs ?? this.defaultDapRequestTimeoutMs) + this.dapParentMarginMs; - setTimeout(() => { - if (this.pendingDapRequests.has(requestId)) { - this.pendingDapRequests.delete(requestId); - if (this.dapState) { - this.dapState = removePendingRequest(this.dapState, requestId); - } - if (this.activeLaunchBarrier && this.activeLaunchBarrierRequestId === requestId) { - this.clearActiveLaunchBarrier(); - } - reject(new Error(ErrorMessages.dapRequestTimeout(command, Math.round(effectiveTimeoutMs / 1000)))); - } - }, effectiveTimeoutMs); }); } @@ -627,7 +679,10 @@ export class ProxyManager extends EventEmitter implements IProxyManager { const handler = () => { if (resolved) return; resolved = true; - if (timer) clearTimeout(timer); + // Detach on success too — this listener is registered with on(), + // and each un-removed acknowledgment handler would otherwise stay + // on the manager for its lifetime (issue #420). + cleanup(); resolve(true); }; @@ -748,30 +803,40 @@ export class ProxyManager extends EventEmitter implements IProxyManager { private setupEventHandlers(): void { if (!this.proxyProcess) return; + // Track every listener installed here so a failed start() can detach the + // lot (issue #420); see trackedProxyListeners. + this.trackedProxyListeners = []; + // eslint-disable-next-line @typescript-eslint/no-explicit-any + const track = (emitter: RemovableEmitter, event: string, listener: (...args: any[]) => void) => { + emitter.on(event, listener); + this.trackedProxyListeners.push({ emitter, event, listener }); + }; + const proc = this.proxyProcess as unknown as RemovableEmitter; + // Handle IPC messages - this.proxyProcess.on('message', (rawMessage: unknown) => { + track(proc, 'message', (rawMessage: unknown) => { this.handleProxyMessage(rawMessage); }); - this.proxyProcess.on('ipc-send-start', (data: { pid?: number; connectedBefore?: boolean; summary?: string; timestamp?: number }) => { + track(proc, 'ipc-send-start', (data: { pid?: number; connectedBefore?: boolean; summary?: string; timestamp?: number }) => { this.logger.debug( `[ProxyManager] IPC send start pid=${data?.pid ?? 'unknown'} connected=${data?.connectedBefore} summary=${data?.summary ?? 'n/a'}` ); }); - this.proxyProcess.on('ipc-send-complete', (data: { pid?: number; connectedAfter?: boolean; summary?: string; timestamp?: number; queueSizeBefore?: number; queueSizeAfter?: number }) => { + track(proc, 'ipc-send-complete', (data: { pid?: number; connectedAfter?: boolean; summary?: string; timestamp?: number; queueSizeBefore?: number; queueSizeAfter?: number }) => { this.logger.debug( `[ProxyManager] IPC send complete pid=${data?.pid ?? 'unknown'} connected=${data?.connectedAfter} summary=${data?.summary ?? 'n/a'} queueBefore=${data?.queueSizeBefore ?? 'n/a'} queueAfter=${data?.queueSizeAfter ?? 'n/a'}` ); }); - this.proxyProcess.on('ipc-send-failed', (data: { pid?: number; killed?: boolean; childProcessKilled?: boolean | string; summary?: string; timestamp?: number }) => { + track(proc, 'ipc-send-failed', (data: { pid?: number; killed?: boolean; childProcessKilled?: boolean | string; summary?: string; timestamp?: number }) => { this.logger.warn( `[ProxyManager] IPC send returned false pid=${data?.pid ?? 'unknown'} killed=${data?.killed} childKilled=${data?.childProcessKilled} summary=${data?.summary ?? 'n/a'}` ); }); - this.proxyProcess.on('ipc-send-error', (data: { pid?: number; error?: string; summary?: string; timestamp?: number }) => { + track(proc, 'ipc-send-error', (data: { pid?: number; error?: string; summary?: string; timestamp?: number }) => { this.logger.error( `[ProxyManager] IPC send error pid=${data?.pid ?? 'unknown'} error=${data?.error ?? 'unknown'} summary=${data?.summary ?? 'n/a'}` ); @@ -783,19 +848,22 @@ export class ProxyManager extends EventEmitter implements IProxyManager { // patterns (issue #151). Scoped to this process's handlers so a pending // partial line survives until this stream's own 'end'/'close', and never // bleeds into a later process's stderr. - const stderrLineBuffer = new LineBuffer(); - this.proxyProcess.stderr?.on('data', (data: Buffer | string) => { - this.recordStderrLines(stderrLineBuffer.append(data.toString())); - }); - // Flush the trailing partial line only once the stream itself is done. - // Flushing on process 'exit' would be wrong: the pipe can still deliver - // the rest of a split line afterwards, re-creating the straddle leak. - const flushStderr = () => this.recordStderrLines(stderrLineBuffer.flush()); - this.proxyProcess.stderr?.on('end', flushStderr); - this.proxyProcess.stderr?.on('close', flushStderr); + const stderr = this.proxyProcess.stderr as unknown as RemovableEmitter | null; + if (stderr) { + const stderrLineBuffer = new LineBuffer(); + track(stderr, 'data', (data: Buffer | string) => { + this.recordStderrLines(stderrLineBuffer.append(data.toString())); + }); + // Flush the trailing partial line only once the stream itself is done. + // Flushing on process 'exit' would be wrong: the pipe can still deliver + // the rest of a split line afterwards, re-creating the straddle leak. + const flushStderr = () => this.recordStderrLines(stderrLineBuffer.flush()); + track(stderr, 'end', flushStderr); + track(stderr, 'close', flushStderr); + } // Handle exit - this.proxyProcess.on('exit', (code: number | null, signal: string | null) => { + track(proc, 'exit', (code: number | null, signal: string | null) => { this.logger.info(`[ProxyManager] Proxy exited. Code: ${code}, Signal: ${signal}`); this.lastExitDetails = { @@ -816,13 +884,32 @@ export class ProxyManager extends EventEmitter implements IProxyManager { }); // Handle errors - this.proxyProcess.on('error', (err: Error) => { + track(proc, 'error', (err: Error) => { this.logger.error(`[ProxyManager] Proxy error:`, err); this.emit('error', err); this.cleanup(); }); } + /** + * Remove the listeners setupEventHandlers installed on the proxy process. + * Called when start() fails: the manager is about to be discarded, and a + * stale process handle must not keep driving handleProxyExit/cleanup — + * those reject pending requests with nobody left to listen (issue #420). + * The caller (SessionManager) still runs stop(), which operates on the + * process handle directly and needs none of these listeners. + */ + private detachProxyEventHandlers(): void { + for (const { emitter, event, listener } of this.trackedProxyListeners) { + try { + emitter.removeListener(event, listener); + } catch { + // Best-effort: a torn-down stream may throw on removeListener. + } + } + this.trackedProxyListeners = []; + } + /** * Log and capture complete stderr lines, sanitized. Lines can arrive after * the process 'exit' event snapshotted the buffer (the pipe drains last), @@ -972,6 +1059,7 @@ export class ProxyManager extends EventEmitter implements IProxyManager { } this.pendingDapRequests.delete(message.requestId); + if (pending.timer) clearTimeout(pending.timer); // Mirror completion into functional core if (this.dapState) { this.dapState = removePendingRequest(this.dapState, message.requestId); @@ -1148,6 +1236,7 @@ export class ProxyManager extends EventEmitter implements IProxyManager { // Clean up pending requests this.pendingDapRequests.forEach(pending => { + if (pending.timer) clearTimeout(pending.timer); pending.reject(new Error('Proxy exited')); }); this.pendingDapRequests.clear(); @@ -1167,6 +1256,7 @@ export class ProxyManager extends EventEmitter implements IProxyManager { if (this.pendingDapRequests.size > 0) { this.logger.debug(`[ProxyManager] Clearing ${this.pendingDapRequests.size} pending DAP requests during cleanup`); for (const pending of this.pendingDapRequests.values()) { + if (pending.timer) clearTimeout(pending.timer); pending.reject(new Error(`Request cancelled during proxy shutdown: ${pending.command}`)); } this.pendingDapRequests.clear(); diff --git a/tests/proxy/dap-proxy-worker.test.ts b/tests/proxy/dap-proxy-worker.test.ts index cc438e3c..ab86e56f 100644 --- a/tests/proxy/dap-proxy-worker.test.ts +++ b/tests/proxy/dap-proxy-worker.test.ts @@ -588,6 +588,36 @@ describe('DapProxyWorker', () => { } }); + it('resolves (not rejects) the onInitialized event handler when worker state is missing (issue #420)', async () => { + // Event listeners are fire-and-forget: nothing awaits the async + // onInitialized handler, so a rejection escaping it surfaces as an + // unhandled rejection — in production and as cross-test noise under + // shuffled unit runs. + const connectionStub = { + setupEventHandlers: vi.fn() + }; + + (worker as any).logger = mockLogger; + (worker as any).dapClient = mockDapClient; + (worker as any).connectionManager = connectionStub; + (worker as any).adapterPolicy = DefaultAdapterPolicy; + (worker as any).adapterState = DefaultAdapterPolicy.createInitialState(); + (worker as any).setupDapEventHandlers(); + + const handlers = connectionStub.setupEventHandlers.mock.calls[0][1] as { + onInitialized: () => Promise; + }; + + // Tear down the state handleInitializedEvent requires + (worker as any).currentInitPayload = null; + + await expect(handlers.onInitialized()).resolves.toBeUndefined(); + expect(mockLogger.error).toHaveBeenCalledWith( + expect.stringContaining('initialized'), + expect.anything() + ); + }); + it('forwards logMessage and suspendPolicy on initial breakpoints (issue #235)', async () => { const connectionStub = { setBreakpoints: vi.fn().mockResolvedValue({ body: { breakpoints: [] } }), diff --git a/tests/proxy/go-initialized-fallback.test.ts b/tests/proxy/go-initialized-fallback.test.ts index d4f4bcc4..3a956907 100644 --- a/tests/proxy/go-initialized-fallback.test.ts +++ b/tests/proxy/go-initialized-fallback.test.ts @@ -336,15 +336,21 @@ describe('Go initialized event fallback', () => { // Start the connection — it will wait for initialized const connectPromise = (worker as any).startAdapterAndConnect(GO_PAYLOAD); - - // Advance past Phase 1 (2s) and Phase 2 (10s) - await vi.advanceTimersByTimeAsync(13000); - - await expect(connectPromise).rejects.toThrow( + // Attach the rejection expectation BEFORE the timer advance: the async + // fake-timer loop yields through real ticks, where a handler-less + // rejection surfaces as unhandled (issue #420). + const rejection = expect(connectPromise).rejects.toThrow( /Timeout waiting for initialized event \(after launch fallback\)/ ); - vi.useRealTimers(); + try { + // Advance past Phase 1 (2s) and Phase 2 (10s) + await vi.advanceTimersByTimeAsync(13000); + + await rejection; + } finally { + vi.useRealTimers(); + } }); /** diff --git a/tests/unit/proxy/proxy-manager-message-handling.test.ts b/tests/unit/proxy/proxy-manager-message-handling.test.ts index de558229..bd0c11ef 100644 --- a/tests/unit/proxy/proxy-manager-message-handling.test.ts +++ b/tests/unit/proxy/proxy-manager-message-handling.test.ts @@ -703,10 +703,14 @@ describe('ProxyManager Message Handling', () => { vi.useFakeTimers(); const request = proxyManager.sendDapRequest('threads'); + // Attach the rejection expectation BEFORE the timer advance — the async + // fake-timer loop yields through real ticks, where a handler-less + // rejection surfaces as unhandled (issue #420). + const rejection = expect(request).rejects.toThrow(/Debug adapter did not respond/i); await vi.advanceTimersByTimeAsync(35_000); - await expect(request).rejects.toThrow(/Debug adapter did not respond/i); + await rejection; const pending = (proxyManager as unknown as { pendingDapRequests: Map }).pendingDapRequests; expect(pending.size).toBe(0); @@ -1091,11 +1095,14 @@ describe('ProxyManager Message Handling', () => { createInitialState('timeout-session'); const requestPromise = proxyManager.sendDapRequest('launch', {}); + // Attach before advancing so the rejection is never handler-less at a + // real tick boundary (issue #420). + const rejection = expect(requestPromise).rejects.toThrow(/Debug adapter did not respond to 'launch'/); await vi.advanceTimersByTimeAsync(35000); try { - await expect(requestPromise).rejects.toThrow(/Debug adapter did not respond to 'launch'/); + await rejection; expect(barrier.dispose).toHaveBeenCalled(); } finally { vi.useRealTimers(); diff --git a/tests/unit/proxy/proxy-manager.start.test.ts b/tests/unit/proxy/proxy-manager.start.test.ts index 9dad53ed..593efebe 100644 --- a/tests/unit/proxy/proxy-manager.start.test.ts +++ b/tests/unit/proxy/proxy-manager.start.test.ts @@ -1,4 +1,4 @@ -import { describe, it, expect, beforeEach, vi } from 'vitest'; +import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; import { EventEmitter } from 'events'; import path from 'path'; import { pathToFileURL } from 'url'; @@ -88,6 +88,20 @@ describe('ProxyManager.start', () => { ); }); + // Under shuffled ordering (issue #420, seed 1038859894) anything this file + // leaves behind — fake timers, live listeners between the manager and its + // fake process, stray setImmediate emits — fires into whichever test runs + // next and surfaces there as unhandled-rejection noise. Tear it all down. + afterEach(async () => { + vi.useRealTimers(); + // Detach the fake first so any straggling emit finds no manager handlers. + fakeProcess.removeAllListeners(); + (fakeProcess.stderr as unknown as EventEmitter | null)?.removeAllListeners(); + proxyManager.removeAllListeners(); + // Flush this test's stray macrotasks inside its own attribution window. + await new Promise((resolve) => setImmediate(resolve)); + }); + const baseConfig: ProxyConfig = { sessionId: 'session-123', language: DebugLanguage.JAVASCRIPT, @@ -499,9 +513,13 @@ describe('ProxyManager.start', () => { const startPromise = proxyManager.start(baseConfig); + // Attach the rejection expectation BEFORE driving the rejection: the + // async fake-timer loop yields through real ticks, where an unhandled + // rejection would otherwise be flagged (issue #420). + const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy after 6 attempts\. Last error: ipc failure/); await vi.advanceTimersByTimeAsync(16500); - await expect(startPromise).rejects.toThrow(/Failed to initialize proxy after 6 attempts\. Last error: ipc failure/); + await rejection; expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Error sending init on attempt 6')); }); }); @@ -526,10 +544,11 @@ describe('ProxyManager.start', () => { }); try { + const rejection = expect(startPromise).rejects.toThrow(/Debug proxy initialization did not complete within 30s/); await vi.advanceTimersByTimeAsync(30000); await vi.runOnlyPendingTimersAsync(); await Promise.resolve(); - await expect(startPromise).rejects.toThrow(/Debug proxy initialization did not complete within 30s/); + await rejection; } finally { vi.useRealTimers(); } @@ -568,12 +587,13 @@ describe('ProxyManager.start', () => { }); const startPromise = proxyManager.start({ ...baseConfig, dryRunSpawn: false }); + const rejection = expect(startPromise).rejects.toThrow( + /Proxy exit details -> code=2 signal=SIGTERM stderr:\nboot failure/ + ); // Drive the init-retry backoff via fake timers: 35s covers the ~15.5s // backoff schedule plus timeout margins. await vi.advanceTimersByTimeAsync(35000); - await expect(startPromise).rejects.toThrow( - /Proxy exit details -> code=2 signal=SIGTERM stderr:\nboot failure/ - ); + await rejection; } finally { vi.useRealTimers(); } @@ -791,12 +811,13 @@ describe('ProxyManager.start', () => { }); const startPromise = proxyManager.start({ ...baseConfig, dryRunSpawn: false }); + const rejection = expect(startPromise).rejects.toThrow( + /Proxy exit details -> code=2 signal=SIGTERM stderr:\nlate boot failure/ + ); // Drive the init-retry backoff via fake timers: 35s covers the ~15.5s // backoff schedule plus timeout margins. await vi.advanceTimersByTimeAsync(35000); - await expect(startPromise).rejects.toThrow( - /Proxy exit details -> code=2 signal=SIGTERM stderr:\nlate boot failure/ - ); + await rejection; } finally { vi.useRealTimers(); } @@ -886,26 +907,29 @@ describe('ProxyManager.start', () => { describe('stop and cleanup behavior', () => { it('sends terminate and force kills when proxy does not exit in time', async () => { vi.useFakeTimers(); - - (proxyManager as unknown as { proxyProcess: IProxyProcess | null }).proxyProcess = fakeProcess; - (proxyManager as unknown as { sessionId: string | null }).sessionId = baseConfig.sessionId; - - fakeProcess.killed = false; - fakeProcess.exitCode = null; - fakeProcess.send.mockClear(); - fakeProcess.kill.mockClear(); - - const stopPromise = proxyManager.stop(); - - await vi.advanceTimersByTimeAsync(5000); - await vi.runOnlyPendingTimersAsync(); - await stopPromise; - - expect(fakeProcess.send).toHaveBeenCalledWith({ cmd: 'terminate', sessionId: baseConfig.sessionId }); - expect(fakeProcess.kill).toHaveBeenCalledWith('SIGKILL'); - expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Timeout waiting for proxy exit')); - - vi.useRealTimers(); + try { + (proxyManager as unknown as { proxyProcess: IProxyProcess | null }).proxyProcess = fakeProcess; + (proxyManager as unknown as { sessionId: string | null }).sessionId = baseConfig.sessionId; + + fakeProcess.killed = false; + fakeProcess.exitCode = null; + fakeProcess.send.mockClear(); + fakeProcess.kill.mockClear(); + + const stopPromise = proxyManager.stop(); + + await vi.advanceTimersByTimeAsync(5000); + await vi.runOnlyPendingTimersAsync(); + await stopPromise; + + expect(fakeProcess.send).toHaveBeenCalledWith({ cmd: 'terminate', sessionId: baseConfig.sessionId }); + expect(fakeProcess.kill).toHaveBeenCalledWith('SIGKILL'); + expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Timeout waiting for proxy exit')); + } finally { + // Without the finally, a failed assertion above would leak fake + // timers into the next shuffled test (issue #420). + vi.useRealTimers(); + } }); it('resolves immediately when proxy already exited', async () => { @@ -1354,10 +1378,11 @@ describe('ProxyManager.start', () => { }); const request = proxyManager.sendDapRequest('continue'); + const rejection = expect(request).rejects.toThrow(/Debug adapter did not respond to 'continue'/); await vi.advanceTimersByTimeAsync(35000); - await expect(request).rejects.toThrow(/Debug adapter did not respond to 'continue'/); + await rejection; const pending = (proxyManager as unknown as { pendingDapRequests: Map }).pendingDapRequests; expect(pending.size).toBe(0); } finally { @@ -1413,13 +1438,14 @@ describe('ProxyManager.start', () => { }); const startPromise = proxyManager.start(config); + // With retry logic, error message is different + const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy after \d+ attempts/); // Drive the init-retry backoff via fake timers: 35s covers the ~15.5s // backoff schedule plus timeout margins. await vi.advanceTimersByTimeAsync(35000); - // With retry logic, error message is different - await expect(startPromise).rejects.toThrow(/Failed to initialize proxy after \d+ attempts/); + await rejection; } finally { vi.useRealTimers(); } @@ -1441,13 +1467,14 @@ describe('ProxyManager.start', () => { }); const startPromise = proxyManager.start(config); + // With retry logic, error message is different + const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy after \d+ attempts/); // Drive the init-retry backoff via fake timers: 35s covers the ~15.5s // backoff schedule plus timeout margins. await vi.advanceTimersByTimeAsync(35000); - // With retry logic, error message is different - await expect(startPromise).rejects.toThrow(/Failed to initialize proxy after \d+ attempts/); + await rejection; } finally { vi.useRealTimers(); } @@ -1490,6 +1517,11 @@ describe('ProxyManager.start', () => { const startPromise = proxyManager.start(config); const stopPromise = proxyManager.stop(); + // Attach the rejection expectation BEFORE the timer advance: this was + // the worst offender of the seed-1038859894 flake — startPromise sat + // handler-less across the whole 35s advance (issue #420). + const startRejection = expect(startPromise).rejects.toThrow(/Proxy/); + setImmediate(() => { fakeProcess.emit('exit', 0, null); }); @@ -1499,7 +1531,7 @@ describe('ProxyManager.start', () => { await vi.advanceTimersByTimeAsync(35000); await expect(stopPromise).resolves.toBeUndefined(); - await expect(startPromise).rejects.toThrow(/Proxy/); + await startRejection; } finally { vi.useRealTimers(); } @@ -1514,6 +1546,126 @@ describe('ProxyManager.start', () => { await expect(proxyManager.stop()).resolves.toBeUndefined(); }); + + // Leaked timers and listeners from settled operations were the enablers of + // the seed-1038859894 shuffle flake: rejections fired into later tests + // after this file's tests had finished (issue #420). + describe('listener and timer hygiene (issue #420)', () => { + it('clears the DAP parent backstop timer when the response arrives', async () => { + (proxyManager as unknown as { proxyProcess: IProxyProcess | null }).proxyProcess = fakeProcess; + (proxyManager as unknown as { isInitialized: boolean }).isInitialized = true; + (proxyManager as unknown as { sessionId: string | null }).sessionId = baseConfig.sessionId; + (proxyManager as unknown as { dapState: ReturnType | null }).dapState = + createInitialState(baseConfig.sessionId); + + vi.useFakeTimers(); + try { + fakeProcess.sendCommand.mockImplementation((payload) => { + if (payload.cmd === 'dap') { + (proxyManager as unknown as { + handleProxyMessage: (message: object) => void; + }).handleProxyMessage({ + type: 'dapResponse', + sessionId: baseConfig.sessionId, + requestId: payload.requestId, + success: true, + response: { type: 'response', seq: 1, request_seq: 1, command: payload.dapCommand, success: true } + }); + } + }); + + const before = vi.getTimerCount(); + await proxyManager.sendDapRequest('threads'); + + // The ~35s backstop must not survive a settled request. + expect(vi.getTimerCount()).toBe(before); + } finally { + vi.useRealTimers(); + } + }); + + it('removes the init-received listener after a successful start', async () => { + await proxyManager.start(baseConfig); + + expect(proxyManager.listenerCount('init-received')).toBe(0); + }); + + it('detaches proxy process listeners when start fails via init exhaustion', async () => { + vi.useFakeTimers(); + try { + fakeProcess.sendCommand.mockReset(); + fakeProcess.sendCommand.mockImplementation(() => { + throw new Error('ipc failure'); + }); + + const startPromise = proxyManager.start(baseConfig); + const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy/); + await vi.advanceTimersByTimeAsync(16500); + await rejection; + + // A stale process emitting after the failed start must not reach the + // manager (it would fire handleProxyExit into a later test). + const exitSpy = vi.fn(); + proxyManager.on('exit', exitSpy); + fakeProcess.emit('exit', 1, null); + fakeProcess.emit('message', { type: 'status', status: 'terminated', sessionId: baseConfig.sessionId }); + expect(exitSpy).not.toHaveBeenCalled(); + + expect(fakeProcess.listenerCount('exit')).toBe(0); + expect(fakeProcess.listenerCount('message')).toBe(0); + expect((fakeProcess.stderr as unknown as EventEmitter).listenerCount('data')).toBe(0); + } finally { + vi.useRealTimers(); + } + }); + + it('detaches proxy process listeners when start times out awaiting readiness', async () => { + vi.useFakeTimers(); + try { + fakeProcess.sendCommand.mockImplementation((cmd: { cmd?: string; sessionId?: string }) => { + if (cmd.cmd === 'init') { + setTimeout(() => { + fakeProcess.emit('message', { + type: 'status', + status: 'init_received', + sessionId: cmd.sessionId + }); + }, 0); + } + }); + + const startPromise = proxyManager.start({ ...baseConfig, dryRunSpawn: false }); + const rejection = expect(startPromise).rejects.toThrow(/did not complete within 30s/); + await vi.advanceTimersByTimeAsync(30100); + await rejection; + + expect(fakeProcess.listenerCount('exit')).toBe(0); + expect(fakeProcess.listenerCount('message')).toBe(0); + } finally { + vi.useRealTimers(); + } + }); + + it('removes the stop() exit listener when the force-kill timeout wins', async () => { + vi.useFakeTimers(); + try { + (proxyManager as unknown as { proxyProcess: IProxyProcess | null }).proxyProcess = fakeProcess; + (proxyManager as unknown as { sessionId: string | null }).sessionId = baseConfig.sessionId; + fakeProcess.killed = false; + fakeProcess.exitCode = null; + + const baseline = fakeProcess.listenerCount('exit'); + const stopPromise = proxyManager.stop(); + await vi.advanceTimersByTimeAsync(5000); + await stopPromise; + + expect(fakeProcess.kill).toHaveBeenCalledWith('SIGKILL'); + expect(fakeProcess.listenerCount('exit')).toBe(baseline); + } finally { + vi.useRealTimers(); + } + }); + }); }); describe('ProxyManager helpers', () => {