diff --git a/apps/sim/app/api/mcp/copilot/route.ts b/apps/sim/app/api/mcp/copilot/route.ts index 8dae511d5..a49288994 100644 --- a/apps/sim/app/api/mcp/copilot/route.ts +++ b/apps/sim/app/api/mcp/copilot/route.ts @@ -620,11 +620,6 @@ async function handleBuildToolCall( abortSignal?: AbortSignal ): Promise { try { - logger.info('[MCP-BUILD] handleBuildToolCall ENTER', { - hasAbortSignal: !!abortSignal, - abortSignalAborted: abortSignal?.aborted, - argsKeys: Object.keys(args), - }) const requestText = (args.request as string) || JSON.stringify(args) const { model } = getCopilotModel('chat') const workflowId = args.workflowId as string | undefined @@ -666,12 +661,6 @@ async function handleBuildToolCall( source: 'mcp', } - logger.info('[MCP-BUILD] Calling orchestrateCopilotStream', { - workflowId: resolved.workflowId, - chatId, - hasAbortSignal: !!abortSignal, - }) - const result = await orchestrateCopilotStream(requestPayload, { userId, workflowId: resolved.workflowId, @@ -682,14 +671,6 @@ async function handleBuildToolCall( abortSignal, }) - logger.info('[MCP-BUILD] orchestrateCopilotStream returned', { - success: result.success, - contentLength: result.content?.length, - toolCallCount: result.toolCalls?.length, - error: result.error, - errors: result.errors, - }) - const responseData = { success: result.success, content: result.content, @@ -702,7 +683,7 @@ async function handleBuildToolCall( isError: !result.success, } } catch (error) { - logger.error('[MCP-BUILD] Build tool call THREW', { error }) + logger.error('Build tool call failed', { error }) return { content: [ { diff --git a/apps/sim/lib/copilot/orchestrator/sse-handlers/handlers.ts b/apps/sim/lib/copilot/orchestrator/sse-handlers/handlers.ts index 612eb6b29..9a061029e 100644 --- a/apps/sim/lib/copilot/orchestrator/sse-handlers/handlers.ts +++ b/apps/sim/lib/copilot/orchestrator/sse-handlers/handlers.ts @@ -109,13 +109,7 @@ export const sseHandlers: Record = { const toolData = getEventData(event) || ({} as Record) const toolCallId = (toolData.id as string | undefined) || event.toolCallId const toolName = (toolData.name as string | undefined) || event.toolName - - logger.info('[TOOL_CALL] Received', { toolCallId, toolName, hasToolData: !!toolData }) - - if (!toolCallId || !toolName) { - logger.warn('[TOOL_CALL] Missing toolCallId or toolName, returning early', { toolCallId, toolName }) - return - } + if (!toolCallId || !toolName) return const args = (toolData.arguments || toolData.input || asRecord(event.data).input) as | Record @@ -123,23 +117,12 @@ export const sseHandlers: Record = { const isPartial = toolData.partial === true const existing = context.toolCalls.get(toolCallId) - logger.info('[TOOL_CALL] State check', { - toolCallId, - toolName, - isPartial, - hasExisting: !!existing, - existingStatus: existing?.status, - existingEndTime: existing?.endTime, - hasArgs: !!args, - }) - // If we've already completed this tool call, ignore late/duplicate tool_call events // to avoid resetting UI/state back to pending and re-executing. if ( existing?.endTime || (existing && existing.status !== 'pending' && existing.status !== 'executing') ) { - logger.info('[TOOL_CALL] Already completed, skipping', { toolCallId, toolName, status: existing?.status }) if (!existing.params && args) { existing.params = args } @@ -160,31 +143,20 @@ export const sseHandlers: Record = { addContentBlock(context, { type: 'tool_call', toolCall: created }) } - if (isPartial) { - logger.info('[TOOL_CALL] Partial event, returning early', { toolCallId, toolName }) - return - } - if (wasToolResultSeen(toolCallId)) { - logger.info('[TOOL_CALL] Result already seen (dedup), returning early', { toolCallId, toolName }) - return - } + if (isPartial) return + if (wasToolResultSeen(toolCallId)) return const toolCall = context.toolCalls.get(toolCallId) - if (!toolCall) { - logger.warn('[TOOL_CALL] toolCall not found in map after set, returning early', { toolCallId }) - return - } + if (!toolCall) return // Subagent tools are executed by the copilot backend, not sim side. if (SUBAGENT_TOOL_SET.has(toolName)) { - logger.info('[TOOL_CALL] Subagent tool, skipping local execution', { toolCallId, toolName }) return } // Respond tools are internal to copilot's subagent system - skip execution. // The copilot backend handles these internally to signal subagent completion. if (RESPOND_TOOL_SET.has(toolName)) { - logger.info('[TOOL_CALL] Respond tool, skipping', { toolCallId, toolName }) toolCall.status = 'success' toolCall.endTime = Date.now() toolCall.result = { @@ -197,14 +169,6 @@ export const sseHandlers: Record = { const isInterruptTool = isInterruptToolName(toolName) const isInteractive = options.interactive === true - logger.info('[TOOL_CALL] Pre-execute check', { - toolCallId, - toolName, - isInterruptTool, - isInteractive, - autoExecuteTools: options.autoExecuteTools, - }) - if (isInterruptTool && isInteractive) { const decision = await waitForToolDecision( toolCallId, @@ -266,11 +230,7 @@ export const sseHandlers: Record = { } if (options.autoExecuteTools !== false) { - logger.info('[TOOL_CALL] Calling executeToolAndReport', { toolCallId, toolName }) await executeToolAndReport(toolCallId, context, execContext, options) - logger.info('[TOOL_CALL] executeToolAndReport returned', { toolCallId, toolName }) - } else { - logger.info('[TOOL_CALL] autoExecuteTools is false, skipping execution', { toolCallId, toolName }) } }, reasoning: (event, context) => { diff --git a/apps/sim/lib/copilot/orchestrator/sse-handlers/tool-execution.ts b/apps/sim/lib/copilot/orchestrator/sse-handlers/tool-execution.ts index aef6c8601..80c4c6036 100644 --- a/apps/sim/lib/copilot/orchestrator/sse-handlers/tool-execution.ts +++ b/apps/sim/lib/copilot/orchestrator/sse-handlers/tool-execution.ts @@ -32,31 +32,14 @@ export async function executeToolAndReport( options?: OrchestratorOptions ): Promise { const toolCall = context.toolCalls.get(toolCallId) - if (!toolCall) { - logger.warn('[EXEC] toolCall not found in context map', { toolCallId }) - return - } + if (!toolCall) return - if (toolCall.status === 'executing') { - logger.warn('[EXEC] toolCall already executing, skipping', { toolCallId, toolName: toolCall.name }) - return - } - if (wasToolResultSeen(toolCall.id)) { - logger.warn('[EXEC] toolCall result already seen (dedup), skipping', { toolCallId, toolName: toolCall.name }) - return - } + if (toolCall.status === 'executing') return + if (wasToolResultSeen(toolCall.id)) return - logger.info('[EXEC] Starting tool execution', { toolCallId, toolName: toolCall.name, params: toolCall.params ? Object.keys(toolCall.params) : [] }) toolCall.status = 'executing' try { const result = await executeToolServerSide(toolCall, execContext) - logger.info('[EXEC] executeToolServerSide returned', { - toolCallId, - toolName: toolCall.name, - success: result.success, - hasOutput: !!result.output, - error: result.error, - }) toolCall.status = result.success ? 'success' : 'error' toolCall.result = result toolCall.error = result.error @@ -85,21 +68,14 @@ export async function executeToolAndReport( // the SSE reader (our for-await loop) is paused while we're in this // handler. Awaiting here would deadlock: sim waits for Go's response, // Go waits for sim to drain the SSE stream. - logger.info('[EXEC] Firing markToolComplete (fire-and-forget)', { - toolCallId: toolCall.id, - toolName: toolCall.name, - status: result.success ? 200 : 500, - }) markToolComplete( toolCall.id, toolCall.name, result.success ? 200 : 500, result.error || (result.success ? 'Tool completed' : 'Tool failed'), result.output - ).then((ok) => { - logger.info('[EXEC] markToolComplete resolved', { toolCallId: toolCall.id, toolName: toolCall.name, ok }) - }).catch((err) => { - logger.error('[EXEC] markToolComplete fire-and-forget FAILED', { + ).catch((err) => { + logger.error('markToolComplete fire-and-forget failed', { toolCallId: toolCall.id, toolName: toolCall.name, error: err instanceof Error ? err.message : String(err), @@ -120,13 +96,7 @@ export async function executeToolAndReport( }, } await options?.onEvent?.(resultEvent) - logger.info('[EXEC] executeToolAndReport complete', { toolCallId, toolName: toolCall.name }) } catch (error) { - logger.error('[EXEC] executeToolAndReport CAUGHT ERROR', { - toolCallId, - toolName: toolCall.name, - error: error instanceof Error ? error.message : String(error), - }) toolCall.status = 'error' toolCall.error = error instanceof Error ? error.message : String(error) toolCall.endTime = Date.now() @@ -134,10 +104,8 @@ export async function executeToolAndReport( markToolResultSeen(toolCall.id) // Fire-and-forget (same reasoning as above). - markToolComplete(toolCall.id, toolCall.name, 500, toolCall.error).then((ok) => { - logger.info('[EXEC] markToolComplete (error path) resolved', { toolCallId: toolCall.id, ok }) - }).catch((err) => { - logger.error('[EXEC] markToolComplete (error path) FAILED', { + markToolComplete(toolCall.id, toolCall.name, 500, toolCall.error).catch((err) => { + logger.error('markToolComplete fire-and-forget failed', { toolCallId: toolCall.id, toolName: toolCall.name, error: err instanceof Error ? err.message : String(err), diff --git a/apps/sim/lib/copilot/orchestrator/sse-utils.ts b/apps/sim/lib/copilot/orchestrator/sse-utils.ts index 832823d08..afcbf2111 100644 --- a/apps/sim/lib/copilot/orchestrator/sse-utils.ts +++ b/apps/sim/lib/copilot/orchestrator/sse-utils.ts @@ -1,9 +1,6 @@ -import { createLogger } from '@sim/logger' import { STREAM_BUFFER_MAX_DEDUP_ENTRIES } from '@/lib/copilot/constants' import type { SSEEvent } from '@/lib/copilot/orchestrator/types' -const logger = createLogger('CopilotSseUtils') - type EventDataObject = Record | undefined /** Safely cast event.data to a record for property access. */ @@ -110,10 +107,7 @@ export function shouldSkipToolCallEvent(event: SSEEvent): boolean { if (!toolCallId) return false const eventData = getEventData(event) if (eventData?.partial === true) return false - const resultSeen = wasToolResultSeen(toolCallId) - const callSeen = wasToolCallSeen(toolCallId) - if (resultSeen || callSeen) { - logger.info('[DEDUP] Skipping tool_call event', { toolCallId, resultSeen, callSeen, seenToolCallsSize: seenToolCalls.size, seenToolResultsSize: seenToolResults.size }) + if (wasToolResultSeen(toolCallId) || wasToolCallSeen(toolCallId)) { return true } markToolCallSeen(toolCallId) @@ -124,10 +118,7 @@ export function shouldSkipToolResultEvent(event: SSEEvent): boolean { if (event.type !== 'tool_result') return false const toolCallId = getToolCallIdFromEvent(event) if (!toolCallId) return false - if (wasToolResultSeen(toolCallId)) { - logger.info('[DEDUP] Skipping tool_result event', { toolCallId, seenToolResultsSize: seenToolResults.size }) - return true - } + if (wasToolResultSeen(toolCallId)) return true markToolResultSeen(toolCallId) return false } diff --git a/apps/sim/lib/copilot/orchestrator/stream-core.ts b/apps/sim/lib/copilot/orchestrator/stream-core.ts index 25034ef36..e1dc2e2fc 100644 --- a/apps/sim/lib/copilot/orchestrator/stream-core.ts +++ b/apps/sim/lib/copilot/orchestrator/stream-core.ts @@ -89,15 +89,8 @@ export async function runStreamLoop( const reader = response.body.getReader() const decoder = new TextDecoder() - let eventCount = 0 - - logger.info('[STREAM] SSE stream connected, starting event loop', { - timeout, - hasAbortSignal: !!abortSignal, - }) const timeoutId = setTimeout(() => { - logger.warn('[STREAM] Timeout fired, cancelling reader', { timeout, eventCount }) context.errors.push('Request timed out') context.streamComplete = true reader.cancel().catch(() => {}) @@ -105,37 +98,17 @@ export async function runStreamLoop( try { for await (const event of parseSSEStream(reader, decoder, abortSignal)) { - eventCount++ - if (abortSignal?.aborted) { - logger.warn('[STREAM] AbortSignal aborted, breaking', { eventCount }) context.wasAborted = true break } const normalizedEvent = normalizeSseEvent(event) - logger.info('[STREAM] Event received', { - eventNum: eventCount, - type: normalizedEvent.type, - toolCallId: normalizedEvent.toolCallId, - toolName: normalizedEvent.toolName, - hasSubagent: !!normalizedEvent.subagent, - }) - // Skip duplicate tool events. const shouldSkipToolCall = shouldSkipToolCallEvent(normalizedEvent) const shouldSkipToolResult = shouldSkipToolResultEvent(normalizedEvent) - if (shouldSkipToolCall || shouldSkipToolResult) { - logger.info('[STREAM] Skipping duplicate event', { - type: normalizedEvent.type, - toolCallId: normalizedEvent.toolCallId, - skipToolCall: shouldSkipToolCall, - skipToolResult: shouldSkipToolResult, - }) - } - if (!shouldSkipToolCall && !shouldSkipToolResult) { try { await options.onEvent?.(normalizedEvent) @@ -183,18 +156,10 @@ export async function runStreamLoop( // Main event handler dispatch. const handler = sseHandlers[normalizedEvent.type] if (handler) { - logger.info('[STREAM] Dispatching to handler', { type: normalizedEvent.type, toolCallId: normalizedEvent.toolCallId }) await handler(normalizedEvent, context, execContext, options) - logger.info('[STREAM] Handler returned', { type: normalizedEvent.type, toolCallId: normalizedEvent.toolCallId, streamComplete: context.streamComplete }) - } else { - logger.info('[STREAM] No handler for event type', { type: normalizedEvent.type }) - } - if (context.streamComplete) { - logger.info('[STREAM] Stream marked complete, breaking', { eventCount, errors: context.errors }) - break } + if (context.streamComplete) break } - logger.info('[STREAM] Event loop ended', { eventCount, streamComplete: context.streamComplete, wasAborted: context.wasAborted, errors: context.errors }) } finally { clearTimeout(timeoutId) } diff --git a/apps/sim/lib/copilot/orchestrator/tool-executor/index.ts b/apps/sim/lib/copilot/orchestrator/tool-executor/index.ts index f4bcf4e9d..12dbbf598 100644 --- a/apps/sim/lib/copilot/orchestrator/tool-executor/index.ts +++ b/apps/sim/lib/copilot/orchestrator/tool-executor/index.ts @@ -219,50 +219,29 @@ export async function markToolComplete( message?: unknown, data?: unknown ): Promise { - const url = `${SIM_AGENT_API_URL}/api/tools/mark-complete` - logger.info('[MARK-COMPLETE] Starting', { - toolCallId, - toolName, - status, - url, - hasData: !!data, - hasCopilotApiKey: !!env.COPILOT_API_KEY, - }) - try { const controller = new AbortController() const timeoutId = setTimeout(() => controller.abort(), MARK_COMPLETE_TIMEOUT_MS) try { - const body = JSON.stringify({ - id: toolCallId, - name: toolName, - status, - message, - data, - }) - logger.info('[MARK-COMPLETE] Sending POST', { toolCallId, toolName, bodyLength: body.length }) - - const response = await fetch(url, { + const response = await fetch(`${SIM_AGENT_API_URL}/api/tools/mark-complete`, { method: 'POST', headers: { 'Content-Type': 'application/json', ...(env.COPILOT_API_KEY ? { 'x-api-key': env.COPILOT_API_KEY } : {}), }, - body, + body: JSON.stringify({ + id: toolCallId, + name: toolName, + status, + message, + data, + }), signal: controller.signal, }) - logger.info('[MARK-COMPLETE] Response received', { - toolCallId, - toolName, - httpStatus: response.status, - ok: response.ok, - }) - if (!response.ok) { - const responseText = await response.text().catch(() => '') - logger.warn('[MARK-COMPLETE] Non-OK response', { toolCallId, toolName, httpStatus: response.status, responseText }) + logger.warn('Mark-complete call failed', { toolCallId, toolName, status: response.status }) return false } @@ -273,12 +252,11 @@ export async function markToolComplete( } catch (error) { const isTimeout = error instanceof DOMException && error.name === 'AbortError' - logger.error('[MARK-COMPLETE] FAILED', { + logger.error('Mark-complete call failed', { toolCallId, toolName, timedOut: isTimeout, error: error instanceof Error ? error.message : String(error), - errorName: error instanceof Error ? error.name : undefined, }) return false }