From 7c340042239d76a9df5c56273db76661b1e8eb35 Mon Sep 17 00:00:00 2001 From: Waleed Latif Date: Sat, 15 Mar 2025 05:52:22 -0700 Subject: [PATCH] feat(logs): added tool calls + time to execute to logs, updated workflow_logs db to include metadata --- sim/app/api/proxy/route.ts | 47 +- sim/app/api/workflow/[id]/log/route.ts | 23 +- .../db/migrations/0015_brief_martin_li.sql | 1 + sim/app/db/migrations/meta/0015_snapshot.json | 811 ++++++++++++++++++ sim/app/db/migrations/meta/_journal.json | 7 + sim/app/db/schema.ts | 1 + sim/app/executor/handlers.ts | 34 +- sim/app/lib/logs/execution-logger.ts | 604 ++++++++++++- sim/app/providers/anthropic/index.ts | 4 + sim/app/providers/cerebras/index.ts | 4 + sim/app/providers/deepseek/index.ts | 4 + sim/app/providers/google/index.ts | 4 + sim/app/providers/groq/index.ts | 4 + sim/app/providers/openai/index.ts | 4 + sim/app/providers/types.ts | 6 + sim/app/providers/xai/index.ts | 4 + sim/app/tools/index.ts | 109 ++- sim/app/tools/types.ts | 5 + .../w/[id]/hooks/use-workflow-execution.ts | 101 +-- sim/app/w/logs/components/copy-button.tsx | 48 ++ sim/app/w/logs/components/sidebar/sidebar.tsx | 54 +- .../tool-calls/tool-calls-display.tsx | 176 ++++ sim/app/w/logs/stores/types.ts | 16 + sim/drizzle.config.ts | 4 +- 24 files changed, 1952 insertions(+), 123 deletions(-) create mode 100644 sim/app/db/migrations/0015_brief_martin_li.sql create mode 100644 sim/app/db/migrations/meta/0015_snapshot.json create mode 100644 sim/app/w/logs/components/copy-button.tsx create mode 100644 sim/app/w/logs/components/tool-calls/tool-calls-display.tsx diff --git a/sim/app/api/proxy/route.ts b/sim/app/api/proxy/route.ts index a0a035018a..3a33f5d41f 100644 --- a/sim/app/api/proxy/route.ts +++ b/sim/app/api/proxy/route.ts @@ -7,6 +7,8 @@ const logger = createLogger('ProxyAPI') export async function POST(request: Request) { const requestId = crypto.randomUUID().slice(0, 8) + const startTime = new Date() + const startTimeISO = startTime.toISOString() try { const { toolId, params } = await request.json() @@ -26,9 +28,18 @@ export async function POST(request: Request) { toolId, error: error instanceof Error ? error.message : String(error), }) + + // Add timing information even to error responses + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return NextResponse.json({ success: false, error: error instanceof Error ? error.message : String(error), + startTime: startTimeISO, + endTime: endTimeISO, + duration, }) } @@ -81,8 +92,32 @@ export async function POST(request: Request) { } } - logger.info(`[${requestId}] Tool executed successfully`, { toolId }) - return NextResponse.json(result) + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + + // Add explicit timing information directly to the response + // This will ensure it's passed to the agent block + const responseWithTimingData = { + ...result, + // Add timing data both at root level and in nested timing object + startTime: startTimeISO, + endTime: endTimeISO, + duration, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } + + logger.info(`[${requestId}] Tool executed successfully`, { + toolId, + duration, + startTime: startTimeISO, + endTime: endTimeISO, + }) + return NextResponse.json(responseWithTimingData) } catch (error: any) { throw error } @@ -91,9 +126,17 @@ export async function POST(request: Request) { error: error instanceof Error ? error.message : String(error), }) + // Add timing information even to error responses + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return NextResponse.json({ success: false, error: error instanceof Error ? error.message : String(error), + startTime: startTimeISO, + endTime: endTimeISO, + duration, }) } } diff --git a/sim/app/api/workflow/[id]/log/route.ts b/sim/app/api/workflow/[id]/log/route.ts index cbbde71b06..7a8d0fc705 100644 --- a/sim/app/api/workflow/[id]/log/route.ts +++ b/sim/app/api/workflow/[id]/log/route.ts @@ -1,7 +1,7 @@ import { NextRequest } from 'next/server' import { v4 as uuidv4 } from 'uuid' import { createLogger } from '@/lib/logs/console-logger' -import { persistLog } from '@/lib/logs/execution-logger' +import { persistExecutionLogs, persistLog } from '@/lib/logs/execution-logger' import { validateWorkflowAccess } from '../../middleware' import { createErrorResponse, createSuccessResponse } from '../../utils' @@ -21,8 +21,22 @@ export async function POST(request: NextRequest, { params }: { params: Promise<{ } const body = await request.json() - const { logs, executionId } = body + const { logs, executionId, result } = body + // If result is provided, use persistExecutionLogs for full tool call extraction + if (result) { + logger.info(`[${requestId}] Persisting execution result for workflow: ${id}`, { + executionId, + success: result.success, + }) + + // Use persistExecutionLogs which handles tool call extraction + await persistExecutionLogs(id, executionId, result, 'manual') + + return createSuccessResponse({ message: 'Execution logs persisted successfully' }) + } + + // Fall back to the original log format if 'result' isn't provided if (!logs || !Array.isArray(logs) || logs.length === 0) { logger.warn(`[${requestId}] No logs provided for workflow: ${id}`) return createErrorResponse('No logs provided', 400) @@ -32,7 +46,7 @@ export async function POST(request: NextRequest, { params }: { params: Promise<{ executionId, }) - // Persist each log + // Persist each log using the original method for (const log of logs) { await persistLog({ id: uuidv4(), @@ -41,8 +55,9 @@ export async function POST(request: NextRequest, { params }: { params: Promise<{ level: log.level, message: log.message, duration: log.duration, - trigger: 'manual', + trigger: log.trigger || 'manual', createdAt: new Date(log.createdAt || new Date()), + metadata: log.metadata, }) } diff --git a/sim/app/db/migrations/0015_brief_martin_li.sql b/sim/app/db/migrations/0015_brief_martin_li.sql new file mode 100644 index 0000000000..a4f158ff2f --- /dev/null +++ b/sim/app/db/migrations/0015_brief_martin_li.sql @@ -0,0 +1 @@ +ALTER TABLE "workflow_logs" ADD COLUMN "metadata" json; \ No newline at end of file diff --git a/sim/app/db/migrations/meta/0015_snapshot.json b/sim/app/db/migrations/meta/0015_snapshot.json new file mode 100644 index 0000000000..b690220ac8 --- /dev/null +++ b/sim/app/db/migrations/meta/0015_snapshot.json @@ -0,0 +1,811 @@ +{ + "id": "ae998729-181f-4ead-bcfe-9abe7ea6046d", + "prevId": "0e9f1d5e-b6fc-4429-ba94-82efa2ef1b21", + "version": "7", + "dialect": "postgresql", + "tables": { + "public.account": { + "name": "account", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "account_id": { + "name": "account_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "provider_id": { + "name": "provider_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "user_id": { + "name": "user_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "access_token": { + "name": "access_token", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "refresh_token": { + "name": "refresh_token", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "id_token": { + "name": "id_token", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "access_token_expires_at": { + "name": "access_token_expires_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "refresh_token_expires_at": { + "name": "refresh_token_expires_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "scope": { + "name": "scope", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "password": { + "name": "password", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + } + }, + "indexes": {}, + "foreignKeys": { + "account_user_id_user_id_fk": { + "name": "account_user_id_user_id_fk", + "tableFrom": "account", + "tableTo": "user", + "columnsFrom": ["user_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": {}, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.environment": { + "name": "environment", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "user_id": { + "name": "user_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "variables": { + "name": "variables", + "type": "json", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + } + }, + "indexes": {}, + "foreignKeys": { + "environment_user_id_user_id_fk": { + "name": "environment_user_id_user_id_fk", + "tableFrom": "environment", + "tableTo": "user", + "columnsFrom": ["user_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "environment_user_id_unique": { + "name": "environment_user_id_unique", + "nullsNotDistinct": false, + "columns": ["user_id"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.session": { + "name": "session", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "expires_at": { + "name": "expires_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "token": { + "name": "token", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "ip_address": { + "name": "ip_address", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "user_agent": { + "name": "user_agent", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "user_id": { + "name": "user_id", + "type": "text", + "primaryKey": false, + "notNull": true + } + }, + "indexes": {}, + "foreignKeys": { + "session_user_id_user_id_fk": { + "name": "session_user_id_user_id_fk", + "tableFrom": "session", + "tableTo": "user", + "columnsFrom": ["user_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "session_token_unique": { + "name": "session_token_unique", + "nullsNotDistinct": false, + "columns": ["token"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.settings": { + "name": "settings", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "user_id": { + "name": "user_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "general": { + "name": "general", + "type": "json", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + } + }, + "indexes": {}, + "foreignKeys": { + "settings_user_id_user_id_fk": { + "name": "settings_user_id_user_id_fk", + "tableFrom": "settings", + "tableTo": "user", + "columnsFrom": ["user_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "settings_user_id_unique": { + "name": "settings_user_id_unique", + "nullsNotDistinct": false, + "columns": ["user_id"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.user": { + "name": "user", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "name": { + "name": "name", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "email": { + "name": "email", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "email_verified": { + "name": "email_verified", + "type": "boolean", + "primaryKey": false, + "notNull": true + }, + "image": { + "name": "image", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + } + }, + "indexes": {}, + "foreignKeys": {}, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "user_email_unique": { + "name": "user_email_unique", + "nullsNotDistinct": false, + "columns": ["email"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.verification": { + "name": "verification", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "identifier": { + "name": "identifier", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "value": { + "name": "value", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "expires_at": { + "name": "expires_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + } + }, + "indexes": {}, + "foreignKeys": {}, + "compositePrimaryKeys": {}, + "uniqueConstraints": {}, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.waitlist": { + "name": "waitlist", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "email": { + "name": "email", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "status": { + "name": "status", + "type": "text", + "primaryKey": false, + "notNull": true, + "default": "'pending'" + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + } + }, + "indexes": {}, + "foreignKeys": {}, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "waitlist_email_unique": { + "name": "waitlist_email_unique", + "nullsNotDistinct": false, + "columns": ["email"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.webhook": { + "name": "webhook", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "workflow_id": { + "name": "workflow_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "path": { + "name": "path", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "provider": { + "name": "provider", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "provider_config": { + "name": "provider_config", + "type": "json", + "primaryKey": false, + "notNull": false + }, + "is_active": { + "name": "is_active", + "type": "boolean", + "primaryKey": false, + "notNull": true, + "default": true + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + } + }, + "indexes": { + "path_idx": { + "name": "path_idx", + "columns": [ + { + "expression": "path", + "isExpression": false, + "asc": true, + "nulls": "last" + } + ], + "isUnique": true, + "concurrently": false, + "method": "btree", + "with": {} + } + }, + "foreignKeys": { + "webhook_workflow_id_workflow_id_fk": { + "name": "webhook_workflow_id_workflow_id_fk", + "tableFrom": "webhook", + "tableTo": "workflow", + "columnsFrom": ["workflow_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": {}, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.workflow": { + "name": "workflow", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "user_id": { + "name": "user_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "name": { + "name": "name", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "description": { + "name": "description", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "state": { + "name": "state", + "type": "json", + "primaryKey": false, + "notNull": true + }, + "color": { + "name": "color", + "type": "text", + "primaryKey": false, + "notNull": true, + "default": "'#3972F6'" + }, + "last_synced": { + "name": "last_synced", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true + }, + "is_deployed": { + "name": "is_deployed", + "type": "boolean", + "primaryKey": false, + "notNull": true, + "default": false + }, + "deployed_at": { + "name": "deployed_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "api_key": { + "name": "api_key", + "type": "text", + "primaryKey": false, + "notNull": false + } + }, + "indexes": {}, + "foreignKeys": { + "workflow_user_id_user_id_fk": { + "name": "workflow_user_id_user_id_fk", + "tableFrom": "workflow", + "tableTo": "user", + "columnsFrom": ["user_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": {}, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.workflow_logs": { + "name": "workflow_logs", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "workflow_id": { + "name": "workflow_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "execution_id": { + "name": "execution_id", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "level": { + "name": "level", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "message": { + "name": "message", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "duration": { + "name": "duration", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "trigger": { + "name": "trigger", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + }, + "metadata": { + "name": "metadata", + "type": "json", + "primaryKey": false, + "notNull": false + } + }, + "indexes": {}, + "foreignKeys": { + "workflow_logs_workflow_id_workflow_id_fk": { + "name": "workflow_logs_workflow_id_workflow_id_fk", + "tableFrom": "workflow_logs", + "tableTo": "workflow", + "columnsFrom": ["workflow_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": {}, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + }, + "public.workflow_schedule": { + "name": "workflow_schedule", + "schema": "", + "columns": { + "id": { + "name": "id", + "type": "text", + "primaryKey": true, + "notNull": true + }, + "workflow_id": { + "name": "workflow_id", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "cron_expression": { + "name": "cron_expression", + "type": "text", + "primaryKey": false, + "notNull": false + }, + "next_run_at": { + "name": "next_run_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "last_ran_at": { + "name": "last_ran_at", + "type": "timestamp", + "primaryKey": false, + "notNull": false + }, + "trigger_type": { + "name": "trigger_type", + "type": "text", + "primaryKey": false, + "notNull": true + }, + "created_at": { + "name": "created_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + }, + "updated_at": { + "name": "updated_at", + "type": "timestamp", + "primaryKey": false, + "notNull": true, + "default": "now()" + } + }, + "indexes": {}, + "foreignKeys": { + "workflow_schedule_workflow_id_workflow_id_fk": { + "name": "workflow_schedule_workflow_id_workflow_id_fk", + "tableFrom": "workflow_schedule", + "tableTo": "workflow", + "columnsFrom": ["workflow_id"], + "columnsTo": ["id"], + "onDelete": "cascade", + "onUpdate": "no action" + } + }, + "compositePrimaryKeys": {}, + "uniqueConstraints": { + "workflow_schedule_workflow_id_unique": { + "name": "workflow_schedule_workflow_id_unique", + "nullsNotDistinct": false, + "columns": ["workflow_id"] + } + }, + "policies": {}, + "checkConstraints": {}, + "isRLSEnabled": false + } + }, + "enums": {}, + "schemas": {}, + "sequences": {}, + "roles": {}, + "policies": {}, + "views": {}, + "_meta": { + "columns": {}, + "schemas": {}, + "tables": {} + } +} diff --git a/sim/app/db/migrations/meta/_journal.json b/sim/app/db/migrations/meta/_journal.json index 29cc37939f..04c8967c5f 100644 --- a/sim/app/db/migrations/meta/_journal.json +++ b/sim/app/db/migrations/meta/_journal.json @@ -106,6 +106,13 @@ "when": 1741390762290, "tag": "0014_nice_dragon_lord", "breakpoints": true + }, + { + "idx": 15, + "version": "7", + "when": 1742039670528, + "tag": "0015_brief_martin_li", + "breakpoints": true } ] } diff --git a/sim/app/db/schema.ts b/sim/app/db/schema.ts index df88462cb3..77cd218d46 100644 --- a/sim/app/db/schema.ts +++ b/sim/app/db/schema.ts @@ -86,6 +86,7 @@ export const workflowLogs = pgTable('workflow_logs', { duration: text('duration'), // Store as text to allow 'NA' for errors trigger: text('trigger'), // e.g. "api", "schedule", "manual" createdAt: timestamp('created_at').notNull().defaultNow(), + metadata: json('metadata'), // Optional JSON field for storing additional context like tool calls }) export const environment = pgTable('environment', { diff --git a/sim/app/executor/handlers.ts b/sim/app/executor/handlers.ts index dd822a5103..6795ea2fa5 100644 --- a/sim/app/executor/handlers.ts +++ b/sim/app/executor/handlers.ts @@ -272,7 +272,15 @@ export class AgentBlockHandler implements BlockHandler { }, toolCalls: response.toolCalls ? { - list: response.toolCalls, + list: response.toolCalls.map((tc) => ({ + ...tc, + // Preserve timing information if available + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + input: tc.arguments || tc.input, + output: tc.result || tc.output, + })), count: response.toolCalls.length, } : undefined, @@ -295,7 +303,17 @@ export class AgentBlockHandler implements BlockHandler { total: 0, }, toolCalls: { - list: response.toolCalls || [], + list: response.toolCalls + ? response.toolCalls.map((tc) => ({ + ...tc, + // Preserve timing information if available + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + input: tc.arguments || tc.input, + output: tc.result || tc.output, + })) + : [], count: response.toolCalls?.length || 0, }, }, @@ -314,7 +332,17 @@ export class AgentBlockHandler implements BlockHandler { total: 0, }, toolCalls: { - list: response.toolCalls || [], + list: response.toolCalls + ? response.toolCalls.map((tc) => ({ + ...tc, + // Preserve timing information if available + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + input: tc.arguments || tc.input, + output: tc.result || tc.output, + })) + : [], count: response.toolCalls?.length || 0, }, }, diff --git a/sim/app/lib/logs/execution-logger.ts b/sim/app/lib/logs/execution-logger.ts index 3823df6843..cacb02dfc5 100644 --- a/sim/app/lib/logs/execution-logger.ts +++ b/sim/app/lib/logs/execution-logger.ts @@ -15,6 +15,23 @@ export interface LogEntry { createdAt: Date duration?: string trigger?: string + metadata?: ToolCallMetadata | Record +} + +// Define types for tool call tracking +export interface ToolCallMetadata { + toolCalls?: ToolCall[] +} + +export interface ToolCall { + name: string + duration: number // in milliseconds + startTime: string // ISO timestamp + endTime: string // ISO timestamp + status: 'success' | 'error' // Status of the tool call + input?: Record // Input parameters (optional) + output?: Record // Output data (optional) + error?: string // Error message if status is 'error' } export async function persistLog(log: LogEntry) { @@ -26,17 +43,324 @@ export async function persistLog(log: LogEntry) { * @param workflowId - The ID of the workflow * @param executionId - The ID of the execution * @param result - The execution result - * @param triggerType - The type of trigger (api, webhook, schedule) + * @param triggerType - The type of trigger (api, webhook, schedule, manual) */ export async function persistExecutionLogs( workflowId: string, executionId: string, result: ExecutorResult, - triggerType: 'api' | 'webhook' | 'schedule' + triggerType: 'api' | 'webhook' | 'schedule' | 'manual' ) { try { // Log each execution step for (const log of result.logs || []) { + // Check for agent block and tool calls + let metadata: ToolCallMetadata | undefined = undefined + + logger.debug('block type', log.blockType) + // If this is an agent block + if (log.blockType === 'agent' && log.output) { + logger.debug('Processing agent block output for tool calls', { + blockId: log.blockId, + blockName: log.blockName, + outputKeys: Object.keys(log.output), + hasToolCalls: !!log.output.toolCalls, + hasResponse: !!log.output.response, + }) + + // Extract tool calls from different possible structures + const blockStartTime = log.startedAt + const blockEndTime = log.endedAt || new Date().toISOString() + const blockDuration = log.durationMs || 0 + let toolCallData: any[] = [] + + // Case 1: Direct toolCalls array + if (Array.isArray(log.output.toolCalls)) { + logger.debug('Found direct toolCalls array', { count: log.output.toolCalls.length }) + + // Log raw timing data for debugging + log.output.toolCalls.forEach((tc: any, idx: number) => { + logger.debug(`Tool call ${idx} raw timing data:`, { + name: tc.name, + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + timing: tc.timing, + argumentKeys: tc.arguments ? Object.keys(tc.arguments) : undefined, + }) + }) + + toolCallData = log.output.toolCalls.map((toolCall: any) => { + // Extract timing info - try various formats that providers might use + const duration = extractDuration(toolCall) + const timing = extractTimingInfo( + toolCall, + blockStartTime ? new Date(blockStartTime) : undefined, + blockEndTime ? new Date(blockEndTime) : undefined + ) + + // Log what we extracted + logger.debug(`Tool call timing extracted:`, { + name: toolCall.name, + extracted_duration: duration, + extracted_startTime: timing.startTime, + extracted_endTime: timing.endTime, + }) + + return { + name: toolCall.name, + duration: duration, + startTime: timing.startTime, + endTime: timing.endTime, + status: toolCall.error ? 'error' : 'success', + input: toolCall.input || toolCall.arguments, + output: toolCall.output || toolCall.result, + error: toolCall.error, + } + }) + } + // Case 2: toolCalls with a list array (as seen in the screenshot) + else if (log.output.toolCalls && Array.isArray(log.output.toolCalls.list)) { + logger.debug('Found toolCalls with list array', { + count: log.output.toolCalls.list.length, + }) + + // Log raw timing data for debugging + log.output.toolCalls.list.forEach((tc: any, idx: number) => { + logger.debug(`Tool call list ${idx} raw timing data:`, { + name: tc.name, + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + timing: tc.timing, + argumentKeys: tc.arguments ? Object.keys(tc.arguments) : undefined, + }) + }) + + toolCallData = log.output.toolCalls.list.map((toolCall: any) => { + // Extract timing info - try various formats that providers might use + const duration = extractDuration(toolCall) + const timing = extractTimingInfo( + toolCall, + blockStartTime ? new Date(blockStartTime) : undefined, + blockEndTime ? new Date(blockEndTime) : undefined + ) + + // Log what we extracted + logger.debug(`Tool call list timing extracted:`, { + name: toolCall.name, + extracted_duration: duration, + extracted_startTime: timing.startTime, + extracted_endTime: timing.endTime, + }) + + return { + name: toolCall.name, + duration: duration, + startTime: timing.startTime, + endTime: timing.endTime, + status: toolCall.error ? 'error' : 'success', + input: toolCall.arguments || toolCall.input, + output: toolCall.result || toolCall.output, + error: toolCall.error, + } + }) + } + // Case 3: Response has toolCalls + else if (log.output.response && log.output.response.toolCalls) { + const toolCalls = Array.isArray(log.output.response.toolCalls) + ? log.output.response.toolCalls + : log.output.response.toolCalls.list || [] + + logger.debug('Found toolCalls in response', { count: toolCalls.length }) + + // Log raw timing data for debugging + toolCalls.forEach((tc: any, idx: number) => { + logger.debug(`Response tool call ${idx} raw timing data:`, { + name: tc.name, + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + timing: tc.timing, + argumentKeys: tc.arguments ? Object.keys(tc.arguments) : undefined, + }) + }) + + toolCallData = toolCalls.map((toolCall: any) => { + // Extract timing info - try various formats that providers might use + const duration = extractDuration(toolCall) + const timing = extractTimingInfo( + toolCall, + blockStartTime ? new Date(blockStartTime) : undefined, + blockEndTime ? new Date(blockEndTime) : undefined + ) + + // Log what we extracted + logger.debug(`Response tool call timing extracted:`, { + name: toolCall.name, + extracted_duration: duration, + extracted_startTime: timing.startTime, + extracted_endTime: timing.endTime, + }) + + return { + name: toolCall.name, + duration: duration, + startTime: timing.startTime, + endTime: timing.endTime, + status: toolCall.error ? 'error' : 'success', + input: toolCall.arguments || toolCall.input, + output: toolCall.result || toolCall.output, + error: toolCall.error, + } + }) + } + // Case 4: toolCalls is an object and has a list property + else if ( + log.output.toolCalls && + typeof log.output.toolCalls === 'object' && + log.output.toolCalls.list + ) { + const toolCalls = log.output.toolCalls + + logger.debug('Found toolCalls object with list property', { + count: toolCalls.list.length, + }) + + // Log raw timing data for debugging + toolCalls.list.forEach((tc: any, idx: number) => { + logger.debug(`toolCalls object list ${idx} raw timing data:`, { + name: tc.name, + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + timing: tc.timing, + argumentKeys: tc.arguments ? Object.keys(tc.arguments) : undefined, + }) + }) + + toolCallData = toolCalls.list.map((toolCall: any) => { + // Extract timing info - try various formats that providers might use + const duration = extractDuration(toolCall) + const timing = extractTimingInfo( + toolCall, + blockStartTime ? new Date(blockStartTime) : undefined, + blockEndTime ? new Date(blockEndTime) : undefined + ) + + // Log what we extracted + logger.debug(`toolCalls object list timing extracted:`, { + name: toolCall.name, + extracted_duration: duration, + extracted_startTime: timing.startTime, + extracted_endTime: timing.endTime, + }) + + return { + name: toolCall.name, + duration: duration, + startTime: timing.startTime, + endTime: timing.endTime, + status: toolCall.error ? 'error' : 'success', + input: toolCall.arguments || toolCall.input, + output: toolCall.result || toolCall.output, + error: toolCall.error, + } + }) + } + // Case 5: Parse the response string for toolCalls as a last resort + else if (typeof log.output.response === 'string') { + const match = log.output.response.match(/"toolCalls"\s*:\s*({[^}]*}|(\[.*?\]))/s) + if (match) { + try { + const toolCallsJson = JSON.parse(`{${match[0]}}`) + const list = Array.isArray(toolCallsJson.toolCalls) + ? toolCallsJson.toolCalls + : toolCallsJson.toolCalls.list || [] + + logger.debug('Found toolCalls in parsed response string', { + count: list.length, + }) + + // Log raw timing data for debugging + list.forEach((tc: any, idx: number) => { + logger.debug(`Parsed response ${idx} raw timing data:`, { + name: tc.name, + startTime: tc.startTime, + endTime: tc.endTime, + duration: tc.duration, + timing: tc.timing, + argumentKeys: tc.arguments ? Object.keys(tc.arguments) : undefined, + }) + }) + + toolCallData = list.map((toolCall: any) => { + // Extract timing info - try various formats that providers might use + const duration = extractDuration(toolCall) + const timing = extractTimingInfo( + toolCall, + blockStartTime ? new Date(blockStartTime) : undefined, + blockEndTime ? new Date(blockEndTime) : undefined + ) + + // Log what we extracted + logger.debug(`Parsed response timing extracted:`, { + name: toolCall.name, + extracted_duration: duration, + extracted_startTime: timing.startTime, + extracted_endTime: timing.endTime, + }) + + return { + name: toolCall.name, + duration: duration, + startTime: timing.startTime, + endTime: timing.endTime, + status: toolCall.error ? 'error' : 'success', + input: toolCall.arguments || toolCall.input, + output: toolCall.result || toolCall.output, + error: toolCall.error, + } + }) + } catch (error) { + logger.error('Error parsing toolCalls from response string', { + error, + response: log.output.response, + }) + } + } + } + // Verbose output debugging as a fallback + else { + logger.debug('Could not find tool calls in standard formats, output data:', { + outputSample: JSON.stringify(log.output).substring(0, 500) + '...', + }) + } + + // Fill in missing timing information + if (toolCallData.length > 0) { + const estimatedToolCalls = estimateToolCallTimings( + toolCallData, + blockStartTime, + blockEndTime, + blockDuration + ) + + const redactedToolCalls = estimatedToolCalls.map((toolCall) => ({ + ...toolCall, + input: redactApiKeys(toolCall.input), + })) + + metadata = { + toolCalls: redactedToolCalls, + } + + logger.debug('Created metadata with tool calls', { + count: redactedToolCalls.length, + }) + } + } + await persistLog({ id: uuidv4(), workflowId, @@ -48,7 +372,16 @@ export async function persistExecutionLogs( duration: log.success ? `${log.durationMs}ms` : 'NA', trigger: triggerType, createdAt: new Date(log.endedAt || log.startedAt), + metadata, }) + + if (metadata) { + logger.debug('Persisted log with metadata', { + logId: uuidv4(), + executionId, + toolCallCount: metadata.toolCalls?.length || 0, + }) + } } // Calculate total duration from successful block logs @@ -81,13 +414,13 @@ export async function persistExecutionLogs( * @param workflowId - The ID of the workflow * @param executionId - The ID of the execution * @param error - The error that occurred - * @param triggerType - The type of trigger (api, webhook, schedule) + * @param triggerType - The type of trigger (api, webhook, schedule, manual) */ export async function persistExecutionError( workflowId: string, executionId: string, error: Error, - triggerType: 'api' | 'webhook' | 'schedule' + triggerType: 'api' | 'webhook' | 'schedule' | 'manual' ) { try { const errorPrefix = getTriggerErrorPrefix(triggerType) @@ -108,7 +441,7 @@ export async function persistExecutionError( } // Helper functions for trigger-specific messages -function getTriggerSuccessMessage(triggerType: 'api' | 'webhook' | 'schedule'): string { +function getTriggerSuccessMessage(triggerType: 'api' | 'webhook' | 'schedule' | 'manual'): string { switch (triggerType) { case 'api': return 'API workflow executed successfully' @@ -116,12 +449,14 @@ function getTriggerSuccessMessage(triggerType: 'api' | 'webhook' | 'schedule'): return 'Webhook workflow executed successfully' case 'schedule': return 'Scheduled workflow executed successfully' + case 'manual': + return 'Manual workflow executed successfully' default: return 'Workflow executed successfully' } } -function getTriggerErrorPrefix(triggerType: 'api' | 'webhook' | 'schedule'): string { +function getTriggerErrorPrefix(triggerType: 'api' | 'webhook' | 'schedule' | 'manual'): string { switch (triggerType) { case 'api': return 'API workflow' @@ -129,7 +464,264 @@ function getTriggerErrorPrefix(triggerType: 'api' | 'webhook' | 'schedule'): str return 'Webhook workflow' case 'schedule': return 'Scheduled workflow' + case 'manual': + return 'Manual workflow' default: return 'Workflow' } } + +/** + * Extracts duration information for tool calls + * This function preserves actual timing data while ensuring duration is calculated + */ +function estimateToolCallTimings( + toolCalls: any[], + blockStart: string, + blockEnd: string, + totalDuration: number +): any[] { + if (!toolCalls || toolCalls.length === 0) return [] + + logger.debug('Estimating tool call timings', { + toolCallCount: toolCalls.length, + blockStartTime: blockStart, + blockEndTime: blockEnd, + totalDuration, + }) + + // First, try to preserve any existing timing data + const result = toolCalls.map((toolCall, index) => { + // Start with the original tool call + const enhancedToolCall = { ...toolCall } + + // If we don't have timing data, set it from the block timing info + // Divide block duration evenly among tools as a fallback + const toolDuration = totalDuration / toolCalls.length + const toolStartOffset = index * toolDuration + + // Force a minimum duration of 1000ms if none exists + if (!enhancedToolCall.duration || enhancedToolCall.duration === 0) { + enhancedToolCall.duration = Math.max(1000, toolDuration) + logger.debug(`Setting minimum duration for tool ${toolCall.name}`, { + duration: enhancedToolCall.duration, + }) + } + + // Force reasonable startTime and endTime if missing + if (!enhancedToolCall.startTime) { + const startTimestamp = new Date(blockStart).getTime() + toolStartOffset + enhancedToolCall.startTime = new Date(startTimestamp).toISOString() + logger.debug(`Setting startTime for tool ${toolCall.name}`, { + startTime: enhancedToolCall.startTime, + }) + } + + if (!enhancedToolCall.endTime) { + const endTimestamp = + new Date(enhancedToolCall.startTime).getTime() + enhancedToolCall.duration + enhancedToolCall.endTime = new Date(endTimestamp).toISOString() + logger.debug(`Setting endTime for tool ${toolCall.name}`, { + endTime: enhancedToolCall.endTime, + }) + } + + return enhancedToolCall + }) + + logger.debug('Finished estimating tool call timings', { + originalTools: toolCalls.map((t) => ({ + name: t.name, + hadDuration: !!t.duration, + hadStartTime: !!t.startTime, + hadEndTime: !!t.endTime, + })), + enhancedTools: result.map((t) => ({ + name: t.name, + duration: t.duration, + startTime: t.startTime, + endTime: t.endTime, + })), + }) + + return result +} + +/** + * Extracts the duration from a tool call object, trying various property formats + * that different agent providers might use + */ +function extractDuration(toolCall: any): number { + if (!toolCall) return 0 + + // Direct duration fields (various formats providers might use) + if (typeof toolCall.duration === 'number' && toolCall.duration > 0) return toolCall.duration + if (typeof toolCall.durationMs === 'number' && toolCall.durationMs > 0) return toolCall.durationMs + if (typeof toolCall.duration_ms === 'number' && toolCall.duration_ms > 0) + return toolCall.duration_ms + if (typeof toolCall.executionTime === 'number' && toolCall.executionTime > 0) + return toolCall.executionTime + if (typeof toolCall.execution_time === 'number' && toolCall.execution_time > 0) + return toolCall.execution_time + if (typeof toolCall.timing?.duration === 'number' && toolCall.timing.duration > 0) + return toolCall.timing.duration + + // Try to calculate from timestamps if available + if (toolCall.startTime && toolCall.endTime) { + try { + const start = new Date(toolCall.startTime).getTime() + const end = new Date(toolCall.endTime).getTime() + if (!isNaN(start) && !isNaN(end) && end >= start) { + return end - start + } + } catch (e) { + // Silently fail if date parsing fails + } + } + + // Also check for startedAt/endedAt format + if (toolCall.startedAt && toolCall.endedAt) { + try { + const start = new Date(toolCall.startedAt).getTime() + const end = new Date(toolCall.endedAt).getTime() + if (!isNaN(start) && !isNaN(end) && end >= start) { + return end - start + } + } catch (e) { + // Silently fail if date parsing fails + } + } + + // For some providers, timing info might be in a separate object + if (toolCall.timing) { + if (toolCall.timing.startTime && toolCall.timing.endTime) { + try { + const start = new Date(toolCall.timing.startTime).getTime() + const end = new Date(toolCall.timing.endTime).getTime() + if (!isNaN(start) && !isNaN(end) && end >= start) { + return end - start + } + } catch (e) { + // Silently fail if date parsing fails + } + } + } + + // No duration info found + return 0 +} + +/** + * Extract timing information from a tool call object + * @param toolCall The tool call object + * @param blockStartTime Optional block start time (for reference, not used as fallback anymore) + * @param blockEndTime Optional block end time (for reference, not used as fallback anymore) + * @returns Object with startTime and endTime properties + */ +function extractTimingInfo( + toolCall: any, + blockStartTime?: Date, + blockEndTime?: Date +): { startTime?: Date; endTime?: Date } { + logger.debug('Extracting timing info from tool call', { + tool: toolCall.name, + hasStartTime: !!toolCall.startTime, + hasEndTime: !!toolCall.endTime, + hasTiming: !!toolCall.timing, + blockStartRef: blockStartTime?.toISOString(), + blockEndRef: blockEndTime?.toISOString(), + }) + + let startTime: Date | undefined = undefined + let endTime: Date | undefined = undefined + + // Try to get direct timing properties + if (toolCall.startTime && isValidDate(toolCall.startTime)) { + startTime = new Date(toolCall.startTime) + } else if (toolCall.timing?.startTime && isValidDate(toolCall.timing.startTime)) { + startTime = new Date(toolCall.timing.startTime) + } else if (toolCall.timing?.start && isValidDate(toolCall.timing.start)) { + startTime = new Date(toolCall.timing.start) + } else if (toolCall.startedAt && isValidDate(toolCall.startedAt)) { + startTime = new Date(toolCall.startedAt) + } + + if (toolCall.endTime && isValidDate(toolCall.endTime)) { + endTime = new Date(toolCall.endTime) + } else if (toolCall.timing?.endTime && isValidDate(toolCall.timing.endTime)) { + endTime = new Date(toolCall.timing.endTime) + } else if (toolCall.timing?.end && isValidDate(toolCall.timing.end)) { + endTime = new Date(toolCall.timing.end) + } else if (toolCall.completedAt && isValidDate(toolCall.completedAt)) { + endTime = new Date(toolCall.completedAt) + } + + // If we have start time but no end time, calculate end time from duration + if (startTime && !endTime) { + const duration = extractDuration(toolCall) + if (duration > 0) { + endTime = new Date(startTime.getTime() + duration) + logger.debug('Calculated end time from start time and duration', { + tool: toolCall.name, + startTime: startTime.toISOString(), + duration, + calculatedEndTime: endTime.toISOString(), + }) + } + } + + // Log the final timing information + logger.debug('Final extracted timing info', { + tool: toolCall.name, + startTime: startTime?.toISOString(), + endTime: endTime?.toISOString(), + hasStartTime: !!startTime, + hasEndTime: !!endTime, + }) + + return { startTime, endTime } +} + +/** + * Helper function to check if a string is a valid date + */ +function isValidDate(dateString: string): boolean { + if (!dateString) return false + + try { + const timestamp = Date.parse(dateString) + return !isNaN(timestamp) + } catch (e) { + return false + } +} + +// Add this utility function for redacting API keys in tool call inputs +function redactApiKeys(obj: any): any { + if (!obj || typeof obj !== 'object') { + return obj + } + + if (Array.isArray(obj)) { + return obj.map(redactApiKeys) + } + + const result: Record = {} + + for (const [key, value] of Object.entries(obj)) { + // Check if the key is 'apiKey' (case insensitive) or related keys + if ( + key.toLowerCase() === 'apikey' || + key.toLowerCase() === 'api_key' || + key.toLowerCase() === 'access_token' + ) { + result[key] = '***REDACTED***' + } else if (typeof value === 'object' && value !== null) { + result[key] = redactApiKeys(value) + } else { + result[key] = value + } + } + + return result +} diff --git a/sim/app/providers/anthropic/index.ts b/sim/app/providers/anthropic/index.ts index 4836a92abc..8c4e559916 100644 --- a/sim/app/providers/anthropic/index.ts +++ b/sim/app/providers/anthropic/index.ts @@ -239,6 +239,10 @@ ${fieldDescriptions} toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/cerebras/index.ts b/sim/app/providers/cerebras/index.ts index 367d14e9fc..1c016e77f2 100644 --- a/sim/app/providers/cerebras/index.ts +++ b/sim/app/providers/cerebras/index.ts @@ -154,6 +154,10 @@ export const cerebrasProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/deepseek/index.ts b/sim/app/providers/deepseek/index.ts index ecba4cc052..fe9e01531c 100644 --- a/sim/app/providers/deepseek/index.ts +++ b/sim/app/providers/deepseek/index.ts @@ -127,6 +127,10 @@ export const deepseekProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/google/index.ts b/sim/app/providers/google/index.ts index 6b59d4162e..864e92ef05 100644 --- a/sim/app/providers/google/index.ts +++ b/sim/app/providers/google/index.ts @@ -126,6 +126,10 @@ export const googleProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/groq/index.ts b/sim/app/providers/groq/index.ts index 9277cc77aa..3a31d2e3a2 100644 --- a/sim/app/providers/groq/index.ts +++ b/sim/app/providers/groq/index.ts @@ -125,6 +125,10 @@ export const groqProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/openai/index.ts b/sim/app/providers/openai/index.ts index 1ce42b4e99..7cb62b301b 100644 --- a/sim/app/providers/openai/index.ts +++ b/sim/app/providers/openai/index.ts @@ -152,6 +152,10 @@ export const openaiProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) // Add the tool call and result to messages diff --git a/sim/app/providers/types.ts b/sim/app/providers/types.ts index 626320c8ae..fd05c8553f 100644 --- a/sim/app/providers/types.ts +++ b/sim/app/providers/types.ts @@ -31,6 +31,12 @@ export interface ProviderConfig { export interface FunctionCallResponse { name: string arguments: Record + startTime?: string + endTime?: string + duration?: number + result?: Record + output?: Record + input?: Record } export interface ProviderResponse { diff --git a/sim/app/providers/xai/index.ts b/sim/app/providers/xai/index.ts index 2df6f8a824..c65198bc6a 100644 --- a/sim/app/providers/xai/index.ts +++ b/sim/app/providers/xai/index.ts @@ -125,6 +125,10 @@ export const xAIProvider: ProviderConfig = { toolCalls.push({ name: toolName, arguments: toolArgs, + startTime: result.timing?.startTime, + endTime: result.timing?.endTime, + duration: result.timing?.duration, + result: result.output, }) currentMessages.push({ diff --git a/sim/app/tools/index.ts b/sim/app/tools/index.ts index 39660a9b1b..55a5a4f733 100644 --- a/sim/app/tools/index.ts +++ b/sim/app/tools/index.ts @@ -294,6 +294,10 @@ export async function executeTool( skipProxy = false, skipPostProcess = false ): Promise { + // Capture start time for precise timing + const startTime = new Date() + const startTimeISO = startTime.toISOString() + try { const tool = getTool(toolId) @@ -309,7 +313,18 @@ export async function executeTool( if (toolId.startsWith('custom_') && tool.directExecution) { const directResult = await tool.directExecution(params) if (directResult) { - return directResult + // Add timing data to the result + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...directResult, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } // If directExecution returns undefined, fall back to API route } @@ -321,15 +336,50 @@ export async function executeTool( // Apply post-processing if available and not skipped if (tool.postProcess && result.success && !skipPostProcess) { try { - return await tool.postProcess(result, params, executeTool) + const postProcessResult = await tool.postProcess(result, params, executeTool) + + // Add timing data to the post-processed result + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...postProcessResult, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } catch (error) { logger.error(`Error in post-processing for tool ${toolId}:`, { error }) // Return original result if post-processing fails - return result + // Still include timing data + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...result, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } } - return result + // Add timing data to the result + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...result, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } // For external APIs, use the proxy @@ -338,15 +388,49 @@ export async function executeTool( // Apply post-processing if available and not skipped if (tool.postProcess && result.success && !skipPostProcess) { try { - return await tool.postProcess(result, params, executeTool) + const postProcessResult = await tool.postProcess(result, params, executeTool) + + // Add timing data to the post-processed result + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...postProcessResult, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } catch (error) { logger.error(`Error in post-processing for tool ${toolId}:`, { error }) - // Return original result if post-processing fails - return result + // Return original result if post-processing fails, but include timing data + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...result, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } } - return result + // Add timing data to the result + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() + return { + ...result, + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, + } } catch (error: any) { logger.error(`Error executing tool ${toolId}:`, { error }) @@ -360,10 +444,19 @@ export async function executeTool( logger.error(`Looking for custom tool with identifier: ${identifier}`) } + // Add timing data even for errors + const endTime = new Date() + const endTimeISO = endTime.toISOString() + const duration = endTime.getTime() - startTime.getTime() return { success: false, output: {}, error: error.message || 'Unknown error', + timing: { + startTime: startTimeISO, + endTime: endTimeISO, + duration, + }, } } } diff --git a/sim/app/tools/types.ts b/sim/app/tools/types.ts index fdbb145541..ce1756b0c5 100644 --- a/sim/app/tools/types.ts +++ b/sim/app/tools/types.ts @@ -6,6 +6,11 @@ export interface ToolResponse { success: boolean // Whether the tool execution was successful output: Record // The structured output from the tool error?: string // Error message if success is false + timing?: { + startTime: string // ISO timestamp when the tool execution started + endTime: string // ISO timestamp when the tool execution ended + duration: number // Duration in milliseconds + } } export interface OAuthConfig { diff --git a/sim/app/w/[id]/hooks/use-workflow-execution.ts b/sim/app/w/[id]/hooks/use-workflow-execution.ts index 6c03595027..46d27b3dc4 100644 --- a/sim/app/w/[id]/hooks/use-workflow-execution.ts +++ b/sim/app/w/[id]/hooks/use-workflow-execution.ts @@ -24,59 +24,17 @@ export function useWorkflowExecution() { const { isExecuting, setIsExecuting } = useExecutionStore() const [executionResult, setExecutionResult] = useState(null) - const persistLogs = async (logs: any[], executionId: string) => { - // Check if we're in local storage mode - const useLocalStorage = - typeof window !== 'undefined' && - (window.localStorage.getItem('USE_LOCAL_STORAGE') === 'true' || - process.env.NEXT_PUBLIC_USE_LOCAL_STORAGE === 'true') - - if (useLocalStorage) { - // Store logs in localStorage - try { - const storageKey = `workflow-logs-${activeWorkflowId}-${executionId}` - window.localStorage.setItem( - storageKey, - JSON.stringify({ - logs, - timestamp: new Date().toISOString(), - workflowId: activeWorkflowId, - }) - ) - - // Also update a list of all execution logs for this workflow - const logListKey = `workflow-logs-list-${activeWorkflowId}` - const existingLogList = window.localStorage.getItem(logListKey) - const logList = existingLogList ? JSON.parse(existingLogList) : [] - logList.push({ - executionId, - timestamp: new Date().toISOString(), - }) - - // Keep only the last 20 executions - if (logList.length > 20) { - const removedLogs = logList.splice(0, logList.length - 20) - // Clean up old logs - removedLogs.forEach((log: any) => { - window.localStorage.removeItem(`workflow-logs-${activeWorkflowId}-${log.executionId}`) - }) - } - - window.localStorage.setItem(logListKey, JSON.stringify(logList)) - } catch (error) { - logger.error('Error storing logs in localStorage:', { error }) - } - return - } - - // Fall back to API if not in local storage mode + const persistLogs = async (executionId: string, result: ExecutionResult) => { try { const response = await fetch(`/api/workflow/${activeWorkflowId}/log`, { method: 'POST', headers: { 'Content-Type': 'application/json', }, - body: JSON.stringify({ logs, executionId }), + body: JSON.stringify({ + executionId, + result, + }), }) if (!response.ok) { @@ -140,59 +98,26 @@ export function useWorkflowExecution() { activeWorkflowId ) - // Prepare logs for persistence (moved after notification) - const blockLogs = (result.logs || []).map((log) => ({ - level: log.success ? 'info' : 'error', - message: log.success - ? `Block ${log.blockName || log.blockId} (${log.blockType}): ${JSON.stringify(log.output?.response || {})}` - : `Block ${log.blockName || log.blockId} (${log.blockType}): ${log.error || 'Failed'}`, - duration: log.success ? `${log.durationMs}ms` : 'NA', - createdAt: new Date(log.endedAt || log.startedAt).toISOString(), - })) - - // Calculate total duration from successful block logs - const totalDuration = (result.logs || []) - .filter((log) => log.success) - .reduce((sum, log) => sum + log.durationMs, 0) - - // Add final execution result log - blockLogs.push({ - level: result.success ? 'info' : 'error', - message: result.success - ? 'Manual workflow executed successfully' - : `Manual workflow execution failed: ${result.error}`, - duration: result.success ? `${totalDuration}ms` : 'NA', - createdAt: new Date().toISOString(), - }) - - // Persist logs after notification - await persistLogs(blockLogs, executionId) + // Send the entire execution result to our API to be processed server-side + await persistLogs(executionId, result) } catch (error: any) { logger.error('Workflow Execution Error:', { error }) const errorMessage = error instanceof Error ? error.message : 'Unknown error' // Set error result and show notification immediately - setExecutionResult({ + const errorResult = { success: false, output: { response: {} }, error: errorMessage, logs: [], - }) + } + + setExecutionResult(errorResult) addNotification('error', `Workflow execution failed: ${errorMessage}`, activeWorkflowId) - // Persist error log after notification - await persistLogs( - [ - { - level: 'error', - message: `Manual workflow execution failed: ${errorMessage}`, - duration: 'NA', - createdAt: new Date().toISOString(), - }, - ], - executionId - ) + // Also send the error result to the API + await persistLogs(executionId, errorResult) } finally { setIsExecuting(false) } diff --git a/sim/app/w/logs/components/copy-button.tsx b/sim/app/w/logs/components/copy-button.tsx new file mode 100644 index 0000000000..b0bab96fa1 --- /dev/null +++ b/sim/app/w/logs/components/copy-button.tsx @@ -0,0 +1,48 @@ +'use client' + +import { useState } from 'react' +import { Check, Copy } from 'lucide-react' +import { Button } from '@/components/ui/button' + +interface CopyButtonProps { + text: string + className?: string + showLabel?: boolean +} + +export function CopyButton({ text, className = '', showLabel = true }: CopyButtonProps) { + const [copied, setCopied] = useState(false) + + const copyToClipboard = () => { + navigator.clipboard.writeText(text) + setCopied(true) + setTimeout(() => setCopied(false), 2000) + } + + return ( +
+ {showLabel && ( +
+ {copied ? 'Copied!' : 'Click to copy'} +
+ )} + +
+ ) +} diff --git a/sim/app/w/logs/components/sidebar/sidebar.tsx b/sim/app/w/logs/components/sidebar/sidebar.tsx index 302a38cebf..069a1e4a39 100644 --- a/sim/app/w/logs/components/sidebar/sidebar.tsx +++ b/sim/app/w/logs/components/sidebar/sidebar.tsx @@ -6,6 +6,8 @@ import { Button } from '@/components/ui/button' import { ScrollArea } from '@/components/ui/scroll-area' import { WorkflowLog } from '@/app/w/logs/stores/types' import { formatDate } from '@/app/w/logs/utils/format-date' +import { CopyButton } from '../copy-button' +import { ToolCallsDisplay } from '../tool-calls/tool-calls-display' interface LogSidebarProps { log: WorkflowLog | null @@ -55,7 +57,8 @@ const formatSingleJsonContent = (content: string): JSX.Element => { return (
{messagePart &&
{messagePart}
} -
+
+ 
               {JSON.stringify(jsonData, null, 2)}
@@ -77,7 +80,8 @@ const formatSingleJsonContent = (content: string): JSX.Element => { try { const parsedJson = JSON.parse(jsonStr) return ( -
+
+ 
                       {JSON.stringify(parsedJson, null, 2)}
@@ -85,7 +89,8 @@ const formatSingleJsonContent = (content: string): JSX.Element => { ) } catch { return ( -
+
+ {jsonStr}
) @@ -99,7 +104,12 @@ const formatSingleJsonContent = (content: string): JSX.Element => { // If all parsing fails, return the original content } - return
{content}
+ return ( +
+ + {content} +
+ ) } export function Sidebar({ log, isOpen, onClose }: LogSidebarProps) { @@ -187,7 +197,10 @@ export function Sidebar({ log, isOpen, onClose }: LogSidebarProps) { {/* Timestamp */}

Timestamp

-

{formatDate(log.createdAt).full}

+

+ + {formatDate(log.createdAt).full} +

{/* Workflow */} @@ -195,12 +208,13 @@ export function Sidebar({ log, isOpen, onClose }: LogSidebarProps) {

Workflow

+ {log.workflow.name}
@@ -210,21 +224,30 @@ export function Sidebar({ log, isOpen, onClose }: LogSidebarProps) { {log.executionId && (

Execution ID

-

{log.executionId}

+

+ + {log.executionId} +

)} {/* Level */}

Level

-

{log.level}

+

+ + {log.level} +

{/* Trigger */} {log.trigger && (

Trigger

-

{log.trigger}

+

+ + {log.trigger} +

)} @@ -232,7 +255,18 @@ export function Sidebar({ log, isOpen, onClose }: LogSidebarProps) { {log.duration && (

Duration

-

{log.duration}

+

+ + {log.duration} +

+
+ )} + + {/* Tool Calls (if available) */} + {log.metadata?.toolCalls && log.metadata.toolCalls.length > 0 && ( +
+

Tool Calls

+
)} diff --git a/sim/app/w/logs/components/tool-calls/tool-calls-display.tsx b/sim/app/w/logs/components/tool-calls/tool-calls-display.tsx new file mode 100644 index 0000000000..f583bb8762 --- /dev/null +++ b/sim/app/w/logs/components/tool-calls/tool-calls-display.tsx @@ -0,0 +1,176 @@ +'use client' + +import { useState } from 'react' +import { AlertCircle, CheckCircle2, ChevronDown, ChevronRight, Clock } from 'lucide-react' +import { cn } from '@/lib/utils' +import { ToolCall, ToolCallMetadata } from '../../stores/types' +import { CopyButton } from '../copy-button' + +interface ToolCallsDisplayProps { + metadata: ToolCallMetadata +} + +export function ToolCallsDisplay({ metadata }: ToolCallsDisplayProps) { + if (!metadata.toolCalls || metadata.toolCalls.length === 0) { + return
No tool calls recorded
+ } + + return ( +
+
+ {metadata.toolCalls.map((toolCall, index) => ( + + ))} +
+
+ ) +} + +interface ToolCallItemProps { + toolCall: ToolCall + index: number +} + +function ToolCallItem({ toolCall, index }: ToolCallItemProps) { + const [expanded, setExpanded] = useState(false) + + // Always show exact milliseconds for duration + const formattedDuration = toolCall.duration ? `${toolCall.duration}ms` : 'N/A' + + // Determine status color + const statusColor = toolCall.status === 'success' ? 'text-green-500' : 'text-red-500' + const StatusIcon = toolCall.status === 'success' ? CheckCircle2 : AlertCircle + + return ( +
+ {/* Tool call header */} +
setExpanded(!expanded)} + > +
+ {expanded ? : } +
+ +
+ {toolCall.name} +
+
+ + {formattedDuration} +
+
+ + {toolCall.status} +
+
+
+
+ + {/* Tool call details */} + {expanded && ( +
+
+ {/* Timing information */} +
+
+
Start Time
+
+ {toolCall.startTime && isValidDate(toolCall.startTime) ? ( + <> + + {formatDateWithMilliseconds(new Date(toolCall.startTime))} + + ) : ( + 'Not available' + )} +
+
+
+
End Time
+
+ {toolCall.endTime && isValidDate(toolCall.endTime) ? ( + <> + + {formatDateWithMilliseconds(new Date(toolCall.endTime))} + + ) : ( + 'Not available' + )} +
+
+
+ + {/* Input */} + {toolCall.input && ( +
+
Input
+ 
+                  
+                  {JSON.stringify(toolCall.input, null, 2)}
+
+
+ )} + + {/* Output or Error */} + {toolCall.status === 'success' && toolCall.output && ( +
+
Output
+ 
+                  
+                  {JSON.stringify(toolCall.output, null, 2)}
+
+
+ )} + + {toolCall.status === 'error' && toolCall.error && ( +
+
Error
+ 
+                  
+                  {toolCall.error}
+
+
+ )} +
+
+ )} +
+ ) +} + +/** + * Helper function to check if a string is a valid date + */ +function isValidDate(dateString: string): boolean { + if (!dateString) return false + + try { + const timestamp = Date.parse(dateString) + return !isNaN(timestamp) + } catch (e) { + return false + } +} + +/** + * Format a date with millisecond precision + */ +function formatDateWithMilliseconds(date: Date): string { + // Get hours, minutes, seconds components + const hours = date.getHours().toString().padStart(2, '0') + const minutes = date.getMinutes().toString().padStart(2, '0') + const seconds = date.getSeconds().toString().padStart(2, '0') + + // Get milliseconds and format to 3 digits + const milliseconds = date.getMilliseconds().toString().padStart(3, '0') + + // Format as HH:MM:SS.mmm + return `${hours}:${minutes}:${seconds}.${milliseconds}` +} diff --git a/sim/app/w/logs/stores/types.ts b/sim/app/w/logs/stores/types.ts index f7d02a20d0..3e2d3caddb 100644 --- a/sim/app/w/logs/stores/types.ts +++ b/sim/app/w/logs/stores/types.ts @@ -7,6 +7,21 @@ export interface WorkflowData { // Add other workflow fields as needed } +export interface ToolCall { + name: string + duration: number // in milliseconds + startTime: string // ISO timestamp + endTime: string // ISO timestamp + status: 'success' | 'error' // Status of the tool call + input?: Record // Input parameters (optional) + output?: Record // Output data (optional) + error?: string // Error message if status is 'error' +} + +export interface ToolCallMetadata { + toolCalls?: ToolCall[] +} + export interface WorkflowLog { id: string workflowId: string @@ -17,6 +32,7 @@ export interface WorkflowLog { trigger: string | null createdAt: string workflow?: WorkflowData | null + metadata?: ToolCallMetadata | Record // Add metadata for tool calls } export interface LogsResponse { diff --git a/sim/drizzle.config.ts b/sim/drizzle.config.ts index c7ddc326a7..dcfb180251 100644 --- a/sim/drizzle.config.ts +++ b/sim/drizzle.config.ts @@ -1,8 +1,8 @@ import type { Config } from 'drizzle-kit' export default { - schema: './db/schema.ts', - out: './db/migrations', + schema: './app/db/schema.ts', + out: './app/db/migrations', dialect: 'postgresql', dbCredentials: { url: process.env.DATABASE_URL!,