diff --git a/src/api/providers/openai-native.ts b/src/api/providers/openai-native.ts index 74ba621c43..1dd5fc2fae 100644 --- a/src/api/providers/openai-native.ts +++ b/src/api/providers/openai-native.ts @@ -1,5 +1,6 @@ import { Anthropic } from "@anthropic-ai/sdk" import OpenAI from "openai" +import { debugNativeToolCall } from "../../utils/debugNativeToolCalls" import { type ModelInfo, @@ -786,6 +787,13 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio parsed.type === "response.function_call_arguments.done" || parsed.type === "response.tool_call_arguments.done" ) { + debugNativeToolCall("[OpenAI-Native] SSE tool call event:", { + type: parsed.type, + callId: parsed.call_id || parsed.tool_call_id || parsed.id, + hasName: !!(parsed.name || parsed.function_name), + hasDelta: !!(parsed.delta || parsed.arguments), + }) + // Delegated to processEvent (handles accumulation and completion) for await (const outChunk of this.processEvent(parsed, model)) { yield outChunk @@ -1076,21 +1084,36 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio event?.type === "response.function_call_arguments.delta" ) { const callId = event.call_id || event.tool_call_id || event.id + debugNativeToolCall("[OpenAI-Native] Tool call delta received:", { + type: event.type, + callId, + hasName: !!(event.name || event.function_name), + hasDelta: !!(event.delta || event.arguments), + deltaLength: (event.delta || event.arguments)?.length, + }) + if (callId) { if (!this.currentToolCalls.has(callId)) { this.currentToolCalls.set(callId, { name: "", arguments: "" }) + debugNativeToolCall(`[OpenAI-Native] Created new tool call accumulator for ID: ${callId}`) } const toolCall = this.currentToolCalls.get(callId)! // Update name if present (usually in the first delta) if (event.name || event.function_name) { toolCall.name = event.name || event.function_name + debugNativeToolCall(`[OpenAI-Native] Set tool call name: ${toolCall.name} for ID: ${callId}`) } // Append arguments delta if (event.delta || event.arguments) { toolCall.arguments += event.delta || event.arguments + debugNativeToolCall( + `[OpenAI-Native] Appended arguments delta for ${toolCall.name || "unnamed"}, total length: ${toolCall.arguments.length}`, + ) } + } else { + console.warn("[OpenAI-Native] Tool call delta received without call ID:", event) } return } @@ -1100,8 +1123,21 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio event?.type === "response.function_call_arguments.done" ) { const callId = event.call_id || event.tool_call_id || event.id + debugNativeToolCall("[OpenAI-Native] Tool call done event:", { + type: event.type, + callId, + hasAccumulated: this.currentToolCalls.has(callId), + }) + if (callId && this.currentToolCalls.has(callId)) { const toolCall = this.currentToolCalls.get(callId)! + debugNativeToolCall(`[OpenAI-Native] Completing tool call:`, { + id: callId, + name: toolCall.name, + argumentsLength: toolCall.arguments.length, + argumentsPreview: toolCall.arguments.substring(0, 200), + }) + // Yield the complete tool call yield { type: "tool_call", @@ -1111,6 +1147,9 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio } // Remove from accumulator this.currentToolCalls.delete(callId) + debugNativeToolCall(`[OpenAI-Native] Tool call yielded and removed from accumulator: ${callId}`) + } else { + console.warn(`[OpenAI-Native] Tool call done event for unknown ID: ${callId}`) } return } @@ -1136,12 +1175,28 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio ) { // Handle complete tool/function call item const callId = item.call_id || item.tool_call_id || item.id + debugNativeToolCall("[OpenAI-Native] Output item tool/function call:", { + type: item.type, + callId, + name: item.name || item.function?.name || item.function_name, + hasArguments: !!(item.arguments || item.function?.arguments || item.function_arguments), + }) + if (callId && !this.currentToolCalls.has(callId)) { const args = item.arguments || item.function?.arguments || item.function_arguments + const toolName = item.name || item.function?.name || item.function_name || "" + + debugNativeToolCall(`[OpenAI-Native] Yielding complete tool call from output item:`, { + id: callId, + name: toolName, + argumentsType: typeof args, + argumentsLength: typeof args === "string" ? args.length : 0, + }) + yield { type: "tool_call", id: callId, - name: item.name || item.function?.name || item.function_name || "", + name: toolName, arguments: typeof args === "string" ? args : "{}", } } @@ -1154,7 +1209,17 @@ export class OpenAiNativeHandler extends BaseProvider implements SingleCompletio if (event?.type === "response.done" || event?.type === "response.completed") { // Yield any pending tool calls that didn't get a 'done' event (fallback) if (this.currentToolCalls.size > 0) { + debugNativeToolCall( + `[OpenAI-Native] Response completed with ${this.currentToolCalls.size} pending tool calls (fallback)`, + ) + for (const [callId, toolCall] of this.currentToolCalls) { + debugNativeToolCall(`[OpenAI-Native] Yielding pending tool call (fallback):`, { + id: callId, + name: toolCall.name, + argumentsLength: toolCall.arguments?.length || 0, + }) + yield { type: "tool_call", id: callId, diff --git a/src/core/assistant-message/NativeToolCallParser.ts b/src/core/assistant-message/NativeToolCallParser.ts index c463d4a5cd..fa0adec35b 100644 --- a/src/core/assistant-message/NativeToolCallParser.ts +++ b/src/core/assistant-message/NativeToolCallParser.ts @@ -1,5 +1,6 @@ import { type ToolName, toolNames, type FileEntry } from "@roo-code/types" import { type ToolUse, type ToolParamName, toolParamNames, type NativeToolArgs } from "../../shared/tools" +import { debugNativeToolCall } from "../../utils/debugNativeToolCalls" /** * Helper type to extract properly typed native arguments for a given tool. @@ -28,21 +29,31 @@ export class NativeToolCallParser { name: TName arguments: string }): ToolUse | null { + // Debug: Log incoming tool call + debugNativeToolCall("[NativeToolCallParser] Parsing tool call:", { + id: toolCall.id, + name: toolCall.name, + argumentsLength: toolCall.arguments?.length, + argumentsPreview: toolCall.arguments?.substring(0, 200), + }) + // Check if this is a dynamic MCP tool (mcp_serverName_toolName) if (typeof toolCall.name === "string" && toolCall.name.startsWith("mcp_")) { + debugNativeToolCall("[NativeToolCallParser] Detected dynamic MCP tool:", toolCall.name) return this.parseDynamicMcpTool(toolCall) as ToolUse | null } // Validate tool name if (!toolNames.includes(toolCall.name as ToolName)) { - console.error(`Invalid tool name: ${toolCall.name}`) - console.error(`Valid tool names:`, toolNames) + console.error(`[NativeToolCallParser] Invalid tool name: ${toolCall.name}`) + console.error(`[NativeToolCallParser] Valid tool names:`, toolNames) return null } try { // Parse the arguments JSON string const args = JSON.parse(toolCall.arguments) + debugNativeToolCall(`[NativeToolCallParser] Parsed arguments for ${toolCall.name}:`, args) // Build legacy params object for backward compatibility with XML protocol and UI. // Native execution path uses nativeArgs instead, which has proper typing. @@ -78,6 +89,8 @@ export class NativeToolCallParser { // will fall back to legacy parameter parsing if supported. let nativeArgs: NativeArgsFor | undefined = undefined + debugNativeToolCall(`[NativeToolCallParser] Building nativeArgs for tool: ${toolCall.name}`) + switch (toolCall.name) { case "read_file": if (args.files && Array.isArray(args.files)) { @@ -238,6 +251,15 @@ export class NativeToolCallParser { break } + // Debug: Log the constructed nativeArgs + if (nativeArgs) { + debugNativeToolCall(`[NativeToolCallParser] Built nativeArgs for ${toolCall.name}:`, nativeArgs) + } else { + debugNativeToolCall( + `[NativeToolCallParser] No nativeArgs built for ${toolCall.name} (validation failed or not implemented)`, + ) + } + const result: ToolUse = { type: "tool_use" as const, name: toolCall.name, @@ -246,10 +268,20 @@ export class NativeToolCallParser { nativeArgs, } + debugNativeToolCall(`[NativeToolCallParser] Successfully parsed tool call ${toolCall.name}:`, { + hasNativeArgs: !!nativeArgs, + paramKeys: Object.keys(params), + toolId: toolCall.id, + }) + return result } catch (error) { - console.error(`Failed to parse tool call arguments:`, error) - console.error(`Error details:`, error instanceof Error ? error.message : String(error)) + console.error(`[NativeToolCallParser] Failed to parse tool call arguments:`, error) + console.error( + `[NativeToolCallParser] Error details:`, + error instanceof Error ? error.message : String(error), + ) + console.error(`[NativeToolCallParser] Raw arguments that failed to parse:`, toolCall.arguments) return null } } @@ -264,8 +296,14 @@ export class NativeToolCallParser { name: string arguments: string }): ToolUse<"use_mcp_tool"> | null { + debugNativeToolCall("[NativeToolCallParser] Parsing dynamic MCP tool:", { + name: toolCall.name, + argumentsLength: toolCall.arguments?.length, + }) + try { const args = JSON.parse(toolCall.arguments) + debugNativeToolCall("[NativeToolCallParser] Parsed MCP tool arguments:", args) // Extract server_name and tool_name from the arguments // The dynamic tool schema includes these as const properties @@ -274,7 +312,8 @@ export class NativeToolCallParser { const toolInputProps = args.toolInputProps if (!serverName || !toolName) { - console.error(`Missing server_name or tool_name in dynamic MCP tool`) + console.error(`[NativeToolCallParser] Missing server_name or tool_name in dynamic MCP tool`) + console.error(`[NativeToolCallParser] Received args:`, args) return null } @@ -303,9 +342,16 @@ export class NativeToolCallParser { nativeArgs, } + debugNativeToolCall(`[NativeToolCallParser] Successfully parsed dynamic MCP tool:`, { + serverName, + toolName, + hasToolInputProps: !!toolInputProps, + }) + return result } catch (error) { - console.error(`Failed to parse dynamic MCP tool:`, error) + console.error(`[NativeToolCallParser] Failed to parse dynamic MCP tool:`, error) + console.error(`[NativeToolCallParser] Raw arguments:`, toolCall.arguments) return null } } diff --git a/src/core/assistant-message/presentAssistantMessage.ts b/src/core/assistant-message/presentAssistantMessage.ts index 3282eb90d1..bae3f40cbe 100644 --- a/src/core/assistant-message/presentAssistantMessage.ts +++ b/src/core/assistant-message/presentAssistantMessage.ts @@ -1,6 +1,7 @@ import cloneDeep from "clone-deep" import { serializeError } from "serialize-error" import { Anthropic } from "@anthropic-ai/sdk" +import { debugNativeToolCall } from "../../utils/debugNativeToolCalls" import type { ToolName, ClineAsk, ToolProgressStatus } from "@roo-code/types" import { TelemetryService } from "@roo-code/telemetry" @@ -170,6 +171,17 @@ export async function presentAssistantMessage(cline: Task) { break } case "tool_use": + // Debug: Log tool use block details + debugNativeToolCall("[presentAssistantMessage] Processing tool_use block:", { + name: block.name, + hasId: !!block.id, + hasNativeArgs: !!block.nativeArgs, + hasParams: !!block.params, + partial: block.partial, + paramKeys: block.params ? Object.keys(block.params) : [], + nativeArgsKeys: block.nativeArgs ? Object.keys(block.nativeArgs) : [], + }) + const toolDescription = (): string => { switch (block.name) { case "execute_command": @@ -258,6 +270,12 @@ export async function presentAssistantMessage(cline: Task) { ? `Skipping tool ${toolDescription()} due to user rejecting a previous tool.` : `Tool ${toolDescription()} was interrupted and not executed due to user rejecting a previous tool.` + debugNativeToolCall(`[presentAssistantMessage] Tool rejected:`, { + toolName: block.name, + toolCallId, + errorMessage, + }) + if (toolCallId) { // Native protocol: MUST send tool_result for every tool_use cline.userMessageContent.push({ @@ -283,6 +301,12 @@ export async function presentAssistantMessage(cline: Task) { const toolCallId = block.id const errorMessage = `Tool [${block.name}] was not executed because a tool has already been used in this message. Only one tool may be used per message. You must assess the first tool's result before proceeding to use the next tool.` + debugNativeToolCall(`[presentAssistantMessage] Tool already used:`, { + toolName: block.name, + toolCallId, + errorMessage, + }) + if (toolCallId) { // Native protocol: MUST send tool_result for every tool_use cline.userMessageContent.push({ @@ -311,7 +335,20 @@ export async function presentAssistantMessage(cline: Task) { const toolCallId = (block as any).id const toolProtocol = toolCallId ? TOOL_PROTOCOL.NATIVE : TOOL_PROTOCOL.XML + debugNativeToolCall(`[presentAssistantMessage] Tool protocol detected:`, { + protocol: toolProtocol, + toolCallId, + toolName: block.name, + }) + const pushToolResult = (content: ToolResponse) => { + debugNativeToolCall(`[presentAssistantMessage] Pushing tool result:`, { + protocol: toolProtocol, + toolCallId, + contentType: typeof content, + hasToolResult, + }) + if (toolProtocol === TOOL_PROTOCOL.NATIVE) { // For native protocol, only allow ONE tool_result per tool call if (hasToolResult) { @@ -352,6 +389,11 @@ export async function presentAssistantMessage(cline: Task) { } hasToolResult = true + debugNativeToolCall(`[presentAssistantMessage] Native tool_result pushed:`, { + toolCallId, + resultLength: resultContent.length, + imageCount: imageBlocks.length, + }) } else { // For XML protocol, add as text blocks (legacy behavior) cline.userMessageContent.push({ type: "text", text: `${toolDescription()} Result:` }) @@ -490,6 +532,10 @@ export async function presentAssistantMessage(cline: Task) { } if (!block.partial) { + debugNativeToolCall(`[presentAssistantMessage] Recording tool usage:`, { + toolName: block.name, + protocol: toolProtocol, + }) cline.recordToolUsage(block.name) TelemetryService.instance.captureToolUsage(cline.taskId, block.name, toolProtocol) } @@ -553,6 +599,8 @@ export async function presentAssistantMessage(cline: Task) { } } + debugNativeToolCall(`[presentAssistantMessage] Executing tool handler for: ${block.name}`) + switch (block.name) { case "write_to_file": await checkpointSaveAndMark(cline) @@ -795,6 +843,8 @@ export async function presentAssistantMessage(cline: Task) { break } + debugNativeToolCall(`[presentAssistantMessage] Tool handler completed for: ${block.name}`) + break } diff --git a/src/package.json b/src/package.json index 9ee1bc3ba8..a1f000bdd5 100644 --- a/src/package.json +++ b/src/package.json @@ -436,6 +436,11 @@ "minimum": 1, "maximum": 200, "description": "%settings.codeIndex.embeddingBatchSize.description%" + }, + "roo-cline.debugNativeToolCalls": { + "type": "boolean", + "default": false, + "description": "Enable debug logging for native tool calls to help diagnose issues with tool execution" } } } diff --git a/src/utils/debugNativeToolCalls.ts b/src/utils/debugNativeToolCalls.ts new file mode 100644 index 0000000000..5c0cfb3ef9 --- /dev/null +++ b/src/utils/debugNativeToolCalls.ts @@ -0,0 +1,27 @@ +import * as vscode from "vscode" +import { Package } from "../shared/package" + +/** + * Check if debug logging for native tool calls is enabled + */ +export function isNativeToolCallDebugEnabled(): boolean { + try { + return vscode.workspace.getConfiguration(Package.name).get("debugNativeToolCalls", false) + } catch { + // If there's any error accessing configuration, default to false + return false + } +} + +/** + * Log debug information for native tool calls if debugging is enabled + */ +export function debugNativeToolCall(message: string, data?: any): void { + if (isNativeToolCallDebugEnabled()) { + if (data !== undefined) { + console.debug(message, data) + } else { + console.debug(message) + } + } +}