diff --git a/src/agent/acp/AcpBackend.ts b/src/agent/acp/AcpBackend.ts index c2dbc645..b44e91e7 100644 --- a/src/agent/acp/AcpBackend.ts +++ b/src/agent/acp/AcpBackend.ts @@ -31,13 +31,39 @@ import type { McpServerConfig, } from '../core'; import { logger } from '@/ui/logger'; +import { delay } from '@/utils/time'; import packageJson from '../../../package.json'; + +/** + * Retry configuration for ACP operations + */ +const RETRY_CONFIG = { + /** Maximum number of retry attempts for init/newSession */ + maxAttempts: 3, + /** Base delay between retries in ms */ + baseDelayMs: 1000, + /** Maximum delay between retries in ms */ + maxDelayMs: 5000, +} as const; import { type TransportHandler, type StderrContext, type ToolNameContext, DefaultTransport, } from '../transport'; +import { + type SessionUpdate, + type HandlerContext, + DEFAULT_IDLE_TIMEOUT_MS, + DEFAULT_TOOL_CALL_TIMEOUT_MS, + handleAgentMessageChunk, + handleAgentThoughtChunk, + handleToolCallUpdate, + handleToolCall, + handleLegacyMessageChunk, + handlePlanUpdate, + handleThinkingUpdate, +} from './sessionUpdateHandlers'; /** * Extended RequestPermissionRequest with additional fields that may be present @@ -196,6 +222,45 @@ function nodeToWebStreams( return { writable, readable }; } +/** + * Helper to run an async operation with retry logic + */ +async function withRetry( + operation: () => Promise, + options: { + operationName: string; + maxAttempts: number; + baseDelayMs: number; + maxDelayMs: number; + onRetry?: (attempt: number, error: Error) => void; + } +): Promise { + let lastError: Error | null = null; + + for (let attempt = 1; attempt <= options.maxAttempts; attempt++) { + try { + return await operation(); + } catch (error) { + lastError = error instanceof Error ? error : new Error(String(error)); + + if (attempt < options.maxAttempts) { + // Calculate delay with exponential backoff + const delayMs = Math.min( + options.baseDelayMs * Math.pow(2, attempt - 1), + options.maxDelayMs + ); + + logger.debug(`[AcpBackend] ${options.operationName} failed (attempt ${attempt}/${options.maxAttempts}): ${lastError.message}. Retrying in ${delayMs}ms...`); + options.onRetry?.(attempt, lastError); + + await delay(delayMs); + } + } + } + + throw lastError; +} + /** * ACP backend using the official @agentclientprotocol/sdk */ @@ -575,7 +640,7 @@ export class AcpBackend implements AgentBackend { stream ); - // Initialize the connection with timeout + // Initialize the connection with timeout and retry const initRequest: InitializeRequest = { protocolVersion: 1, clientCapabilities: { @@ -590,34 +655,50 @@ export class AcpBackend implements AgentBackend { }, }; - logger.debug(`[AcpBackend] Initializing connection...`); - let initTimeout: NodeJS.Timeout | null = null; - const initResponse = await Promise.race([ - this.connection.initialize(initRequest).then((result) => { - // Clear timeout if initialization succeeds - if (initTimeout) { - clearTimeout(initTimeout); - initTimeout = null; + const initTimeout = this.transport.getInitTimeout(); + logger.debug(`[AcpBackend] Initializing connection (timeout: ${initTimeout}ms)...`); + + await withRetry( + async () => { + let timeoutHandle: NodeJS.Timeout | null = null; + try { + const result = await Promise.race([ + this.connection!.initialize(initRequest).then((res) => { + if (timeoutHandle) { + clearTimeout(timeoutHandle); + timeoutHandle = null; + } + return res; + }), + new Promise((_, reject) => { + timeoutHandle = setTimeout(() => { + reject(new Error(`Initialize timeout after ${initTimeout}ms - ${this.transport.agentName} did not respond`)); + }, initTimeout); + }), + ]); + return result; + } finally { + if (timeoutHandle) { + clearTimeout(timeoutHandle); + } } - return result; - }), - new Promise((_, reject) => { - const timeout = this.transport.getInitTimeout(); - initTimeout = setTimeout(() => { - logger.debug(`[AcpBackend] Initialize timeout after ${timeout}ms`); - reject(new Error(`Initialize timeout after ${timeout}ms - ${this.transport.agentName} did not respond`)); - }, timeout); - }), - ]); + }, + { + operationName: 'Initialize', + maxAttempts: RETRY_CONFIG.maxAttempts, + baseDelayMs: RETRY_CONFIG.baseDelayMs, + maxDelayMs: RETRY_CONFIG.maxDelayMs, + } + ); logger.debug(`[AcpBackend] Initialize completed`); - // Create a new session - const mcpServers = this.options.mcpServers + // Create a new session with retry + const mcpServers = this.options.mcpServers ? Object.entries(this.options.mcpServers).map(([name, config]) => ({ name, command: config.command, args: config.args || [], - env: config.env + env: config.env ? Object.entries(config.env).map(([envName, envValue]) => ({ name: envName, value: envValue })) : [], })) @@ -629,24 +710,39 @@ export class AcpBackend implements AgentBackend { }; logger.debug(`[AcpBackend] Creating new session...`); - let newSessionTimeout: NodeJS.Timeout | null = null; - const sessionResponse = await Promise.race([ - this.connection.newSession(newSessionRequest).then((result) => { - // Clear timeout if session creation succeeds - if (newSessionTimeout) { - clearTimeout(newSessionTimeout); - newSessionTimeout = null; + + const sessionResponse = await withRetry( + async () => { + let timeoutHandle: NodeJS.Timeout | null = null; + try { + const result = await Promise.race([ + this.connection!.newSession(newSessionRequest).then((res) => { + if (timeoutHandle) { + clearTimeout(timeoutHandle); + timeoutHandle = null; + } + return res; + }), + new Promise((_, reject) => { + timeoutHandle = setTimeout(() => { + reject(new Error(`New session timeout after ${initTimeout}ms - ${this.transport.agentName} did not respond`)); + }, initTimeout); + }), + ]); + return result; + } finally { + if (timeoutHandle) { + clearTimeout(timeoutHandle); + } } - return result; - }), - new Promise((_, reject) => { - const timeout = this.transport.getInitTimeout(); - newSessionTimeout = setTimeout(() => { - logger.debug(`[AcpBackend] NewSession timeout after ${timeout}ms`); - reject(new Error(`New session timeout after ${timeout}ms - ${this.transport.agentName} did not respond`)); - }, timeout); - }), - ]); + }, + { + operationName: 'NewSession', + maxAttempts: RETRY_CONFIG.maxAttempts, + baseDelayMs: RETRY_CONFIG.baseDelayMs, + maxDelayMs: RETRY_CONFIG.maxDelayMs, + } + ); this.acpSessionId = sessionResponse.sessionId; logger.debug(`[AcpBackend] Session created: ${this.acpSessionId}`); @@ -675,18 +771,46 @@ export class AcpBackend implements AgentBackend { } } + /** + * Create handler context for session update processing + */ + private createHandlerContext(): HandlerContext { + return { + transport: this.transport, + activeToolCalls: this.activeToolCalls, + toolCallStartTimes: this.toolCallStartTimes, + toolCallTimeouts: this.toolCallTimeouts, + toolCallIdToNameMap: this.toolCallIdToNameMap, + idleTimeout: this.idleTimeout, + toolCallCountSincePrompt: this.toolCallCountSincePrompt, + emit: (msg) => this.emit(msg), + emitIdleStatus: () => this.emitIdleStatus(), + clearIdleTimeout: () => { + if (this.idleTimeout) { + clearTimeout(this.idleTimeout); + this.idleTimeout = null; + } + }, + setIdleTimeout: (callback, ms) => { + this.idleTimeout = setTimeout(() => { + callback(); + this.idleTimeout = null; + }, ms); + }, + }; + } + private handleSessionUpdate(params: SessionNotification): void { - // SessionNotification structure: { sessionId, update: { sessionUpdate, content, ... } } const notification = params as ExtendedSessionNotification; const update = notification.update; - + if (!update) { logger.debug('[AcpBackend] Received session update without update field:', params); return; } const sessionUpdateType = update.sessionUpdate; - + // Log session updates for debugging (but not every chunk to avoid log spam) if (sessionUpdateType !== 'agent_message_chunk') { logger.debug(`[AcpBackend] Received session update: ${sessionUpdateType}`, JSON.stringify({ @@ -699,447 +823,47 @@ export class AcpBackend implements AgentBackend { }, null, 2)); } - // Handle agent message chunks (text output from Gemini) + const ctx = this.createHandlerContext(); + + // Dispatch to appropriate handler based on update type if (sessionUpdateType === 'agent_message_chunk') { - - const content = update.content; - if (content && typeof content === 'object' && 'text' in content && typeof content.text === 'string') { - const text = content.text; - - // Filter out "thinking" messages (start with **...**) - // These are internal reasoning, not user-facing output - const isThinking = /^\*\*[^*]+\*\*\n/.test(text); - - if (isThinking) { - // Emit as thinking event instead of model output - this.emit({ - type: 'event', - name: 'thinking', - payload: { text }, - }); - } else { - logger.debug(`[AcpBackend] Received message chunk (length: ${text.length}): ${text.substring(0, 50)}...`); - this.emit({ - type: 'model-output', - textDelta: text, - }); - - // Reset idle timeout - more chunks are coming - if (this.idleTimeout) { - clearTimeout(this.idleTimeout); - this.idleTimeout = null; - } - - // Set timeout to emit 'idle' after a short delay when no more chunks arrive - // This delay ensures all chunks (especially options blocks) are received before marking as idle - this.idleTimeout = setTimeout(() => { - // Only emit idle if no active tool calls - if (this.activeToolCalls.size === 0) { - logger.debug('[AcpBackend] No more chunks received, emitting idle status'); - this.emitIdleStatus(); - } else { - logger.debug(`[AcpBackend] Delaying idle status - ${this.activeToolCalls.size} active tool calls`); - } - this.idleTimeout = null; - }, 500); // 500ms delay to batch chunks (reduced from 500ms, but still enough for options) - } - } + handleAgentMessageChunk(update as SessionUpdate, ctx); + return; } - // Handle tool call updates if (sessionUpdateType === 'tool_call_update') { - const status = update.status; - const toolCallId = update.toolCallId; - - if (!toolCallId) { - logger.debug('[AcpBackend] Tool call update without toolCallId:', update); - return; - } - - if (status === 'in_progress' || status === 'pending') { - // Only emit tool-call if we haven't seen this toolCallId before - if (!this.activeToolCalls.has(toolCallId)) { - const startTime = Date.now(); - const toolKind = update.kind || 'unknown'; - const isInvestigation = this.transport.isInvestigationTool?.(toolCallId, typeof toolKind === 'string' ? toolKind : undefined) ?? false; - - // Determine real tool name from toolCallId (e.g., "change_title-1765385846663" -> "change_title") - const extractedName = this.transport.extractToolNameFromId?.(toolCallId); - const realToolName = extractedName ?? (typeof toolKind === 'string' ? toolKind : 'unknown'); - - // Store mapping for permission requests - this.toolCallIdToNameMap.set(toolCallId, realToolName); - - this.activeToolCalls.add(toolCallId); - this.toolCallStartTimes.set(toolCallId, startTime); - logger.debug(`[AcpBackend] ⏱️ Set startTime for ${toolCallId} at ${new Date(startTime).toISOString()} (from tool_call_update)`); - - // Increment tool call counter for context tracking - this.toolCallCountSincePrompt++; - - logger.debug(`[AcpBackend] 🔧 Tool call START: ${toolCallId} (${toolKind} -> ${realToolName})${isInvestigation ? ' [INVESTIGATION TOOL]' : ''}`); - if (isInvestigation) { - logger.debug(`[AcpBackend] 🔍 Investigation tool detected (by toolCallId) - extended timeout (10min) will be used`); - } - - // Set timeout for tool call completion (especially important for investigation tools) - // This ensures timeout is set even if tool_call event doesn't arrive - const timeoutMs = this.transport.getToolCallTimeout?.(toolCallId, typeof toolKind === 'string' ? toolKind : undefined) ?? 120000; - - // Only set timeout if not already set (from tool_call event) - if (!this.toolCallTimeouts.has(toolCallId)) { - const timeout = setTimeout(() => { - const startTime = this.toolCallStartTimes.get(toolCallId); - const duration = startTime ? Date.now() - startTime : null; - const durationStr = duration ? `${(duration / 1000).toFixed(2)}s` : 'unknown'; - - logger.debug(`[AcpBackend] ⏱️ Tool call TIMEOUT (from tool_call_update): ${toolCallId} (${toolKind}) after ${(timeoutMs / 1000).toFixed(0)}s - Duration: ${durationStr}, removing from active set`); - this.activeToolCalls.delete(toolCallId); - this.toolCallStartTimes.delete(toolCallId); - this.toolCallTimeouts.delete(toolCallId); - - // Check if we should emit idle status - if (this.activeToolCalls.size === 0) { - logger.debug('[AcpBackend] No more active tool calls after timeout, emitting idle status'); - this.emitIdleStatus(); - } - }, timeoutMs); - - this.toolCallTimeouts.set(toolCallId, timeout); - logger.debug(`[AcpBackend] ⏱️ Set timeout for ${toolCallId}: ${(timeoutMs / 1000).toFixed(0)}s${isInvestigation ? ' (investigation tool)' : ''}`); - } else { - logger.debug(`[AcpBackend] Timeout already set for ${toolCallId}, skipping`); - } - - // Clear idle timeout - tool call is starting, agent is working - if (this.idleTimeout) { - clearTimeout(this.idleTimeout); - this.idleTimeout = null; - } - - // Emit running status when tool call starts - this.emit({ type: 'status', status: 'running' }); - - // Parse args from content (can be array or object) - let args: Record = {}; - if (Array.isArray(update.content)) { - // Convert array content to object if needed - args = { items: update.content }; - } else if (update.content && typeof update.content === 'object' && update.content !== null) { - args = update.content as Record; - } - - // Log tool call details for investigation tools - if (isInvestigation && args.objective) { - logger.debug(`[AcpBackend] 🔍 Investigation tool objective: ${String(args.objective).substring(0, 100)}...`); - } - - this.emit({ - type: 'tool-call', - toolName: typeof toolKind === 'string' ? toolKind : 'unknown', - args, - callId: toolCallId, - }); - } else { - // Tool call already tracked - might be an update - logger.debug(`[AcpBackend] Tool call ${toolCallId} already tracked, status: ${status}`); - } - } else if (status === 'completed') { - // Tool call finished - remove from active set and clear timeout - const startTime = this.toolCallStartTimes.get(toolCallId); - const duration = startTime ? Date.now() - startTime : null; - const toolKind = update.kind || 'unknown'; - - this.activeToolCalls.delete(toolCallId); - this.toolCallStartTimes.delete(toolCallId); - - const timeout = this.toolCallTimeouts.get(toolCallId); - if (timeout) { - clearTimeout(timeout); - this.toolCallTimeouts.delete(toolCallId); - } - - const durationStr = duration ? `${(duration / 1000).toFixed(2)}s` : 'unknown'; - logger.debug(`[AcpBackend] ✅ Tool call COMPLETED: ${toolCallId} (${toolKind}) - Duration: ${durationStr}. Active tool calls: ${this.activeToolCalls.size}`); - - this.emit({ - type: 'tool-result', - toolName: typeof toolKind === 'string' ? toolKind : 'unknown', - result: update.content, - callId: toolCallId, - }); - - // If no more active tool calls, emit 'idle' immediately (like Codex's task_complete) - // No timeout needed - when all tool calls complete, task is done - if (this.activeToolCalls.size === 0) { - if (this.idleTimeout) { - clearTimeout(this.idleTimeout); - this.idleTimeout = null; - } - logger.debug('[AcpBackend] All tool calls completed, emitting idle status'); - this.emitIdleStatus(); - } - } else if (status === 'failed' || status === 'cancelled') { - // Tool call failed or was cancelled - remove from active set and clear timeout - // IMPORTANT: Save values BEFORE deleting them for logging - const startTime = this.toolCallStartTimes.get(toolCallId); - const duration = startTime ? Date.now() - startTime : null; - const toolKind = update.kind || 'unknown'; - const isInvestigation = this.transport.isInvestigationTool?.(toolCallId, typeof toolKind === 'string' ? toolKind : undefined) ?? false; - const hadTimeout = this.toolCallTimeouts.has(toolCallId); - - // Log detailed timing information for investigation tools BEFORE cleanup - if (isInvestigation) { - const durationStr = duration ? `${(duration / 1000).toFixed(2)}s` : 'unknown'; - const durationMinutes = duration ? (duration / 1000 / 60).toFixed(2) : 'unknown'; - logger.debug(`[AcpBackend] 🔍 Investigation tool ${status.toUpperCase()} after ${durationMinutes} minutes (${durationStr})`); - - // Check if this matches a 3-minute timeout pattern - if (duration) { - const threeMinutes = 3 * 60 * 1000; - const tolerance = 5000; // 5 second tolerance - if (Math.abs(duration - threeMinutes) < tolerance) { - logger.debug(`[AcpBackend] 🔍 ⚠️ Investigation tool failed at ~3 minutes - likely Gemini CLI timeout, not our timeout`); - } - } - - logger.debug(`[AcpBackend] 🔍 Investigation tool FAILED - full update.content:`, JSON.stringify(update.content, null, 2)); - logger.debug(`[AcpBackend] 🔍 Investigation tool timeout status BEFORE cleanup: ${hadTimeout ? 'timeout was set' : 'no timeout was set'}`); - logger.debug(`[AcpBackend] 🔍 Investigation tool startTime status BEFORE cleanup: ${startTime ? `set at ${new Date(startTime).toISOString()}` : 'not set'}`); - } - - // Now cleanup - remove from active set and clear timeout - this.activeToolCalls.delete(toolCallId); - this.toolCallStartTimes.delete(toolCallId); - - const timeout = this.toolCallTimeouts.get(toolCallId); - if (timeout) { - clearTimeout(timeout); - this.toolCallTimeouts.delete(toolCallId); - logger.debug(`[AcpBackend] Cleared timeout for ${toolCallId} (tool call ${status})`); - } else { - logger.debug(`[AcpBackend] No timeout found for ${toolCallId} (tool call ${status}) - timeout may not have been set`); - } - - const durationStr = duration ? `${(duration / 1000).toFixed(2)}s` : 'unknown'; - logger.debug(`[AcpBackend] ❌ Tool call ${status.toUpperCase()}: ${toolCallId} (${toolKind}) - Duration: ${durationStr}. Active tool calls: ${this.activeToolCalls.size}`); - - // Extract error information from update.content if available - let errorDetail: string | undefined; - - if (update.content) { - if (typeof update.content === 'string') { - errorDetail = update.content; - } else if (typeof update.content === 'object' && update.content !== null && !Array.isArray(update.content)) { - const content = update.content as unknown as Record; - if (content.error) { - const error = content.error; - errorDetail = typeof error === 'string' - ? error - : (error && typeof error === 'object' && 'message' in error && typeof error.message === 'string') - ? error.message - : JSON.stringify(error); - } else if (typeof content.message === 'string') { - errorDetail = content.message; - } else { - // Try to extract any error-like fields - const status = typeof content.status === 'string' ? content.status : undefined; - const reason = typeof content.reason === 'string' ? content.reason : undefined; - errorDetail = status || reason || JSON.stringify(content).substring(0, 500); - } - } - } - - if (errorDetail) { - logger.debug(`[AcpBackend] ❌ Tool call error details: ${errorDetail.substring(0, 500)}`); - } else { - logger.debug(`[AcpBackend] ❌ Tool call ${status} but no error details in update.content`); - } - - // Emit tool-result with error information so user can see what went wrong - this.emit({ - type: 'tool-result', - toolName: typeof toolKind === 'string' ? toolKind : 'unknown', - result: errorDetail - ? { error: errorDetail, status: status } - : { error: `Tool call ${status}`, status: status }, - callId: toolCallId, - }); - - // If no more active tool calls, emit 'idle' immediately (like Codex's task_complete) - if (this.activeToolCalls.size === 0) { - if (this.idleTimeout) { - clearTimeout(this.idleTimeout); - this.idleTimeout = null; - } - logger.debug('[AcpBackend] All tool calls completed/failed, emitting idle status'); - this.emitIdleStatus(); - } + const result = handleToolCallUpdate(update as SessionUpdate, ctx); + if (result.toolCallCountSincePrompt !== undefined) { + this.toolCallCountSincePrompt = result.toolCallCountSincePrompt; } + return; } - // Legacy format support (in case some agents use old format) - if (update.messageChunk) { - const chunk = update.messageChunk; - if (chunk.textDelta) { - this.emit({ - type: 'model-output', - textDelta: chunk.textDelta, - }); - } - } - - // Handle plan updates - if (update.plan) { - this.emit({ - type: 'event', - name: 'plan', - payload: update.plan, - }); - } - - // Handle agent_thought_chunk (Gemini's thinking/reasoning chunks) if (sessionUpdateType === 'agent_thought_chunk') { - - const content = update.content; - if (content && typeof content === 'object' && 'text' in content && typeof content.text === 'string') { - const text = content.text; - // Log thinking chunks for investigation tools (they can be long) - const hasActiveInvestigation = Array.from(this.activeToolCalls).some(() => { - // We can't directly check tool kind here, but we log for correlation - return true; // Log all thinking chunks when tool calls are active - }); - - if (hasActiveInvestigation && this.activeToolCalls.size > 0) { - const activeToolCallsList = Array.from(this.activeToolCalls); - logger.debug(`[AcpBackend] 💭 Thinking chunk received (${text.length} chars) during active tool calls: ${activeToolCallsList.join(', ')}`); - } - - // Emit as thinking event - don't show as regular message - this.emit({ - type: 'event', - name: 'thinking', - payload: { text }, - }); - } + handleAgentThoughtChunk(update as SessionUpdate, ctx); + return; } - // Handle tool_call (direct tool call, not just tool_call_update) if (sessionUpdateType === 'tool_call') { - const toolCallId = update.toolCallId; - const status = update.status; - - logger.debug(`[AcpBackend] Received tool_call: toolCallId=${toolCallId}, status=${status}, kind=${update.kind}`); - - // tool_call can come without explicit status, assume 'in_progress' if status is missing - const isInProgress = !status || status === 'in_progress' || status === 'pending'; - - if (toolCallId && isInProgress) { - - // Only emit tool-call if we haven't seen this toolCallId before - if (!this.activeToolCalls.has(toolCallId)) { - const startTime = Date.now(); - this.activeToolCalls.add(toolCallId); - this.toolCallStartTimes.set(toolCallId, startTime); - logger.debug(`[AcpBackend] Added tool call ${toolCallId} to active set. Total active: ${this.activeToolCalls.size}`); - logger.debug(`[AcpBackend] ⏱️ Set startTime for ${toolCallId} at ${new Date(startTime).toISOString()}`); - - // Clear idle timeout - tool call is starting, agent is working - if (this.idleTimeout) { - clearTimeout(this.idleTimeout); - this.idleTimeout = null; - } - - // Set timeout for tool call completion (especially for "think" tools that may not send completion updates) - // Think tools typically complete quickly, but we set a longer timeout for other tools - // codebase_investigator and similar investigation tools can take 5+ minutes, so we use a much longer timeout - // NOTE: update.kind may be "think" even for codebase_investigator, so we check toolCallId instead - const toolKindStr = typeof update.kind === 'string' ? update.kind : undefined; - const isInvestigation = this.transport.isInvestigationTool?.(toolCallId, toolKindStr) ?? false; - - if (isInvestigation) { - logger.debug(`[AcpBackend] 🔍 Investigation tool detected (toolCallId: ${toolCallId}, kind: ${update.kind}) - using extended timeout (10min)`); - } - - const timeoutMs = this.transport.getToolCallTimeout?.(toolCallId, toolKindStr) ?? 120000; - - // Only set timeout if not already set (from tool_call_update) - if (!this.toolCallTimeouts.has(toolCallId)) { - const timeout = setTimeout(() => { - const startTime = this.toolCallStartTimes.get(toolCallId); - const duration = startTime ? Date.now() - startTime : null; - const durationStr = duration ? `${(duration / 1000).toFixed(2)}s` : 'unknown'; - - logger.debug(`[AcpBackend] ⏱️ Tool call TIMEOUT (from tool_call): ${toolCallId} (${update.kind}) after ${(timeoutMs / 1000).toFixed(0)}s - Duration: ${durationStr}, removing from active set`); - this.activeToolCalls.delete(toolCallId); - this.toolCallStartTimes.delete(toolCallId); - this.toolCallTimeouts.delete(toolCallId); - - // Check if we should emit idle status - if (this.activeToolCalls.size === 0) { - logger.debug('[AcpBackend] No more active tool calls after timeout, emitting idle status'); - this.emitIdleStatus(); - } - }, timeoutMs); - - this.toolCallTimeouts.set(toolCallId, timeout); - logger.debug(`[AcpBackend] ⏱️ Set timeout for ${toolCallId}: ${(timeoutMs / 1000).toFixed(0)}s${isInvestigation ? ' (investigation tool)' : ''}`); - } else { - logger.debug(`[AcpBackend] Timeout already set for ${toolCallId}, skipping`); - } - - // Emit running status when tool call starts - this.emit({ type: 'status', status: 'running' }); - - // Parse args from content (can be array or object) - let args: Record = {}; - if (Array.isArray(update.content)) { - args = { items: update.content }; - } else if (update.content && typeof update.content === 'object') { - args = update.content; - } - - // Extract locations if present (for file operations) - if (update.locations && Array.isArray(update.locations)) { - args.locations = update.locations; - } - - logger.debug(`[AcpBackend] Emitting tool-call event: toolName=${update.kind}, toolCallId=${toolCallId}, args=`, JSON.stringify(args)); - - this.emit({ - type: 'tool-call', - toolName: update.kind || 'unknown', - args, - callId: toolCallId, - }); - } else { - logger.debug(`[AcpBackend] Tool call ${toolCallId} already in active set, skipping`); - } - } else { - logger.debug(`[AcpBackend] Tool call ${toolCallId} not in progress (status: ${status}), skipping`); - } + handleToolCall(update as SessionUpdate, ctx); + return; } - // Handle thinking/reasoning (explicit thinking field) - if (update.thinking) { - - this.emit({ - type: 'event', - name: 'thinking', - payload: update.thinking, - }); - } - + // Handle legacy and auxiliary update types + handleLegacyMessageChunk(update as SessionUpdate, ctx); + handlePlanUpdate(update as SessionUpdate, ctx); + handleThinkingUpdate(update as SessionUpdate, ctx); + // Log unhandled session update types for debugging - if (sessionUpdateType && - sessionUpdateType !== 'agent_message_chunk' && - sessionUpdateType !== 'tool_call_update' && - sessionUpdateType !== 'agent_thought_chunk' && - sessionUpdateType !== 'tool_call' && + // Cast to string to avoid TypeScript errors (SDK types don't include all Gemini-specific update types) + const updateTypeStr = sessionUpdateType as string; + const handledTypes = ['agent_message_chunk', 'tool_call_update', 'agent_thought_chunk', 'tool_call']; + if (updateTypeStr && + !handledTypes.includes(updateTypeStr) && !update.messageChunk && !update.plan && !update.thinking) { - logger.debug(`[AcpBackend] Unhandled session update type: ${sessionUpdateType}`, JSON.stringify(update, null, 2)); + logger.debug(`[AcpBackend] Unhandled session update type: ${updateTypeStr}`, JSON.stringify(update, null, 2)); } } @@ -1273,12 +997,24 @@ export class AcpBackend implements AgentBackend { } } + /** + * Emit permission response event for UI/logging purposes. + * + * **IMPORTANT:** For ACP backends, this method does NOT send the actual permission + * response to the agent. The ACP protocol requires synchronous permission handling, + * which is done inside the `requestPermission` RPC handler via `this.options.permissionHandler`. + * + * This method only emits a `permission-response` event for: + * - UI updates (e.g., closing permission dialogs) + * - Logging and debugging + * - Other parts of the CLI that need to react to permission decisions + * + * @param requestId - The ID of the permission request + * @param approved - Whether the permission was granted + */ async respondToPermission(requestId: string, approved: boolean): Promise { - logger.debug(`[AcpBackend] Permission response: ${requestId} = ${approved}`); + logger.debug(`[AcpBackend] Permission response event (UI only): ${requestId} = ${approved}`); this.emit({ type: 'permission-response', id: requestId, approved }); - // IMPORTANT: The actual ACP permission response is handled synchronously - // within the `requestPermission` method via `this.options.permissionHandler`. - // This method only emits an internal event for other parts of the CLI to react to. } async dispose(): Promise { diff --git a/src/agent/acp/index.ts b/src/agent/acp/index.ts index aeb49b79..a921f7b6 100644 --- a/src/agent/acp/index.ts +++ b/src/agent/acp/index.ts @@ -12,6 +12,26 @@ // Core ACP backend export { AcpBackend, type AcpBackendOptions, type AcpPermissionHandler } from './AcpBackend'; +// Session update handlers (for testing and extension) +export { + type SessionUpdate, + type HandlerContext, + type HandlerResult, + DEFAULT_IDLE_TIMEOUT_MS, + DEFAULT_TOOL_CALL_TIMEOUT_MS, + parseArgsFromContent, + extractErrorDetail, + formatDuration, + formatDurationMinutes, + handleAgentMessageChunk, + handleAgentThoughtChunk, + handleToolCallUpdate, + handleToolCall, + handleLegacyMessageChunk, + handlePlanUpdate, + handleThinkingUpdate, +} from './sessionUpdateHandlers'; + // Factory helper for generic ACP backends export { createAcpBackend, type CreateAcpBackendOptions } from './createAcpBackend'; diff --git a/src/agent/acp/sessionUpdateHandlers.ts b/src/agent/acp/sessionUpdateHandlers.ts new file mode 100644 index 00000000..4c68c46d --- /dev/null +++ b/src/agent/acp/sessionUpdateHandlers.ts @@ -0,0 +1,558 @@ +/** + * Session Update Handlers for ACP Backend + * + * This module contains handlers for different types of ACP session updates. + * Each handler is responsible for processing a specific update type and + * emitting appropriate AgentMessages. + * + * Extracted from AcpBackend to improve maintainability and testability. + */ + +import type { AgentMessage } from '../core'; +import type { TransportHandler } from '../transport'; +import { logger } from '@/ui/logger'; + +/** + * Default timeout for idle detection after message chunks (ms) + * Used when transport handler doesn't provide getIdleTimeout() + */ +export const DEFAULT_IDLE_TIMEOUT_MS = 500; + +/** + * Default timeout for tool calls if transport doesn't specify (ms) + */ +export const DEFAULT_TOOL_CALL_TIMEOUT_MS = 120_000; + +/** + * Extended session update structure with all possible fields + */ +export interface SessionUpdate { + sessionUpdate?: string; + toolCallId?: string; + status?: string; + kind?: string | unknown; + content?: { + text?: string; + error?: string | { message?: string }; + [key: string]: unknown; + } | string | unknown; + locations?: unknown[]; + messageChunk?: { + textDelta?: string; + }; + plan?: unknown; + thinking?: unknown; + [key: string]: unknown; +} + +/** + * Context for session update handlers + */ +export interface HandlerContext { + /** Transport handler for agent-specific behavior */ + transport: TransportHandler; + /** Set of active tool call IDs */ + activeToolCalls: Set; + /** Map of tool call ID to start time */ + toolCallStartTimes: Map; + /** Map of tool call ID to timeout handle */ + toolCallTimeouts: Map; + /** Map of tool call ID to tool name */ + toolCallIdToNameMap: Map; + /** Current idle timeout handle */ + idleTimeout: NodeJS.Timeout | null; + /** Tool call counter since last prompt */ + toolCallCountSincePrompt: number; + /** Emit function to send agent messages */ + emit: (msg: AgentMessage) => void; + /** Emit idle status helper */ + emitIdleStatus: () => void; + /** Clear idle timeout helper */ + clearIdleTimeout: () => void; + /** Set idle timeout helper */ + setIdleTimeout: (callback: () => void, ms: number) => void; +} + +/** + * Result of handling a session update + */ +export interface HandlerResult { + /** Whether the update was handled */ + handled: boolean; + /** Updated tool call counter */ + toolCallCountSincePrompt?: number; +} + +/** + * Parse args from update content (can be array or object) + */ +export function parseArgsFromContent(content: unknown): Record { + if (Array.isArray(content)) { + return { items: content }; + } + if (content && typeof content === 'object' && content !== null) { + return content as Record; + } + return {}; +} + +/** + * Extract error detail from update content + */ +export function extractErrorDetail(content: unknown): string | undefined { + if (!content) return undefined; + + if (typeof content === 'string') { + return content; + } + + if (typeof content === 'object' && content !== null && !Array.isArray(content)) { + const obj = content as Record; + + if (obj.error) { + const error = obj.error; + if (typeof error === 'string') return error; + if (error && typeof error === 'object' && 'message' in error) { + const errObj = error as { message?: unknown }; + if (typeof errObj.message === 'string') return errObj.message; + } + return JSON.stringify(error); + } + + if (typeof obj.message === 'string') return obj.message; + + const status = typeof obj.status === 'string' ? obj.status : undefined; + const reason = typeof obj.reason === 'string' ? obj.reason : undefined; + return status || reason || JSON.stringify(obj).substring(0, 500); + } + + return undefined; +} + +/** + * Format duration for logging + */ +export function formatDuration(startTime: number | undefined): string { + if (!startTime) return 'unknown'; + const duration = Date.now() - startTime; + return `${(duration / 1000).toFixed(2)}s`; +} + +/** + * Format duration in minutes for logging + */ +export function formatDurationMinutes(startTime: number | undefined): string { + if (!startTime) return 'unknown'; + const duration = Date.now() - startTime; + return (duration / 1000 / 60).toFixed(2); +} + +/** + * Handle agent_message_chunk update (text output from model) + */ +export function handleAgentMessageChunk( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + const content = update.content; + + if (!content || typeof content !== 'object' || !('text' in content)) { + return { handled: false }; + } + + const text = (content as { text?: string }).text; + if (typeof text !== 'string') { + return { handled: false }; + } + + // Filter out "thinking" messages (start with **...**) + const isThinking = /^\*\*[^*]+\*\*\n/.test(text); + + if (isThinking) { + ctx.emit({ + type: 'event', + name: 'thinking', + payload: { text }, + }); + } else { + logger.debug(`[AcpBackend] Received message chunk (length: ${text.length}): ${text.substring(0, 50)}...`); + ctx.emit({ + type: 'model-output', + textDelta: text, + }); + + // Reset idle timeout - more chunks are coming + ctx.clearIdleTimeout(); + + // Set timeout to emit 'idle' after a short delay when no more chunks arrive + const idleTimeoutMs = ctx.transport.getIdleTimeout?.() ?? DEFAULT_IDLE_TIMEOUT_MS; + ctx.setIdleTimeout(() => { + if (ctx.activeToolCalls.size === 0) { + logger.debug('[AcpBackend] No more chunks received, emitting idle status'); + ctx.emitIdleStatus(); + } else { + logger.debug(`[AcpBackend] Delaying idle status - ${ctx.activeToolCalls.size} active tool calls`); + } + }, idleTimeoutMs); + } + + return { handled: true }; +} + +/** + * Handle agent_thought_chunk update (Gemini's thinking/reasoning) + */ +export function handleAgentThoughtChunk( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + const content = update.content; + + if (!content || typeof content !== 'object' || !('text' in content)) { + return { handled: false }; + } + + const text = (content as { text?: string }).text; + if (typeof text !== 'string') { + return { handled: false }; + } + + // Log thinking chunks when tool calls are active + if (ctx.activeToolCalls.size > 0) { + const activeToolCallsList = Array.from(ctx.activeToolCalls); + logger.debug(`[AcpBackend] 💭 Thinking chunk received (${text.length} chars) during active tool calls: ${activeToolCallsList.join(', ')}`); + } + + ctx.emit({ + type: 'event', + name: 'thinking', + payload: { text }, + }); + + return { handled: true }; +} + +/** + * Start tracking a new tool call + */ +export function startToolCall( + toolCallId: string, + toolKind: string | unknown, + update: SessionUpdate, + ctx: HandlerContext, + source: 'tool_call' | 'tool_call_update' +): void { + const startTime = Date.now(); + const toolKindStr = typeof toolKind === 'string' ? toolKind : undefined; + const isInvestigation = ctx.transport.isInvestigationTool?.(toolCallId, toolKindStr) ?? false; + + // Extract real tool name from toolCallId + const extractedName = ctx.transport.extractToolNameFromId?.(toolCallId); + const realToolName = extractedName ?? (toolKindStr || 'unknown'); + + // Store mapping for permission requests + ctx.toolCallIdToNameMap.set(toolCallId, realToolName); + + ctx.activeToolCalls.add(toolCallId); + ctx.toolCallStartTimes.set(toolCallId, startTime); + + logger.debug(`[AcpBackend] ⏱️ Set startTime for ${toolCallId} at ${new Date(startTime).toISOString()} (from ${source})`); + logger.debug(`[AcpBackend] 🔧 Tool call START: ${toolCallId} (${toolKind} -> ${realToolName})${isInvestigation ? ' [INVESTIGATION TOOL]' : ''}`); + + if (isInvestigation) { + logger.debug(`[AcpBackend] 🔍 Investigation tool detected - extended timeout (10min) will be used`); + } + + // Set timeout for tool call completion + const timeoutMs = ctx.transport.getToolCallTimeout?.(toolCallId, toolKindStr) ?? DEFAULT_TOOL_CALL_TIMEOUT_MS; + + if (!ctx.toolCallTimeouts.has(toolCallId)) { + const timeout = setTimeout(() => { + const duration = formatDuration(ctx.toolCallStartTimes.get(toolCallId)); + logger.debug(`[AcpBackend] ⏱️ Tool call TIMEOUT (from ${source}): ${toolCallId} (${toolKind}) after ${(timeoutMs / 1000).toFixed(0)}s - Duration: ${duration}, removing from active set`); + + ctx.activeToolCalls.delete(toolCallId); + ctx.toolCallStartTimes.delete(toolCallId); + ctx.toolCallTimeouts.delete(toolCallId); + + if (ctx.activeToolCalls.size === 0) { + logger.debug('[AcpBackend] No more active tool calls after timeout, emitting idle status'); + ctx.emitIdleStatus(); + } + }, timeoutMs); + + ctx.toolCallTimeouts.set(toolCallId, timeout); + logger.debug(`[AcpBackend] ⏱️ Set timeout for ${toolCallId}: ${(timeoutMs / 1000).toFixed(0)}s${isInvestigation ? ' (investigation tool)' : ''}`); + } else { + logger.debug(`[AcpBackend] Timeout already set for ${toolCallId}, skipping`); + } + + // Clear idle timeout - tool call is starting + ctx.clearIdleTimeout(); + + // Emit running status + ctx.emit({ type: 'status', status: 'running' }); + + // Parse args and emit tool-call event + const args = parseArgsFromContent(update.content); + + // Extract locations if present + if (update.locations && Array.isArray(update.locations)) { + args.locations = update.locations; + } + + // Log investigation tool objective + if (isInvestigation && args.objective) { + logger.debug(`[AcpBackend] 🔍 Investigation tool objective: ${String(args.objective).substring(0, 100)}...`); + } + + ctx.emit({ + type: 'tool-call', + toolName: toolKindStr || 'unknown', + args, + callId: toolCallId, + }); +} + +/** + * Complete a tool call successfully + */ +export function completeToolCall( + toolCallId: string, + toolKind: string | unknown, + content: unknown, + ctx: HandlerContext +): void { + const startTime = ctx.toolCallStartTimes.get(toolCallId); + const duration = formatDuration(startTime); + const toolKindStr = typeof toolKind === 'string' ? toolKind : 'unknown'; + + ctx.activeToolCalls.delete(toolCallId); + ctx.toolCallStartTimes.delete(toolCallId); + + const timeout = ctx.toolCallTimeouts.get(toolCallId); + if (timeout) { + clearTimeout(timeout); + ctx.toolCallTimeouts.delete(toolCallId); + } + + logger.debug(`[AcpBackend] ✅ Tool call COMPLETED: ${toolCallId} (${toolKindStr}) - Duration: ${duration}. Active tool calls: ${ctx.activeToolCalls.size}`); + + ctx.emit({ + type: 'tool-result', + toolName: toolKindStr, + result: content, + callId: toolCallId, + }); + + // If no more active tool calls, emit idle + if (ctx.activeToolCalls.size === 0) { + ctx.clearIdleTimeout(); + logger.debug('[AcpBackend] All tool calls completed, emitting idle status'); + ctx.emitIdleStatus(); + } +} + +/** + * Fail a tool call + */ +export function failToolCall( + toolCallId: string, + status: 'failed' | 'cancelled', + toolKind: string | unknown, + content: unknown, + ctx: HandlerContext +): void { + const startTime = ctx.toolCallStartTimes.get(toolCallId); + const duration = startTime ? Date.now() - startTime : null; + const toolKindStr = typeof toolKind === 'string' ? toolKind : 'unknown'; + const isInvestigation = ctx.transport.isInvestigationTool?.(toolCallId, toolKindStr) ?? false; + const hadTimeout = ctx.toolCallTimeouts.has(toolCallId); + + // Log detailed timing for investigation tools BEFORE cleanup + if (isInvestigation) { + const durationStr = formatDuration(startTime); + const durationMinutes = formatDurationMinutes(startTime); + logger.debug(`[AcpBackend] 🔍 Investigation tool ${status.toUpperCase()} after ${durationMinutes} minutes (${durationStr})`); + + // Check for 3-minute timeout pattern (Gemini CLI internal timeout) + if (duration) { + const threeMinutes = 3 * 60 * 1000; + const tolerance = 5000; + if (Math.abs(duration - threeMinutes) < tolerance) { + logger.debug(`[AcpBackend] 🔍 ⚠️ Investigation tool failed at ~3 minutes - likely Gemini CLI timeout, not our timeout`); + } + } + + logger.debug(`[AcpBackend] 🔍 Investigation tool FAILED - full content:`, JSON.stringify(content, null, 2)); + logger.debug(`[AcpBackend] 🔍 Investigation tool timeout status BEFORE cleanup: ${hadTimeout ? 'timeout was set' : 'no timeout was set'}`); + logger.debug(`[AcpBackend] 🔍 Investigation tool startTime status BEFORE cleanup: ${startTime ? `set at ${new Date(startTime).toISOString()}` : 'not set'}`); + } + + // Cleanup + ctx.activeToolCalls.delete(toolCallId); + ctx.toolCallStartTimes.delete(toolCallId); + + const timeout = ctx.toolCallTimeouts.get(toolCallId); + if (timeout) { + clearTimeout(timeout); + ctx.toolCallTimeouts.delete(toolCallId); + logger.debug(`[AcpBackend] Cleared timeout for ${toolCallId} (tool call ${status})`); + } else { + logger.debug(`[AcpBackend] No timeout found for ${toolCallId} (tool call ${status}) - timeout may not have been set`); + } + + const durationStr = formatDuration(startTime); + logger.debug(`[AcpBackend] ❌ Tool call ${status.toUpperCase()}: ${toolCallId} (${toolKindStr}) - Duration: ${durationStr}. Active tool calls: ${ctx.activeToolCalls.size}`); + + // Extract error detail + const errorDetail = extractErrorDetail(content); + if (errorDetail) { + logger.debug(`[AcpBackend] ❌ Tool call error details: ${errorDetail.substring(0, 500)}`); + } else { + logger.debug(`[AcpBackend] ❌ Tool call ${status} but no error details in content`); + } + + // Emit tool-result with error + ctx.emit({ + type: 'tool-result', + toolName: toolKindStr, + result: errorDetail + ? { error: errorDetail, status } + : { error: `Tool call ${status}`, status }, + callId: toolCallId, + }); + + // If no more active tool calls, emit idle + if (ctx.activeToolCalls.size === 0) { + ctx.clearIdleTimeout(); + logger.debug('[AcpBackend] All tool calls completed/failed, emitting idle status'); + ctx.emitIdleStatus(); + } +} + +/** + * Handle tool_call_update session update + */ +export function handleToolCallUpdate( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + const status = update.status; + const toolCallId = update.toolCallId; + + if (!toolCallId) { + logger.debug('[AcpBackend] Tool call update without toolCallId:', update); + return { handled: false }; + } + + const toolKind = update.kind || 'unknown'; + let toolCallCountSincePrompt = ctx.toolCallCountSincePrompt; + + if (status === 'in_progress' || status === 'pending') { + if (!ctx.activeToolCalls.has(toolCallId)) { + toolCallCountSincePrompt++; + startToolCall(toolCallId, toolKind, update, ctx, 'tool_call_update'); + } else { + logger.debug(`[AcpBackend] Tool call ${toolCallId} already tracked, status: ${status}`); + } + } else if (status === 'completed') { + completeToolCall(toolCallId, toolKind, update.content, ctx); + } else if (status === 'failed' || status === 'cancelled') { + failToolCall(toolCallId, status, toolKind, update.content, ctx); + } + + return { handled: true, toolCallCountSincePrompt }; +} + +/** + * Handle tool_call session update (direct tool call) + */ +export function handleToolCall( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + const toolCallId = update.toolCallId; + const status = update.status; + + logger.debug(`[AcpBackend] Received tool_call: toolCallId=${toolCallId}, status=${status}, kind=${update.kind}`); + + // tool_call can come without explicit status, assume 'in_progress' if missing + const isInProgress = !status || status === 'in_progress' || status === 'pending'; + + if (!toolCallId || !isInProgress) { + logger.debug(`[AcpBackend] Tool call ${toolCallId} not in progress (status: ${status}), skipping`); + return { handled: false }; + } + + if (ctx.activeToolCalls.has(toolCallId)) { + logger.debug(`[AcpBackend] Tool call ${toolCallId} already in active set, skipping`); + return { handled: true }; + } + + startToolCall(toolCallId, update.kind, update, ctx, 'tool_call'); + return { handled: true }; +} + +/** + * Handle legacy messageChunk format + */ +export function handleLegacyMessageChunk( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + if (!update.messageChunk) { + return { handled: false }; + } + + const chunk = update.messageChunk; + if (chunk.textDelta) { + ctx.emit({ + type: 'model-output', + textDelta: chunk.textDelta, + }); + return { handled: true }; + } + + return { handled: false }; +} + +/** + * Handle plan update + */ +export function handlePlanUpdate( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + if (!update.plan) { + return { handled: false }; + } + + ctx.emit({ + type: 'event', + name: 'plan', + payload: update.plan, + }); + + return { handled: true }; +} + +/** + * Handle explicit thinking field + */ +export function handleThinkingUpdate( + update: SessionUpdate, + ctx: HandlerContext +): HandlerResult { + if (!update.thinking) { + return { handled: false }; + } + + ctx.emit({ + type: 'event', + name: 'thinking', + payload: update.thinking, + }); + + return { handled: true }; +} diff --git a/src/agent/core/AgentBackend.ts b/src/agent/core/AgentBackend.ts index f71868a7..61367988 100644 --- a/src/agent/core/AgentBackend.ts +++ b/src/agent/core/AgentBackend.ts @@ -141,7 +141,16 @@ export interface AgentBackend { /** * Respond to a permission request. - * + * + * **Implementation Note for ACP backends:** + * For ACP-based agents (Gemini, Codex via ACP), permission handling is done + * synchronously within the `requestPermission` RPC handler via `AcpPermissionHandler`. + * This method only emits an internal `permission-response` event for UI/logging purposes. + * The actual ACP response is already sent by the time this method is called. + * + * For non-ACP backends, this method should actually send the permission response + * to the agent. + * * @param requestId - The ID of the permission request * @param approved - Whether the permission was granted */ diff --git a/src/agent/factories/gemini.ts b/src/agent/factories/gemini.ts index a7be3599..8a8b3d6d 100644 --- a/src/agent/factories/gemini.ts +++ b/src/agent/factories/gemini.ts @@ -50,17 +50,28 @@ export interface GeminiBackendOptions extends AgentFactoryOptions { permissionHandler?: AcpPermissionHandler; } +/** + * Result of creating a Gemini backend + */ +export interface GeminiBackendResult { + /** The created AgentBackend instance */ + backend: AgentBackend; + /** The resolved model that will be used (single source of truth) */ + model: string; + /** Source of the model selection for logging */ + modelSource: 'explicit' | 'env-var' | 'local-config' | 'default'; +} + /** * Create a Gemini backend using ACP (official SDK). - * + * * The Gemini CLI must be installed and available in PATH. * Uses the --experimental-acp flag to enable ACP mode. - * + * * @param options - Configuration options - * @returns AgentBackend instance for Gemini + * @returns GeminiBackendResult with backend and resolved model (single source of truth) */ - -export function createGeminiBackend(options: GeminiBackendOptions): AgentBackend { +export function createGeminiBackend(options: GeminiBackendOptions): GeminiBackendResult { // Resolve API key from multiple sources (in priority order): // 1. Happy cloud OAuth token (via 'happy connect gemini') - highest priority @@ -145,7 +156,7 @@ export function createGeminiBackend(options: GeminiBackendOptions): AgentBackend // Determine model source for logging const modelSource = getGeminiModelSource(options.model, localConfig); - + logger.debug('[Gemini] Creating ACP SDK backend with options:', { cwd: backendOptions.cwd, command: backendOptions.command, @@ -156,7 +167,11 @@ export function createGeminiBackend(options: GeminiBackendOptions): AgentBackend mcpServerCount: options.mcpServers ? Object.keys(options.mcpServers).length : 0, }); - return new AcpBackend(backendOptions); + return { + backend: new AcpBackend(backendOptions), + model, + modelSource, + }; } /** @@ -166,7 +181,7 @@ export function createGeminiBackend(options: GeminiBackendOptions): AgentBackend * to make the Gemini agent available for use. */ export function registerGeminiAgent(): void { - agentRegistry.register('gemini', (opts) => createGeminiBackend(opts)); + agentRegistry.register('gemini', (opts) => createGeminiBackend(opts).backend); logger.debug('[Gemini] Registered with agent registry'); } diff --git a/src/agent/factories/index.ts b/src/agent/factories/index.ts index 4b2af74a..b653073a 100644 --- a/src/agent/factories/index.ts +++ b/src/agent/factories/index.ts @@ -12,6 +12,7 @@ export { createGeminiBackend, registerGeminiAgent, type GeminiBackendOptions, + type GeminiBackendResult, } from './gemini'; // Future factories: diff --git a/src/agent/transport/TransportHandler.ts b/src/agent/transport/TransportHandler.ts index 68860fef..1f04ac9a 100644 --- a/src/agent/transport/TransportHandler.ts +++ b/src/agent/transport/TransportHandler.ts @@ -162,4 +162,15 @@ export interface TransportHandler { input: Record, context: ToolNameContext ): string; + + /** + * Get idle detection timeout in milliseconds. + * + * This timeout is used to detect when the agent has finished producing output + * and is ready for the next prompt. After no chunks arrive for this duration, + * the backend emits 'idle' status. + * + * @returns Timeout in milliseconds (default: 500) + */ + getIdleTimeout?(): number; } diff --git a/src/agent/transport/handlers/GeminiTransport.ts b/src/agent/transport/handlers/GeminiTransport.ts index e8bf735b..a516b946 100644 --- a/src/agent/transport/handlers/GeminiTransport.ts +++ b/src/agent/transport/handlers/GeminiTransport.ts @@ -20,11 +20,12 @@ import type { ToolNameContext, } from '../TransportHandler'; import type { AgentMessage } from '../../core'; +import { logger } from '@/ui/logger'; /** * Gemini-specific timeout values (in milliseconds) */ -const GEMINI_TIMEOUTS = { +export const GEMINI_TIMEOUTS = { /** Gemini CLI can be slow on first start (downloading models, etc.) */ init: 120_000, /** Standard tool call timeout */ @@ -33,24 +34,43 @@ const GEMINI_TIMEOUTS = { investigation: 600_000, /** Think tools are usually quick */ think: 30_000, + /** Idle detection after last message chunk */ + idle: 500, } as const; /** * Known tool name patterns for Gemini CLI. * Used to extract real tool names from toolCallId when Gemini sends "other". + * + * Each pattern includes: + * - name: canonical tool name + * - patterns: strings to match in toolCallId (case-insensitive) + * - inputFields: optional fields that indicate this tool when present in input + * - emptyInputDefault: if true, this tool is the default when input is empty */ -const GEMINI_TOOL_PATTERNS: ToolPattern[] = [ +interface ExtendedToolPattern extends ToolPattern { + /** Fields in input that indicate this tool */ + inputFields?: string[]; + /** If true, this is the default tool when input is empty and toolName is "other" */ + emptyInputDefault?: boolean; +} + +const GEMINI_TOOL_PATTERNS: ExtendedToolPattern[] = [ { name: 'change_title', - patterns: ['change_title', 'change-title', 'happy__change_title'], + patterns: ['change_title', 'change-title', 'happy__change_title', 'mcp__happy__change_title'], + inputFields: ['title'], + emptyInputDefault: true, // change_title often has empty input (title extracted from context) }, { name: 'save_memory', patterns: ['save_memory', 'save-memory'], + inputFields: ['memory', 'content'], }, { name: 'think', patterns: ['think'], + inputFields: ['thought', 'thinking'], }, ]; @@ -202,6 +222,13 @@ export class GeminiTransport implements TransportHandler { return GEMINI_TIMEOUTS.toolCall; } + /** + * Get idle detection timeout + */ + getIdleTimeout(): number { + return GEMINI_TIMEOUTS.idle; + } + /** * Extract tool name from toolCallId using Gemini patterns. * @@ -221,19 +248,32 @@ export class GeminiTransport implements TransportHandler { return null; } + /** + * Check if input is effectively empty + */ + private isEmptyInput(input: Record | undefined | null): boolean { + if (!input) return true; + if (Array.isArray(input)) return input.length === 0; + if (typeof input === 'object') return Object.keys(input).length === 0; + return false; + } + /** * Determine the real tool name from various sources. * * When Gemini sends "other" or "Unknown tool", tries to determine the real name from: - * 1. toolCallId patterns (most reliable) - * 2. input parameters - * 3. Context (first tool call after change_title instruction) + * 1. toolCallId patterns (most reliable - tool name often embedded in ID) + * 2. Input field signatures (specific fields indicate specific tools) + * 3. Empty input default (some tools like change_title have empty input) + * + * Context-based heuristics were removed as they were fragile and the above + * methods cover all known cases. */ determineToolName( toolName: string, toolCallId: string, input: Record, - context: ToolNameContext + _context: ToolNameContext ): string { // If tool name is already known, return it if (toolName !== 'other' && toolName !== 'Unknown tool') { @@ -241,55 +281,49 @@ export class GeminiTransport implements TransportHandler { } // 1. Check toolCallId for known tool names (most reliable) + // Tool IDs often contain the tool name: "change_title-123456" -> "change_title" const idToolName = this.extractToolNameFromId(toolCallId); if (idToolName) { return idToolName; } - // 2. Check input for function names or tool identifiers - if (input && typeof input === 'object') { - const inputStr = JSON.stringify(input).toLowerCase(); + // 2. Check input fields for tool-specific signatures + if (input && typeof input === 'object' && !Array.isArray(input)) { + const inputKeys = Object.keys(input); + for (const toolPattern of GEMINI_TOOL_PATTERNS) { - for (const pattern of toolPattern.patterns) { - if (inputStr.includes(pattern.toLowerCase())) { + if (toolPattern.inputFields) { + // Check if any input field matches this tool's signature + const hasMatchingField = toolPattern.inputFields.some((field) => + inputKeys.some((key) => key.toLowerCase() === field.toLowerCase()) + ); + if (hasMatchingField) { return toolPattern.name; } } } } - // 3. Check if input contains 'title' field - likely change_title - if (input && typeof input === 'object' && 'title' in input) { - return 'change_title'; - } - - // 4. Context-based heuristic: if prompt had change_title instruction - // and tool is "other" with empty input, it's likely change_title - if (context.recentPromptHadChangeTitle) { - const isEmptyInput = - !input || - (Array.isArray(input) && input.length === 0) || - (typeof input === 'object' && Object.keys(input).length === 0); - - if (isEmptyInput && toolName === 'other') { - return 'change_title'; + // 3. For empty input, use the default tool (if configured) + // This handles cases like change_title where the title is extracted from context + if (this.isEmptyInput(input) && toolName === 'other') { + const defaultTool = GEMINI_TOOL_PATTERNS.find((p) => p.emptyInputDefault); + if (defaultTool) { + return defaultTool.name; } } - // 5. Fallback: if toolName is "other" with empty input, it's most likely change_title - // This is because change_title is the only MCP tool that: - // - Gets reported as "other" by Gemini ACP - // - Has empty input (title is extracted from context, not passed as input) - const isEmptyInput = - !input || - (Array.isArray(input) && input.length === 0) || - (typeof input === 'object' && Object.keys(input).length === 0); - - if (isEmptyInput && toolName === 'other') { - return 'change_title'; + // Return original tool name if we couldn't determine it + // Log unknown patterns so developers can add them to GEMINI_TOOL_PATTERNS + if (toolName === 'other' || toolName === 'Unknown tool') { + const inputKeys = input && typeof input === 'object' ? Object.keys(input) : []; + logger.debug( + `[GeminiTransport] Unknown tool pattern - toolCallId: "${toolCallId}", ` + + `toolName: "${toolName}", inputKeys: [${inputKeys.join(', ')}]. ` + + `Consider adding a new pattern to GEMINI_TOOL_PATTERNS if this tool appears frequently.` + ); } - // Return original tool name if we couldn't determine it return toolName; } } diff --git a/src/gemini/runGemini.ts b/src/gemini/runGemini.ts index 71689ea9..43bf6423 100644 --- a/src/gemini/runGemini.ts +++ b/src/gemini/runGemini.ts @@ -40,11 +40,10 @@ import { GeminiDiffProcessor } from '@/gemini/utils/diffProcessor'; import type { GeminiMode, CodexMessagePayload } from '@/gemini/types'; import type { PermissionMode } from '@/api/types'; import { GEMINI_MODEL_ENV, DEFAULT_GEMINI_MODEL, CHANGE_TITLE_INSTRUCTION } from '@/gemini/constants'; -import { - readGeminiLocalConfig, - determineGeminiModel, +import { + readGeminiLocalConfig, saveGeminiModelToConfig, - getInitialGeminiModel + getInitialGeminiModel } from '@/gemini/utils/config'; import { parseOptionsFromText, @@ -137,6 +136,27 @@ export async function runGemini(opts: { // Permission handler declared here so it can be updated in onSessionSwap callback // (assigned later after Happy server setup) let permissionHandler: GeminiPermissionHandler; + + // Session swap synchronization to prevent race conditions during message processing + // When a swap is requested during processing, it's queued and applied after the current cycle + let isProcessingMessage = false; + let pendingSessionSwap: ApiSessionClient | null = null; + + /** + * Apply a pending session swap. Called between message processing cycles. + * This ensures session swaps happen at safe points, not during message processing. + */ + const applyPendingSessionSwap = () => { + if (pendingSessionSwap) { + logger.debug('[gemini] Applying pending session swap'); + session = pendingSessionSwap; + if (permissionHandler) { + permissionHandler.updateSession(pendingSessionSwap); + } + pendingSessionSwap = null; + } + }; + const { session: initialSession, reconnectionHandle } = setupOfflineReconnection({ api, sessionTag, @@ -144,10 +164,17 @@ export async function runGemini(opts: { state, response, onSessionSwap: (newSession) => { - session = newSession; - // Update permission handler with new session to avoid stale reference - if (permissionHandler) { - permissionHandler.updateSession(newSession); + // If we're processing a message, queue the swap for later + // This prevents race conditions where session changes mid-processing + if (isProcessingMessage) { + logger.debug('[gemini] Session swap requested during message processing - queueing'); + pendingSessionSwap = newSession; + } else { + // Safe to swap immediately + session = newSession; + if (permissionHandler) { + permissionHandler.updateSession(newSession); + } } } }); @@ -911,10 +938,10 @@ export async function runGemini(opts: { await geminiBackend.dispose(); geminiBackend = null; } - + // Create new backend with new model const modelToUse = message.mode?.model === undefined ? undefined : (message.mode.model || null); - geminiBackend = createGeminiBackend({ + const backendResult = createGeminiBackend({ cwd: process.cwd(), mcpServers, permissionHandler, @@ -924,16 +951,14 @@ export async function runGemini(opts: { // If explicitly null, will skip local config and use env/default model: modelToUse, }); - + geminiBackend = backendResult.backend; + // Set up message handler again setupGeminiMessageHandler(geminiBackend); - - // Start new session - // Determine actual model that will be used (from backend creation logic) - // Replicate backend logic: message model > env var > local config > default - const localConfigForModel = readGeminiLocalConfig(); - const actualModel = determineGeminiModel(modelToUse, localConfigForModel); - logger.debug(`[gemini] Model change - modelToUse=${modelToUse}, actualModel=${actualModel}`); + + // Use model from factory result (single source of truth - no duplicate resolution) + const actualModel = backendResult.model; + logger.debug(`[gemini] Model change - modelToUse=${modelToUse}, actualModel=${actualModel} (from ${backendResult.modelSource})`); // Update conversation history with new model conversationHistory.setCurrentModel(actualModel); @@ -961,12 +986,15 @@ export async function runGemini(opts: { const userMessageToShow = message.mode?.originalUserMessage || message.message; messageBuffer.addMessage(userMessageToShow, 'user'); + // Mark that we're processing a message to synchronize session swaps + isProcessingMessage = true; + try { if (first || !wasSessionCreated) { // First message or session not created yet - create backend and start session if (!geminiBackend) { const modelToUse = message.mode?.model === undefined ? undefined : (message.mode.model || null); - geminiBackend = createGeminiBackend({ + const backendResult = createGeminiBackend({ cwd: process.cwd(), mcpServers, permissionHandler, @@ -976,25 +1004,14 @@ export async function runGemini(opts: { // If explicitly null, will skip local config and use env/default model: modelToUse, }); - + geminiBackend = backendResult.backend; + // Set up message handler setupGeminiMessageHandler(geminiBackend); - - // Determine actual model that will be used - // Backend will determine model from: message model > env var > local config > default - // We need to replicate this logic here to show correct model in UI - const localConfigForModel = readGeminiLocalConfig(); - const actualModel = determineGeminiModel(modelToUse, localConfigForModel); - - const modelSource = modelToUse !== undefined - ? 'message' - : process.env[GEMINI_MODEL_ENV] - ? 'env-var' - : localConfigForModel.model - ? 'local-config' - : 'default'; - - logger.debug(`[gemini] Backend created, model will be: ${actualModel} (from ${modelSource})`); + + // Use model from factory result (single source of truth - no duplicate resolution) + const actualModel = backendResult.model; + logger.debug(`[gemini] Backend created, model will be: ${actualModel} (from ${backendResult.modelSource})`); logger.debug(`[gemini] Calling updateDisplayedModel with: ${actualModel}`); updateDisplayedModel(actualModel, false); // Don't save - this is backend initialization @@ -1258,7 +1275,11 @@ export async function runGemini(opts: { // Use same logic as Codex - emit ready if idle (no pending operations, no queue) emitReadyIfIdle(); - + + // Message processing complete - safe to apply any pending session swap + isProcessingMessage = false; + applyPendingSessionSwap(); + logger.debug(`[gemini] Main loop: turn completed, continuing to next iteration (queue size: ${messageQueue.size()})`); } } diff --git a/src/gemini/utils/conversationHistory.ts b/src/gemini/utils/conversationHistory.ts index 859c705e..b8a228ce 100644 --- a/src/gemini/utils/conversationHistory.ts +++ b/src/gemini/utils/conversationHistory.ts @@ -46,37 +46,76 @@ export class ConversationHistory { this.currentModel = model; } + /** + * Check if content is a duplicate of the last message with the same role. + * Deduplication prevents inflating history when the same message is sent multiple times. + */ + private isDuplicate(role: 'user' | 'assistant', content: string): boolean { + if (this.messages.length === 0) return false; + + // Find the last message with the same role + for (let i = this.messages.length - 1; i >= 0; i--) { + const msg = this.messages[i]; + if (msg.role === role) { + // Check if content matches (normalize whitespace for comparison) + const normalizedNew = content.trim().replace(/\s+/g, ' '); + const normalizedExisting = msg.content.replace(/\s+/g, ' '); + return normalizedNew === normalizedExisting; + } + } + + return false; + } + /** * Add a user message to history + * Skips duplicate messages to prevent history inflation */ addUserMessage(content: string): void { if (!content.trim()) return; - + + const trimmedContent = content.trim(); + + // Skip duplicate messages + if (this.isDuplicate('user', trimmedContent)) { + logger.debug(`[ConversationHistory] Skipping duplicate user message (${trimmedContent.length} chars)`); + return; + } + this.messages.push({ role: 'user', - content: content.trim(), + content: trimmedContent, timestamp: Date.now(), }); - + this.trimHistory(); - logger.debug(`[ConversationHistory] Added user message (${content.length} chars), total: ${this.messages.length}`); + logger.debug(`[ConversationHistory] Added user message (${trimmedContent.length} chars), total: ${this.messages.length}`); } /** * Add an assistant response to history + * Skips duplicate messages to prevent history inflation */ addAssistantMessage(content: string): void { if (!content.trim()) return; - + + const trimmedContent = content.trim(); + + // Skip duplicate messages + if (this.isDuplicate('assistant', trimmedContent)) { + logger.debug(`[ConversationHistory] Skipping duplicate assistant message (${trimmedContent.length} chars)`); + return; + } + this.messages.push({ role: 'assistant', - content: content.trim(), + content: trimmedContent, timestamp: Date.now(), model: this.currentModel, }); - + this.trimHistory(); - logger.debug(`[ConversationHistory] Added assistant message (${content.length} chars), total: ${this.messages.length}`); + logger.debug(`[ConversationHistory] Added assistant message (${trimmedContent.length} chars), total: ${this.messages.length}`); } /** diff --git a/src/gemini/utils/permissionHandler.ts b/src/gemini/utils/permissionHandler.ts index 4e66dd67..aa766bde 100644 --- a/src/gemini/utils/permissionHandler.ts +++ b/src/gemini/utils/permissionHandler.ts @@ -31,6 +31,13 @@ export class GeminiPermissionHandler extends BasePermissionHandler { return '[Gemini]'; } + /** + * Update session reference (override for type visibility) + */ + updateSession(newSession: ApiSessionClient): void { + super.updateSession(newSession); + } + /** * Set the current permission mode * This affects how tool calls are automatically approved/denied