diff --git a/apps/sim/lib/logs/trace-spans.test.ts b/apps/sim/lib/logs/trace-spans.test.ts new file mode 100644 index 0000000000..a2938ca6e9 --- /dev/null +++ b/apps/sim/lib/logs/trace-spans.test.ts @@ -0,0 +1,273 @@ +import { describe, expect, test } from 'vitest' +import type { ExecutionResult } from '@/executor/types' +import { buildTraceSpans, stripCustomToolPrefix } from './trace-spans' + +describe('buildTraceSpans', () => { + test('should extract tool calls from agent block output with toolCalls.list format', () => { + const mockExecutionResult: ExecutionResult = { + success: true, + output: { content: 'Final output' }, + logs: [ + { + blockId: 'agent-1', + blockName: 'Test Agent', + blockType: 'agent', + startedAt: '2024-01-01T10:00:00.000Z', + endedAt: '2024-01-01T10:00:05.000Z', + durationMs: 5000, + success: true, + input: { userPrompt: 'Test prompt' }, + output: { + content: 'Agent response', + model: 'gpt-4o', + tokens: { prompt: 10, completion: 20, total: 30 }, + providerTiming: { + duration: 4000, + startTime: '2024-01-01T10:00:00.500Z', + endTime: '2024-01-01T10:00:04.500Z', + }, + toolCalls: { + list: [ + { + name: 'custom_test_tool', + arguments: { input: 'test input' }, + result: { output: 'test output' }, + duration: 1000, + startTime: '2024-01-01T10:00:01.000Z', + endTime: '2024-01-01T10:00:02.000Z', + }, + { + name: 'http_request', + arguments: { url: 'https://api.example.com' }, + result: { status: 200, data: 'response' }, + duration: 2000, + startTime: '2024-01-01T10:00:02.000Z', + endTime: '2024-01-01T10:00:04.000Z', + }, + ], + count: 2, + }, + }, + }, + ], + } + + const { traceSpans } = buildTraceSpans(mockExecutionResult) + + expect(traceSpans).toHaveLength(1) + const agentSpan = traceSpans[0] + expect(agentSpan.type).toBe('agent') + expect(agentSpan.toolCalls).toBeDefined() + expect(agentSpan.toolCalls).toHaveLength(2) + + // Check first tool call + const firstToolCall = agentSpan.toolCalls![0] + expect(firstToolCall.name).toBe('test_tool') // custom_ prefix should be stripped + expect(firstToolCall.duration).toBe(1000) + expect(firstToolCall.status).toBe('success') + expect(firstToolCall.input).toEqual({ input: 'test input' }) + expect(firstToolCall.output).toEqual({ output: 'test output' }) + + // Check second tool call + const secondToolCall = agentSpan.toolCalls![1] + expect(secondToolCall.name).toBe('http_request') + expect(secondToolCall.duration).toBe(2000) + expect(secondToolCall.status).toBe('success') + expect(secondToolCall.input).toEqual({ url: 'https://api.example.com' }) + expect(secondToolCall.output).toEqual({ status: 200, data: 'response' }) + }) + + test('should extract tool calls from agent block output with direct toolCalls array format', () => { + const mockExecutionResult: ExecutionResult = { + success: true, + output: { content: 'Final output' }, + logs: [ + { + blockId: 'agent-2', + blockName: 'Test Agent 2', + blockType: 'agent', + startedAt: '2024-01-01T10:00:00.000Z', + endedAt: '2024-01-01T10:00:03.000Z', + durationMs: 3000, + success: true, + input: { userPrompt: 'Test prompt' }, + output: { + content: 'Agent response', + model: 'gpt-4o', + providerTiming: { + duration: 2500, + startTime: '2024-01-01T10:00:00.250Z', + endTime: '2024-01-01T10:00:02.750Z', + }, + toolCalls: [ + { + name: 'serper_search', + arguments: { query: 'test search' }, + result: { results: ['result1', 'result2'] }, + duration: 1500, + startTime: '2024-01-01T10:00:00.500Z', + endTime: '2024-01-01T10:00:02.000Z', + }, + ], + }, + }, + ], + } + + const { traceSpans } = buildTraceSpans(mockExecutionResult) + + expect(traceSpans).toHaveLength(1) + const agentSpan = traceSpans[0] + expect(agentSpan.toolCalls).toBeDefined() + expect(agentSpan.toolCalls).toHaveLength(1) + + const toolCall = agentSpan.toolCalls![0] + expect(toolCall.name).toBe('serper_search') + expect(toolCall.duration).toBe(1500) + expect(toolCall.status).toBe('success') + expect(toolCall.input).toEqual({ query: 'test search' }) + expect(toolCall.output).toEqual({ results: ['result1', 'result2'] }) + }) + + test('should extract tool calls from streaming response with executionData format', () => { + const mockExecutionResult: ExecutionResult = { + success: true, + output: { content: 'Final output' }, + logs: [ + { + blockId: 'agent-3', + blockName: 'Streaming Agent', + blockType: 'agent', + startedAt: '2024-01-01T10:00:00.000Z', + endedAt: '2024-01-01T10:00:04.000Z', + durationMs: 4000, + success: true, + input: { userPrompt: 'Test prompt' }, + output: { + content: 'Agent response', + model: 'gpt-4o', + executionData: { + output: { + toolCalls: { + list: [ + { + name: 'custom_analysis_tool', + arguments: { data: 'sample data' }, + result: { analysis: 'completed' }, + duration: 2000, + startTime: '2024-01-01T10:00:01.000Z', + endTime: '2024-01-01T10:00:03.000Z', + }, + ], + }, + }, + }, + }, + }, + ], + } + + const { traceSpans } = buildTraceSpans(mockExecutionResult) + + expect(traceSpans).toHaveLength(1) + const agentSpan = traceSpans[0] + expect(agentSpan.toolCalls).toBeDefined() + expect(agentSpan.toolCalls).toHaveLength(1) + + const toolCall = agentSpan.toolCalls![0] + expect(toolCall.name).toBe('analysis_tool') // custom_ prefix should be stripped + expect(toolCall.duration).toBe(2000) + expect(toolCall.status).toBe('success') + expect(toolCall.input).toEqual({ data: 'sample data' }) + expect(toolCall.output).toEqual({ analysis: 'completed' }) + }) + + test('should handle tool calls with errors', () => { + const mockExecutionResult: ExecutionResult = { + success: true, + output: { content: 'Final output' }, + logs: [ + { + blockId: 'agent-4', + blockName: 'Error Agent', + blockType: 'agent', + startedAt: '2024-01-01T10:00:00.000Z', + endedAt: '2024-01-01T10:00:02.000Z', + durationMs: 2000, + success: true, + input: { userPrompt: 'Test prompt' }, + output: { + content: 'Agent response', + model: 'gpt-4o', + toolCalls: { + list: [ + { + name: 'failing_tool', + arguments: { input: 'test' }, + error: 'Tool execution failed', + duration: 1000, + startTime: '2024-01-01T10:00:00.500Z', + endTime: '2024-01-01T10:00:01.500Z', + }, + ], + count: 1, + }, + }, + }, + ], + } + + const { traceSpans } = buildTraceSpans(mockExecutionResult) + + expect(traceSpans).toHaveLength(1) + const agentSpan = traceSpans[0] + expect(agentSpan.toolCalls).toBeDefined() + expect(agentSpan.toolCalls).toHaveLength(1) + + const toolCall = agentSpan.toolCalls![0] + expect(toolCall.name).toBe('failing_tool') + expect(toolCall.status).toBe('error') + expect(toolCall.error).toBe('Tool execution failed') + expect(toolCall.input).toEqual({ input: 'test' }) + }) + + test('should handle blocks without tool calls', () => { + const mockExecutionResult: ExecutionResult = { + success: true, + output: { content: 'Final output' }, + logs: [ + { + blockId: 'text-1', + blockName: 'Text Block', + blockType: 'text', + startedAt: '2024-01-01T10:00:00.000Z', + endedAt: '2024-01-01T10:00:01.000Z', + durationMs: 1000, + success: true, + input: { content: 'Hello world' }, + output: { content: 'Hello world' }, + }, + ], + } + + const { traceSpans } = buildTraceSpans(mockExecutionResult) + + expect(traceSpans).toHaveLength(1) + const textSpan = traceSpans[0] + expect(textSpan.type).toBe('text') + expect(textSpan.toolCalls).toBeUndefined() + }) +}) + +describe('stripCustomToolPrefix', () => { + test('should strip custom_ prefix from tool names', () => { + expect(stripCustomToolPrefix('custom_test_tool')).toBe('test_tool') + expect(stripCustomToolPrefix('custom_analysis')).toBe('analysis') + }) + + test('should leave non-custom tool names unchanged', () => { + expect(stripCustomToolPrefix('http_request')).toBe('http_request') + expect(stripCustomToolPrefix('serper_search')).toBe('serper_search') + expect(stripCustomToolPrefix('regular_tool')).toBe('regular_tool') + }) +}) diff --git a/apps/sim/lib/logs/trace-spans.ts b/apps/sim/lib/logs/trace-spans.ts index fa7e277ec0..8bcbcf4e75 100644 --- a/apps/sim/lib/logs/trace-spans.ts +++ b/apps/sim/lib/logs/trace-spans.ts @@ -85,107 +85,101 @@ export function buildTraceSpans(result: ExecutionResult): { endTime: providerTiming.endTime, segments: providerTiming.timeSegments || [], } + } - // Add cost information if available - if (log.output?.cost) { - ;(span as any).cost = log.output.cost - logger.debug(`Added cost to span ${span.id}`, { + // Always add cost, token, and model information if available (regardless of provider timing) + if (log.output?.cost) { + ;(span as any).cost = log.output.cost + logger.debug(`Added cost to span ${span.id}`, { + blockId: log.blockId, + blockType: log.blockType, + cost: log.output.cost, + }) + } + + if (log.output?.tokens) { + ;(span as any).tokens = log.output.tokens + logger.debug(`Added tokens to span ${span.id}`, { + blockId: log.blockId, + blockType: log.blockType, + tokens: log.output.tokens, + }) + } + + if (log.output?.model) { + ;(span as any).model = log.output.model + logger.debug(`Added model to span ${span.id}`, { + blockId: log.blockId, + blockType: log.blockType, + model: log.output.model, + }) + } + + // Always extract tool calls if they exist (regardless of provider timing) + // Tool calls handling for different formats: + // 1. Standard format in response.toolCalls.list + // 2. Direct toolCalls array in response + // 3. Streaming response formats with executionData + + // Check all possible paths for toolCalls + let toolCallsList = null + + // Wrap extraction in try-catch to handle unexpected toolCalls formats + try { + if (log.output?.toolCalls?.list) { + // Standard format with list property + toolCallsList = log.output.toolCalls.list + } else if (Array.isArray(log.output?.toolCalls)) { + // Direct array format + toolCallsList = log.output.toolCalls + } else if (log.output?.executionData?.output?.toolCalls) { + // Streaming format with executionData + const tcObj = log.output.executionData.output.toolCalls + toolCallsList = Array.isArray(tcObj) ? tcObj : tcObj.list || [] + } + + // Validate that toolCallsList is actually an array before processing + if (toolCallsList && !Array.isArray(toolCallsList)) { + logger.warn(`toolCallsList is not an array: ${typeof toolCallsList}`, { blockId: log.blockId, blockType: log.blockType, - cost: log.output.cost, }) + toolCallsList = [] } + } catch (error) { + logger.error(`Error extracting toolCalls from block ${log.blockId}:`, error) + toolCallsList = [] // Set to empty array as fallback + } - // Add token information if available - if (log.output?.tokens) { - ;(span as any).tokens = log.output.tokens - logger.debug(`Added tokens to span ${span.id}`, { - blockId: log.blockId, - blockType: log.blockType, - tokens: log.output.tokens, - }) - } + if (toolCallsList && toolCallsList.length > 0) { + span.toolCalls = toolCallsList + .map((tc: any) => { + // Add null check for each tool call + if (!tc) return null - // Add model information - if (log.output?.model) { - ;(span as any).model = log.output.model - logger.debug(`Added model to span ${span.id}`, { - blockId: log.blockId, - blockType: log.blockType, - model: log.output.model, - }) - } - } else { - // When not using provider timing, still add cost and token information - if (log.output?.cost) { - ;(span as any).cost = log.output.cost - } - - if (log.output?.tokens) { - ;(span as any).tokens = log.output.tokens - } - - if (log.output?.model) { - ;(span as any).model = log.output.model - } - - // When not using provider timing at all, add tool calls if they exist - // Tool calls handling for different formats: - // 1. Standard format in response.toolCalls.list - // 2. Direct toolCalls array in response - // 3. Streaming response formats with executionData - - // Check all possible paths for toolCalls - let toolCallsList = null - - // Wrap extraction in try-catch to handle unexpected toolCalls formats - try { - if (log.output?.toolCalls?.list) { - // Standard format with list property - toolCallsList = log.output.toolCalls.list - } else if (Array.isArray(log.output?.toolCalls)) { - // Direct array format - toolCallsList = log.output.toolCalls - } else if (log.output?.executionData?.output?.toolCalls) { - // Streaming format with executionData - const tcObj = log.output.executionData.output.toolCalls - toolCallsList = Array.isArray(tcObj) ? tcObj : tcObj.list || [] - } - - // Validate that toolCallsList is actually an array before processing - if (toolCallsList && !Array.isArray(toolCallsList)) { - console.warn(`toolCallsList is not an array: ${typeof toolCallsList}`) - toolCallsList = [] - } - } catch (error) { - console.error(`Error extracting toolCalls: ${error}`) - toolCallsList = [] // Set to empty array as fallback - } - - if (toolCallsList && toolCallsList.length > 0) { - span.toolCalls = toolCallsList - .map((tc: any) => { - // Add null check for each tool call - if (!tc) return null - - try { - return { - name: stripCustomToolPrefix(tc.name || 'unnamed-tool'), - duration: tc.duration || 0, - startTime: tc.startTime || log.startedAt, - endTime: tc.endTime || log.endedAt, - status: tc.error ? 'error' : 'success', - input: tc.arguments || tc.input, - output: tc.result || tc.output, - error: tc.error, - } - } catch (tcError) { - console.error(`Error processing tool call: ${tcError}`) - return null + try { + return { + name: stripCustomToolPrefix(tc.name || 'unnamed-tool'), + duration: tc.duration || 0, + startTime: tc.startTime || log.startedAt, + endTime: tc.endTime || log.endedAt, + status: tc.error ? 'error' : 'success', + input: tc.arguments || tc.input, + output: tc.result || tc.output, + error: tc.error, } - }) - .filter(Boolean) // Remove any null entries from failed processing - } + } catch (tcError) { + logger.error(`Error processing tool call in block ${log.blockId}:`, tcError) + return null + } + }) + .filter(Boolean) // Remove any null entries from failed processing + + logger.debug(`Added ${span.toolCalls?.length || 0} tool calls to span ${span.id}`, { + blockId: log.blockId, + blockType: log.blockType, + toolCallNames: span.toolCalls?.map((tc) => tc.name) || [], + }) } // Store in map