From f2d85a8a341908a5d8efc369642801f7a8cf6f2a Mon Sep 17 00:00:00 2001 From: JF Date: Thu, 27 Aug 2026 00:36:32 -0400 Subject: [PATCH] fix(#493): make the proxy-init timeout say what actually stalled MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The 30s init-timeout message — "the debug adapter failed to start or is not properly configured; check that it is installed" — was written for the nothing-ever-connected case and was confidently wrong for every other stage. In #492's incident the adapter spawned, opened its socket, accepted the connection, and emitted a DAP event; the one missing thing was a response frame, and the one diagnostic fact that names it (which handshake request is outstanding) was known worker-side and discarded. For an agent that is worse than unhelpful: it is a directed wrong lead. The worker now reports init progress over the existing status IPC: adapter_spawned {pid} and dap_handshake_stage {transport_connected | request_pending | response_received, command} around each blocking handshake request (initialize/launch/attach). Both statuses are handled imperatively only — deliberately no dap-core case, following the adapter_capabilities convention, so nothing is double-processed and the js-debug launch barrier is untouched ('adapter_connected' keeps its unblock semantics; the new status names avoid it on purpose). ProxyManager tracks the progress and the timeout message now reflects the reached stage, keeping the first sentence invariant (tests pin it, docs quote it): connected + request outstanding names the request and the live adapter PID and says "protocol stall, not a missing install"; spawned-but-never-connected and connected-but-idle get their own wording; the install hint survives only for no-progress. The structured facts ride on the Error object and land in the failed start_debugging result's data ({initProgress, proxyLogPath}) — previously they were logged server-side where the agent reading the error can't see them. Fixes #493 Co-Authored-By: Claude Fable 5 --- CHANGELOG.md | 1 + docs/architecture/component-design.md | 10 +-- docs/architecture/system-overview.md | 10 +-- docs/patterns/error-handling.md | 10 +-- src/dap-core/types.ts | 2 + src/proxy/dap-proxy-worker.ts | 54 +++++++++++---- src/proxy/proxy-manager.ts | 39 ++++++++++- src/session/session-manager-operations.ts | 24 ++++++- src/utils/error-messages.ts | 52 +++++++++++++-- tests/proxy/dap-proxy-worker.test.ts | 24 +++++++ tests/unit/proxy/proxy-manager.start.test.ts | 69 ++++++++++++++++++++ tests/unit/utils/error-messages.test.ts | 53 +++++++++++++++ 12 files changed, 317 insertions(+), 31 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 771b32af..b4a5eb72 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -28,6 +28,7 @@ and this project adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0 ### Fixed - **Ruby launches survive rdbg's dropped `initialize` response** — rdbg can process `initialize` (provably: it emits the `initialized` event 34ms later) yet never send the response, and the proxy awaited that response unconditionally — so the launch sat silent until the 30s init deadline killed it blaming adapter startup, even though an immediate retry always worked. Ruby launch initialization now races the response against the `initialized` event plus a 2s grace period: when the event wins, the launch proceeds with unknown capabilities (a late response still captures them) and a warning names what happened. Attach sessions and other adapters are unchanged (#492) +- **The 30s proxy-init timeout now says what actually stalled instead of blaming adapter installation** — the old message ("the debug adapter failed to start or is not properly configured — check that it is installed") was written for the nothing-ever-connected case and was confidently wrong for every other stage, sending agents to verify healthy toolchains with nowhere to go next (#492's incident: adapter spawned, connected, and emitted events — one response frame was missing). The worker now reports init progress to the parent (process spawned + PID, DAP transport connected, which handshake request is in flight), and the timeout message reflects the reached stage — e.g. *connected to the debug adapter, but the "initialize" request never received a response; the adapter process is running (PID N); an adapter-side protocol stall, not a missing install* — with the structured facts (`initProgress`, `proxyLogPath`) included in the failed `start_debugging` result's `data`, where the agent can actually see them. The install hint survives only for the case it correctly describes (#493) - **An adopted thread anchor survives `list_threads` and follow-up inspection calls** — the anchor adopted by `get_stack_trace`'s frameless-thread fallback (or an explicit `get_stack_trace {threadId}`, #465) was silently reverted to the stale stopped-event thread by the functional-core state echo on the very next DAP response or event: `list_threads` clobbered it, and even the documented `threadId` recovery survived exactly one inspection call because that call's own response reverted it — so stack → threads → locals answered about the frameless thread and returned nothing. The echo no longer overwrites the live anchor (the imperative fast path is authoritative), and adoptions are mirrored into the functional-core snapshot so the two stores can't disagree again (#496) - **js breakpoints tell the truth about binding — attach and launch** — js-debug binds breakpoints in a child session while the parent answers with provisional stubs (`verified:false`, "Unbound breakpoint", parent-space ids), and nothing reconciled the two on the attach path: a breakpoint set after `attach_to_process` raced a fire-and-forget child mirror, and one set before attach stayed "Unbound breakpoint" with no adapterId forever — even after it demonstrably fired — because js-debug answers a no-change re-send with an empty echo and emits no late bind event for it. The proxy now hands the child's authoritative `setBreakpoints` response back through the sync path (marked child-sourced, bounded 3s wait), `attach_to_process` gains the post-launch belt-and-braces re-sync (with a clear+re-set to force a fresh echo for already-registered sets), and every previously-silent mirror failure mode logs. Child-origin `breakpoint` events are tagged at the proxy, so a late parent stub whose integer id collides with the stored child id can no longer downgrade a verified record by id-match, and parent-space/provisional-stub ids never enter the store (the #495 intermittent signature); `syncBreakpointsForFile` also normalizes raw l10n keys before storing, closing #471's last gap (#500, #495) - **Attach-mode `statement`/`expectedContent` rejection states the real reason** — the error claimed the file "is a class name or remote path" even for a readable local `.py` the server had just echoed contents from, sending agents down a path-problem rabbit hole that doesn't exist; the rejection (which is the documented contract) now says what's actually going on — content addressing is not supported for attach sessions because the debuggee's loaded source, not the host's copy, is the authority — while the class-name wording remains for the case it genuinely describes (Java FQCNs) (#497) diff --git a/docs/architecture/component-design.md b/docs/architecture/component-design.md index b9eeba36..450fcdb9 100644 --- a/docs/architecture/component-design.md +++ b/docs/architecture/component-design.md @@ -420,10 +420,12 @@ export const ErrorMessages = { `This typically means the debug adapter has crashed or lost connection. ` + `Try restart_debugging to relaunch the session. If the problem persists, check the debug adapter logs.`, - proxyInitTimeout: (timeout: number) => - `Debug proxy initialization did not complete within ${timeout}s. ` + - `This may indicate that the debug adapter failed to start or is not properly configured. ` + - `Check that the required debug adapter is installed and accessible.` + proxyInitTimeout: (timeout: number, progress?: ProxyInitProgress) => + // Invariant first sentence; the rest reflects how far initialization + // actually got (spawned? transport connected? which DAP request is + // unanswered?) so the error never blames a missing install when the + // adapter demonstrably connected (issue #493) + `Debug proxy initialization did not complete within ${timeout}s. ` + /* stage-aware detail */ }; ``` diff --git a/docs/architecture/system-overview.md b/docs/architecture/system-overview.md index f301664a..37c257da 100644 --- a/docs/architecture/system-overview.md +++ b/docs/architecture/system-overview.md @@ -303,10 +303,12 @@ The system uses centralized error messages (`src/utils/error-messages.ts`) with: Example from error-messages.ts: ```typescript -proxyInitTimeout: (timeout: number) => - `Debug proxy initialization did not complete within ${timeout}s. ` + - `This may indicate that the debug adapter failed to start or is not properly configured. ` + - `Check that the required debug adapter is installed and accessible.` +proxyInitTimeout: (timeout: number, progress?: ProxyInitProgress) => + // Invariant first sentence; the rest reflects how far initialization got + // (spawned? transport connected? which DAP request is unanswered?) so the + // error never blames a missing install when the adapter demonstrably + // connected (issue #493) + `Debug proxy initialization did not complete within ${timeout}s. ` + /* stage-aware detail */ ``` ## Next Steps diff --git a/docs/patterns/error-handling.md b/docs/patterns/error-handling.md index abf43999..2b87ad20 100644 --- a/docs/patterns/error-handling.md +++ b/docs/patterns/error-handling.md @@ -27,10 +27,12 @@ export const ErrorMessages = { `If the operation is expected to take this long, retry with a larger 'timeout' (ms) argument. ` + `Note the operation may still be running in the debuggee.`, - proxyInitTimeout: (timeout: number) => - `Debug proxy initialization did not complete within ${timeout}s. ` + - `This may indicate that the debug adapter failed to start or is not properly configured. ` + - `Check that the required debug adapter is installed and accessible.`, + proxyInitTimeout: (timeout: number, progress?: ProxyInitProgress) => + // Invariant first sentence; the rest reflects how far initialization + // actually got (spawned? transport connected? which DAP request is + // unanswered?) so the error never blames a missing install when the + // adapter demonstrably connected (issue #493) + `Debug proxy initialization did not complete within ${timeout}s. ` + /* stage-aware detail */, stepStillRunning: (graceSeconds: number) => `Step dispatched; the program is still executing after ${graceSeconds}s ` + diff --git a/src/dap-core/types.ts b/src/dap-core/types.ts index e8cc606e..95cb878b 100644 --- a/src/dap-core/types.ts +++ b/src/dap-core/types.ts @@ -55,6 +55,8 @@ export type ProxyStatusMessage = | { type: 'status'; sessionId: string; status: 'adapter_capabilities'; capabilities: DebugProtocol.Capabilities; data?: unknown } | { type: 'status'; sessionId: string; status: 'function_breakpoints_synced'; functionBreakpoints: Array<{ name: string; verified: boolean; id?: number; line?: number; source?: string }>; data?: unknown } | { type: 'status'; sessionId: string; status: 'breakpoints_synced'; breakpoints: Array<{ id?: string; file: string; line: number; verified: boolean; adapterId?: number; boundLine?: number; message?: string }>; data?: unknown } + | { type: 'status'; sessionId: string; status: 'adapter_spawned'; pid?: number; data?: unknown } + | { type: 'status'; sessionId: string; status: 'dap_handshake_stage'; stage: 'transport_connected' | 'request_pending' | 'response_received'; command?: string; data?: unknown } | { type: 'status'; sessionId: string; status: 'adapter_exited' | 'dap_connection_closed' | 'terminated'; code?: number | null; signal?: NodeJS.Signals | null; expected?: boolean; data?: unknown }; export type ProxyDapEventMessage = { diff --git a/src/proxy/dap-proxy-worker.ts b/src/proxy/dap-proxy-worker.ts index b4550392..6dad58a1 100644 --- a/src/proxy/dap-proxy-worker.ts +++ b/src/proxy/dap-proxy-worker.ts @@ -469,6 +469,8 @@ export class DapProxyWorker { } this.adapterExitCodeIsDebuggeeExitCode = spawnConfig.adapterExitCodeIsDebuggeeExitCode === true; this.logger!.info(`[Worker] Adapter spawned with PID: ${spawnResult.pid}`); + // Init-progress fact for the parent's proxyInitTimeout diagnosis (issue #493). + this.sendStatus('adapter_spawned', { pid: spawnResult.pid }); this.adapterProcess.on('error', (err) => { this.logger!.error('[Worker] Adapter process error:', err); @@ -506,6 +508,11 @@ export class DapProxyWorker { // sessions (js-debug) can apply the same filters (issue #220). this.dapClient.setExceptionBreakMode?.(payload.breakOnExceptions ?? 'none'); + // Init-progress fact for the parent's proxyInitTimeout diagnosis (issue + // #493). Deliberately NOT 'adapter_connected', whose parent handler marks + // the session initialized to unblock the js-debug queueing handshake. + this.sendStatus('dap_handshake_stage', { stage: 'transport_connected' }); + // Set up event handlers this.setupDapEventHandlers(); @@ -557,10 +564,14 @@ export class DapProxyWorker { // so the attach response must not be awaited before handleInitializedEvent. const attachPayload = payload.launchConfig || {}; this.logger!.info(`[Worker] Attach-first mode — sending attach. Keys: ${Object.keys(attachPayload).join(', ')}`); + this.sendStatus('dap_handshake_stage', { stage: 'request_pending', command: 'attach' }); const attachRequest = this.connectionManager!.sendAttachRequest( this.dapClient, attachPayload - ); + ).then((attachResult) => { + this.sendStatus('dap_handshake_stage', { stage: 'response_received', command: 'attach' }); + return attachResult; + }); // Surface early attach failures (connection refused, bad args) instead // of waiting out the initialized timeout. Promise.race subscribes to // every arm, so this rejection is consumed even when another arm wins. @@ -595,10 +606,10 @@ export class DapProxyWorker { this.logger!.info('[Worker] "initialized" event received, sending attach request'); - await this.connectionManager!.sendAttachRequest( - this.dapClient, + await this.trackedHandshakeRequest('attach', () => this.connectionManager!.sendAttachRequest( + this.dapClient!, payload.launchConfig || {} - ); + )); this.deferInitializedHandling = false; await this.handleInitializedEvent(); @@ -618,14 +629,14 @@ export class DapProxyWorker { } // Standard two-phase: send launch, wait for response, then configurationDone - await this.connectionManager!.sendLaunchRequest( - this.dapClient, + await this.trackedHandshakeRequest('launch', () => this.connectionManager!.sendLaunchRequest( + this.dapClient!, payload.scriptPath, payload.scriptArgs, payload.stopOnEntry, payload.justMyCode, payload.launchConfig - ); + )); if (!receivedBeforeLaunch) { // Phase 2: Wait for initialized after launch @@ -646,14 +657,14 @@ export class DapProxyWorker { // Python/debugpy sends "initialized" AFTER receiving the launch request this.logger!.info('[Worker] Sending launch request with scriptPath:', payload.scriptPath); - await this.connectionManager!.sendLaunchRequest( - this.dapClient, + await this.trackedHandshakeRequest('launch', () => this.connectionManager!.sendLaunchRequest( + this.dapClient!, payload.scriptPath, payload.scriptArgs, payload.stopOnEntry, payload.justMyCode, payload.launchConfig - ); + )); } } @@ -674,16 +685,35 @@ export class DapProxyWorker { * with unknown capabilities (a documented-legal value) and a late response * still captures them. */ + /** + * Run a blocking init-phase DAP request bracketed by handshake-stage + * statuses, so the parent knows which request is outstanding if the init + * deadline fires (issue #493). A rejection leaves the request marked + * pending — its own error carries the diagnosis then. + */ + private async trackedHandshakeRequest(command: string, run: () => Promise): Promise { + this.sendStatus('dap_handshake_stage', { stage: 'request_pending', command }); + const result = await run(); + this.sendStatus('dap_handshake_stage', { stage: 'response_received', command }); + return result; + } + private async awaitInitializeResponse( payload: ProxyInitPayload, initBehavior: ReturnType, isAttachMode: boolean ): Promise { - const initPromise = this.connectionManager!.initializeSession( + this.sendStatus('dap_handshake_stage', { stage: 'request_pending', command: 'initialize' }); + // Promise.resolve: initializeSession stubs may return bare undefined + // (documented-legal for degenerate adapters). + const initPromise = Promise.resolve(this.connectionManager!.initializeSession( this.dapClient!, payload.sessionId, this.adapterPolicy.getDapAdapterConfiguration().type - ); + )).then((caps) => { + this.sendStatus('dap_handshake_stage', { stage: 'response_received', command: 'initialize' }); + return caps; + }); if (isAttachMode || !initBehavior.initializeResponseOptional || !this.initializedEventPromise) { return initPromise; diff --git a/src/proxy/proxy-manager.ts b/src/proxy/proxy-manager.ts index a5930b77..86bee51d 100644 --- a/src/proxy/proxy-manager.ts +++ b/src/proxy/proxy-manager.ts @@ -27,7 +27,7 @@ import type { ProxyDapResponseMessage, ProxyMessage } from '../dap-core/types.js'; -import { ErrorMessages } from '../utils/error-messages.js'; +import { ErrorMessages, ProxyInitProgress } from '../utils/error-messages.js'; import { ProxyConfig } from './proxy-config.js'; import type { BreakpointSyncResult, FunctionBreakpointSyncResult } from './dap-proxy-interfaces.js'; import { IPC_HEARTBEAT, IPC_HEARTBEAT_TICK } from './dap-proxy-interfaces.js'; @@ -168,6 +168,13 @@ export class ProxyManager extends EventEmitter implements IProxyManager { private activeLaunchBarrierRequestId: string | null = null; private proxyMessageCounter = 0; private exitEmitted = false; + /** + * How far worker-side initialization got, from the worker's progress + * statuses (adapter_spawned / dap_handshake_stage). Read only when the init + * deadline fires, to say what actually stalled instead of blaming adapter + * installation (issue #493). + */ + private initProgress: ProxyInitProgress = { transportConnected: false }; /** * Listeners installed on the proxy process (and its stderr stream) by * setupEventHandlers, tracked so a failed start() can detach them — a stale @@ -305,7 +312,13 @@ export class ProxyManager extends EventEmitter implements IProxyManager { return new Promise((resolve, reject) => { const timeout = setTimeout(() => { cleanup(); - reject(new Error(ErrorMessages.proxyInitTimeout(30))); + const error = new Error(ErrorMessages.proxyInitTimeout(30, this.initProgress)) as Error & { + initProgress?: ProxyInitProgress; + }; + // Structured copy of the facts behind the message, for the tool + // result's error payload (issue #493). + error.initProgress = { ...this.initProgress }; + reject(error); }, 30000); const cleanup = () => { @@ -1207,6 +1220,28 @@ export class ProxyManager extends EventEmitter implements IProxyManager { this.emit('adapter-capabilities', message.capabilities); break; + case 'adapter_spawned': + // Like adapter_capabilities: handled here only, no dap-core case, so + // never double-processed. Progress fact for the init-timeout + // diagnosis (issue #493) — no event to emit. + this.initProgress.adapterPid = typeof message.pid === 'number' ? message.pid : undefined; + this.logger.info(`[ProxyManager] Adapter process spawned (PID ${message.pid ?? 'unknown'})`); + break; + + case 'dap_handshake_stage': + // Like adapter_capabilities: handled here only, no dap-core case (issue #493). + if (message.stage === 'transport_connected') { + this.initProgress.transportConnected = true; + } else if (message.stage === 'request_pending') { + this.initProgress.pendingCommand = message.command; + } else if (message.stage === 'response_received' && this.initProgress.pendingCommand === message.command) { + this.initProgress.pendingCommand = undefined; + } + this.logger.info( + `[ProxyManager] DAP handshake stage: ${message.stage}${message.command ? ` (${message.command})` : ''}` + ); + break; + case 'function_breakpoints_synced': // Like adapter_capabilities: emitted here only, no dap-core case, so // never double-processed (issue #302). diff --git a/src/session/session-manager-operations.ts b/src/session/session-manager-operations.ts index 0d405cd6..03cc2cd9 100644 --- a/src/session/session-manager-operations.ts +++ b/src/session/session-manager-operations.ts @@ -992,6 +992,9 @@ export abstract class SessionManagerOperations extends SessionManagerData { }>>`; } + // Structured init-progress facts from a proxy init timeout (issue #493) + const initProgress = (error as { initProgress?: Record })?.initProgress; + // Comprehensive error capture for debugging Windows CI issues const errorDetails: Record = { type: error?.constructor?.name || 'Unknown', @@ -1002,6 +1005,7 @@ export abstract class SessionManagerOperations extends SessionManagerData { syscall: (error as Record)?.syscall, path: (error as Record)?.path, toString: error?.toString ? error.toString() : 'No toString', + initProgress, proxyLogPath, proxyLogTail }; @@ -1069,7 +1073,25 @@ export abstract class SessionManagerOperations extends SessionManagerData { }; } - return { success: false, error: errorMessage, state: session.state, errorType, errorCode }; + // Surface the diagnosis in the tool result, not just the server log + // (issue #493): which init stage stalled, and where the full proxy log + // lives — the agent reading the error has no other way to these facts. + const diagnosticData: Record = {}; + if (initProgress) { + diagnosticData.initProgress = initProgress; + } + if (proxyLogPath) { + diagnosticData.proxyLogPath = proxyLogPath; + } + + return { + success: false, + error: errorMessage, + state: session.state, + errorType, + errorCode, + ...(Object.keys(diagnosticData).length > 0 ? { data: diagnosticData } : {}) + }; } } diff --git a/src/utils/error-messages.ts b/src/utils/error-messages.ts index 1cad368d..ade19ec4 100644 --- a/src/utils/error-messages.ts +++ b/src/utils/error-messages.ts @@ -3,6 +3,21 @@ * This ensures consistency between implementation and tests. */ +/** + * How far debug-proxy initialization got before the deadline fired, tracked by + * ProxyManager from the worker's progress statuses (issue #493). Drives the + * stage-aware proxyInitTimeout message and rides on the timeout Error object + * so the structured facts reach the tool result. + */ +export interface ProxyInitProgress { + /** PID of the spawned adapter process; absent in connect mode (no process). */ + adapterPid?: number; + /** The DAP transport (TCP) to the adapter connected successfully. */ + transportConnected: boolean; + /** The DAP handshake request that was sent and has not been answered. */ + pendingCommand?: string; +} + export const ErrorMessages = { /** * Error message for DAP request timeouts @@ -33,12 +48,41 @@ export const ErrorMessages = { * Occurs when: The debug proxy process fails to initialize within the timeout period * Used in: src/proxy/proxy-manager.ts * Default timeout: 30 seconds + * + * The first sentence is an invariant prefix (pinned by tests and quoted in + * docs); the rest reflects how far initialization actually got (issue #493). + * The install-hint wording survives only for the case it correctly + * describes: nothing ever spawned or connected. Blaming a missing install + * when the adapter demonstrably connected and answered events sent agents + * to verify healthy toolchains with nowhere to go afterwards. + * * @param timeout - The timeout duration in seconds + * @param progress - How far initialization got (issue #493); omit for the generic message */ - proxyInitTimeout: (timeout: number) => - `Debug proxy initialization did not complete within ${timeout}s. ` + - `This may indicate that the debug adapter failed to start or is not properly configured. ` + - `Check that the required debug adapter is installed and accessible.`, + proxyInitTimeout: (timeout: number, progress?: ProxyInitProgress) => { + const base = `Debug proxy initialization did not complete within ${timeout}s.`; + if (progress?.transportConnected) { + const pidNote = progress.adapterPid !== undefined + ? ` The adapter process is running (PID ${progress.adapterPid}).` + : ''; + if (progress.pendingCommand) { + return `${base} Connected to the debug adapter, but the "${progress.pendingCommand}" request ` + + `never received a response.${pidNote} This is an adapter-side protocol stall, not a missing ` + + `install — the adapter started and accepted the connection. Retrying usually succeeds; ` + + `if it recurs, capture a DAP trace (DAP_TRACE=1) of the failing launch.`; + } + return `${base} Connected to the debug adapter and the DAP handshake began, but initialization ` + + `stalled before completing.${pidNote}`; + } + if (progress?.adapterPid !== undefined) { + return `${base} The adapter process spawned (PID ${progress.adapterPid}) but the DAP connection ` + + `was never established. Check that the adapter's port is reachable and nothing is blocking ` + + `loopback TCP connections.`; + } + return `${base} ` + + `This may indicate that the debug adapter failed to start or is not properly configured. ` + + `Check that the required debug adapter is installed and accessible.`; + }, /** * Informational message for step operations still executing after the grace window diff --git a/tests/proxy/dap-proxy-worker.test.ts b/tests/proxy/dap-proxy-worker.test.ts index c6abf1e1..1a6d54c1 100644 --- a/tests/proxy/dap-proxy-worker.test.ts +++ b/tests/proxy/dap-proxy-worker.test.ts @@ -1617,6 +1617,30 @@ describe('DapProxyWorker', () => { expect(mockLogger.warn).not.toHaveBeenCalledWith(expect.stringContaining('issue #492')); }); + it('emits init-progress statuses for the parent init-timeout diagnosis (issue #493)', async () => { + const payload = rubyLaunchPayload(); + const { processStub, connectionStub } = makeStubs(async () => { + setImmediate(() => (mockDapClient as EventEmitter).emit('initialized')); + return { supportsConfigurationDoneRequest: true }; + }); + wireWorker(payload, processStub, connectionStub, RubyAdapterPolicy); + + await (worker as any).startAdapterAndConnect(payload); + + const progress = mockMessageSender.send.mock.calls + .map(([m]) => m as StatusMessage & { pid?: number; stage?: string; command?: string }) + .filter((m) => m.type === 'status' && (m.status === 'adapter_spawned' || m.status === 'dap_handshake_stage')) + .map((m) => (m.status === 'adapter_spawned' ? `spawned:${m.pid}` : `${m.stage}:${m.command ?? ''}`)); + expect(progress).toEqual([ + 'spawned:4242', + 'transport_connected:', + 'request_pending:initialize', + 'response_received:initialize', + 'request_pending:launch', + 'response_received:launch' + ]); + }); + it('a policy without the opt-in still blocks on a missing initialize response', async () => { vi.useFakeTimers(); try { diff --git a/tests/unit/proxy/proxy-manager.start.test.ts b/tests/unit/proxy/proxy-manager.start.test.ts index f9be0598..6a13f095 100644 --- a/tests/unit/proxy/proxy-manager.start.test.ts +++ b/tests/unit/proxy/proxy-manager.start.test.ts @@ -554,6 +554,75 @@ describe('ProxyManager.start', () => { } }); + it('names the stalled handshake request and adapter PID when init times out after progress (issue #493)', async () => { + vi.useFakeTimers(); + fakeProcess.sendCommand.mockImplementation((cmd: any) => { + if (cmd.cmd === 'init') { + setTimeout(() => { + const emitStatus = (extra: Record) => + fakeProcess.emit('message', { type: 'status', sessionId: cmd.sessionId, ...extra }); + emitStatus({ status: 'init_received' }); + emitStatus({ status: 'adapter_spawned', pid: 52875 }); + emitStatus({ status: 'dap_handshake_stage', stage: 'transport_connected' }); + emitStatus({ status: 'dap_handshake_stage', stage: 'request_pending', command: 'initialize' }); + }, 0); + } + }); + + const startPromise = proxyManager.start({ ...baseConfig, dryRunSpawn: false }); + + try { + const rejection = expect(startPromise).rejects.toThrow( + /Debug proxy initialization did not complete within 30s\. Connected to the debug adapter, but the "initialize" request never received a response\. The adapter process is running \(PID 52875\)\./ + ); + await vi.advanceTimersByTimeAsync(30000); + await vi.runOnlyPendingTimersAsync(); + await Promise.resolve(); + await rejection; + + // The structured facts ride on the error object for the tool result. + const error = await startPromise.catch((e: unknown) => e); + expect((error as { initProgress?: unknown }).initProgress).toEqual({ + adapterPid: 52875, + transportConnected: true, + pendingCommand: 'initialize' + }); + } finally { + vi.useRealTimers(); + } + }); + + it('an answered handshake request no longer reads as pending when init later times out (issue #493)', async () => { + vi.useFakeTimers(); + fakeProcess.sendCommand.mockImplementation((cmd: any) => { + if (cmd.cmd === 'init') { + setTimeout(() => { + const emitStatus = (extra: Record) => + fakeProcess.emit('message', { type: 'status', sessionId: cmd.sessionId, ...extra }); + emitStatus({ status: 'init_received' }); + emitStatus({ status: 'adapter_spawned', pid: 4242 }); + emitStatus({ status: 'dap_handshake_stage', stage: 'transport_connected' }); + emitStatus({ status: 'dap_handshake_stage', stage: 'request_pending', command: 'initialize' }); + emitStatus({ status: 'dap_handshake_stage', stage: 'response_received', command: 'initialize' }); + }, 0); + } + }); + + const startPromise = proxyManager.start({ ...baseConfig, dryRunSpawn: false }); + + try { + const rejection = expect(startPromise).rejects.toThrow( + /stalled before completing\. The adapter process is running \(PID 4242\)\./ + ); + await vi.advanceTimersByTimeAsync(30000); + await vi.runOnlyPendingTimersAsync(); + await Promise.resolve(); + await rejection; + } finally { + vi.useRealTimers(); + } + }); + it('resolves when dry-run proxy exits cleanly before reporting completion', async () => { fakeProcess.sendCommand.mockImplementation((cmd: any) => { if (cmd.cmd === 'init') { diff --git a/tests/unit/utils/error-messages.test.ts b/tests/unit/utils/error-messages.test.ts index c974321b..251fd1e6 100644 --- a/tests/unit/utils/error-messages.test.ts +++ b/tests/unit/utils/error-messages.test.ts @@ -21,6 +21,59 @@ describe('ErrorMessages', () => { expect(message).toMatch(/debug proxy/i); }); + describe('stage-aware proxy initialization timeout (issue #493)', () => { + const invariantPrefix = 'Debug proxy initialization did not complete within 30s.'; + + it('keeps the install hint only for the no-progress case', () => { + const message = ErrorMessages.proxyInitTimeout(30, { transportConnected: false }); + expect(message).toContain(invariantPrefix); + expect(message).toContain('installed and accessible'); + }); + + it('names the outstanding request and adapter PID after a connected handshake stalls', () => { + const message = ErrorMessages.proxyInitTimeout(30, { + transportConnected: true, + pendingCommand: 'initialize', + adapterPid: 52875 + }); + expect(message).toContain(invariantPrefix); + expect(message).toContain('"initialize" request never received a response'); + expect(message).toContain('PID 52875'); + expect(message).toContain('not a missing install'); + expect(message).not.toContain('installed and accessible'); + }); + + it('omits the PID note in connect mode (no adapter process)', () => { + const message = ErrorMessages.proxyInitTimeout(30, { + transportConnected: true, + pendingCommand: 'attach' + }); + expect(message).toContain('"attach" request never received a response'); + expect(message).not.toContain('PID'); + }); + + it('reports a connected handshake with no outstanding request as a stall, not a bad install', () => { + const message = ErrorMessages.proxyInitTimeout(30, { + transportConnected: true, + adapterPid: 4242 + }); + expect(message).toContain(invariantPrefix); + expect(message).toContain('stalled before completing'); + expect(message).toContain('PID 4242'); + expect(message).not.toContain('installed and accessible'); + }); + + it('reports spawned-but-never-connected distinctly', () => { + const message = ErrorMessages.proxyInitTimeout(30, { + transportConnected: false, + adapterPid: 999 + }); + expect(message).toContain('spawned (PID 999)'); + expect(message).toContain('never established'); + expect(message).not.toContain('installed and accessible'); + }); + }); + it('builds step still-running message', () => { const message = ErrorMessages.stepStillRunning(5); expect(message).toContain('5s');