From 31b32acffc6d15f082deb4ee800bc6be05638af0 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Wed, 11 Mar 2026 18:59:38 +0300 Subject: [PATCH 01/11] fix(execution): finalize runs before wrapper recovery --- apps/sim/background/schedule-execution.ts | 9 +- apps/sim/background/webhook-execution.ts | 9 +- apps/sim/background/workflow-execution.ts | 9 +- .../logs/execution/logging-session.test.ts | 75 ++++ .../sim/lib/logs/execution/logging-session.ts | 20 +- .../workflows/executor/execution-core.test.ts | 364 ++++++++++++++++++ .../lib/workflows/executor/execution-core.ts | 187 +++++---- 7 files changed, 601 insertions(+), 72 deletions(-) create mode 100644 apps/sim/lib/logs/execution/logging-session.test.ts create mode 100644 apps/sim/lib/workflows/executor/execution-core.test.ts diff --git a/apps/sim/background/schedule-execution.ts b/apps/sim/background/schedule-execution.ts index 7b6fd625761..7f78260e00c 100644 --- a/apps/sim/background/schedule-execution.ts +++ b/apps/sim/background/schedule-execution.ts @@ -8,7 +8,10 @@ import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core import { preprocessExecution } from '@/lib/execution/preprocessing' import { LoggingSession } from '@/lib/logs/execution/logging-session' import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans' -import { executeWorkflowCore } from '@/lib/workflows/executor/execution-core' +import { + executeWorkflowCore, + wasExecutionFinalizedByCore, +} from '@/lib/workflows/executor/execution-core' import { PauseResumeManager } from '@/lib/workflows/executor/human-in-the-loop-manager' import { blockExistsInDeployment, @@ -249,6 +252,10 @@ async function runWorkflowExecution({ } catch (error: unknown) { logger.error(`[${requestId}] Early failure in scheduled workflow ${payload.workflowId}`, error) + if (wasExecutionFinalizedByCore(error, executionId)) { + throw error + } + const executionResult = hasExecutionResult(error) ? error.executionResult : undefined const { traceSpans } = executionResult ? buildTraceSpans(executionResult) : { traceSpans: [] } diff --git a/apps/sim/background/webhook-execution.ts b/apps/sim/background/webhook-execution.ts index 26b2179012c..6efb444850d 100644 --- a/apps/sim/background/webhook-execution.ts +++ b/apps/sim/background/webhook-execution.ts @@ -12,7 +12,10 @@ import { LoggingSession } from '@/lib/logs/execution/logging-session' import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans' import { WebhookAttachmentProcessor } from '@/lib/webhooks/attachment-processor' import { fetchAndProcessAirtablePayloads, formatWebhookInput } from '@/lib/webhooks/utils.server' -import { executeWorkflowCore } from '@/lib/workflows/executor/execution-core' +import { + executeWorkflowCore, + wasExecutionFinalizedByCore, +} from '@/lib/workflows/executor/execution-core' import { PauseResumeManager } from '@/lib/workflows/executor/human-in-the-loop-manager' import { loadDeployedWorkflowState } from '@/lib/workflows/persistence/utils' import { resolveOAuthAccountId } from '@/app/api/auth/oauth/utils' @@ -623,6 +626,10 @@ async function executeWebhookJobInternal( provider: payload.provider, }) + if (wasExecutionFinalizedByCore(error, executionId)) { + throw error + } + try { await loggingSession.safeStart({ userId: payload.userId, diff --git a/apps/sim/background/workflow-execution.ts b/apps/sim/background/workflow-execution.ts index 8183f5a5ea9..360cbd4548d 100644 --- a/apps/sim/background/workflow-execution.ts +++ b/apps/sim/background/workflow-execution.ts @@ -5,7 +5,10 @@ import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core import { preprocessExecution } from '@/lib/execution/preprocessing' import { LoggingSession } from '@/lib/logs/execution/logging-session' import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans' -import { executeWorkflowCore } from '@/lib/workflows/executor/execution-core' +import { + executeWorkflowCore, + wasExecutionFinalizedByCore, +} from '@/lib/workflows/executor/execution-core' import { PauseResumeManager } from '@/lib/workflows/executor/human-in-the-loop-manager' import { ExecutionSnapshot } from '@/executor/execution/snapshot' import type { ExecutionMetadata } from '@/executor/execution/types' @@ -178,6 +181,10 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { executionId, }) + if (wasExecutionFinalizedByCore(error, executionId)) { + throw error + } + const executionResult = hasExecutionResult(error) ? error.executionResult : undefined const { traceSpans } = executionResult ? buildTraceSpans(executionResult) : { traceSpans: [] } diff --git a/apps/sim/lib/logs/execution/logging-session.test.ts b/apps/sim/lib/logs/execution/logging-session.test.ts new file mode 100644 index 00000000000..21c741378c3 --- /dev/null +++ b/apps/sim/lib/logs/execution/logging-session.test.ts @@ -0,0 +1,75 @@ +import { describe, expect, it, vi } from 'vitest' + +vi.mock('@sim/db', () => ({ + db: {}, +})) + +vi.mock('@sim/db/schema', () => ({ + workflowExecutionLogs: {}, +})) + +vi.mock('@sim/logger', () => ({ + createLogger: () => ({ + info: vi.fn(), + error: vi.fn(), + warn: vi.fn(), + debug: vi.fn(), + }), +})) + +vi.mock('drizzle-orm', () => ({ + eq: vi.fn(), + sql: vi.fn(), +})) + +vi.mock('@/lib/logs/execution/logger', () => ({ + executionLogger: { + startWorkflowExecution: vi.fn(), + completeWorkflowExecution: vi.fn(), + }, +})) + +vi.mock('@/lib/logs/execution/logging-factory', () => ({ + calculateCostSummary: vi.fn().mockReturnValue({ + totalCost: 0, + totalInputCost: 0, + totalOutputCost: 0, + totalTokens: 0, + totalPromptTokens: 0, + totalCompletionTokens: 0, + baseExecutionCharge: 0, + modelCost: 0, + models: {}, + }), + createEnvironmentObject: vi.fn(), + createTriggerObject: vi.fn(), + loadDeployedWorkflowStateForLogging: vi.fn(), + loadWorkflowStateForExecution: vi.fn(), +})) + +import { LoggingSession } from './logging-session' + +describe('LoggingSession completion retries', () => { + it('clears failed completion promise so error finalization can retry', async () => { + const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') as any + + const successFinalizeError = new Error('success finalize failed') + session.complete = vi.fn().mockRejectedValue(successFinalizeError) + session.completeWithCostOnlyLog = vi.fn().mockRejectedValue(successFinalizeError) + session.completeWithError = vi.fn().mockResolvedValue(undefined) + + await expect(session.safeComplete({ finalOutput: { ok: true } })).rejects.toThrow( + 'success finalize failed' + ) + + await expect( + session.safeCompleteWithError({ + error: { message: 'fallback error finalize' }, + }) + ).resolves.toBeUndefined() + + expect(session.complete).toHaveBeenCalledTimes(1) + expect(session.completeWithCostOnlyLog).toHaveBeenCalledTimes(1) + expect(session.completeWithError).toHaveBeenCalledTimes(1) + }) +}) diff --git a/apps/sim/lib/logs/execution/logging-session.ts b/apps/sim/lib/logs/execution/logging-session.ts index 10a4fc577e6..f5b260c65f1 100644 --- a/apps/sim/lib/logs/execution/logging-session.ts +++ b/apps/sim/lib/logs/execution/logging-session.ts @@ -690,7 +690,10 @@ export class LoggingSession { async safeComplete(params: SessionCompleteParams = {}): Promise { if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteImpl(params) + this.completionPromise = this._safeCompleteImpl(params).catch((error) => { + this.completionPromise = null + throw error + }) return this.completionPromise } @@ -715,7 +718,10 @@ export class LoggingSession { async safeCompleteWithError(params?: SessionErrorCompleteParams): Promise { if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithErrorImpl(params) + this.completionPromise = this._safeCompleteWithErrorImpl(params).catch((error) => { + this.completionPromise = null + throw error + }) return this.completionPromise } @@ -742,7 +748,10 @@ export class LoggingSession { async safeCompleteWithCancellation(params?: SessionCancelledParams): Promise { if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithCancellationImpl(params) + this.completionPromise = this._safeCompleteWithCancellationImpl(params).catch((error) => { + this.completionPromise = null + throw error + }) return this.completionPromise } @@ -768,7 +777,10 @@ export class LoggingSession { async safeCompleteWithPause(params?: SessionPausedParams): Promise { if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithPauseImpl(params) + this.completionPromise = this._safeCompleteWithPauseImpl(params).catch((error) => { + this.completionPromise = null + throw error + }) return this.completionPromise } diff --git a/apps/sim/lib/workflows/executor/execution-core.test.ts b/apps/sim/lib/workflows/executor/execution-core.test.ts new file mode 100644 index 00000000000..9c15eb01b2e --- /dev/null +++ b/apps/sim/lib/workflows/executor/execution-core.test.ts @@ -0,0 +1,364 @@ +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const { + loadWorkflowFromNormalizedTablesMock, + loadDeployedWorkflowStateMock, + getPersonalAndWorkspaceEnvMock, + mergeSubblockStateWithValuesMock, + safeStartMock, + safeCompleteMock, + safeCompleteWithErrorMock, + safeCompleteWithCancellationMock, + safeCompleteWithPauseMock, + updateWorkflowRunCountsMock, + clearExecutionCancellationMock, + buildTraceSpansMock, + serializeWorkflowMock, + executorExecuteMock, +} = vi.hoisted(() => ({ + loadWorkflowFromNormalizedTablesMock: vi.fn(), + loadDeployedWorkflowStateMock: vi.fn(), + getPersonalAndWorkspaceEnvMock: vi.fn(), + mergeSubblockStateWithValuesMock: vi.fn(), + safeStartMock: vi.fn(), + safeCompleteMock: vi.fn(), + safeCompleteWithErrorMock: vi.fn(), + safeCompleteWithCancellationMock: vi.fn(), + safeCompleteWithPauseMock: vi.fn(), + updateWorkflowRunCountsMock: vi.fn(), + clearExecutionCancellationMock: vi.fn(), + buildTraceSpansMock: vi.fn(), + serializeWorkflowMock: vi.fn(), + executorExecuteMock: vi.fn(), +})) + +vi.mock('@sim/logger', () => ({ + createLogger: () => ({ + info: vi.fn(), + error: vi.fn(), + warn: vi.fn(), + debug: vi.fn(), + }), +})) + +vi.mock('@/lib/environment/utils', () => ({ + getPersonalAndWorkspaceEnv: getPersonalAndWorkspaceEnvMock, +})) + +vi.mock('@/lib/execution/cancellation', () => ({ + clearExecutionCancellation: clearExecutionCancellationMock, +})) + +vi.mock('@/lib/logs/execution/trace-spans/trace-spans', () => ({ + buildTraceSpans: buildTraceSpansMock, +})) + +vi.mock('@/lib/workflows/persistence/utils', () => ({ + loadWorkflowFromNormalizedTables: loadWorkflowFromNormalizedTablesMock, + loadDeployedWorkflowState: loadDeployedWorkflowStateMock, +})) + +vi.mock('@/lib/workflows/subblocks', () => ({ + mergeSubblockStateWithValues: mergeSubblockStateWithValuesMock, +})) + +vi.mock('@/lib/workflows/triggers/triggers', () => ({ + TriggerUtils: { + findStartBlock: vi.fn().mockReturnValue({ + blockId: 'start-block', + block: { type: 'start_trigger' }, + path: ['start-block'], + }), + }, +})) + +vi.mock('@/lib/workflows/utils', () => ({ + updateWorkflowRunCounts: updateWorkflowRunCountsMock, +})) + +vi.mock('@/executor', () => ({ + Executor: vi.fn().mockImplementation(() => ({ + execute: executorExecuteMock, + executeFromBlock: executorExecuteMock, + })), +})) + +vi.mock('@/serializer', () => ({ + Serializer: vi.fn().mockImplementation(() => ({ + serializeWorkflow: serializeWorkflowMock, + })), +})) + +import { executeWorkflowCore, wasExecutionFinalizedByCore } from './execution-core' + +describe('executeWorkflowCore terminal finalization sequencing', () => { + const loggingSession = { + safeStart: safeStartMock, + safeComplete: safeCompleteMock, + safeCompleteWithError: safeCompleteWithErrorMock, + safeCompleteWithCancellation: safeCompleteWithCancellationMock, + safeCompleteWithPause: safeCompleteWithPauseMock, + } + + const createSnapshot = () => ({ + metadata: { + requestId: 'req-1', + workflowId: 'workflow-1', + userId: 'user-1', + workspaceId: 'workspace-1', + triggerType: 'api', + executionId: 'execution-1', + triggerBlockId: undefined, + useDraftState: true, + isClientSession: false, + enforceCredentialAccess: false, + startTime: new Date().toISOString(), + }, + workflow: { + id: 'workflow-1', + userId: 'workflow-owner', + variables: {}, + }, + input: { hello: 'world' }, + workflowVariables: {}, + selectedOutputs: [], + state: undefined, + }) + + beforeEach(() => { + vi.clearAllMocks() + + loadWorkflowFromNormalizedTablesMock.mockResolvedValue({ + blocks: { + 'start-block': { + id: 'start-block', + type: 'start_trigger', + subBlocks: {}, + name: 'Start', + }, + }, + edges: [], + loops: {}, + parallels: {}, + }) + + loadDeployedWorkflowStateMock.mockResolvedValue({ + blocks: {}, + edges: [], + loops: {}, + parallels: {}, + deploymentVersionId: 'dep-1', + }) + + getPersonalAndWorkspaceEnvMock.mockResolvedValue({ + personalEncrypted: {}, + workspaceEncrypted: {}, + personalDecrypted: {}, + workspaceDecrypted: {}, + }) + + mergeSubblockStateWithValuesMock.mockImplementation((blocks) => blocks) + serializeWorkflowMock.mockReturnValue({ loops: {}, parallels: {} }) + buildTraceSpansMock.mockReturnValue({ traceSpans: [{ id: 'span-1' }], totalDuration: 123 }) + safeStartMock.mockResolvedValue(undefined) + safeCompleteMock.mockResolvedValue(undefined) + safeCompleteWithErrorMock.mockResolvedValue(undefined) + safeCompleteWithCancellationMock.mockResolvedValue(undefined) + safeCompleteWithPauseMock.mockResolvedValue(undefined) + updateWorkflowRunCountsMock.mockResolvedValue(undefined) + clearExecutionCancellationMock.mockResolvedValue(undefined) + }) + + it('awaits terminal completion before updating run counts and returning', async () => { + const callOrder: string[] = [] + + executorExecuteMock.mockResolvedValue({ + success: true, + status: 'completed', + output: { done: true }, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + safeCompleteMock.mockImplementation(async () => { + callOrder.push('safeComplete:start') + await Promise.resolve() + callOrder.push('safeComplete:end') + }) + + clearExecutionCancellationMock.mockImplementation(async () => { + callOrder.push('clearCancellation') + }) + + updateWorkflowRunCountsMock.mockImplementation(async () => { + callOrder.push('updateRunCounts') + }) + + const result = await executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + + expect(result.status).toBe('completed') + expect(callOrder).toEqual([ + 'safeComplete:start', + 'safeComplete:end', + 'clearCancellation', + 'updateRunCounts', + ]) + }) + + it('clears cancellation even when success finalization throws', async () => { + executorExecuteMock.mockResolvedValue({ + success: true, + status: 'completed', + output: { done: true }, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + const completionError = new Error('completion failed') + safeCompleteMock.mockRejectedValue(completionError) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toThrow('completion failed') + + expect(clearExecutionCancellationMock).toHaveBeenCalledWith('execution-1') + expect(updateWorkflowRunCountsMock).not.toHaveBeenCalled() + }) + + it('routes cancelled executions through safeCompleteWithCancellation', async () => { + executorExecuteMock.mockResolvedValue({ + success: false, + status: 'cancelled', + output: {}, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + const result = await executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + + expect(result.status).toBe('cancelled') + expect(safeCompleteWithCancellationMock).toHaveBeenCalledTimes(1) + expect(safeCompleteWithCancellationMock).toHaveBeenCalledWith( + expect.objectContaining({ + totalDurationMs: 123, + traceSpans: [{ id: 'span-1' }], + }) + ) + expect(safeCompleteMock).not.toHaveBeenCalled() + expect(safeCompleteWithPauseMock).not.toHaveBeenCalled() + expect(updateWorkflowRunCountsMock).not.toHaveBeenCalled() + }) + + it('routes paused executions through safeCompleteWithPause', async () => { + executorExecuteMock.mockResolvedValue({ + success: true, + status: 'paused', + output: {}, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + const result = await executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + + expect(result.status).toBe('paused') + expect(safeCompleteWithPauseMock).toHaveBeenCalledTimes(1) + expect(safeCompleteWithPauseMock).toHaveBeenCalledWith( + expect.objectContaining({ + totalDurationMs: 123, + traceSpans: [{ id: 'span-1' }], + workflowInput: { hello: 'world' }, + }) + ) + expect(safeCompleteMock).not.toHaveBeenCalled() + expect(safeCompleteWithCancellationMock).not.toHaveBeenCalled() + expect(updateWorkflowRunCountsMock).not.toHaveBeenCalled() + }) + + it('finalizes errors before rethrowing and marks them as core-finalized', async () => { + const error = new Error('engine failed') + const executionResult = { + success: false, + status: 'failed', + output: {}, + error: 'engine failed', + logs: [], + metadata: { duration: 55, startTime: 'start', endTime: 'end' }, + } + + Object.assign(error, { executionResult }) + executorExecuteMock.mockRejectedValue(error) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe(error) + + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + expect(clearExecutionCancellationMock).toHaveBeenCalledWith('execution-1') + expect(wasExecutionFinalizedByCore(error, 'execution-1')).toBe(true) + }) + + it('marks non-Error throws as core-finalized using executionId guard', async () => { + executorExecuteMock.mockRejectedValue('engine failed') + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + expect(wasExecutionFinalizedByCore('engine failed', 'execution-1')).toBe(true) + expect(wasExecutionFinalizedByCore('engine failed', 'execution-1')).toBe(false) + }) + + it('falls back to error finalization when success finalization rejects', async () => { + executorExecuteMock.mockResolvedValue({ + success: true, + status: 'completed', + output: { done: true }, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + safeCompleteMock.mockRejectedValue(new Error('completion failed')) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toThrow('completion failed') + + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + expect(safeCompleteWithErrorMock).toHaveBeenCalledWith( + expect.objectContaining({ + error: expect.objectContaining({ + message: 'completion failed', + }), + }) + ) + }) +}) diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index b96a872dbf1..c92723786d0 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -112,6 +112,106 @@ function parseVariableValueByType(value: unknown, type: string): unknown { return typeof value === 'string' ? value : String(value) } +type ExecutionErrorWithFinalizationFlag = Error & { + executionFinalizedByCore?: boolean +} + +const finalizedExecutionIds = new Set() + +function markExecutionFinalizedByCore(error: unknown, executionId: string): void { + finalizedExecutionIds.add(executionId) + + if (error instanceof Error) { + ;(error as ExecutionErrorWithFinalizationFlag).executionFinalizedByCore = true + } +} + +export function wasExecutionFinalizedByCore(error: unknown, executionId?: string): boolean { + if (executionId && finalizedExecutionIds.delete(executionId)) { + return true + } + + return ( + error instanceof Error && + (error as ExecutionErrorWithFinalizationFlag).executionFinalizedByCore === true + ) +} + +async function finalizeExecutionOutcome(params: { + result: ExecutionResult + loggingSession: LoggingSession + executionId: string + workflowInput: unknown +}): Promise { + const { result, loggingSession, executionId, workflowInput } = params + const { traceSpans, totalDuration } = buildTraceSpans(result) + const endedAt = new Date().toISOString() + + try { + if (result.status === 'cancelled') { + await loggingSession.safeCompleteWithCancellation({ + endedAt, + totalDurationMs: totalDuration || 0, + traceSpans: traceSpans || [], + }) + return + } + + if (result.status === 'paused') { + await loggingSession.safeCompleteWithPause({ + endedAt, + totalDurationMs: totalDuration || 0, + traceSpans: traceSpans || [], + workflowInput, + }) + return + } + + await loggingSession.safeComplete({ + endedAt, + totalDurationMs: totalDuration || 0, + finalOutput: result.output || {}, + traceSpans: traceSpans || [], + workflowInput, + executionState: result.executionState, + }) + } finally { + await clearExecutionCancellation(executionId) + } +} + +async function finalizeExecutionError(params: { + error: unknown + loggingSession: LoggingSession + executionId: string + requestId: string +}): Promise { + const { error, loggingSession, executionId, requestId } = params + const executionResult = hasExecutionResult(error) ? error.executionResult : undefined + const { traceSpans } = executionResult ? buildTraceSpans(executionResult) : { traceSpans: [] } + + try { + await loggingSession.safeCompleteWithError({ + endedAt: new Date().toISOString(), + totalDurationMs: executionResult?.metadata?.duration || 0, + error: { + message: error instanceof Error ? error.message : 'Execution failed', + stackTrace: error instanceof Error ? error.stack : undefined, + }, + traceSpans, + }) + + return true + } catch (postExecError) { + logger.error(`[${requestId}] Post-execution error logging failed`, { + error: postExecError, + }) + return false + } finally { + await clearExecutionCancellation(executionId) + } +} + export async function executeWorkflowCore( options: ExecuteWorkflowCoreOptions ): Promise { @@ -360,48 +460,20 @@ export async function executeWorkflowCore( )) as ExecutionResult) : ((await executorInstance.execute(workflowId, resolvedTriggerBlockId)) as ExecutionResult) - // Fire-and-forget: post-execution logging, billing, and cleanup - void (async () => { - try { - const { traceSpans, totalDuration } = buildTraceSpans(result) - - if (result.success && result.status !== 'paused') { - try { - await updateWorkflowRunCounts(workflowId) - } catch (runCountError) { - logger.error(`[${requestId}] Failed to update run counts`, { error: runCountError }) - } - } - - if (result.status === 'cancelled') { - await loggingSession.safeCompleteWithCancellation({ - endedAt: new Date().toISOString(), - totalDurationMs: totalDuration || 0, - traceSpans: traceSpans || [], - }) - } else if (result.status === 'paused') { - await loggingSession.safeCompleteWithPause({ - endedAt: new Date().toISOString(), - totalDurationMs: totalDuration || 0, - traceSpans: traceSpans || [], - workflowInput: processedInput, - }) - } else { - await loggingSession.safeComplete({ - endedAt: new Date().toISOString(), - totalDurationMs: totalDuration || 0, - finalOutput: result.output || {}, - traceSpans: traceSpans || [], - workflowInput: processedInput, - executionState: result.executionState, - }) - } + await finalizeExecutionOutcome({ + result, + loggingSession, + executionId, + workflowInput: processedInput, + }) - await clearExecutionCancellation(executionId) - } catch (postExecError) { - logger.error(`[${requestId}] Post-execution logging failed`, { error: postExecError }) + if (result.success && result.status !== 'paused') { + try { + await updateWorkflowRunCounts(workflowId) + } catch (runCountError) { + logger.error(`[${requestId}] Failed to update run counts`, { error: runCountError }) } - })() + } logger.info(`[${requestId}] Workflow execution completed`, { success: result.success, @@ -413,31 +485,16 @@ export async function executeWorkflowCore( } catch (error: unknown) { logger.error(`[${requestId}] Execution failed:`, error) - // Fire-and-forget: error logging and cleanup - void (async () => { - try { - const executionResult = hasExecutionResult(error) ? error.executionResult : undefined - const { traceSpans } = executionResult - ? buildTraceSpans(executionResult) - : { traceSpans: [] } - - await loggingSession.safeCompleteWithError({ - endedAt: new Date().toISOString(), - totalDurationMs: executionResult?.metadata?.duration || 0, - error: { - message: error instanceof Error ? error.message : 'Execution failed', - stackTrace: error instanceof Error ? error.stack : undefined, - }, - traceSpans, - }) - - await clearExecutionCancellation(executionId) - } catch (postExecError) { - logger.error(`[${requestId}] Post-execution error logging failed`, { - error: postExecError, - }) - } - })() + const finalized = await finalizeExecutionError({ + error, + loggingSession, + executionId, + requestId, + }) + + if (finalized) { + markExecutionFinalizedByCore(error, executionId) + } throw error } From b606219495e739198ead2e0216f71811807fb584 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Wed, 11 Mar 2026 20:00:01 +0300 Subject: [PATCH 02/11] fix(async): preserve execution correlation across queued runs --- .../app/api/schedules/execute/route.test.ts | 46 +- apps/sim/app/api/schedules/execute/route.ts | 16 +- .../api/webhooks/trigger/[path]/route.test.ts | 62 +- .../[id]/execute/route.async.test.ts | 160 +++++ .../app/api/workflows/[id]/execute/route.ts | 12 +- .../async-execution-correlation.test.ts | 71 ++ .../async-preprocessing-correlation.test.ts | 164 +++++ apps/sim/background/schedule-execution.ts | 42 +- apps/sim/background/webhook-execution.ts | 613 +++++++++++------- apps/sim/background/workflow-execution.ts | 28 +- apps/sim/executor/execution/types.ts | 2 + .../core/async-jobs/backends/trigger-dev.ts | 4 + apps/sim/lib/core/async-jobs/types.ts | 16 + apps/sim/lib/execution/preprocessing.test.ts | 92 +++ apps/sim/lib/execution/preprocessing.ts | 15 +- .../preprocessing.webhook-correlation.test.ts | 93 +++ apps/sim/lib/logs/execution/logger.test.ts | 53 +- apps/sim/lib/logs/execution/logger.ts | 57 +- .../sim/lib/logs/execution/logging-session.ts | 9 +- apps/sim/lib/logs/types.ts | 6 +- apps/sim/lib/webhooks/processor.ts | 157 ++++- .../lib/workflows/executor/execution-core.ts | 1 + 22 files changed, 1409 insertions(+), 310 deletions(-) create mode 100644 apps/sim/app/api/workflows/[id]/execute/route.async.test.ts create mode 100644 apps/sim/background/async-execution-correlation.test.ts create mode 100644 apps/sim/background/async-preprocessing-correlation.test.ts create mode 100644 apps/sim/lib/execution/preprocessing.test.ts create mode 100644 apps/sim/lib/execution/preprocessing.webhook-correlation.test.ts diff --git a/apps/sim/app/api/schedules/execute/route.test.ts b/apps/sim/app/api/schedules/execute/route.test.ts index 66dc9fd6f3c..c4bb5415333 100644 --- a/apps/sim/app/api/schedules/execute/route.test.ts +++ b/apps/sim/app/api/schedules/execute/route.test.ts @@ -107,7 +107,11 @@ vi.mock('@sim/db', () => ({ }, })) -import { GET } from '@/app/api/schedules/execute/route' +vi.mock('uuid', () => ({ + v4: vi.fn().mockReturnValue('schedule-execution-1'), +})) + +import { GET } from './route' const SINGLE_SCHEDULE = [ { @@ -204,4 +208,44 @@ describe('Scheduled Workflow Execution API Route', () => { const data = await response.json() expect(data).toHaveProperty('executedCount', 2) }) + + it('should enqueue preassigned correlation metadata for schedules', async () => { + mockDbReturning.mockReturnValue(SINGLE_SCHEDULE) + + const response = await GET(createMockRequest()) + + expect(response.status).toBe(200) + expect(mockEnqueue).toHaveBeenCalledWith( + 'schedule-execution', + expect.objectContaining({ + scheduleId: 'schedule-1', + workflowId: 'workflow-1', + executionId: 'schedule-execution-1', + requestId: 'test-request-id', + correlation: { + executionId: 'schedule-execution-1', + requestId: 'test-request-id', + source: 'schedule', + workflowId: 'workflow-1', + scheduleId: 'schedule-1', + triggerType: 'schedule', + scheduledFor: '2025-01-01T00:00:00.000Z', + }, + }), + { + metadata: { + workflowId: 'workflow-1', + correlation: { + executionId: 'schedule-execution-1', + requestId: 'test-request-id', + source: 'schedule', + workflowId: 'workflow-1', + scheduleId: 'schedule-1', + triggerType: 'schedule', + scheduledFor: '2025-01-01T00:00:00.000Z', + }, + }, + } + ) + }) }) diff --git a/apps/sim/app/api/schedules/execute/route.ts b/apps/sim/app/api/schedules/execute/route.ts index c928b171436..fc87b07833a 100644 --- a/apps/sim/app/api/schedules/execute/route.ts +++ b/apps/sim/app/api/schedules/execute/route.ts @@ -2,6 +2,7 @@ import { db, workflowDeploymentVersion, workflowSchedule } from '@sim/db' import { createLogger } from '@sim/logger' import { and, eq, isNull, lt, lte, not, or, sql } from 'drizzle-orm' import { type NextRequest, NextResponse } from 'next/server' +import { v4 as uuidv4 } from 'uuid' import { verifyCronAuth } from '@/lib/auth/internal' import { getJobQueue, shouldExecuteInline } from '@/lib/core/async-jobs' import { generateRequestId } from '@/lib/core/utils/request' @@ -57,10 +58,23 @@ export async function GET(request: NextRequest) { const queuePromises = dueSchedules.map(async (schedule) => { const queueTime = schedule.lastQueuedAt ?? queuedAt + const executionId = uuidv4() + const correlation = { + executionId, + requestId, + source: 'schedule' as const, + workflowId: schedule.workflowId, + scheduleId: schedule.id, + triggerType: 'schedule', + scheduledFor: schedule.nextRunAt?.toISOString(), + } const payload = { scheduleId: schedule.id, workflowId: schedule.workflowId, + executionId, + requestId, + correlation, blockId: schedule.blockId || undefined, cronExpression: schedule.cronExpression || undefined, lastRanAt: schedule.lastRanAt?.toISOString(), @@ -71,7 +85,7 @@ export async function GET(request: NextRequest) { try { const jobId = await jobQueue.enqueue('schedule-execution', payload, { - metadata: { workflowId: schedule.workflowId }, + metadata: { workflowId: schedule.workflowId, correlation }, }) logger.info( `[${requestId}] Queued schedule execution task ${jobId} for workflow ${schedule.workflowId}` diff --git a/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts b/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts index 195572f8cbf..4463ba5d04d 100644 --- a/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts +++ b/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts @@ -101,6 +101,7 @@ const { processWebhookMock, executeMock, getWorkspaceBilledAccountUserIdMock, + queueWebhookExecutionMock, } = vi.hoisted(() => ({ generateRequestHashMock: vi.fn().mockResolvedValue('test-hash-123'), validateSlackSignatureMock: vi.fn().mockResolvedValue(true), @@ -125,6 +126,10 @@ const { .mockImplementation(async (workspaceId: string | null | undefined) => workspaceId ? 'test-user-id' : null ), + queueWebhookExecutionMock: vi.fn().mockImplementation(async () => { + const { NextResponse } = await import('next/server') + return NextResponse.json({ message: 'Webhook processed' }) + }), })) vi.mock('@trigger.dev/sdk', () => ({ @@ -359,12 +364,7 @@ vi.mock('@/lib/webhooks/processor', () => ({ }), shouldSkipWebhookEvent: vi.fn().mockReturnValue(false), handlePreDeploymentVerification: vi.fn().mockReturnValue(null), - queueWebhookExecution: vi.fn().mockImplementation(async () => { - // Call processWebhookMock so tests can verify it was called - processWebhookMock() - const { NextResponse } = await import('next/server') - return NextResponse.json({ message: 'Webhook processed' }) - }), + queueWebhookExecution: queueWebhookExecutionMock, })) vi.mock('drizzle-orm/postgres-js', () => ({ @@ -419,7 +419,7 @@ describe('Webhook Trigger API Route', () => { const params = Promise.resolve({ path: 'non-existent-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(404) @@ -494,6 +494,32 @@ describe('Webhook Trigger API Route', () => { }) describe('Generic Webhook Authentication', () => { + it('passes correlation-bearing request context into webhook queueing', async () => { + testData.webhooks.push({ + id: 'generic-webhook-id', + provider: 'generic', + path: 'test-path', + isActive: true, + providerConfig: { requireAuth: false }, + workflowId: 'test-workflow-id', + }) + + const req = createMockRequest('POST', { event: 'test', id: 'test-123' }) + const params = Promise.resolve({ path: 'test-path' }) + + const response = await POST(req as any, { params }) + + expect(response.status).toBe(200) + expect(queueWebhookExecutionMock).toHaveBeenCalledOnce() + const call = queueWebhookExecutionMock.mock.calls[0] + expect(call[0]).toEqual(expect.objectContaining({ id: 'generic-webhook-id' })) + expect(call[1]).toEqual(expect.objectContaining({ id: 'test-workflow-id' })) + expect(call[2]).toEqual(expect.objectContaining({ event: 'test', id: 'test-123' })) + expect(call[4]).toEqual( + expect.objectContaining({ requestId: 'mock-request-id', path: 'test-path' }) + ) + }) + it('should process generic webhook without authentication', async () => { testData.webhooks.push({ id: 'generic-webhook-id', @@ -514,7 +540,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'test', id: 'test-123' }) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(200) @@ -544,7 +570,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'bearer.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(200) }) @@ -575,7 +601,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'custom.header.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(200) }) @@ -610,7 +636,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'case.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(200) } @@ -645,7 +671,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'custom.case.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(200) } @@ -668,7 +694,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'wrong.token.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain('Unauthorized - Invalid authentication token') @@ -696,7 +722,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'wrong.custom.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain('Unauthorized - Invalid authentication token') @@ -716,7 +742,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'no.auth.test' }) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain('Unauthorized - Invalid authentication token') @@ -744,7 +770,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'exclusivity.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain('Unauthorized - Invalid authentication token') @@ -772,7 +798,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'wrong.header.name.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain('Unauthorized - Invalid authentication token') @@ -797,7 +823,7 @@ describe('Webhook Trigger API Route', () => { const req = createMockRequest('POST', { event: 'no.token.config.test' }, headers) const params = Promise.resolve({ path: 'test-path' }) - const response = await POST(req, { params }) + const response = await POST(req as any, { params }) expect(response.status).toBe(401) expect(await response.text()).toContain( diff --git a/apps/sim/app/api/workflows/[id]/execute/route.async.test.ts b/apps/sim/app/api/workflows/[id]/execute/route.async.test.ts new file mode 100644 index 00000000000..0a9aa008ba9 --- /dev/null +++ b/apps/sim/app/api/workflows/[id]/execute/route.async.test.ts @@ -0,0 +1,160 @@ +/** + * @vitest-environment node + */ + +import { createMockRequest } from '@sim/testing' +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const { + mockCheckHybridAuth, + mockAuthorizeWorkflowByWorkspacePermission, + mockPreprocessExecution, + mockEnqueue, +} = vi.hoisted(() => ({ + mockCheckHybridAuth: vi.fn(), + mockAuthorizeWorkflowByWorkspacePermission: vi.fn(), + mockPreprocessExecution: vi.fn(), + mockEnqueue: vi.fn().mockResolvedValue('job-123'), +})) + +vi.mock('@/lib/auth/hybrid', () => ({ + checkHybridAuth: mockCheckHybridAuth, +})) + +vi.mock('@/lib/workflows/utils', () => ({ + authorizeWorkflowByWorkspacePermission: mockAuthorizeWorkflowByWorkspacePermission, + createHttpResponseFromBlock: vi.fn(), + workflowHasResponseBlock: vi.fn().mockReturnValue(false), +})) + +vi.mock('@/lib/execution/preprocessing', () => ({ + preprocessExecution: mockPreprocessExecution, +})) + +vi.mock('@/lib/core/async-jobs', () => ({ + getJobQueue: vi.fn().mockResolvedValue({ + enqueue: mockEnqueue, + startJob: vi.fn(), + completeJob: vi.fn(), + markJobFailed: vi.fn(), + }), + shouldExecuteInline: vi.fn().mockReturnValue(false), +})) + +vi.mock('@/lib/core/utils/request', () => ({ + generateRequestId: vi.fn().mockReturnValue('req-12345678'), +})) + +vi.mock('@/lib/core/utils/urls', () => ({ + getBaseUrl: vi.fn().mockReturnValue('http://localhost:3000'), +})) + +vi.mock('@/lib/execution/call-chain', () => ({ + SIM_VIA_HEADER: 'x-sim-via', + parseCallChain: vi.fn().mockReturnValue([]), + validateCallChain: vi.fn().mockReturnValue(null), + buildNextCallChain: vi.fn().mockReturnValue(['workflow-1']), +})) + +vi.mock('@/lib/logs/execution/logging-session', () => ({ + LoggingSession: vi.fn().mockImplementation(() => ({})), +})) + +vi.mock('@/background/workflow-execution', () => ({ + executeWorkflowJob: vi.fn(), +})) + +vi.mock('@sim/logger', () => ({ + createLogger: vi.fn().mockReturnValue({ + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }), +})) + +vi.mock('uuid', () => ({ + validate: vi.fn().mockReturnValue(true), + v4: vi.fn().mockReturnValue('execution-123'), +})) + +import { POST } from './route' + +describe('workflow execute async route', () => { + beforeEach(() => { + vi.clearAllMocks() + + mockCheckHybridAuth.mockResolvedValue({ + success: true, + userId: 'session-user-1', + authType: 'session', + }) + + mockAuthorizeWorkflowByWorkspacePermission.mockResolvedValue({ + allowed: true, + workflow: { + id: 'workflow-1', + userId: 'owner-1', + workspaceId: 'workspace-1', + }, + }) + + mockPreprocessExecution.mockResolvedValue({ + success: true, + actorUserId: 'actor-1', + workflowRecord: { + id: 'workflow-1', + userId: 'owner-1', + workspaceId: 'workspace-1', + }, + }) + }) + + it('queues async execution with matching correlation metadata', async () => { + const req = createMockRequest( + 'POST', + { input: { hello: 'world' } }, + { + 'Content-Type': 'application/json', + 'X-Execution-Mode': 'async', + } + ) + const params = Promise.resolve({ id: 'workflow-1' }) + + const response = await POST(req as any, { params }) + const body = await response.json() + + expect(response.status).toBe(202) + expect(body.executionId).toBe('execution-123') + expect(body.jobId).toBe('job-123') + expect(mockEnqueue).toHaveBeenCalledWith( + 'workflow-execution', + expect.objectContaining({ + workflowId: 'workflow-1', + userId: 'actor-1', + executionId: 'execution-123', + requestId: 'req-12345678', + correlation: { + executionId: 'execution-123', + requestId: 'req-12345678', + source: 'workflow', + workflowId: 'workflow-1', + triggerType: 'manual', + }, + }), + { + metadata: { + workflowId: 'workflow-1', + userId: 'actor-1', + correlation: { + executionId: 'execution-123', + requestId: 'req-12345678', + source: 'workflow', + workflowId: 'workflow-1', + triggerType: 'manual', + }, + }, + } + ) + }) +}) diff --git a/apps/sim/app/api/workflows/[id]/execute/route.ts b/apps/sim/app/api/workflows/[id]/execute/route.ts index 6f469e24866..1200debd413 100644 --- a/apps/sim/app/api/workflows/[id]/execute/route.ts +++ b/apps/sim/app/api/workflows/[id]/execute/route.ts @@ -166,19 +166,29 @@ type AsyncExecutionParams = { async function handleAsyncExecution(params: AsyncExecutionParams): Promise { const { requestId, workflowId, userId, input, triggerType, executionId, callChain } = params + const correlation = { + executionId, + requestId, + source: 'workflow' as const, + workflowId, + triggerType, + } + const payload: WorkflowExecutionPayload = { workflowId, userId, input, triggerType, executionId, + requestId, + correlation, callChain, } try { const jobQueue = await getJobQueue() const jobId = await jobQueue.enqueue('workflow-execution', payload, { - metadata: { workflowId, userId }, + metadata: { workflowId, userId, correlation }, }) logger.info(`[${requestId}] Queued async workflow execution`, { diff --git a/apps/sim/background/async-execution-correlation.test.ts b/apps/sim/background/async-execution-correlation.test.ts new file mode 100644 index 00000000000..4b2f8fb097f --- /dev/null +++ b/apps/sim/background/async-execution-correlation.test.ts @@ -0,0 +1,71 @@ +/** + * @vitest-environment node + */ + +import { describe, expect, it } from 'vitest' +import { buildScheduleCorrelation } from './schedule-execution' +import { buildWebhookCorrelation } from './webhook-execution' +import { buildWorkflowCorrelation } from './workflow-execution' + +describe('async execution correlation fallbacks', () => { + it('falls back for legacy workflow payloads missing correlation fields', () => { + const correlation = buildWorkflowCorrelation({ + workflowId: 'workflow-1', + userId: 'user-1', + triggerType: 'api', + executionId: 'execution-legacy', + }) + + expect(correlation).toEqual({ + executionId: 'execution-legacy', + requestId: 'executio', + source: 'workflow', + workflowId: 'workflow-1', + triggerType: 'api', + }) + }) + + it('falls back for legacy schedule payloads missing preassigned request id', () => { + const correlation = buildScheduleCorrelation({ + scheduleId: 'schedule-1', + workflowId: 'workflow-1', + executionId: 'schedule-exec-1', + now: '2025-01-01T00:00:00.000Z', + scheduledFor: '2025-01-01T00:00:00.000Z', + }) + + expect(correlation).toEqual({ + executionId: 'schedule-exec-1', + requestId: 'schedule', + source: 'schedule', + workflowId: 'workflow-1', + scheduleId: 'schedule-1', + triggerType: 'schedule', + scheduledFor: '2025-01-01T00:00:00.000Z', + }) + }) + + it('falls back for legacy webhook payloads missing preassigned fields', () => { + const correlation = buildWebhookCorrelation({ + webhookId: 'webhook-1', + workflowId: 'workflow-1', + userId: 'user-1', + executionId: 'webhook-exec-1', + provider: 'slack', + body: {}, + headers: {}, + path: 'incoming/slack', + }) + + expect(correlation).toEqual({ + executionId: 'webhook-exec-1', + requestId: 'webhook-', + source: 'webhook', + workflowId: 'workflow-1', + webhookId: 'webhook-1', + path: 'incoming/slack', + provider: 'slack', + triggerType: 'webhook', + }) + }) +}) diff --git a/apps/sim/background/async-preprocessing-correlation.test.ts b/apps/sim/background/async-preprocessing-correlation.test.ts new file mode 100644 index 00000000000..4d2cd36f895 --- /dev/null +++ b/apps/sim/background/async-preprocessing-correlation.test.ts @@ -0,0 +1,164 @@ +/** + * @vitest-environment node + */ + +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const { mockPreprocessExecution, mockTask, mockDbUpdate } = vi.hoisted(() => ({ + mockPreprocessExecution: vi.fn(), + mockTask: vi.fn((config) => config), + mockDbUpdate: vi.fn(() => ({ + set: vi.fn(() => ({ where: vi.fn().mockResolvedValue(undefined) })), + })), +})) + +vi.mock('@trigger.dev/sdk', () => ({ task: mockTask })) + +vi.mock('@sim/db', () => ({ + db: { + update: mockDbUpdate, + select: vi.fn(), + }, + workflow: {}, + workflowSchedule: {}, +})) + +vi.mock('drizzle-orm', () => ({ eq: vi.fn() })) + +vi.mock('@/lib/execution/preprocessing', () => ({ + preprocessExecution: mockPreprocessExecution, +})) + +vi.mock('@/lib/logs/execution/logging-session', () => ({ + LoggingSession: vi.fn().mockImplementation(() => ({ + safeStart: vi.fn().mockResolvedValue(true), + safeCompleteWithError: vi.fn().mockResolvedValue(undefined), + markAsFailed: vi.fn().mockResolvedValue(undefined), + })), +})) + +vi.mock('@/lib/core/execution-limits', () => ({ + createTimeoutAbortController: vi.fn(() => ({ + signal: undefined, + cleanup: vi.fn(), + isTimedOut: vi.fn().mockReturnValue(false), + timeoutMs: undefined, + })), + getTimeoutErrorMessage: vi.fn(), +})) + +vi.mock('@/lib/logs/execution/trace-spans/trace-spans', () => ({ + buildTraceSpans: vi.fn(() => ({ traceSpans: [] })), +})) + +vi.mock('@/lib/workflows/executor/execution-core', () => ({ + executeWorkflowCore: vi.fn(), + wasExecutionFinalizedByCore: vi.fn().mockReturnValue(false), +})) + +vi.mock('@/lib/workflows/executor/human-in-the-loop-manager', () => ({ + PauseResumeManager: { + persistPauseResult: vi.fn(), + processQueuedResumes: vi.fn(), + }, +})) + +vi.mock('@/lib/workflows/persistence/utils', () => ({ + blockExistsInDeployment: vi.fn(), + loadDeployedWorkflowState: vi.fn(), +})) + +vi.mock('@/lib/workflows/schedules/utils', () => ({ + calculateNextRunTime: vi.fn(), + getScheduleTimeValues: vi.fn(), + getSubBlockValue: vi.fn(), +})) + +vi.mock('@/executor/execution/snapshot', () => ({ + ExecutionSnapshot: vi.fn(), +})) + +vi.mock('@/executor/utils/errors', () => ({ + hasExecutionResult: vi.fn().mockReturnValue(false), +})) + +vi.mock('@sim/logger', () => ({ + createLogger: vi.fn().mockReturnValue({ + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }), +})) + +import { executeScheduleJob } from './schedule-execution' +import { executeWorkflowJob } from './workflow-execution' + +describe('async preprocessing correlation threading', () => { + beforeEach(() => { + vi.clearAllMocks() + }) + + it('passes workflow correlation into preprocessing', async () => { + mockPreprocessExecution.mockResolvedValueOnce({ + success: false, + error: { message: 'preprocessing failed', statusCode: 500, logCreated: true }, + }) + + await expect( + executeWorkflowJob({ + workflowId: 'workflow-1', + userId: 'user-1', + triggerType: 'api', + executionId: 'execution-1', + requestId: 'request-1', + }) + ).rejects.toThrow('preprocessing failed') + + expect(mockPreprocessExecution).toHaveBeenCalledWith( + expect.objectContaining({ + triggerData: { + correlation: { + executionId: 'execution-1', + requestId: 'request-1', + source: 'workflow', + workflowId: 'workflow-1', + triggerType: 'api', + }, + }, + }) + ) + }) + + it('passes schedule correlation into preprocessing', async () => { + mockPreprocessExecution.mockResolvedValueOnce({ + success: false, + error: { message: 'auth failed', statusCode: 401, logCreated: true }, + }) + + await executeScheduleJob({ + scheduleId: 'schedule-1', + workflowId: 'workflow-1', + executionId: 'execution-2', + requestId: 'request-2', + now: '2025-01-01T00:00:00.000Z', + scheduledFor: '2025-01-01T00:00:00.000Z', + }) + + expect(mockPreprocessExecution).toHaveBeenCalledWith( + expect.objectContaining({ + triggerData: { + correlation: { + executionId: 'execution-2', + requestId: 'request-2', + source: 'schedule', + workflowId: 'workflow-1', + scheduleId: 'schedule-1', + triggerType: 'schedule', + scheduledFor: '2025-01-01T00:00:00.000Z', + }, + }, + }) + ) + }) +}) diff --git a/apps/sim/background/schedule-execution.ts b/apps/sim/background/schedule-execution.ts index 7f78260e00c..54520368ad4 100644 --- a/apps/sim/background/schedule-execution.ts +++ b/apps/sim/background/schedule-execution.ts @@ -4,6 +4,7 @@ import { task } from '@trigger.dev/sdk' import { Cron } from 'croner' import { eq } from 'drizzle-orm' import { v4 as uuidv4 } from 'uuid' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core/execution-limits' import { preprocessExecution } from '@/lib/execution/preprocessing' import { LoggingSession } from '@/lib/logs/execution/logging-session' @@ -39,6 +40,23 @@ type RunWorkflowResult = | { status: 'success'; blocks: Record; executionResult: ExecutionCoreResult } | { status: 'failure'; blocks: Record; executionResult: ExecutionCoreResult } +export function buildScheduleCorrelation( + payload: ScheduleExecutionPayload +): AsyncExecutionCorrelation { + const executionId = payload.executionId || uuidv4() + const requestId = payload.requestId || payload.correlation?.requestId || executionId.slice(0, 8) + + return { + executionId, + requestId, + source: 'schedule', + workflowId: payload.workflowId, + scheduleId: payload.scheduleId, + triggerType: payload.correlation?.triggerType || 'schedule', + scheduledFor: payload.scheduledFor || payload.correlation?.scheduledFor, + } +} + async function applyScheduleUpdate( scheduleId: string, updates: WorkflowScheduleUpdate, @@ -114,6 +132,7 @@ async function determineNextRunAfterError( async function runWorkflowExecution({ payload, + correlation, workflowRecord, actorUserId, loggingSession, @@ -122,6 +141,7 @@ async function runWorkflowExecution({ asyncTimeout, }: { payload: ScheduleExecutionPayload + correlation: AsyncExecutionCorrelation workflowRecord: WorkflowRecord actorUserId: string loggingSession: LoggingSession @@ -174,6 +194,7 @@ async function runWorkflowExecution({ useDraftState: false, startTime: new Date().toISOString(), isClientSession: false, + correlation, } const snapshot = new ExecutionSnapshot( @@ -274,6 +295,9 @@ async function runWorkflowExecution({ export type ScheduleExecutionPayload = { scheduleId: string workflowId: string + executionId?: string + requestId?: string + correlation?: AsyncExecutionCorrelation blockId?: string cronExpression?: string lastRanAt?: string @@ -308,8 +332,9 @@ function calculateNextRunTime( } export async function executeScheduleJob(payload: ScheduleExecutionPayload) { - const executionId = uuidv4() - const requestId = executionId.slice(0, 8) + const correlation = buildScheduleCorrelation(payload) + const executionId = correlation.executionId + const requestId = correlation.requestId const now = new Date(payload.now) const scheduledFor = payload.scheduledFor ? new Date(payload.scheduledFor) : null @@ -336,6 +361,7 @@ export async function executeScheduleJob(payload: ScheduleExecutionPayload) { checkRateLimit: true, checkDeployment: true, loggingSession, + triggerData: { correlation }, }) if (!preprocessResult.success) { @@ -462,11 +488,23 @@ export async function executeScheduleJob(payload: ScheduleExecutionPayload) { return } + if (!workflowRecord.workspaceId) { + throw new Error(`Workflow ${payload.workflowId} has no associated workspace`) + } + + await loggingSession.safeStart({ + userId: actorUserId, + workspaceId: workflowRecord.workspaceId, + variables: {}, + triggerData: { correlation }, + }) + logger.info(`[${requestId}] Executing scheduled workflow ${payload.workflowId}`) try { const executionResult = await runWorkflowExecution({ payload, + correlation, workflowRecord, actorUserId, loggingSession, diff --git a/apps/sim/background/webhook-execution.ts b/apps/sim/background/webhook-execution.ts index 6efb444850d..fef211bde71 100644 --- a/apps/sim/background/webhook-execution.ts +++ b/apps/sim/background/webhook-execution.ts @@ -1,32 +1,60 @@ -import { db } from '@sim/db' -import { account, webhook } from '@sim/db/schema' -import { createLogger } from '@sim/logger' -import { task } from '@trigger.dev/sdk' -import { eq } from 'drizzle-orm' -import { v4 as uuidv4 } from 'uuid' -import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core/execution-limits' -import { IdempotencyService, webhookIdempotency } from '@/lib/core/idempotency' -import { processExecutionFiles } from '@/lib/execution/files' -import { preprocessExecution } from '@/lib/execution/preprocessing' -import { LoggingSession } from '@/lib/logs/execution/logging-session' -import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans' -import { WebhookAttachmentProcessor } from '@/lib/webhooks/attachment-processor' -import { fetchAndProcessAirtablePayloads, formatWebhookInput } from '@/lib/webhooks/utils.server' +import { db } from "@sim/db"; +import { account, webhook } from "@sim/db/schema"; +import { createLogger } from "@sim/logger"; +import { task } from "@trigger.dev/sdk"; +import { eq } from "drizzle-orm"; +import { v4 as uuidv4 } from "uuid"; +import type { AsyncExecutionCorrelation } from "@/lib/core/async-jobs/types"; +import { + createTimeoutAbortController, + getTimeoutErrorMessage, +} from "@/lib/core/execution-limits"; +import { IdempotencyService, webhookIdempotency } from "@/lib/core/idempotency"; +import { processExecutionFiles } from "@/lib/execution/files"; +import { preprocessExecution } from "@/lib/execution/preprocessing"; +import { LoggingSession } from "@/lib/logs/execution/logging-session"; +import { buildTraceSpans } from "@/lib/logs/execution/trace-spans/trace-spans"; +import { WebhookAttachmentProcessor } from "@/lib/webhooks/attachment-processor"; +import { + fetchAndProcessAirtablePayloads, + formatWebhookInput, +} from "@/lib/webhooks/utils.server"; import { executeWorkflowCore, wasExecutionFinalizedByCore, -} from '@/lib/workflows/executor/execution-core' -import { PauseResumeManager } from '@/lib/workflows/executor/human-in-the-loop-manager' -import { loadDeployedWorkflowState } from '@/lib/workflows/persistence/utils' -import { resolveOAuthAccountId } from '@/app/api/auth/oauth/utils' -import { getBlock } from '@/blocks' -import { ExecutionSnapshot } from '@/executor/execution/snapshot' -import type { ExecutionMetadata } from '@/executor/execution/types' -import { hasExecutionResult } from '@/executor/utils/errors' -import { safeAssign } from '@/tools/safe-assign' -import { getTrigger, isTriggerValid } from '@/triggers' - -const logger = createLogger('TriggerWebhookExecution') +} from "@/lib/workflows/executor/execution-core"; +import { PauseResumeManager } from "@/lib/workflows/executor/human-in-the-loop-manager"; +import { loadDeployedWorkflowState } from "@/lib/workflows/persistence/utils"; +import { resolveOAuthAccountId } from "@/app/api/auth/oauth/utils"; +import { getBlock } from "@/blocks"; +import { ExecutionSnapshot } from "@/executor/execution/snapshot"; +import type { ExecutionMetadata } from "@/executor/execution/types"; +import { hasExecutionResult } from "@/executor/utils/errors"; +import { safeAssign } from "@/tools/safe-assign"; +import { getTrigger, isTriggerValid } from "@/triggers"; + +const logger = createLogger("TriggerWebhookExecution"); + +export function buildWebhookCorrelation( + payload: WebhookExecutionPayload, +): AsyncExecutionCorrelation { + const executionId = payload.executionId || uuidv4(); + const requestId = + payload.requestId || + payload.correlation?.requestId || + executionId.slice(0, 8); + + return { + executionId, + requestId, + source: "webhook", + workflowId: payload.workflowId, + webhookId: payload.webhookId, + path: payload.path, + provider: payload.provider, + triggerType: payload.correlation?.triggerType || "webhook", + }; +} /** * Process trigger outputs based on their schema definitions @@ -36,47 +64,54 @@ async function processTriggerFileOutputs( input: any, triggerOutputs: Record, context: { - workspaceId: string - workflowId: string - executionId: string - requestId: string - userId?: string + workspaceId: string; + workflowId: string; + executionId: string; + requestId: string; + userId?: string; }, - path = '' + path = "", ): Promise { - if (!input || typeof input !== 'object') { - return input + if (!input || typeof input !== "object") { + return input; } - const processed: any = Array.isArray(input) ? [] : {} + const processed: any = Array.isArray(input) ? [] : {}; for (const [key, value] of Object.entries(input)) { - const currentPath = path ? `${path}.${key}` : key - const outputDef = triggerOutputs[key] - const val: any = value + const currentPath = path ? `${path}.${key}` : key; + const outputDef = triggerOutputs[key]; + const val: any = value; // If this field is marked as file or file[], process it - if (outputDef?.type === 'file[]' && Array.isArray(val)) { + if (outputDef?.type === "file[]" && Array.isArray(val)) { try { - processed[key] = await WebhookAttachmentProcessor.processAttachments(val as any, context) + processed[key] = await WebhookAttachmentProcessor.processAttachments( + val as any, + context, + ); } catch (error) { - processed[key] = [] + processed[key] = []; } - } else if (outputDef?.type === 'file' && val) { + } else if (outputDef?.type === "file" && val) { try { - const [processedFile] = await WebhookAttachmentProcessor.processAttachments( - [val as any], - context - ) - processed[key] = processedFile + const [processedFile] = + await WebhookAttachmentProcessor.processAttachments( + [val as any], + context, + ); + processed[key] = processedFile; } catch (error) { - logger.error(`[${context.requestId}] Error processing ${currentPath}:`, error) - processed[key] = val + logger.error( + `[${context.requestId}] Error processing ${currentPath}:`, + error, + ); + processed[key] = val; } } else if ( outputDef && - typeof outputDef === 'object' && - (outputDef.type === 'object' || outputDef.type === 'json') && + typeof outputDef === "object" && + (outputDef.type === "object" || outputDef.type === "json") && outputDef.properties ) { // Explicit object schema with properties - recurse into properties @@ -84,36 +119,45 @@ async function processTriggerFileOutputs( val, outputDef.properties, context, - currentPath - ) - } else if (outputDef && typeof outputDef === 'object' && !outputDef.type) { + currentPath, + ); + } else if (outputDef && typeof outputDef === "object" && !outputDef.type) { // Nested object in schema (flat pattern) - recurse with the nested schema - processed[key] = await processTriggerFileOutputs(val, outputDef, context, currentPath) + processed[key] = await processTriggerFileOutputs( + val, + outputDef, + context, + currentPath, + ); } else { // Not a file output - keep as is - processed[key] = val + processed[key] = val; } } - return processed + return processed; } export type WebhookExecutionPayload = { - webhookId: string - workflowId: string - userId: string - provider: string - body: any - headers: Record - path: string - blockId?: string - workspaceId?: string - credentialId?: string -} + webhookId: string; + workflowId: string; + userId: string; + executionId?: string; + requestId?: string; + correlation?: AsyncExecutionCorrelation; + provider: string; + body: any; + headers: Record; + path: string; + blockId?: string; + workspaceId?: string; + credentialId?: string; +}; export async function executeWebhookJob(payload: WebhookExecutionPayload) { - const executionId = uuidv4() - const requestId = executionId.slice(0, 8) + const correlation = buildWebhookCorrelation(payload); + const executionId = correlation.executionId; + const requestId = correlation.requestId; logger.info(`[${requestId}] Starting webhook execution`, { webhookId: payload.webhookId, @@ -121,59 +165,61 @@ export async function executeWebhookJob(payload: WebhookExecutionPayload) { provider: payload.provider, userId: payload.userId, executionId, - }) + }); const idempotencyKey = IdempotencyService.createWebhookIdempotencyKey( payload.webhookId, payload.headers, payload.body, - payload.provider - ) + payload.provider, + ); const runOperation = async () => { - return await executeWebhookJobInternal(payload, executionId, requestId) - } + return await executeWebhookJobInternal(payload, correlation); + }; return await webhookIdempotency.executeWithIdempotency( payload.provider, idempotencyKey, - runOperation - ) + runOperation, + ); } /** * Resolve the account userId for a credential */ -async function resolveCredentialAccountUserId(credentialId: string): Promise { - const resolved = await resolveOAuthAccountId(credentialId) +async function resolveCredentialAccountUserId( + credentialId: string, +): Promise { + const resolved = await resolveOAuthAccountId(credentialId); if (!resolved) { - return undefined + return undefined; } const [credentialRecord] = await db .select({ userId: account.userId }) .from(account) .where(eq(account.id, resolved.accountId)) - .limit(1) - return credentialRecord?.userId + .limit(1); + return credentialRecord?.userId; } async function executeWebhookJobInternal( payload: WebhookExecutionPayload, - executionId: string, - requestId: string + correlation: AsyncExecutionCorrelation, ) { + const { executionId, requestId } = correlation; const loggingSession = new LoggingSession( payload.workflowId, executionId, payload.provider, - requestId - ) + requestId, + ); // Resolve workflow record, billing actor, subscription, and timeout const preprocessResult = await preprocessExecution({ workflowId: payload.workflowId, userId: payload.userId, - triggerType: 'webhook', + triggerType: "webhook", executionId, requestId, checkRateLimit: false, @@ -181,84 +227,99 @@ async function executeWebhookJobInternal( skipUsageLimits: true, workspaceId: payload.workspaceId, loggingSession, - }) + }); if (!preprocessResult.success) { - throw new Error(preprocessResult.error?.message || 'Preprocessing failed in background job') + throw new Error( + preprocessResult.error?.message || + "Preprocessing failed in background job", + ); } - const { workflowRecord, executionTimeout } = preprocessResult + const { workflowRecord, executionTimeout } = preprocessResult; if (!workflowRecord) { - throw new Error(`Workflow ${payload.workflowId} not found during preprocessing`) + throw new Error( + `Workflow ${payload.workflowId} not found during preprocessing`, + ); } - const workspaceId = workflowRecord.workspaceId + const workspaceId = workflowRecord.workspaceId; if (!workspaceId) { - throw new Error(`Workflow ${payload.workflowId} has no associated workspace`) + throw new Error( + `Workflow ${payload.workflowId} has no associated workspace`, + ); } - const workflowVariables = (workflowRecord.variables as Record) || {} - const asyncTimeout = executionTimeout?.async ?? 120_000 - const timeoutController = createTimeoutAbortController(asyncTimeout) + const workflowVariables = + (workflowRecord.variables as Record) || {}; + const asyncTimeout = executionTimeout?.async ?? 120_000; + const timeoutController = createTimeoutAbortController(asyncTimeout); - let deploymentVersionId: string | undefined + let deploymentVersionId: string | undefined; try { // Parallelize workflow state, webhook record, and credential resolution - const [workflowData, webhookRows, resolvedCredentialUserId] = await Promise.all([ - loadDeployedWorkflowState(payload.workflowId, workspaceId), - db.select().from(webhook).where(eq(webhook.id, payload.webhookId)).limit(1), - payload.credentialId - ? resolveCredentialAccountUserId(payload.credentialId) - : Promise.resolve(undefined), - ]) - const credentialAccountUserId = resolvedCredentialUserId + const [workflowData, webhookRows, resolvedCredentialUserId] = + await Promise.all([ + loadDeployedWorkflowState(payload.workflowId, workspaceId), + db + .select() + .from(webhook) + .where(eq(webhook.id, payload.webhookId)) + .limit(1), + payload.credentialId + ? resolveCredentialAccountUserId(payload.credentialId) + : Promise.resolve(undefined), + ]); + const credentialAccountUserId = resolvedCredentialUserId; if (payload.credentialId && !credentialAccountUserId) { logger.warn( - `[${requestId}] Failed to resolve credential account for credential ${payload.credentialId}` - ) + `[${requestId}] Failed to resolve credential account for credential ${payload.credentialId}`, + ); } if (!workflowData) { throw new Error( - 'Workflow state not found. The workflow may not be deployed or the deployment data may be corrupted.' - ) + "Workflow state not found. The workflow may not be deployed or the deployment data may be corrupted.", + ); } - const { blocks, edges, loops, parallels } = workflowData + const { blocks, edges, loops, parallels } = workflowData; deploymentVersionId = - 'deploymentVersionId' in workflowData + "deploymentVersionId" in workflowData ? (workflowData.deploymentVersionId as string) - : undefined + : undefined; // Handle special Airtable case - if (payload.provider === 'airtable') { - logger.info(`[${requestId}] Processing Airtable webhook via fetchAndProcessAirtablePayloads`) + if (payload.provider === "airtable") { + logger.info( + `[${requestId}] Processing Airtable webhook via fetchAndProcessAirtablePayloads`, + ); - const webhookRecord = webhookRows[0] + const webhookRecord = webhookRows[0]; if (!webhookRecord) { - throw new Error(`Webhook record not found: ${payload.webhookId}`) + throw new Error(`Webhook record not found: ${payload.webhookId}`); } const webhookData = { id: payload.webhookId, provider: payload.provider, providerConfig: webhookRecord.providerConfig, - } + }; const mockWorkflow = { id: payload.workflowId, userId: payload.userId, - } + }; const airtableInput = await fetchAndProcessAirtablePayloads( webhookData, mockWorkflow, - requestId - ) + requestId, + ); if (airtableInput) { - logger.info(`[${requestId}] Executing workflow with Airtable changes`) + logger.info(`[${requestId}] Executing workflow with Airtable changes`); const metadata: ExecutionMetadata = { requestId, @@ -268,12 +329,13 @@ async function executeWebhookJobInternal( userId: payload.userId, sessionUserId: undefined, workflowUserId: workflowRecord.userId, - triggerType: payload.provider || 'webhook', + triggerType: payload.provider || "webhook", triggerBlockId: payload.blockId, useDraftState: false, startTime: new Date().toISOString(), isClientSession: false, credentialAccountUserId, + correlation, workflowStateOverride: { blocks, edges, @@ -281,15 +343,15 @@ async function executeWebhookJobInternal( parallels: parallels || {}, deploymentVersionId, }, - } + }; const snapshot = new ExecutionSnapshot( metadata, workflowRecord, airtableInput, workflowVariables, - [] - ) + [], + ); const executionResult = await executeWorkflowCore({ snapshot, @@ -298,24 +360,32 @@ async function executeWebhookJobInternal( includeFileBase64: true, base64MaxBytes: undefined, abortSignal: timeoutController.signal, - }) + }); if ( - executionResult.status === 'cancelled' && + executionResult.status === "cancelled" && timeoutController.isTimedOut() && timeoutController.timeoutMs ) { - const timeoutErrorMessage = getTimeoutErrorMessage(null, timeoutController.timeoutMs) + const timeoutErrorMessage = getTimeoutErrorMessage( + null, + timeoutController.timeoutMs, + ); logger.info(`[${requestId}] Airtable webhook execution timed out`, { timeoutMs: timeoutController.timeoutMs, - }) - await loggingSession.markAsFailed(timeoutErrorMessage) - } else if (executionResult.status === 'paused') { + }); + await loggingSession.markAsFailed(timeoutErrorMessage); + } else if (executionResult.status === "paused") { if (!executionResult.snapshotSeed) { - logger.error(`[${requestId}] Missing snapshot seed for paused execution`, { - executionId, - }) - await loggingSession.markAsFailed('Missing snapshot seed for paused execution') + logger.error( + `[${requestId}] Missing snapshot seed for paused execution`, + { + executionId, + }, + ); + await loggingSession.markAsFailed( + "Missing snapshot seed for paused execution", + ); } else { try { await PauseResumeManager.persistPauseResult({ @@ -324,25 +394,28 @@ async function executeWebhookJobInternal( pausePoints: executionResult.pausePoints || [], snapshotSeed: executionResult.snapshotSeed, executorUserId: executionResult.metadata?.userId, - }) + }); } catch (pauseError) { logger.error(`[${requestId}] Failed to persist pause result`, { executionId, - error: pauseError instanceof Error ? pauseError.message : String(pauseError), - }) + error: + pauseError instanceof Error + ? pauseError.message + : String(pauseError), + }); await loggingSession.markAsFailed( - `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}` - ) + `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}`, + ); } } } else { - await PauseResumeManager.processQueuedResumes(executionId) + await PauseResumeManager.processQueuedResumes(executionId); } logger.info(`[${requestId}] Airtable webhook execution completed`, { success: executionResult.success, workflowId: payload.workflowId, - }) + }); return { success: executionResult.success, @@ -351,10 +424,10 @@ async function executeWebhookJobInternal( output: executionResult.output, executedAt: new Date().toISOString(), provider: payload.provider, - } + }; } // No changes to process - logger.info(`[${requestId}] No Airtable changes to process`) + logger.info(`[${requestId}] No Airtable changes to process`); await loggingSession.safeStart({ userId: payload.userId, @@ -362,24 +435,25 @@ async function executeWebhookJobInternal( variables: {}, triggerData: { isTest: false, + correlation, }, deploymentVersionId, - }) + }); await loggingSession.safeComplete({ endedAt: new Date().toISOString(), totalDurationMs: 0, - finalOutput: { message: 'No Airtable changes to process' }, + finalOutput: { message: "No Airtable changes to process" }, traceSpans: [], - }) + }); return { success: true, workflowId: payload.workflowId, executionId, - output: { message: 'No Airtable changes to process' }, + output: { message: "No Airtable changes to process" }, executedAt: new Date().toISOString(), - } + }; } // Format input for standard webhooks @@ -390,20 +464,27 @@ async function executeWebhookJobInternal( provider: payload.provider, blockId: payload.blockId, providerConfig: {}, - } + }; const mockWorkflow = { id: payload.workflowId, userId: payload.userId, - } + }; const mockRequest = { headers: new Map(Object.entries(payload.headers)), - } as any + } as any; - const input = await formatWebhookInput(actualWebhook, mockWorkflow, payload.body, mockRequest) + const input = await formatWebhookInput( + actualWebhook, + mockWorkflow, + payload.body, + mockRequest, + ); - if (!input && payload.provider === 'whatsapp') { - logger.info(`[${requestId}] No messages in WhatsApp payload, skipping execution`) + if (!input && payload.provider === "whatsapp") { + logger.info( + `[${requestId}] No messages in WhatsApp payload, skipping execution`, + ); await loggingSession.safeStart({ userId: payload.userId, @@ -411,115 +492,153 @@ async function executeWebhookJobInternal( variables: {}, triggerData: { isTest: false, + correlation, }, deploymentVersionId, - }) + }); await loggingSession.safeComplete({ endedAt: new Date().toISOString(), totalDurationMs: 0, - finalOutput: { message: 'No messages in WhatsApp payload' }, + finalOutput: { message: "No messages in WhatsApp payload" }, traceSpans: [], - }) + }); return { success: true, workflowId: payload.workflowId, executionId, - output: { message: 'No messages in WhatsApp payload' }, + output: { message: "No messages in WhatsApp payload" }, executedAt: new Date().toISOString(), - } + }; } // Process trigger file outputs based on schema if (input && payload.blockId && blocks[payload.blockId]) { try { - const triggerBlock = blocks[payload.blockId] - const rawSelectedTriggerId = triggerBlock?.subBlocks?.selectedTriggerId?.value - const rawTriggerId = triggerBlock?.subBlocks?.triggerId?.value + const triggerBlock = blocks[payload.blockId]; + const rawSelectedTriggerId = + triggerBlock?.subBlocks?.selectedTriggerId?.value; + const rawTriggerId = triggerBlock?.subBlocks?.triggerId?.value; let resolvedTriggerId = [rawSelectedTriggerId, rawTriggerId].find( (candidate): candidate is string => - typeof candidate === 'string' && isTriggerValid(candidate) - ) + typeof candidate === "string" && isTriggerValid(candidate), + ); if (!resolvedTriggerId) { - const blockConfig = getBlock(triggerBlock.type) - if (blockConfig?.category === 'triggers' && isTriggerValid(triggerBlock.type)) { - resolvedTriggerId = triggerBlock.type - } else if (triggerBlock.triggerMode && blockConfig?.triggers?.enabled) { - const available = blockConfig.triggers?.available?.[0] + const blockConfig = getBlock(triggerBlock.type); + if ( + blockConfig?.category === "triggers" && + isTriggerValid(triggerBlock.type) + ) { + resolvedTriggerId = triggerBlock.type; + } else if ( + triggerBlock.triggerMode && + blockConfig?.triggers?.enabled + ) { + const available = blockConfig.triggers?.available?.[0]; if (available && isTriggerValid(available)) { - resolvedTriggerId = available + resolvedTriggerId = available; } } } if (resolvedTriggerId) { - const triggerConfig = getTrigger(resolvedTriggerId) + const triggerConfig = getTrigger(resolvedTriggerId); if (triggerConfig.outputs) { - const processedInput = await processTriggerFileOutputs(input, triggerConfig.outputs, { - workspaceId, - workflowId: payload.workflowId, - executionId, - requestId, - userId: payload.userId, - }) - safeAssign(input, processedInput as Record) + const processedInput = await processTriggerFileOutputs( + input, + triggerConfig.outputs, + { + workspaceId, + workflowId: payload.workflowId, + executionId, + requestId, + userId: payload.userId, + }, + ); + safeAssign(input, processedInput as Record); } } } catch (error) { - logger.error(`[${requestId}] Error processing trigger file outputs:`, error) + logger.error( + `[${requestId}] Error processing trigger file outputs:`, + error, + ); } } // Process generic webhook files based on inputFormat - if (input && payload.provider === 'generic' && payload.blockId && blocks[payload.blockId]) { + if ( + input && + payload.provider === "generic" && + payload.blockId && + blocks[payload.blockId] + ) { try { - const triggerBlock = blocks[payload.blockId] + const triggerBlock = blocks[payload.blockId]; if (triggerBlock?.subBlocks?.inputFormat?.value) { - const inputFormat = triggerBlock.subBlocks.inputFormat.value as unknown as Array<{ - name: string - type: 'string' | 'number' | 'boolean' | 'object' | 'array' | 'file[]' - }> - - const fileFields = inputFormat.filter((field) => field.type === 'file[]') - - if (fileFields.length > 0 && typeof input === 'object' && input !== null) { + const inputFormat = triggerBlock.subBlocks.inputFormat + .value as unknown as Array<{ + name: string; + type: + | "string" + | "number" + | "boolean" + | "object" + | "array" + | "file[]"; + }>; + + const fileFields = inputFormat.filter( + (field) => field.type === "file[]", + ); + + if ( + fileFields.length > 0 && + typeof input === "object" && + input !== null + ) { const executionContext = { workspaceId, workflowId: payload.workflowId, executionId, - } + }; for (const fileField of fileFields) { - const fieldValue = input[fileField.name] + const fieldValue = input[fileField.name]; - if (fieldValue && typeof fieldValue === 'object') { + if (fieldValue && typeof fieldValue === "object") { const uploadedFiles = await processExecutionFiles( fieldValue, executionContext, requestId, - payload.userId - ) + payload.userId, + ); if (uploadedFiles.length > 0) { - input[fileField.name] = uploadedFiles + input[fileField.name] = uploadedFiles; logger.info( - `[${requestId}] Successfully processed ${uploadedFiles.length} file(s) for field: ${fileField.name}` - ) + `[${requestId}] Successfully processed ${uploadedFiles.length} file(s) for field: ${fileField.name}`, + ); } } } } } } catch (error) { - logger.error(`[${requestId}] Error processing generic webhook files:`, error) + logger.error( + `[${requestId}] Error processing generic webhook files:`, + error, + ); } } - logger.info(`[${requestId}] Executing workflow for ${payload.provider} webhook`) + logger.info( + `[${requestId}] Executing workflow for ${payload.provider} webhook`, + ); const metadata: ExecutionMetadata = { requestId, @@ -529,12 +648,13 @@ async function executeWebhookJobInternal( userId: payload.userId, sessionUserId: undefined, workflowUserId: workflowRecord.userId, - triggerType: payload.provider || 'webhook', + triggerType: payload.provider || "webhook", triggerBlockId: payload.blockId, useDraftState: false, startTime: new Date().toISOString(), isClientSession: false, credentialAccountUserId, + correlation, workflowStateOverride: { blocks, edges, @@ -542,17 +662,17 @@ async function executeWebhookJobInternal( parallels: parallels || {}, deploymentVersionId, }, - } + }; - const triggerInput = input || {} + const triggerInput = input || {}; const snapshot = new ExecutionSnapshot( metadata, workflowRecord, triggerInput, workflowVariables, - [] - ) + [], + ); const executionResult = await executeWorkflowCore({ snapshot, @@ -560,24 +680,32 @@ async function executeWebhookJobInternal( loggingSession, includeFileBase64: true, abortSignal: timeoutController.signal, - }) + }); if ( - executionResult.status === 'cancelled' && + executionResult.status === "cancelled" && timeoutController.isTimedOut() && timeoutController.timeoutMs ) { - const timeoutErrorMessage = getTimeoutErrorMessage(null, timeoutController.timeoutMs) + const timeoutErrorMessage = getTimeoutErrorMessage( + null, + timeoutController.timeoutMs, + ); logger.info(`[${requestId}] Webhook execution timed out`, { timeoutMs: timeoutController.timeoutMs, - }) - await loggingSession.markAsFailed(timeoutErrorMessage) - } else if (executionResult.status === 'paused') { + }); + await loggingSession.markAsFailed(timeoutErrorMessage); + } else if (executionResult.status === "paused") { if (!executionResult.snapshotSeed) { - logger.error(`[${requestId}] Missing snapshot seed for paused execution`, { - executionId, - }) - await loggingSession.markAsFailed('Missing snapshot seed for paused execution') + logger.error( + `[${requestId}] Missing snapshot seed for paused execution`, + { + executionId, + }, + ); + await loggingSession.markAsFailed( + "Missing snapshot seed for paused execution", + ); } else { try { await PauseResumeManager.persistPauseResult({ @@ -586,26 +714,29 @@ async function executeWebhookJobInternal( pausePoints: executionResult.pausePoints || [], snapshotSeed: executionResult.snapshotSeed, executorUserId: executionResult.metadata?.userId, - }) + }); } catch (pauseError) { logger.error(`[${requestId}] Failed to persist pause result`, { executionId, - error: pauseError instanceof Error ? pauseError.message : String(pauseError), - }) + error: + pauseError instanceof Error + ? pauseError.message + : String(pauseError), + }); await loggingSession.markAsFailed( - `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}` - ) + `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}`, + ); } } } else { - await PauseResumeManager.processQueuedResumes(executionId) + await PauseResumeManager.processQueuedResumes(executionId); } logger.info(`[${requestId}] Webhook execution completed`, { success: executionResult.success, workflowId: payload.workflowId, provider: payload.provider, - }) + }); return { success: executionResult.success, @@ -614,20 +745,20 @@ async function executeWebhookJobInternal( output: executionResult.output, executedAt: new Date().toISOString(), provider: payload.provider, - } + }; } catch (error: unknown) { - const errorMessage = error instanceof Error ? error.message : String(error) - const errorStack = error instanceof Error ? error.stack : undefined + const errorMessage = error instanceof Error ? error.message : String(error); + const errorStack = error instanceof Error ? error.stack : undefined; logger.error(`[${requestId}] Webhook execution failed`, { error: errorMessage, stack: errorStack, workflowId: payload.workflowId, provider: payload.provider, - }) + }); if (wasExecutionFinalizedByCore(error, executionId)) { - throw error + throw error; } try { @@ -637,9 +768,10 @@ async function executeWebhookJobInternal( variables: {}, triggerData: { isTest: false, + correlation, }, deploymentVersionId, - }) + }); const executionResult = hasExecutionResult(error) ? error.executionResult @@ -647,33 +779,36 @@ async function executeWebhookJobInternal( success: false, output: {}, logs: [], - } - const { traceSpans } = buildTraceSpans(executionResult) + }; + const { traceSpans } = buildTraceSpans(executionResult); await loggingSession.safeCompleteWithError({ endedAt: new Date().toISOString(), totalDurationMs: 0, error: { - message: errorMessage || 'Webhook execution failed', + message: errorMessage || "Webhook execution failed", stackTrace: errorStack, }, traceSpans, - }) + }); } catch (loggingError) { - logger.error(`[${requestId}] Failed to complete logging session`, loggingError) + logger.error( + `[${requestId}] Failed to complete logging session`, + loggingError, + ); } - throw error + throw error; } finally { - timeoutController.cleanup() + timeoutController.cleanup(); } } export const webhookExecution = task({ - id: 'webhook-execution', - machine: 'medium-1x', + id: "webhook-execution", + machine: "medium-1x", retry: { maxAttempts: 1, }, run: async (payload: WebhookExecutionPayload) => executeWebhookJob(payload), -}) +}); diff --git a/apps/sim/background/workflow-execution.ts b/apps/sim/background/workflow-execution.ts index 360cbd4548d..9188b9d5565 100644 --- a/apps/sim/background/workflow-execution.ts +++ b/apps/sim/background/workflow-execution.ts @@ -1,6 +1,7 @@ import { createLogger } from '@sim/logger' import { task } from '@trigger.dev/sdk' import { v4 as uuidv4 } from 'uuid' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core/execution-limits' import { preprocessExecution } from '@/lib/execution/preprocessing' import { LoggingSession } from '@/lib/logs/execution/logging-session' @@ -17,12 +18,29 @@ import type { CoreTriggerType } from '@/stores/logs/filters/types' const logger = createLogger('TriggerWorkflowExecution') +export function buildWorkflowCorrelation( + payload: WorkflowExecutionPayload +): AsyncExecutionCorrelation { + const executionId = payload.executionId || uuidv4() + const requestId = payload.requestId || payload.correlation?.requestId || executionId.slice(0, 8) + + return { + executionId, + requestId, + source: 'workflow', + workflowId: payload.workflowId, + triggerType: payload.triggerType || payload.correlation?.triggerType || 'api', + } +} + export type WorkflowExecutionPayload = { workflowId: string userId: string input?: any triggerType?: CoreTriggerType executionId?: string + requestId?: string + correlation?: AsyncExecutionCorrelation metadata?: Record callChain?: string[] } @@ -34,8 +52,9 @@ export type WorkflowExecutionPayload = { */ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { const workflowId = payload.workflowId - const executionId = payload.executionId || uuidv4() - const requestId = executionId.slice(0, 8) + const correlation = buildWorkflowCorrelation(payload) + const executionId = correlation.executionId + const requestId = correlation.requestId logger.info(`[${requestId}] Starting workflow execution job: ${workflowId}`, { userId: payload.userId, @@ -43,7 +62,7 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { executionId, }) - const triggerType = payload.triggerType || 'api' + const triggerType = (correlation.triggerType || 'api') as CoreTriggerType const loggingSession = new LoggingSession(workflowId, executionId, triggerType, requestId) try { @@ -56,6 +75,7 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { checkRateLimit: true, checkDeployment: true, loggingSession: loggingSession, + triggerData: { correlation }, }) if (!preprocessResult.success) { @@ -79,6 +99,7 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { userId: actorUserId, workspaceId, variables: {}, + triggerData: { correlation }, }) const workflow = preprocessResult.workflowRecord! @@ -96,6 +117,7 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { startTime: new Date().toISOString(), isClientSession: false, callChain: payload.callChain, + correlation, } const snapshot = new ExecutionSnapshot( diff --git a/apps/sim/executor/execution/types.ts b/apps/sim/executor/execution/types.ts index 933aaa20604..b343be9f977 100644 --- a/apps/sim/executor/execution/types.ts +++ b/apps/sim/executor/execution/types.ts @@ -1,4 +1,5 @@ import type { Edge } from 'reactflow' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' import type { NodeMetadata } from '@/executor/dag/types' import type { BlockLog, @@ -34,6 +35,7 @@ export interface ExecutionMetadata { deploymentVersionId?: string } callChain?: string[] + correlation?: AsyncExecutionCorrelation } export interface SerializableExecutionState { diff --git a/apps/sim/lib/core/async-jobs/backends/trigger-dev.ts b/apps/sim/lib/core/async-jobs/backends/trigger-dev.ts index 18b01a3c228..436024e24ca 100644 --- a/apps/sim/lib/core/async-jobs/backends/trigger-dev.ts +++ b/apps/sim/lib/core/async-jobs/backends/trigger-dev.ts @@ -80,6 +80,10 @@ export class TriggerDevJobQueue implements JobQueueBackend { const metadata: JobMetadata = { workflowId: payload?.workflowId as string | undefined, userId: payload?.userId as string | undefined, + correlation: + payload?.correlation && typeof payload.correlation === 'object' + ? (payload.correlation as JobMetadata['correlation']) + : undefined, } return { diff --git a/apps/sim/lib/core/async-jobs/types.ts b/apps/sim/lib/core/async-jobs/types.ts index 398513b69f2..27137ddadc3 100644 --- a/apps/sim/lib/core/async-jobs/types.ts +++ b/apps/sim/lib/core/async-jobs/types.ts @@ -22,6 +22,21 @@ export type JobStatus = (typeof JOB_STATUS)[keyof typeof JOB_STATUS] export type JobType = 'workflow-execution' | 'schedule-execution' | 'webhook-execution' +export type AsyncExecutionCorrelationSource = 'workflow' | 'schedule' | 'webhook' + +export interface AsyncExecutionCorrelation { + executionId: string + requestId: string + source: AsyncExecutionCorrelationSource + workflowId: string + triggerType?: string + webhookId?: string + scheduleId?: string + path?: string + provider?: string + scheduledFor?: string +} + export interface Job { id: string type: JobType @@ -40,6 +55,7 @@ export interface Job { export interface JobMetadata { workflowId?: string userId?: string + correlation?: AsyncExecutionCorrelation [key: string]: unknown } diff --git a/apps/sim/lib/execution/preprocessing.test.ts b/apps/sim/lib/execution/preprocessing.test.ts new file mode 100644 index 00000000000..6d9258b341c --- /dev/null +++ b/apps/sim/lib/execution/preprocessing.test.ts @@ -0,0 +1,92 @@ +/** + * @vitest-environment node + */ + +import { describe, expect, it, vi } from 'vitest' + +const { mockGetWorkspaceBilledAccountUserId } = vi.hoisted(() => ({ + mockGetWorkspaceBilledAccountUserId: vi.fn(), +})) + +vi.mock('@sim/db', () => ({ db: {} })) +vi.mock('@sim/db/schema', () => ({ workflow: {} })) +vi.mock('@sim/logger', () => ({ + createLogger: vi.fn().mockReturnValue({ + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }), +})) +vi.mock('drizzle-orm', () => ({ eq: vi.fn() })) +vi.mock('@/lib/billing/calculations/usage-monitor', () => ({ + checkServerSideUsageLimits: vi.fn(), +})) +vi.mock('@/lib/billing/core/subscription', () => ({ + getHighestPrioritySubscription: vi.fn(), +})) +vi.mock('@/lib/core/execution-limits', () => ({ + getExecutionTimeout: vi.fn(() => 0), +})) +vi.mock('@/lib/core/rate-limiter/rate-limiter', () => ({ + RateLimiter: vi.fn(), +})) +vi.mock('@/lib/logs/execution/logging-session', () => ({ + LoggingSession: vi.fn(), +})) +vi.mock('@/lib/workspaces/utils', () => ({ + getWorkspaceBilledAccountUserId: mockGetWorkspaceBilledAccountUserId, +})) + +import { preprocessExecution } from './preprocessing' + +describe('preprocessExecution correlation logging', () => { + it('preserves trigger correlation when logging preprocessing failures', async () => { + mockGetWorkspaceBilledAccountUserId.mockResolvedValueOnce(null) + + const loggingSession = { + safeStart: vi.fn().mockResolvedValue(true), + safeCompleteWithError: vi.fn().mockResolvedValue(undefined), + } + + const correlation = { + executionId: 'execution-1', + requestId: 'request-1', + source: 'schedule' as const, + workflowId: 'workflow-1', + scheduleId: 'schedule-1', + triggerType: 'schedule', + scheduledFor: '2025-01-01T00:00:00.000Z', + } + + const result = await preprocessExecution({ + workflowId: 'workflow-1', + userId: 'unknown', + triggerType: 'schedule', + executionId: 'execution-1', + requestId: 'request-1', + loggingSession: loggingSession as any, + triggerData: { correlation }, + workflowRecord: { + id: 'workflow-1', + workspaceId: 'workspace-1', + isDeployed: true, + } as any, + }) + + expect(result).toMatchObject({ + success: false, + error: { + statusCode: 500, + logCreated: true, + }, + }) + + expect(loggingSession.safeStart).toHaveBeenCalledWith({ + userId: 'unknown', + workspaceId: 'workspace-1', + variables: {}, + triggerData: { correlation }, + }) + }) +}) diff --git a/apps/sim/lib/execution/preprocessing.ts b/apps/sim/lib/execution/preprocessing.ts index 90bbfcdfd34..a86c2ca0ebf 100644 --- a/apps/sim/lib/execution/preprocessing.ts +++ b/apps/sim/lib/execution/preprocessing.ts @@ -8,7 +8,7 @@ import { getHighestPrioritySubscription } from '@/lib/billing/core/subscription' import { getExecutionTimeout } from '@/lib/core/execution-limits' import { RateLimiter } from '@/lib/core/rate-limiter/rate-limiter' import type { SubscriptionPlan } from '@/lib/core/rate-limiter/types' -import { LoggingSession } from '@/lib/logs/execution/logging-session' +import { LoggingSession, type SessionStartParams } from '@/lib/logs/execution/logging-session' import { getWorkspaceBilledAccountUserId } from '@/lib/workspaces/utils' import type { CoreTriggerType } from '@/stores/logs/filters/types' @@ -36,6 +36,7 @@ export interface PreprocessExecutionOptions { // Context information workspaceId?: string // If known, used for billing resolution loggingSession?: LoggingSession // If provided, will be used for error logging + triggerData?: SessionStartParams['triggerData'] isResumeContext?: boolean // Deprecated: no billing fallback is allowed useAuthenticatedUserAsActor?: boolean // If true, use the authenticated userId as actorUserId (for client-side executions and personal API keys) /** @deprecated No longer used - background/async executions always use deployed state */ @@ -85,6 +86,7 @@ export async function preprocessExecution( skipUsageLimits = false, workspaceId: providedWorkspaceId, loggingSession: providedLoggingSession, + triggerData, isResumeContext: _isResumeContext = false, useAuthenticatedUserAsActor = false, workflowRecord: prefetchedWorkflowRecord, @@ -125,6 +127,7 @@ export async function preprocessExecution( errorMessage: 'Workflow not found. The workflow may have been deleted or is no longer accessible.', loggingSession: providedLoggingSession, + triggerData, }) return { @@ -150,6 +153,7 @@ export async function preprocessExecution( workspaceId: providedWorkspaceId || '', errorMessage: 'Internal error while fetching workflow', loggingSession: providedLoggingSession, + triggerData, }) return { @@ -229,6 +233,7 @@ export async function preprocessExecution( workspaceId, errorMessage: BILLING_ERROR_MESSAGES.BILLING_REQUIRED, loggingSession: providedLoggingSession, + triggerData, }) return { @@ -252,6 +257,7 @@ export async function preprocessExecution( workspaceId, errorMessage: BILLING_ERROR_MESSAGES.BILLING_ERROR_GENERIC, loggingSession: providedLoggingSession, + triggerData, }) return { @@ -293,6 +299,7 @@ export async function preprocessExecution( usageCheck.message || `Usage limit exceeded: $${usageCheck.currentUsage?.toFixed(2)} used of $${usageCheck.limit?.toFixed(2)} limit. Please upgrade your plan to continue.`, loggingSession: providedLoggingSession, + triggerData, }) return { @@ -321,6 +328,7 @@ export async function preprocessExecution( errorMessage: 'Unable to determine usage limits. Execution blocked for security. Please contact support.', loggingSession: providedLoggingSession, + triggerData, }) return { @@ -363,6 +371,7 @@ export async function preprocessExecution( workspaceId, errorMessage: `Rate limit exceeded. ${rateLimitInfo.remaining} requests remaining. Resets at ${rateLimitInfo.resetAt.toISOString()}.`, loggingSession: providedLoggingSession, + triggerData, }) return { @@ -386,6 +395,7 @@ export async function preprocessExecution( workspaceId, errorMessage: 'Error checking rate limits. Execution blocked for safety.', loggingSession: providedLoggingSession, + triggerData, }) return { @@ -434,6 +444,7 @@ async function logPreprocessingError(params: { workspaceId: string errorMessage: string loggingSession?: LoggingSession + triggerData?: SessionStartParams['triggerData'] }): Promise { const { workflowId, @@ -444,6 +455,7 @@ async function logPreprocessingError(params: { workspaceId, errorMessage, loggingSession, + triggerData, } = params if (!workspaceId) { @@ -463,6 +475,7 @@ async function logPreprocessingError(params: { userId, workspaceId, variables: {}, + triggerData, }) await session.safeCompleteWithError({ diff --git a/apps/sim/lib/execution/preprocessing.webhook-correlation.test.ts b/apps/sim/lib/execution/preprocessing.webhook-correlation.test.ts new file mode 100644 index 00000000000..dbb975359cc --- /dev/null +++ b/apps/sim/lib/execution/preprocessing.webhook-correlation.test.ts @@ -0,0 +1,93 @@ +/** + * @vitest-environment node + */ + +import { describe, expect, it, vi } from 'vitest' + +const { mockGetWorkspaceBilledAccountUserId } = vi.hoisted(() => ({ + mockGetWorkspaceBilledAccountUserId: vi.fn(), +})) + +vi.mock('@sim/db', () => ({ db: {} })) +vi.mock('@sim/db/schema', () => ({ workflow: {} })) +vi.mock('@sim/logger', () => ({ + createLogger: vi.fn().mockReturnValue({ + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }), +})) +vi.mock('drizzle-orm', () => ({ eq: vi.fn() })) +vi.mock('@/lib/billing/calculations/usage-monitor', () => ({ + checkServerSideUsageLimits: vi.fn(), +})) +vi.mock('@/lib/billing/core/subscription', () => ({ + getHighestPrioritySubscription: vi.fn(), +})) +vi.mock('@/lib/core/execution-limits', () => ({ + getExecutionTimeout: vi.fn(() => 0), +})) +vi.mock('@/lib/core/rate-limiter/rate-limiter', () => ({ + RateLimiter: vi.fn(), +})) +vi.mock('@/lib/logs/execution/logging-session', () => ({ + LoggingSession: vi.fn(), +})) +vi.mock('@/lib/workspaces/utils', () => ({ + getWorkspaceBilledAccountUserId: mockGetWorkspaceBilledAccountUserId, +})) + +import { preprocessExecution } from './preprocessing' + +describe('preprocessExecution webhook correlation logging', () => { + it('preserves webhook correlation when logging preprocessing failures', async () => { + mockGetWorkspaceBilledAccountUserId.mockResolvedValueOnce(null) + + const loggingSession = { + safeStart: vi.fn().mockResolvedValue(true), + safeCompleteWithError: vi.fn().mockResolvedValue(undefined), + } + + const correlation = { + executionId: 'execution-webhook-1', + requestId: 'request-webhook-1', + source: 'webhook' as const, + workflowId: 'workflow-1', + webhookId: 'webhook-1', + path: 'incoming/slack', + provider: 'slack', + triggerType: 'webhook', + } + + const result = await preprocessExecution({ + workflowId: 'workflow-1', + userId: 'unknown', + triggerType: 'webhook', + executionId: 'execution-webhook-1', + requestId: 'request-webhook-1', + loggingSession: loggingSession as any, + triggerData: { correlation }, + workflowRecord: { + id: 'workflow-1', + workspaceId: 'workspace-1', + isDeployed: true, + } as any, + }) + + expect(result).toMatchObject({ + success: false, + error: { + statusCode: 500, + logCreated: true, + }, + }) + + expect(loggingSession.safeStart).toHaveBeenCalledWith({ + userId: 'unknown', + workspaceId: 'workspace-1', + variables: {}, + triggerData: { correlation }, + }) + }) +}) diff --git a/apps/sim/lib/logs/execution/logger.test.ts b/apps/sim/lib/logs/execution/logger.test.ts index 00f73c627ef..a1bd9962d8d 100644 --- a/apps/sim/lib/logs/execution/logger.test.ts +++ b/apps/sim/lib/logs/execution/logger.test.ts @@ -1,6 +1,6 @@ import { databaseMock, loggerMock } from '@sim/testing' import { beforeEach, describe, expect, test, vi } from 'vitest' -import { ExecutionLogger } from '@/lib/logs/execution/logger' +import { ExecutionLogger } from './logger' vi.mock('@sim/db', () => databaseMock) @@ -111,6 +111,57 @@ describe('ExecutionLogger', () => { test('should have getWorkflowExecution method', () => { expect(typeof logger.getWorkflowExecution).toBe('function') }) + + test('preserves start correlation data when execution completes', () => { + const loggerInstance = new ExecutionLogger() as any + + const completedData = loggerInstance.buildCompletedExecutionData({ + existingExecutionData: { + environment: { + variables: {}, + workflowId: 'workflow-123', + executionId: 'execution-123', + userId: 'user-123', + workspaceId: 'workspace-123', + }, + trigger: { + type: 'webhook', + source: 'webhook', + timestamp: '2025-01-01T00:00:00.000Z', + data: { + correlation: { + executionId: 'execution-123', + requestId: 'req-1234', + source: 'webhook', + workflowId: 'workflow-123', + webhookId: 'webhook-123', + path: 'incoming/slack', + triggerType: 'webhook', + }, + }, + }, + }, + traceSpans: [], + finalOutput: { ok: true }, + executionCost: { + tokens: { input: 0, output: 0, total: 0 }, + models: {}, + }, + }) + + expect(completedData.environment?.workflowId).toBe('workflow-123') + expect(completedData.trigger?.data?.correlation).toEqual({ + executionId: 'execution-123', + requestId: 'req-1234', + source: 'webhook', + workflowId: 'workflow-123', + webhookId: 'webhook-123', + path: 'incoming/slack', + triggerType: 'webhook', + }) + expect(completedData.correlation).toEqual(completedData.trigger?.data?.correlation) + expect(completedData.finalOutput).toEqual({ ok: true }) + }) }) describe('file extraction', () => { diff --git a/apps/sim/lib/logs/execution/logger.ts b/apps/sim/lib/logs/execution/logger.ts index c9e2fb8d65d..7cb61bd7050 100644 --- a/apps/sim/lib/logs/execution/logger.ts +++ b/apps/sim/lib/logs/execution/logger.ts @@ -49,6 +49,46 @@ export interface ToolCall { const logger = createLogger('ExecutionLogger') export class ExecutionLogger implements IExecutionLoggerService { + private buildCompletedExecutionData(params: { + existingExecutionData?: WorkflowExecutionLog['executionData'] + traceSpans?: TraceSpan[] + finalOutput: BlockOutputData + executionCost: { + tokens: { + input: number + output: number + total: number + } + models: NonNullable + } + executionState?: SerializableExecutionState + }): WorkflowExecutionLog['executionData'] { + const { existingExecutionData, traceSpans, finalOutput, executionCost, executionState } = params + + return { + ...(existingExecutionData?.environment + ? { environment: existingExecutionData.environment } + : {}), + ...(existingExecutionData?.trigger ? { trigger: existingExecutionData.trigger } : {}), + ...(existingExecutionData?.correlation || existingExecutionData?.trigger?.data?.correlation + ? { + correlation: + existingExecutionData?.correlation || + existingExecutionData?.trigger?.data?.correlation, + } + : {}), + traceSpans, + finalOutput, + tokens: { + input: executionCost.tokens.input, + output: executionCost.tokens.output, + total: executionCost.tokens.total, + }, + models: executionCost.models, + ...(executionState ? { executionState } : {}), + } + } + async startWorkflowExecution(params: { workflowId: string workspaceId: string @@ -131,6 +171,7 @@ export class ExecutionLogger implements IExecutionLoggerService { executionData: { environment, trigger, + ...(trigger.data?.correlation ? { correlation: trigger.data.correlation } : {}), }, cost: { total: BASE_EXECUTION_CHARGE, @@ -216,7 +257,7 @@ export class ExecutionLogger implements IExecutionLoggerService { .limit(1) const billingUserId = this.extractBillingUserId(existingLog?.executionData) const existingExecutionData = existingLog?.executionData as - | { traceSpans?: TraceSpan[] } + | WorkflowExecutionLog['executionData'] | undefined // Determine if workflow failed by checking trace spans for unhandled errors @@ -280,17 +321,13 @@ export class ExecutionLogger implements IExecutionLoggerService { endedAt: new Date(endedAt), totalDurationMs: totalDuration, files: executionFiles.length > 0 ? executionFiles : null, - executionData: { + executionData: this.buildCompletedExecutionData({ + existingExecutionData, traceSpans: redactedTraceSpans, finalOutput: redactedFinalOutput, - tokens: { - input: executionCost.tokens.input, - output: executionCost.tokens.output, - total: executionCost.tokens.total, - }, - models: executionCost.models, - ...(executionState ? { executionState } : {}), - }, + executionCost, + executionState, + }), cost: executionCost, }) .where(eq(workflowExecutionLogs.executionId, executionId)) diff --git a/apps/sim/lib/logs/execution/logging-session.ts b/apps/sim/lib/logs/execution/logging-session.ts index f5b260c65f1..245e7eb3562 100644 --- a/apps/sim/lib/logs/execution/logging-session.ts +++ b/apps/sim/lib/logs/execution/logging-session.ts @@ -19,13 +19,17 @@ import type { } from '@/lib/logs/types' import type { SerializableExecutionState } from '@/executor/execution/types' +type TriggerData = Record & { + correlation?: NonNullable['correlation'] +} + const logger = createLogger('LoggingSession') export interface SessionStartParams { userId?: string workspaceId: string variables?: Record - triggerData?: Record + triggerData?: TriggerData skipLogCreation?: boolean // For resume executions - reuse existing log entry deploymentVersionId?: string // ID of the deployment version used (null for manual/editor executions) } @@ -87,6 +91,7 @@ export class LoggingSession { private trigger?: ExecutionTrigger private environment?: ExecutionEnvironment private workflowState?: WorkflowState + private correlation?: NonNullable['correlation'] private isResume = false private completed = false /** Synchronous flag to prevent concurrent completion attempts (race condition guard) */ @@ -216,6 +221,7 @@ export class LoggingSession { try { this.trigger = createTriggerObject(this.triggerType, triggerData) + this.correlation = triggerData?.correlation this.environment = createEnvironmentObject( this.workflowId, this.executionId, @@ -633,6 +639,7 @@ export class LoggingSession { try { const { userId, workspaceId, variables, triggerData, deploymentVersionId } = params this.trigger = createTriggerObject(this.triggerType, triggerData) + this.correlation = triggerData?.correlation this.environment = createEnvironmentObject( this.workflowId, this.executionId, diff --git a/apps/sim/lib/logs/types.ts b/apps/sim/lib/logs/types.ts index eb568398fcd..c785c3037db 100644 --- a/apps/sim/lib/logs/types.ts +++ b/apps/sim/lib/logs/types.ts @@ -1,4 +1,5 @@ import type { Edge } from 'reactflow' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' import type { ParentIteration, SerializableExecutionState } from '@/executor/execution/types' import type { BlockLog, NormalizedBlockOutput } from '@/executor/types' import type { DeploymentStatus } from '@/stores/workflows/registry/types' @@ -57,7 +58,9 @@ import type { CoreTriggerType } from '@/stores/logs/filters/types' export interface ExecutionTrigger { type: CoreTriggerType | string source: string - data?: Record + data?: Record & { + correlation?: AsyncExecutionCorrelation + } timestamp: string } @@ -101,6 +104,7 @@ export interface WorkflowExecutionLog { executionData: { environment?: ExecutionEnvironment trigger?: ExecutionTrigger + correlation?: AsyncExecutionCorrelation traceSpans?: TraceSpan[] tokens?: { input?: number; output?: number; total?: number } models?: Record< diff --git a/apps/sim/lib/webhooks/processor.ts b/apps/sim/lib/webhooks/processor.ts index 46d81337219..225c3052c41 100644 --- a/apps/sim/lib/webhooks/processor.ts +++ b/apps/sim/lib/webhooks/processor.ts @@ -242,7 +242,10 @@ export function handleProviderReachabilityTest( logger.info( `[${requestId}] Grain reachability test detected - returning 200 for webhook verification` ) - return NextResponse.json({ status: 'ok', message: 'Webhook endpoint verified' }) + return NextResponse.json({ + status: 'ok', + message: 'Webhook endpoint verified', + }) } } @@ -323,7 +326,10 @@ export function handlePreDeploymentVerification( logger.info( `[${requestId}] ${webhook.provider} webhook - block not in deployment, returning 200 OK for URL validation` ) - return NextResponse.json({ status: 'ok', message: 'Webhook endpoint verified' }) + return NextResponse.json({ + status: 'ok', + message: 'Webhook endpoint verified', + }) } return null } @@ -501,7 +507,9 @@ export async function verifyProviderAuth( foundWorkflow.workspaceId ) } catch (error) { - logger.error(`[${requestId}] Failed to fetch environment variables`, { error }) + logger.error(`[${requestId}] Failed to fetch environment variables`, { + error, + }) } // Step 2: Resolve {{VARIABLE}} references in providerConfig @@ -516,7 +524,9 @@ export async function verifyProviderAuth( logger.warn( `[${requestId}] Microsoft Teams outgoing webhook missing HMAC authorization header` ) - return new NextResponse('Unauthorized - Missing HMAC signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing HMAC signature', { + status: 401, + }) } const isValidSignature = validateMicrosoftTeamsSignature( @@ -527,7 +537,9 @@ export async function verifyProviderAuth( if (!isValidSignature) { logger.warn(`[${requestId}] Microsoft Teams HMAC signature verification failed`) - return new NextResponse('Unauthorized - Invalid HMAC signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid HMAC signature', { + status: 401, + }) } } } @@ -563,7 +575,9 @@ export async function verifyProviderAuth( if (!isTokenValid) { logger.warn(`[${requestId}] Google Forms webhook authentication failed`) - return new NextResponse('Unauthorized - Invalid secret', { status: 401 }) + return new NextResponse('Unauthorized - Invalid secret', { + status: 401, + }) } } } @@ -577,7 +591,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Twilio Voice webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Twilio signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Twilio signature', { + status: 401, + }) } let params: Record = {} @@ -591,7 +607,9 @@ export async function verifyProviderAuth( `[${requestId}] Error parsing Twilio webhook body for signature validation:`, error ) - return new NextResponse('Bad Request - Invalid body format', { status: 400 }) + return new NextResponse('Bad Request - Invalid body format', { + status: 400, + }) } const fullUrl = getExternalUrl(request) @@ -604,7 +622,9 @@ export async function verifyProviderAuth( paramsCount: Object.keys(params).length, authTokenLength: authToken.length, }) - return new NextResponse('Unauthorized - Invalid Twilio signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Twilio signature', { + status: 401, + }) } } } @@ -617,7 +637,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Typeform webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Typeform signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Typeform signature', { + status: 401, + }) } const isValidSignature = validateTypeformSignature(secret, signature, rawBody) @@ -627,7 +649,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Typeform signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Typeform signature', { + status: 401, + }) } } } @@ -644,7 +668,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Attio webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Attio signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Attio signature', { + status: 401, + }) } const isValidSignature = validateAttioSignature(secret, signature, rawBody) @@ -654,7 +680,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Attio signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Attio signature', { + status: 401, + }) } } } @@ -667,7 +695,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Linear webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Linear signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Linear signature', { + status: 401, + }) } const isValidSignature = validateLinearSignature(secret, signature, rawBody) @@ -677,7 +707,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Linear signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Linear signature', { + status: 401, + }) } } } @@ -690,7 +722,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Circleback webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Circleback signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Circleback signature', { + status: 401, + }) } const isValidSignature = validateCirclebackSignature(secret, signature, rawBody) @@ -700,7 +734,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Circleback signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Circleback signature', { + status: 401, + }) } } } @@ -713,7 +749,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Cal.com webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Cal.com signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Cal.com signature', { + status: 401, + }) } const isValidSignature = validateCalcomSignature(secret, signature, rawBody) @@ -723,7 +761,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Cal.com signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Cal.com signature', { + status: 401, + }) } } } @@ -736,7 +776,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Jira webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Jira signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Jira signature', { + status: 401, + }) } const isValidSignature = validateJiraSignature(secret, signature, rawBody) @@ -746,7 +788,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Jira signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Jira signature', { + status: 401, + }) } } } @@ -759,7 +803,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Confluence webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Confluence signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Confluence signature', { + status: 401, + }) } const isValidSignature = validateJiraSignature(secret, signature, rawBody) @@ -769,7 +815,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Confluence signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Confluence signature', { + status: 401, + }) } } } @@ -785,7 +833,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] GitHub webhook missing signature header`) - return new NextResponse('Unauthorized - Missing GitHub signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing GitHub signature', { + status: 401, + }) } const isValidSignature = validateGitHubSignature(secret, signature, rawBody) @@ -796,7 +846,9 @@ export async function verifyProviderAuth( secretLength: secret.length, usingSha256: !!signature256, }) - return new NextResponse('Unauthorized - Invalid GitHub signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid GitHub signature', { + status: 401, + }) } } } @@ -809,7 +861,9 @@ export async function verifyProviderAuth( if (!signature) { logger.warn(`[${requestId}] Fireflies webhook missing signature header`) - return new NextResponse('Unauthorized - Missing Fireflies signature', { status: 401 }) + return new NextResponse('Unauthorized - Missing Fireflies signature', { + status: 401, + }) } const isValidSignature = validateFirefliesSignature(secret, signature, rawBody) @@ -819,7 +873,9 @@ export async function verifyProviderAuth( signatureLength: signature.length, secretLength: secret.length, }) - return new NextResponse('Unauthorized - Invalid Fireflies signature', { status: 401 }) + return new NextResponse('Unauthorized - Invalid Fireflies signature', { + status: 401, + }) } } } @@ -872,6 +928,16 @@ export async function checkWebhookPreprocessing( ): Promise { try { const executionId = uuidv4() + const correlation = { + executionId, + requestId, + source: 'webhook' as const, + workflowId: foundWorkflow.id, + webhookId: foundWebhook.id, + path: foundWebhook.path, + provider: foundWebhook.provider, + triggerType: 'webhook', + } const preprocessResult = await preprocessExecution({ workflowId: foundWorkflow.id, @@ -879,6 +945,7 @@ export async function checkWebhookPreprocessing( triggerType: 'webhook', executionId, requestId, + triggerData: { correlation }, checkRateLimit: true, checkDeployment: true, workspaceId: foundWorkflow.workspaceId, @@ -905,7 +972,9 @@ export async function checkWebhookPreprocessing( } } - return { error: NextResponse.json({ error: error.message }, { status: error.statusCode }) } + return { + error: NextResponse.json({ error: error.message }, { status: error.statusCode }), + } } return { error: null, actorUserId: preprocessResult.actorUserId } @@ -1034,7 +1103,10 @@ export async function queueWebhookExecution( bodyKeys: Object.keys(body), } ) - return NextResponse.json({ status: 'skipped', reason: 'event_type_mismatch' }) + return NextResponse.json({ + status: 'skipped', + reason: 'event_type_mismatch', + }) } } } @@ -1132,10 +1204,25 @@ export async function queueWebhookExecution( return NextResponse.json({ error: 'Unable to resolve billing account' }, { status: 500 }) } + const executionId = uuidv4() + const correlation = { + executionId, + requestId: options.requestId, + source: 'webhook' as const, + workflowId: foundWorkflow.id, + webhookId: foundWebhook.id, + path: options.path || foundWebhook.path, + provider: foundWebhook.provider, + triggerType: 'webhook', + } + const payload = { webhookId: foundWebhook.id, workflowId: foundWorkflow.id, userId: actorUserId, + executionId, + requestId: options.requestId, + correlation, provider: foundWebhook.provider, body, headers, @@ -1150,7 +1237,11 @@ export async function queueWebhookExecution( if (isPolling && !shouldExecuteInline()) { const jobQueue = await getJobQueue() const jobId = await jobQueue.enqueue('webhook-execution', payload, { - metadata: { workflowId: foundWorkflow.id, userId: actorUserId }, + metadata: { + workflowId: foundWorkflow.id, + userId: actorUserId, + correlation, + }, }) logger.info( `[${options.requestId}] Queued polling webhook execution task ${jobId} for ${foundWebhook.provider} webhook via job queue` @@ -1158,7 +1249,11 @@ export async function queueWebhookExecution( } else { const jobQueue = await getInlineJobQueue() const jobId = await jobQueue.enqueue('webhook-execution', payload, { - metadata: { workflowId: foundWorkflow.id, userId: actorUserId }, + metadata: { + workflowId: foundWorkflow.id, + userId: actorUserId, + correlation, + }, }) logger.info( `[${options.requestId}] Executing ${foundWebhook.provider} webhook ${jobId} inline` diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index c92723786d0..5425162e6ce 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -304,6 +304,7 @@ export async function executeWorkflowCore( userId, workspaceId: providedWorkspaceId, variables, + triggerData: metadata.correlation ? { correlation: metadata.correlation } : undefined, skipLogCreation, deploymentVersionId, }) From fac0745c3556f572cd8a7ed1bfa8e732d86b7b35 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Thu, 12 Mar 2026 14:06:31 +0300 Subject: [PATCH 03/11] fix(webhooks): pass correlation into preprocessing --- apps/sim/background/webhook-execution.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/apps/sim/background/webhook-execution.ts b/apps/sim/background/webhook-execution.ts index fef211bde71..4081ed00ec4 100644 --- a/apps/sim/background/webhook-execution.ts +++ b/apps/sim/background/webhook-execution.ts @@ -222,6 +222,7 @@ async function executeWebhookJobInternal( triggerType: "webhook", executionId, requestId, + triggerData: { correlation }, checkRateLimit: false, checkDeployment: false, skipUsageLimits: true, From ac7ea2ab38924ac0f952d883e269a12c073272cd Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Thu, 12 Mar 2026 14:06:31 +0300 Subject: [PATCH 04/11] style(webhooks): normalize webhook executor formatting --- apps/sim/background/webhook-execution.ts | 607 ++++++++++------------- 1 file changed, 250 insertions(+), 357 deletions(-) diff --git a/apps/sim/background/webhook-execution.ts b/apps/sim/background/webhook-execution.ts index 4081ed00ec4..8bac6e558cf 100644 --- a/apps/sim/background/webhook-execution.ts +++ b/apps/sim/background/webhook-execution.ts @@ -1,59 +1,50 @@ -import { db } from "@sim/db"; -import { account, webhook } from "@sim/db/schema"; -import { createLogger } from "@sim/logger"; -import { task } from "@trigger.dev/sdk"; -import { eq } from "drizzle-orm"; -import { v4 as uuidv4 } from "uuid"; -import type { AsyncExecutionCorrelation } from "@/lib/core/async-jobs/types"; -import { - createTimeoutAbortController, - getTimeoutErrorMessage, -} from "@/lib/core/execution-limits"; -import { IdempotencyService, webhookIdempotency } from "@/lib/core/idempotency"; -import { processExecutionFiles } from "@/lib/execution/files"; -import { preprocessExecution } from "@/lib/execution/preprocessing"; -import { LoggingSession } from "@/lib/logs/execution/logging-session"; -import { buildTraceSpans } from "@/lib/logs/execution/trace-spans/trace-spans"; -import { WebhookAttachmentProcessor } from "@/lib/webhooks/attachment-processor"; -import { - fetchAndProcessAirtablePayloads, - formatWebhookInput, -} from "@/lib/webhooks/utils.server"; +import { db } from '@sim/db' +import { account, webhook } from '@sim/db/schema' +import { createLogger } from '@sim/logger' +import { task } from '@trigger.dev/sdk' +import { eq } from 'drizzle-orm' +import { v4 as uuidv4 } from 'uuid' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' +import { createTimeoutAbortController, getTimeoutErrorMessage } from '@/lib/core/execution-limits' +import { IdempotencyService, webhookIdempotency } from '@/lib/core/idempotency' +import { processExecutionFiles } from '@/lib/execution/files' +import { preprocessExecution } from '@/lib/execution/preprocessing' +import { LoggingSession } from '@/lib/logs/execution/logging-session' +import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans' +import { WebhookAttachmentProcessor } from '@/lib/webhooks/attachment-processor' +import { fetchAndProcessAirtablePayloads, formatWebhookInput } from '@/lib/webhooks/utils.server' import { executeWorkflowCore, wasExecutionFinalizedByCore, -} from "@/lib/workflows/executor/execution-core"; -import { PauseResumeManager } from "@/lib/workflows/executor/human-in-the-loop-manager"; -import { loadDeployedWorkflowState } from "@/lib/workflows/persistence/utils"; -import { resolveOAuthAccountId } from "@/app/api/auth/oauth/utils"; -import { getBlock } from "@/blocks"; -import { ExecutionSnapshot } from "@/executor/execution/snapshot"; -import type { ExecutionMetadata } from "@/executor/execution/types"; -import { hasExecutionResult } from "@/executor/utils/errors"; -import { safeAssign } from "@/tools/safe-assign"; -import { getTrigger, isTriggerValid } from "@/triggers"; - -const logger = createLogger("TriggerWebhookExecution"); +} from '@/lib/workflows/executor/execution-core' +import { PauseResumeManager } from '@/lib/workflows/executor/human-in-the-loop-manager' +import { loadDeployedWorkflowState } from '@/lib/workflows/persistence/utils' +import { resolveOAuthAccountId } from '@/app/api/auth/oauth/utils' +import { getBlock } from '@/blocks' +import { ExecutionSnapshot } from '@/executor/execution/snapshot' +import type { ExecutionMetadata } from '@/executor/execution/types' +import { hasExecutionResult } from '@/executor/utils/errors' +import { safeAssign } from '@/tools/safe-assign' +import { getTrigger, isTriggerValid } from '@/triggers' + +const logger = createLogger('TriggerWebhookExecution') export function buildWebhookCorrelation( - payload: WebhookExecutionPayload, + payload: WebhookExecutionPayload ): AsyncExecutionCorrelation { - const executionId = payload.executionId || uuidv4(); - const requestId = - payload.requestId || - payload.correlation?.requestId || - executionId.slice(0, 8); + const executionId = payload.executionId || uuidv4() + const requestId = payload.requestId || payload.correlation?.requestId || executionId.slice(0, 8) return { executionId, requestId, - source: "webhook", + source: 'webhook', workflowId: payload.workflowId, webhookId: payload.webhookId, path: payload.path, provider: payload.provider, - triggerType: payload.correlation?.triggerType || "webhook", - }; + triggerType: payload.correlation?.triggerType || 'webhook', + } } /** @@ -64,54 +55,47 @@ async function processTriggerFileOutputs( input: any, triggerOutputs: Record, context: { - workspaceId: string; - workflowId: string; - executionId: string; - requestId: string; - userId?: string; + workspaceId: string + workflowId: string + executionId: string + requestId: string + userId?: string }, - path = "", + path = '' ): Promise { - if (!input || typeof input !== "object") { - return input; + if (!input || typeof input !== 'object') { + return input } - const processed: any = Array.isArray(input) ? [] : {}; + const processed: any = Array.isArray(input) ? [] : {} for (const [key, value] of Object.entries(input)) { - const currentPath = path ? `${path}.${key}` : key; - const outputDef = triggerOutputs[key]; - const val: any = value; + const currentPath = path ? `${path}.${key}` : key + const outputDef = triggerOutputs[key] + const val: any = value // If this field is marked as file or file[], process it - if (outputDef?.type === "file[]" && Array.isArray(val)) { + if (outputDef?.type === 'file[]' && Array.isArray(val)) { try { - processed[key] = await WebhookAttachmentProcessor.processAttachments( - val as any, - context, - ); + processed[key] = await WebhookAttachmentProcessor.processAttachments(val as any, context) } catch (error) { - processed[key] = []; + processed[key] = [] } - } else if (outputDef?.type === "file" && val) { + } else if (outputDef?.type === 'file' && val) { try { - const [processedFile] = - await WebhookAttachmentProcessor.processAttachments( - [val as any], - context, - ); - processed[key] = processedFile; + const [processedFile] = await WebhookAttachmentProcessor.processAttachments( + [val as any], + context + ) + processed[key] = processedFile } catch (error) { - logger.error( - `[${context.requestId}] Error processing ${currentPath}:`, - error, - ); - processed[key] = val; + logger.error(`[${context.requestId}] Error processing ${currentPath}:`, error) + processed[key] = val } } else if ( outputDef && - typeof outputDef === "object" && - (outputDef.type === "object" || outputDef.type === "json") && + typeof outputDef === 'object' && + (outputDef.type === 'object' || outputDef.type === 'json') && outputDef.properties ) { // Explicit object schema with properties - recurse into properties @@ -119,45 +103,40 @@ async function processTriggerFileOutputs( val, outputDef.properties, context, - currentPath, - ); - } else if (outputDef && typeof outputDef === "object" && !outputDef.type) { + currentPath + ) + } else if (outputDef && typeof outputDef === 'object' && !outputDef.type) { // Nested object in schema (flat pattern) - recurse with the nested schema - processed[key] = await processTriggerFileOutputs( - val, - outputDef, - context, - currentPath, - ); + processed[key] = await processTriggerFileOutputs(val, outputDef, context, currentPath) } else { // Not a file output - keep as is - processed[key] = val; + processed[key] = val } } - return processed; + return processed } export type WebhookExecutionPayload = { - webhookId: string; - workflowId: string; - userId: string; - executionId?: string; - requestId?: string; - correlation?: AsyncExecutionCorrelation; - provider: string; - body: any; - headers: Record; - path: string; - blockId?: string; - workspaceId?: string; - credentialId?: string; -}; + webhookId: string + workflowId: string + userId: string + executionId?: string + requestId?: string + correlation?: AsyncExecutionCorrelation + provider: string + body: any + headers: Record + path: string + blockId?: string + workspaceId?: string + credentialId?: string +} export async function executeWebhookJob(payload: WebhookExecutionPayload) { - const correlation = buildWebhookCorrelation(payload); - const executionId = correlation.executionId; - const requestId = correlation.requestId; + const correlation = buildWebhookCorrelation(payload) + const executionId = correlation.executionId + const requestId = correlation.requestId logger.info(`[${requestId}] Starting webhook execution`, { webhookId: payload.webhookId, @@ -165,61 +144,59 @@ export async function executeWebhookJob(payload: WebhookExecutionPayload) { provider: payload.provider, userId: payload.userId, executionId, - }); + }) const idempotencyKey = IdempotencyService.createWebhookIdempotencyKey( payload.webhookId, payload.headers, payload.body, - payload.provider, - ); + payload.provider + ) const runOperation = async () => { - return await executeWebhookJobInternal(payload, correlation); - }; + return await executeWebhookJobInternal(payload, correlation) + } return await webhookIdempotency.executeWithIdempotency( payload.provider, idempotencyKey, - runOperation, - ); + runOperation + ) } /** * Resolve the account userId for a credential */ -async function resolveCredentialAccountUserId( - credentialId: string, -): Promise { - const resolved = await resolveOAuthAccountId(credentialId); +async function resolveCredentialAccountUserId(credentialId: string): Promise { + const resolved = await resolveOAuthAccountId(credentialId) if (!resolved) { - return undefined; + return undefined } const [credentialRecord] = await db .select({ userId: account.userId }) .from(account) .where(eq(account.id, resolved.accountId)) - .limit(1); - return credentialRecord?.userId; + .limit(1) + return credentialRecord?.userId } async function executeWebhookJobInternal( payload: WebhookExecutionPayload, - correlation: AsyncExecutionCorrelation, + correlation: AsyncExecutionCorrelation ) { - const { executionId, requestId } = correlation; + const { executionId, requestId } = correlation const loggingSession = new LoggingSession( payload.workflowId, executionId, payload.provider, - requestId, - ); + requestId + ) // Resolve workflow record, billing actor, subscription, and timeout const preprocessResult = await preprocessExecution({ workflowId: payload.workflowId, userId: payload.userId, - triggerType: "webhook", + triggerType: 'webhook', executionId, requestId, triggerData: { correlation }, @@ -228,99 +205,84 @@ async function executeWebhookJobInternal( skipUsageLimits: true, workspaceId: payload.workspaceId, loggingSession, - }); + }) if (!preprocessResult.success) { - throw new Error( - preprocessResult.error?.message || - "Preprocessing failed in background job", - ); + throw new Error(preprocessResult.error?.message || 'Preprocessing failed in background job') } - const { workflowRecord, executionTimeout } = preprocessResult; + const { workflowRecord, executionTimeout } = preprocessResult if (!workflowRecord) { - throw new Error( - `Workflow ${payload.workflowId} not found during preprocessing`, - ); + throw new Error(`Workflow ${payload.workflowId} not found during preprocessing`) } - const workspaceId = workflowRecord.workspaceId; + const workspaceId = workflowRecord.workspaceId if (!workspaceId) { - throw new Error( - `Workflow ${payload.workflowId} has no associated workspace`, - ); + throw new Error(`Workflow ${payload.workflowId} has no associated workspace`) } - const workflowVariables = - (workflowRecord.variables as Record) || {}; - const asyncTimeout = executionTimeout?.async ?? 120_000; - const timeoutController = createTimeoutAbortController(asyncTimeout); + const workflowVariables = (workflowRecord.variables as Record) || {} + const asyncTimeout = executionTimeout?.async ?? 120_000 + const timeoutController = createTimeoutAbortController(asyncTimeout) - let deploymentVersionId: string | undefined; + let deploymentVersionId: string | undefined try { // Parallelize workflow state, webhook record, and credential resolution - const [workflowData, webhookRows, resolvedCredentialUserId] = - await Promise.all([ - loadDeployedWorkflowState(payload.workflowId, workspaceId), - db - .select() - .from(webhook) - .where(eq(webhook.id, payload.webhookId)) - .limit(1), - payload.credentialId - ? resolveCredentialAccountUserId(payload.credentialId) - : Promise.resolve(undefined), - ]); - const credentialAccountUserId = resolvedCredentialUserId; + const [workflowData, webhookRows, resolvedCredentialUserId] = await Promise.all([ + loadDeployedWorkflowState(payload.workflowId, workspaceId), + db.select().from(webhook).where(eq(webhook.id, payload.webhookId)).limit(1), + payload.credentialId + ? resolveCredentialAccountUserId(payload.credentialId) + : Promise.resolve(undefined), + ]) + const credentialAccountUserId = resolvedCredentialUserId if (payload.credentialId && !credentialAccountUserId) { logger.warn( - `[${requestId}] Failed to resolve credential account for credential ${payload.credentialId}`, - ); + `[${requestId}] Failed to resolve credential account for credential ${payload.credentialId}` + ) } if (!workflowData) { throw new Error( - "Workflow state not found. The workflow may not be deployed or the deployment data may be corrupted.", - ); + 'Workflow state not found. The workflow may not be deployed or the deployment data may be corrupted.' + ) } - const { blocks, edges, loops, parallels } = workflowData; + const { blocks, edges, loops, parallels } = workflowData deploymentVersionId = - "deploymentVersionId" in workflowData + 'deploymentVersionId' in workflowData ? (workflowData.deploymentVersionId as string) - : undefined; + : undefined // Handle special Airtable case - if (payload.provider === "airtable") { - logger.info( - `[${requestId}] Processing Airtable webhook via fetchAndProcessAirtablePayloads`, - ); + if (payload.provider === 'airtable') { + logger.info(`[${requestId}] Processing Airtable webhook via fetchAndProcessAirtablePayloads`) - const webhookRecord = webhookRows[0]; + const webhookRecord = webhookRows[0] if (!webhookRecord) { - throw new Error(`Webhook record not found: ${payload.webhookId}`); + throw new Error(`Webhook record not found: ${payload.webhookId}`) } const webhookData = { id: payload.webhookId, provider: payload.provider, providerConfig: webhookRecord.providerConfig, - }; + } const mockWorkflow = { id: payload.workflowId, userId: payload.userId, - }; + } const airtableInput = await fetchAndProcessAirtablePayloads( webhookData, mockWorkflow, - requestId, - ); + requestId + ) if (airtableInput) { - logger.info(`[${requestId}] Executing workflow with Airtable changes`); + logger.info(`[${requestId}] Executing workflow with Airtable changes`) const metadata: ExecutionMetadata = { requestId, @@ -330,7 +292,7 @@ async function executeWebhookJobInternal( userId: payload.userId, sessionUserId: undefined, workflowUserId: workflowRecord.userId, - triggerType: payload.provider || "webhook", + triggerType: payload.provider || 'webhook', triggerBlockId: payload.blockId, useDraftState: false, startTime: new Date().toISOString(), @@ -344,15 +306,15 @@ async function executeWebhookJobInternal( parallels: parallels || {}, deploymentVersionId, }, - }; + } const snapshot = new ExecutionSnapshot( metadata, workflowRecord, airtableInput, workflowVariables, - [], - ); + [] + ) const executionResult = await executeWorkflowCore({ snapshot, @@ -361,32 +323,24 @@ async function executeWebhookJobInternal( includeFileBase64: true, base64MaxBytes: undefined, abortSignal: timeoutController.signal, - }); + }) if ( - executionResult.status === "cancelled" && + executionResult.status === 'cancelled' && timeoutController.isTimedOut() && timeoutController.timeoutMs ) { - const timeoutErrorMessage = getTimeoutErrorMessage( - null, - timeoutController.timeoutMs, - ); + const timeoutErrorMessage = getTimeoutErrorMessage(null, timeoutController.timeoutMs) logger.info(`[${requestId}] Airtable webhook execution timed out`, { timeoutMs: timeoutController.timeoutMs, - }); - await loggingSession.markAsFailed(timeoutErrorMessage); - } else if (executionResult.status === "paused") { + }) + await loggingSession.markAsFailed(timeoutErrorMessage) + } else if (executionResult.status === 'paused') { if (!executionResult.snapshotSeed) { - logger.error( - `[${requestId}] Missing snapshot seed for paused execution`, - { - executionId, - }, - ); - await loggingSession.markAsFailed( - "Missing snapshot seed for paused execution", - ); + logger.error(`[${requestId}] Missing snapshot seed for paused execution`, { + executionId, + }) + await loggingSession.markAsFailed('Missing snapshot seed for paused execution') } else { try { await PauseResumeManager.persistPauseResult({ @@ -395,28 +349,25 @@ async function executeWebhookJobInternal( pausePoints: executionResult.pausePoints || [], snapshotSeed: executionResult.snapshotSeed, executorUserId: executionResult.metadata?.userId, - }); + }) } catch (pauseError) { logger.error(`[${requestId}] Failed to persist pause result`, { executionId, - error: - pauseError instanceof Error - ? pauseError.message - : String(pauseError), - }); + error: pauseError instanceof Error ? pauseError.message : String(pauseError), + }) await loggingSession.markAsFailed( - `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}`, - ); + `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}` + ) } } } else { - await PauseResumeManager.processQueuedResumes(executionId); + await PauseResumeManager.processQueuedResumes(executionId) } logger.info(`[${requestId}] Airtable webhook execution completed`, { success: executionResult.success, workflowId: payload.workflowId, - }); + }) return { success: executionResult.success, @@ -425,10 +376,10 @@ async function executeWebhookJobInternal( output: executionResult.output, executedAt: new Date().toISOString(), provider: payload.provider, - }; + } } // No changes to process - logger.info(`[${requestId}] No Airtable changes to process`); + logger.info(`[${requestId}] No Airtable changes to process`) await loggingSession.safeStart({ userId: payload.userId, @@ -439,22 +390,22 @@ async function executeWebhookJobInternal( correlation, }, deploymentVersionId, - }); + }) await loggingSession.safeComplete({ endedAt: new Date().toISOString(), totalDurationMs: 0, - finalOutput: { message: "No Airtable changes to process" }, + finalOutput: { message: 'No Airtable changes to process' }, traceSpans: [], - }); + }) return { success: true, workflowId: payload.workflowId, executionId, - output: { message: "No Airtable changes to process" }, + output: { message: 'No Airtable changes to process' }, executedAt: new Date().toISOString(), - }; + } } // Format input for standard webhooks @@ -465,27 +416,20 @@ async function executeWebhookJobInternal( provider: payload.provider, blockId: payload.blockId, providerConfig: {}, - }; + } const mockWorkflow = { id: payload.workflowId, userId: payload.userId, - }; + } const mockRequest = { headers: new Map(Object.entries(payload.headers)), - } as any; + } as any - const input = await formatWebhookInput( - actualWebhook, - mockWorkflow, - payload.body, - mockRequest, - ); + const input = await formatWebhookInput(actualWebhook, mockWorkflow, payload.body, mockRequest) - if (!input && payload.provider === "whatsapp") { - logger.info( - `[${requestId}] No messages in WhatsApp payload, skipping execution`, - ); + if (!input && payload.provider === 'whatsapp') { + logger.info(`[${requestId}] No messages in WhatsApp payload, skipping execution`) await loggingSession.safeStart({ userId: payload.userId, @@ -496,150 +440,113 @@ async function executeWebhookJobInternal( correlation, }, deploymentVersionId, - }); + }) await loggingSession.safeComplete({ endedAt: new Date().toISOString(), totalDurationMs: 0, - finalOutput: { message: "No messages in WhatsApp payload" }, + finalOutput: { message: 'No messages in WhatsApp payload' }, traceSpans: [], - }); + }) return { success: true, workflowId: payload.workflowId, executionId, - output: { message: "No messages in WhatsApp payload" }, + output: { message: 'No messages in WhatsApp payload' }, executedAt: new Date().toISOString(), - }; + } } // Process trigger file outputs based on schema if (input && payload.blockId && blocks[payload.blockId]) { try { - const triggerBlock = blocks[payload.blockId]; - const rawSelectedTriggerId = - triggerBlock?.subBlocks?.selectedTriggerId?.value; - const rawTriggerId = triggerBlock?.subBlocks?.triggerId?.value; + const triggerBlock = blocks[payload.blockId] + const rawSelectedTriggerId = triggerBlock?.subBlocks?.selectedTriggerId?.value + const rawTriggerId = triggerBlock?.subBlocks?.triggerId?.value let resolvedTriggerId = [rawSelectedTriggerId, rawTriggerId].find( (candidate): candidate is string => - typeof candidate === "string" && isTriggerValid(candidate), - ); + typeof candidate === 'string' && isTriggerValid(candidate) + ) if (!resolvedTriggerId) { - const blockConfig = getBlock(triggerBlock.type); - if ( - blockConfig?.category === "triggers" && - isTriggerValid(triggerBlock.type) - ) { - resolvedTriggerId = triggerBlock.type; - } else if ( - triggerBlock.triggerMode && - blockConfig?.triggers?.enabled - ) { - const available = blockConfig.triggers?.available?.[0]; + const blockConfig = getBlock(triggerBlock.type) + if (blockConfig?.category === 'triggers' && isTriggerValid(triggerBlock.type)) { + resolvedTriggerId = triggerBlock.type + } else if (triggerBlock.triggerMode && blockConfig?.triggers?.enabled) { + const available = blockConfig.triggers?.available?.[0] if (available && isTriggerValid(available)) { - resolvedTriggerId = available; + resolvedTriggerId = available } } } if (resolvedTriggerId) { - const triggerConfig = getTrigger(resolvedTriggerId); + const triggerConfig = getTrigger(resolvedTriggerId) if (triggerConfig.outputs) { - const processedInput = await processTriggerFileOutputs( - input, - triggerConfig.outputs, - { - workspaceId, - workflowId: payload.workflowId, - executionId, - requestId, - userId: payload.userId, - }, - ); - safeAssign(input, processedInput as Record); + const processedInput = await processTriggerFileOutputs(input, triggerConfig.outputs, { + workspaceId, + workflowId: payload.workflowId, + executionId, + requestId, + userId: payload.userId, + }) + safeAssign(input, processedInput as Record) } } } catch (error) { - logger.error( - `[${requestId}] Error processing trigger file outputs:`, - error, - ); + logger.error(`[${requestId}] Error processing trigger file outputs:`, error) } } // Process generic webhook files based on inputFormat - if ( - input && - payload.provider === "generic" && - payload.blockId && - blocks[payload.blockId] - ) { + if (input && payload.provider === 'generic' && payload.blockId && blocks[payload.blockId]) { try { - const triggerBlock = blocks[payload.blockId]; + const triggerBlock = blocks[payload.blockId] if (triggerBlock?.subBlocks?.inputFormat?.value) { - const inputFormat = triggerBlock.subBlocks.inputFormat - .value as unknown as Array<{ - name: string; - type: - | "string" - | "number" - | "boolean" - | "object" - | "array" - | "file[]"; - }>; - - const fileFields = inputFormat.filter( - (field) => field.type === "file[]", - ); - - if ( - fileFields.length > 0 && - typeof input === "object" && - input !== null - ) { + const inputFormat = triggerBlock.subBlocks.inputFormat.value as unknown as Array<{ + name: string + type: 'string' | 'number' | 'boolean' | 'object' | 'array' | 'file[]' + }> + + const fileFields = inputFormat.filter((field) => field.type === 'file[]') + + if (fileFields.length > 0 && typeof input === 'object' && input !== null) { const executionContext = { workspaceId, workflowId: payload.workflowId, executionId, - }; + } for (const fileField of fileFields) { - const fieldValue = input[fileField.name]; + const fieldValue = input[fileField.name] - if (fieldValue && typeof fieldValue === "object") { + if (fieldValue && typeof fieldValue === 'object') { const uploadedFiles = await processExecutionFiles( fieldValue, executionContext, requestId, - payload.userId, - ); + payload.userId + ) if (uploadedFiles.length > 0) { - input[fileField.name] = uploadedFiles; + input[fileField.name] = uploadedFiles logger.info( - `[${requestId}] Successfully processed ${uploadedFiles.length} file(s) for field: ${fileField.name}`, - ); + `[${requestId}] Successfully processed ${uploadedFiles.length} file(s) for field: ${fileField.name}` + ) } } } } } } catch (error) { - logger.error( - `[${requestId}] Error processing generic webhook files:`, - error, - ); + logger.error(`[${requestId}] Error processing generic webhook files:`, error) } } - logger.info( - `[${requestId}] Executing workflow for ${payload.provider} webhook`, - ); + logger.info(`[${requestId}] Executing workflow for ${payload.provider} webhook`) const metadata: ExecutionMetadata = { requestId, @@ -649,7 +556,7 @@ async function executeWebhookJobInternal( userId: payload.userId, sessionUserId: undefined, workflowUserId: workflowRecord.userId, - triggerType: payload.provider || "webhook", + triggerType: payload.provider || 'webhook', triggerBlockId: payload.blockId, useDraftState: false, startTime: new Date().toISOString(), @@ -663,17 +570,17 @@ async function executeWebhookJobInternal( parallels: parallels || {}, deploymentVersionId, }, - }; + } - const triggerInput = input || {}; + const triggerInput = input || {} const snapshot = new ExecutionSnapshot( metadata, workflowRecord, triggerInput, workflowVariables, - [], - ); + [] + ) const executionResult = await executeWorkflowCore({ snapshot, @@ -681,32 +588,24 @@ async function executeWebhookJobInternal( loggingSession, includeFileBase64: true, abortSignal: timeoutController.signal, - }); + }) if ( - executionResult.status === "cancelled" && + executionResult.status === 'cancelled' && timeoutController.isTimedOut() && timeoutController.timeoutMs ) { - const timeoutErrorMessage = getTimeoutErrorMessage( - null, - timeoutController.timeoutMs, - ); + const timeoutErrorMessage = getTimeoutErrorMessage(null, timeoutController.timeoutMs) logger.info(`[${requestId}] Webhook execution timed out`, { timeoutMs: timeoutController.timeoutMs, - }); - await loggingSession.markAsFailed(timeoutErrorMessage); - } else if (executionResult.status === "paused") { + }) + await loggingSession.markAsFailed(timeoutErrorMessage) + } else if (executionResult.status === 'paused') { if (!executionResult.snapshotSeed) { - logger.error( - `[${requestId}] Missing snapshot seed for paused execution`, - { - executionId, - }, - ); - await loggingSession.markAsFailed( - "Missing snapshot seed for paused execution", - ); + logger.error(`[${requestId}] Missing snapshot seed for paused execution`, { + executionId, + }) + await loggingSession.markAsFailed('Missing snapshot seed for paused execution') } else { try { await PauseResumeManager.persistPauseResult({ @@ -715,29 +614,26 @@ async function executeWebhookJobInternal( pausePoints: executionResult.pausePoints || [], snapshotSeed: executionResult.snapshotSeed, executorUserId: executionResult.metadata?.userId, - }); + }) } catch (pauseError) { logger.error(`[${requestId}] Failed to persist pause result`, { executionId, - error: - pauseError instanceof Error - ? pauseError.message - : String(pauseError), - }); + error: pauseError instanceof Error ? pauseError.message : String(pauseError), + }) await loggingSession.markAsFailed( - `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}`, - ); + `Failed to persist pause state: ${pauseError instanceof Error ? pauseError.message : String(pauseError)}` + ) } } } else { - await PauseResumeManager.processQueuedResumes(executionId); + await PauseResumeManager.processQueuedResumes(executionId) } logger.info(`[${requestId}] Webhook execution completed`, { success: executionResult.success, workflowId: payload.workflowId, provider: payload.provider, - }); + }) return { success: executionResult.success, @@ -746,20 +642,20 @@ async function executeWebhookJobInternal( output: executionResult.output, executedAt: new Date().toISOString(), provider: payload.provider, - }; + } } catch (error: unknown) { - const errorMessage = error instanceof Error ? error.message : String(error); - const errorStack = error instanceof Error ? error.stack : undefined; + const errorMessage = error instanceof Error ? error.message : String(error) + const errorStack = error instanceof Error ? error.stack : undefined logger.error(`[${requestId}] Webhook execution failed`, { error: errorMessage, stack: errorStack, workflowId: payload.workflowId, provider: payload.provider, - }); + }) if (wasExecutionFinalizedByCore(error, executionId)) { - throw error; + throw error } try { @@ -772,7 +668,7 @@ async function executeWebhookJobInternal( correlation, }, deploymentVersionId, - }); + }) const executionResult = hasExecutionResult(error) ? error.executionResult @@ -780,36 +676,33 @@ async function executeWebhookJobInternal( success: false, output: {}, logs: [], - }; - const { traceSpans } = buildTraceSpans(executionResult); + } + const { traceSpans } = buildTraceSpans(executionResult) await loggingSession.safeCompleteWithError({ endedAt: new Date().toISOString(), totalDurationMs: 0, error: { - message: errorMessage || "Webhook execution failed", + message: errorMessage || 'Webhook execution failed', stackTrace: errorStack, }, traceSpans, - }); + }) } catch (loggingError) { - logger.error( - `[${requestId}] Failed to complete logging session`, - loggingError, - ); + logger.error(`[${requestId}] Failed to complete logging session`, loggingError) } - throw error; + throw error } finally { - timeoutController.cleanup(); + timeoutController.cleanup() } } export const webhookExecution = task({ - id: "webhook-execution", - machine: "medium-1x", + id: 'webhook-execution', + machine: 'medium-1x', retry: { maxAttempts: 1, }, run: async (payload: WebhookExecutionPayload) => executeWebhookJob(payload), -}); +}) From 7f2447ab56459c1db791c931aee0d967bc1e9ad2 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Thu, 12 Mar 2026 14:27:12 +0300 Subject: [PATCH 05/11] fix(async): avoid pre-starting queued execution logs Let executeWorkflowCore own normal-path logging start so queued workflow and schedule executions persist the richer deployment and environment metadata instead of an earlier placeholder start record. --- .../async-preprocessing-correlation.test.ts | 130 ++++++++++++++++-- apps/sim/background/schedule-execution.ts | 7 - apps/sim/background/workflow-execution.ts | 7 - 3 files changed, 119 insertions(+), 25 deletions(-) diff --git a/apps/sim/background/async-preprocessing-correlation.test.ts b/apps/sim/background/async-preprocessing-correlation.test.ts index 4d2cd36f895..c2844150c6d 100644 --- a/apps/sim/background/async-preprocessing-correlation.test.ts +++ b/apps/sim/background/async-preprocessing-correlation.test.ts @@ -4,12 +4,28 @@ import { beforeEach, describe, expect, it, vi } from 'vitest' -const { mockPreprocessExecution, mockTask, mockDbUpdate } = vi.hoisted(() => ({ +const { + mockPreprocessExecution, + mockTask, + mockDbUpdate, + mockExecuteWorkflowCore, + mockLoggingSession, + mockBlockExistsInDeployment, + mockLoadDeployedWorkflowState, + mockGetScheduleTimeValues, + mockGetSubBlockValue, +} = vi.hoisted(() => ({ mockPreprocessExecution: vi.fn(), mockTask: vi.fn((config) => config), mockDbUpdate: vi.fn(() => ({ set: vi.fn(() => ({ where: vi.fn().mockResolvedValue(undefined) })), })), + mockExecuteWorkflowCore: vi.fn(), + mockLoggingSession: vi.fn(), + mockBlockExistsInDeployment: vi.fn(), + mockLoadDeployedWorkflowState: vi.fn(), + mockGetScheduleTimeValues: vi.fn(), + mockGetSubBlockValue: vi.fn(), })) vi.mock('@trigger.dev/sdk', () => ({ task: mockTask })) @@ -30,11 +46,15 @@ vi.mock('@/lib/execution/preprocessing', () => ({ })) vi.mock('@/lib/logs/execution/logging-session', () => ({ - LoggingSession: vi.fn().mockImplementation(() => ({ - safeStart: vi.fn().mockResolvedValue(true), - safeCompleteWithError: vi.fn().mockResolvedValue(undefined), - markAsFailed: vi.fn().mockResolvedValue(undefined), - })), + LoggingSession: vi.fn().mockImplementation(() => { + const instance = { + safeStart: vi.fn().mockResolvedValue(true), + safeCompleteWithError: vi.fn().mockResolvedValue(undefined), + markAsFailed: vi.fn().mockResolvedValue(undefined), + } + mockLoggingSession(instance) + return instance + }), })) vi.mock('@/lib/core/execution-limits', () => ({ @@ -52,7 +72,7 @@ vi.mock('@/lib/logs/execution/trace-spans/trace-spans', () => ({ })) vi.mock('@/lib/workflows/executor/execution-core', () => ({ - executeWorkflowCore: vi.fn(), + executeWorkflowCore: mockExecuteWorkflowCore, wasExecutionFinalizedByCore: vi.fn().mockReturnValue(false), })) @@ -64,14 +84,14 @@ vi.mock('@/lib/workflows/executor/human-in-the-loop-manager', () => ({ })) vi.mock('@/lib/workflows/persistence/utils', () => ({ - blockExistsInDeployment: vi.fn(), - loadDeployedWorkflowState: vi.fn(), + blockExistsInDeployment: mockBlockExistsInDeployment, + loadDeployedWorkflowState: mockLoadDeployedWorkflowState, })) vi.mock('@/lib/workflows/schedules/utils', () => ({ calculateNextRunTime: vi.fn(), - getScheduleTimeValues: vi.fn(), - getSubBlockValue: vi.fn(), + getScheduleTimeValues: mockGetScheduleTimeValues, + getSubBlockValue: mockGetSubBlockValue, })) vi.mock('@/executor/execution/snapshot', () => ({ @@ -97,6 +117,94 @@ import { executeWorkflowJob } from './workflow-execution' describe('async preprocessing correlation threading', () => { beforeEach(() => { vi.clearAllMocks() + mockLoadDeployedWorkflowState.mockResolvedValue({ + blocks: { + 'schedule-block': { + type: 'schedule', + }, + }, + edges: [], + loops: {}, + parallels: {}, + deploymentVersionId: 'deployment-1', + }) + mockGetSubBlockValue.mockReturnValue('daily') + mockGetScheduleTimeValues.mockReturnValue({ timezone: 'UTC' }) + }) + + it('does not pre-start workflow logging before core execution', async () => { + mockPreprocessExecution.mockResolvedValueOnce({ + success: true, + actorUserId: 'actor-1', + workflowRecord: { + id: 'workflow-1', + userId: 'owner-1', + workspaceId: 'workspace-1', + variables: {}, + }, + executionTimeout: {}, + }) + mockExecuteWorkflowCore.mockResolvedValueOnce({ + success: true, + status: 'success', + output: { ok: true }, + metadata: { duration: 10, userId: 'actor-1' }, + }) + + await executeWorkflowJob({ + workflowId: 'workflow-1', + userId: 'user-1', + triggerType: 'api', + executionId: 'execution-1', + requestId: 'request-1', + }) + + const loggingSession = mockLoggingSession.mock.calls[0]?.[0] + expect(loggingSession).toBeDefined() + expect(loggingSession.safeStart).not.toHaveBeenCalled() + expect(mockExecuteWorkflowCore).toHaveBeenCalledWith( + expect.objectContaining({ + loggingSession, + }) + ) + }) + + it('does not pre-start schedule logging before core execution', async () => { + mockPreprocessExecution.mockResolvedValueOnce({ + success: true, + actorUserId: 'actor-2', + workflowRecord: { + id: 'workflow-1', + userId: 'owner-1', + workspaceId: 'workspace-1', + variables: {}, + }, + executionTimeout: {}, + }) + mockExecuteWorkflowCore.mockResolvedValueOnce({ + success: true, + status: 'success', + output: { ok: true }, + metadata: { duration: 12, userId: 'actor-2' }, + }) + + await executeScheduleJob({ + scheduleId: 'schedule-1', + workflowId: 'workflow-1', + executionId: 'execution-2', + requestId: 'request-2', + now: '2025-01-01T00:00:00.000Z', + scheduledFor: '2025-01-01T00:00:00.000Z', + }) + + const loggingSession = mockLoggingSession.mock.calls[0]?.[0] + expect(loggingSession).toBeDefined() + expect(loggingSession.safeStart).not.toHaveBeenCalled() + expect(mockExecuteWorkflowCore).toHaveBeenCalledWith( + expect.objectContaining({ + loggingSession, + }) + ) }) it('passes workflow correlation into preprocessing', async () => { diff --git a/apps/sim/background/schedule-execution.ts b/apps/sim/background/schedule-execution.ts index 54520368ad4..6d1cbd5939f 100644 --- a/apps/sim/background/schedule-execution.ts +++ b/apps/sim/background/schedule-execution.ts @@ -492,13 +492,6 @@ export async function executeScheduleJob(payload: ScheduleExecutionPayload) { throw new Error(`Workflow ${payload.workflowId} has no associated workspace`) } - await loggingSession.safeStart({ - userId: actorUserId, - workspaceId: workflowRecord.workspaceId, - variables: {}, - triggerData: { correlation }, - }) - logger.info(`[${requestId}] Executing scheduled workflow ${payload.workflowId}`) try { diff --git a/apps/sim/background/workflow-execution.ts b/apps/sim/background/workflow-execution.ts index 9188b9d5565..b936ca859ea 100644 --- a/apps/sim/background/workflow-execution.ts +++ b/apps/sim/background/workflow-execution.ts @@ -95,13 +95,6 @@ export async function executeWorkflowJob(payload: WorkflowExecutionPayload) { logger.info(`[${requestId}] Preprocessing passed. Using actor: ${actorUserId}`) - await loggingSession.safeStart({ - userId: actorUserId, - workspaceId, - variables: {}, - triggerData: { correlation }, - }) - const workflow = preprocessResult.workflowRecord! const metadata: ExecutionMetadata = { From d467c3ebfc04e4ec30771ac63d5be5dadcd77827 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Fri, 13 Mar 2026 00:42:51 +0300 Subject: [PATCH 06/11] fix(async): harden execution finalization guards Prevent leaked core finalization markers from accumulating while keeping outer recovery paths idempotent. Preserve best-effort logging completion by reusing settled completion promises instead of reopening duplicate terminal writes. --- .../logs/execution/logging-session.test.ts | 45 +++++++++++----- .../sim/lib/logs/execution/logging-session.ts | 52 +++++++++++-------- .../workflows/executor/execution-core.test.ts | 49 ++++++++++++++++- .../lib/workflows/executor/execution-core.ts | 27 ++++++++-- 4 files changed, 132 insertions(+), 41 deletions(-) diff --git a/apps/sim/lib/logs/execution/logging-session.test.ts b/apps/sim/lib/logs/execution/logging-session.test.ts index 21c741378c3..0e44130bc87 100644 --- a/apps/sim/lib/logs/execution/logging-session.test.ts +++ b/apps/sim/lib/logs/execution/logging-session.test.ts @@ -1,4 +1,8 @@ -import { describe, expect, it, vi } from 'vitest' +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const { completeWorkflowExecutionMock } = vi.hoisted(() => ({ + completeWorkflowExecutionMock: vi.fn(), +})) vi.mock('@sim/db', () => ({ db: {}, @@ -25,7 +29,7 @@ vi.mock('drizzle-orm', () => ({ vi.mock('@/lib/logs/execution/logger', () => ({ executionLogger: { startWorkflowExecution: vi.fn(), - completeWorkflowExecution: vi.fn(), + completeWorkflowExecution: completeWorkflowExecutionMock, }, })) @@ -50,17 +54,18 @@ vi.mock('@/lib/logs/execution/logging-factory', () => ({ import { LoggingSession } from './logging-session' describe('LoggingSession completion retries', () => { - it('clears failed completion promise so error finalization can retry', async () => { - const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') as any + beforeEach(() => { + vi.clearAllMocks() + }) - const successFinalizeError = new Error('success finalize failed') - session.complete = vi.fn().mockRejectedValue(successFinalizeError) - session.completeWithCostOnlyLog = vi.fn().mockRejectedValue(successFinalizeError) - session.completeWithError = vi.fn().mockResolvedValue(undefined) + it('keeps completion best-effort when full completion and fallback both fail', async () => { + const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') - await expect(session.safeComplete({ finalOutput: { ok: true } })).rejects.toThrow( - 'success finalize failed' - ) + completeWorkflowExecutionMock + .mockRejectedValueOnce(new Error('success finalize failed')) + .mockRejectedValueOnce(new Error('cost only failed')) + + await expect(session.safeComplete({ finalOutput: { ok: true } })).resolves.toBeUndefined() await expect( session.safeCompleteWithError({ @@ -68,8 +73,20 @@ describe('LoggingSession completion retries', () => { }) ).resolves.toBeUndefined() - expect(session.complete).toHaveBeenCalledTimes(1) - expect(session.completeWithCostOnlyLog).toHaveBeenCalledTimes(1) - expect(session.completeWithError).toHaveBeenCalledTimes(1) + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) + }) + + it('reuses the settled completion promise for repeated completion attempts', async () => { + const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') + + completeWorkflowExecutionMock + .mockRejectedValueOnce(new Error('success finalize failed')) + .mockRejectedValueOnce(new Error('cost only failed')) + + await expect(session.safeComplete({ finalOutput: { ok: true } })).resolves.toBeUndefined() + + await expect(session.safeComplete({ finalOutput: { ok: true } })).resolves.toBeUndefined() + + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) }) }) diff --git a/apps/sim/lib/logs/execution/logging-session.ts b/apps/sim/lib/logs/execution/logging-session.ts index 245e7eb3562..df4b11739ca 100644 --- a/apps/sim/lib/logs/execution/logging-session.ts +++ b/apps/sim/lib/logs/execution/logging-session.ts @@ -25,6 +25,8 @@ type TriggerData = Record & { const logger = createLogger('LoggingSession') +type CompletionAttempt = 'complete' | 'error' | 'cancelled' | 'paused' + export interface SessionStartParams { userId?: string workspaceId: string @@ -98,6 +100,8 @@ export class LoggingSession { private completing = false /** Tracks the in-flight completion promise so callers can await it */ private completionPromise: Promise | null = null + private completionAttempt: CompletionAttempt | null = null + private completionAttemptFailed = false private accumulatedCost: AccumulatedCost = { total: BASE_EXECUTION_CHARGE, input: 0, @@ -695,15 +699,32 @@ export class LoggingSession { } } - async safeComplete(params: SessionCompleteParams = {}): Promise { - if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteImpl(params).catch((error) => { - this.completionPromise = null + private shouldStartNewCompletionAttempt(attempt: CompletionAttempt): boolean { + return this.completionAttemptFailed && this.completionAttempt !== 'error' && attempt === 'error' + } + + private runCompletionAttempt( + attempt: CompletionAttempt, + run: () => Promise + ): Promise { + if (this.completionPromise && !this.shouldStartNewCompletionAttempt(attempt)) { + return this.completionPromise + } + + this.completionAttempt = attempt + this.completionAttemptFailed = false + this.completionPromise = run().catch((error) => { + this.completionAttemptFailed = true throw error }) + return this.completionPromise } + async safeComplete(params: SessionCompleteParams = {}): Promise { + return this.runCompletionAttempt('complete', () => this._safeCompleteImpl(params)) + } + private async _safeCompleteImpl(params: SessionCompleteParams = {}): Promise { try { await this.complete(params) @@ -724,12 +745,7 @@ export class LoggingSession { } async safeCompleteWithError(params?: SessionErrorCompleteParams): Promise { - if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithErrorImpl(params).catch((error) => { - this.completionPromise = null - throw error - }) - return this.completionPromise + return this.runCompletionAttempt('error', () => this._safeCompleteWithErrorImpl(params)) } private async _safeCompleteWithErrorImpl(params?: SessionErrorCompleteParams): Promise { @@ -754,12 +770,9 @@ export class LoggingSession { } async safeCompleteWithCancellation(params?: SessionCancelledParams): Promise { - if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithCancellationImpl(params).catch((error) => { - this.completionPromise = null - throw error - }) - return this.completionPromise + return this.runCompletionAttempt('cancelled', () => + this._safeCompleteWithCancellationImpl(params) + ) } private async _safeCompleteWithCancellationImpl(params?: SessionCancelledParams): Promise { @@ -783,12 +796,7 @@ export class LoggingSession { } async safeCompleteWithPause(params?: SessionPausedParams): Promise { - if (this.completionPromise) return this.completionPromise - this.completionPromise = this._safeCompleteWithPauseImpl(params).catch((error) => { - this.completionPromise = null - throw error - }) - return this.completionPromise + return this.runCompletionAttempt('paused', () => this._safeCompleteWithPauseImpl(params)) } private async _safeCompleteWithPauseImpl(params?: SessionPausedParams): Promise { diff --git a/apps/sim/lib/workflows/executor/execution-core.test.ts b/apps/sim/lib/workflows/executor/execution-core.test.ts index 9c15eb01b2e..dceff65c1f3 100644 --- a/apps/sim/lib/workflows/executor/execution-core.test.ts +++ b/apps/sim/lib/workflows/executor/execution-core.test.ts @@ -89,7 +89,11 @@ vi.mock('@/serializer', () => ({ })), })) -import { executeWorkflowCore, wasExecutionFinalizedByCore } from './execution-core' +import { + executeWorkflowCore, + FINALIZED_EXECUTION_ID_TTL_MS, + wasExecutionFinalizedByCore, +} from './execution-core' describe('executeWorkflowCore terminal finalization sequencing', () => { const loggingSession = { @@ -127,6 +131,7 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { beforeEach(() => { vi.clearAllMocks() + vi.useRealTimers() loadWorkflowFromNormalizedTablesMock.mockResolvedValue({ blocks: { @@ -330,7 +335,47 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) expect(wasExecutionFinalizedByCore('engine failed', 'execution-1')).toBe(true) - expect(wasExecutionFinalizedByCore('engine failed', 'execution-1')).toBe(false) + expect(wasExecutionFinalizedByCore('engine failed', 'execution-1')).toBe(true) + }) + + it('expires stale finalized execution ids for callers that never consume the guard', async () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-03-13T00:00:00.000Z')) + + executorExecuteMock.mockRejectedValue('engine failed') + + await expect( + executeWorkflowCore({ + snapshot: { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-stale', + }, + } as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + vi.setSystemTime(new Date(Date.now() + FINALIZED_EXECUTION_ID_TTL_MS + 1)) + + await expect( + executeWorkflowCore({ + snapshot: { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-fresh', + }, + } as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + expect(wasExecutionFinalizedByCore('engine failed', 'execution-stale')).toBe(false) + expect(wasExecutionFinalizedByCore('engine failed', 'execution-fresh')).toBe(true) }) it('falls back to error finalization when success finalization rejects', async () => { diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index 5425162e6ce..c1b21ff1be7 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -116,10 +116,29 @@ type ExecutionErrorWithFinalizationFlag = Error & { executionFinalizedByCore?: boolean } -const finalizedExecutionIds = new Set() +export const FINALIZED_EXECUTION_ID_TTL_MS = 5 * 60 * 1000 + +const finalizedExecutionIds = new Map() + +function cleanupExpiredFinalizedExecutionIds(now = Date.now()): void { + for (const [executionId, expiresAt] of finalizedExecutionIds.entries()) { + if (expiresAt > now) { + break + } + + finalizedExecutionIds.delete(executionId) + } +} + +function rememberFinalizedExecutionId(executionId: string): void { + const now = Date.now() + + cleanupExpiredFinalizedExecutionIds(now) + finalizedExecutionIds.set(executionId, now + FINALIZED_EXECUTION_ID_TTL_MS) +} function markExecutionFinalizedByCore(error: unknown, executionId: string): void { - finalizedExecutionIds.add(executionId) + rememberFinalizedExecutionId(executionId) if (error instanceof Error) { ;(error as ExecutionErrorWithFinalizationFlag).executionFinalizedByCore = true @@ -127,7 +146,9 @@ function markExecutionFinalizedByCore(error: unknown, executionId: string): void } export function wasExecutionFinalizedByCore(error: unknown, executionId?: string): boolean { - if (executionId && finalizedExecutionIds.delete(executionId)) { + cleanupExpiredFinalizedExecutionIds() + + if (executionId && finalizedExecutionIds.has(executionId)) { return true } From 285d2d73451f59156fa5c0b1dd02f1a601be6f5a Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Fri, 13 Mar 2026 01:09:43 +0300 Subject: [PATCH 07/11] fix(async): preserve outcomes during cleanup Keep execution finalization cleanup best-effort so cancellation cleanup failures do not overwrite successful or failed outcomes. Restore webhook processor formatting to the repository Biome style to avoid noisy formatter churn. --- .../workflows/executor/execution-core.test.ts | 38 +++++++++++++++++++ .../lib/workflows/executor/execution-core.ts | 19 ++++++++-- 2 files changed, 54 insertions(+), 3 deletions(-) diff --git a/apps/sim/lib/workflows/executor/execution-core.test.ts b/apps/sim/lib/workflows/executor/execution-core.test.ts index dceff65c1f3..82694b9d752 100644 --- a/apps/sim/lib/workflows/executor/execution-core.test.ts +++ b/apps/sim/lib/workflows/executor/execution-core.test.ts @@ -406,4 +406,42 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { }) ) }) + + it('does not replace a successful outcome when cancellation cleanup fails', async () => { + executorExecuteMock.mockResolvedValue({ + success: true, + status: 'completed', + output: { done: true }, + logs: [], + metadata: { duration: 123, startTime: 'start', endTime: 'end' }, + }) + + clearExecutionCancellationMock.mockRejectedValue(new Error('cleanup failed')) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).resolves.toMatchObject({ status: 'completed', success: true }) + + expect(safeCompleteWithErrorMock).not.toHaveBeenCalled() + }) + + it('does not replace the original error when cancellation cleanup fails', async () => { + const error = new Error('engine failed') + executorExecuteMock.mockRejectedValue(error) + clearExecutionCancellationMock.mockRejectedValue(new Error('cleanup failed')) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe(error) + + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + }) }) diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index c1b21ff1be7..700cd726502 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -137,6 +137,17 @@ function rememberFinalizedExecutionId(executionId: string): void { finalizedExecutionIds.set(executionId, now + FINALIZED_EXECUTION_ID_TTL_MS) } +async function clearExecutionCancellationSafely( + executionId: string, + requestId: string +): Promise { + try { + await clearExecutionCancellation(executionId) + } catch (error) { + logger.error(`[${requestId}] Failed to clear execution cancellation`, { error, executionId }) + } +} + function markExecutionFinalizedByCore(error: unknown, executionId: string): void { rememberFinalizedExecutionId(executionId) @@ -162,9 +173,10 @@ async function finalizeExecutionOutcome(params: { result: ExecutionResult loggingSession: LoggingSession executionId: string + requestId: string workflowInput: unknown }): Promise { - const { result, loggingSession, executionId, workflowInput } = params + const { result, loggingSession, executionId, requestId, workflowInput } = params const { traceSpans, totalDuration } = buildTraceSpans(result) const endedAt = new Date().toISOString() @@ -197,7 +209,7 @@ async function finalizeExecutionOutcome(params: { executionState: result.executionState, }) } finally { - await clearExecutionCancellation(executionId) + await clearExecutionCancellationSafely(executionId, requestId) } } @@ -229,7 +241,7 @@ async function finalizeExecutionError(params: { }) return false } finally { - await clearExecutionCancellation(executionId) + await clearExecutionCancellationSafely(executionId, requestId) } } @@ -486,6 +498,7 @@ export async function executeWorkflowCore( result, loggingSession, executionId, + requestId, workflowInput: processedInput, }) From ca0a24e3f6addbf51fa9b7ea4a3ec4d6126fe47e Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Fri, 13 Mar 2026 01:59:27 +0300 Subject: [PATCH 08/11] fix(async): keep execution finalization state consistent Retry minimal logging for early failures, only mark core finalization after a log row actually completes, and let paused completions fall back cleanly. --- .../logs/execution/logging-session.test.ts | 45 +++++++++++ .../sim/lib/logs/execution/logging-session.ts | 12 +++ .../workflows/executor/execution-core.test.ts | 79 ++++++++++++++++++- .../lib/workflows/executor/execution-core.ts | 32 +++++--- 4 files changed, 158 insertions(+), 10 deletions(-) diff --git a/apps/sim/lib/logs/execution/logging-session.test.ts b/apps/sim/lib/logs/execution/logging-session.test.ts index 0e44130bc87..9be196d95e9 100644 --- a/apps/sim/lib/logs/execution/logging-session.test.ts +++ b/apps/sim/lib/logs/execution/logging-session.test.ts @@ -89,4 +89,49 @@ describe('LoggingSession completion retries', () => { expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) }) + + it('marks paused completions as completed and deduplicates later attempts', async () => { + const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') + + completeWorkflowExecutionMock.mockResolvedValue({}) + + await expect( + session.safeCompleteWithPause({ + endedAt: new Date().toISOString(), + totalDurationMs: 10, + traceSpans: [], + workflowInput: { hello: 'world' }, + }) + ).resolves.toBeUndefined() + + expect(session.hasCompleted()).toBe(true) + + await expect( + session.safeCompleteWithError({ + error: { message: 'should be ignored' }, + }) + ).resolves.toBeUndefined() + + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(1) + }) + + it('falls back to cost-only logging when paused completion fails', async () => { + const session = new LoggingSession('workflow-1', 'execution-2', 'api', 'req-1') + + completeWorkflowExecutionMock + .mockRejectedValueOnce(new Error('pause finalize failed')) + .mockResolvedValueOnce({}) + + await expect( + session.safeCompleteWithPause({ + endedAt: new Date().toISOString(), + totalDurationMs: 10, + traceSpans: [], + workflowInput: { hello: 'world' }, + }) + ).resolves.toBeUndefined() + + expect(session.hasCompleted()).toBe(true) + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) + }) }) diff --git a/apps/sim/lib/logs/execution/logging-session.ts b/apps/sim/lib/logs/execution/logging-session.ts index df4b11739ca..7405477337f 100644 --- a/apps/sim/lib/logs/execution/logging-session.ts +++ b/apps/sim/lib/logs/execution/logging-session.ts @@ -549,6 +549,11 @@ export class LoggingSession { } async completeWithPause(params: SessionPausedParams = {}): Promise { + if (this.completed || this.completing) { + return + } + this.completing = true + try { const { endedAt, totalDurationMs, traceSpans, workflowInput } = params @@ -580,6 +585,8 @@ export class LoggingSession { status: 'pending', }) + this.completed = true + try { const { PlatformEvents, createOTelSpansForWorkflowExecution } = await import( '@/lib/core/telemetry' @@ -616,6 +623,7 @@ export class LoggingSession { ) } } catch (pauseError) { + this.completing = false logger.error(`Failed to complete paused logging for execution ${this.executionId}:`, { requestId: this.requestId, workflowId: this.workflowId, @@ -699,6 +707,10 @@ export class LoggingSession { } } + hasCompleted(): boolean { + return this.completed + } + private shouldStartNewCompletionAttempt(attempt: CompletionAttempt): boolean { return this.completionAttemptFailed && this.completionAttempt !== 'error' && attempt === 'error' } diff --git a/apps/sim/lib/workflows/executor/execution-core.test.ts b/apps/sim/lib/workflows/executor/execution-core.test.ts index 82694b9d752..5fcafa374b1 100644 --- a/apps/sim/lib/workflows/executor/execution-core.test.ts +++ b/apps/sim/lib/workflows/executor/execution-core.test.ts @@ -10,6 +10,7 @@ const { safeCompleteWithErrorMock, safeCompleteWithCancellationMock, safeCompleteWithPauseMock, + hasCompletedMock, updateWorkflowRunCountsMock, clearExecutionCancellationMock, buildTraceSpansMock, @@ -25,6 +26,7 @@ const { safeCompleteWithErrorMock: vi.fn(), safeCompleteWithCancellationMock: vi.fn(), safeCompleteWithPauseMock: vi.fn(), + hasCompletedMock: vi.fn(), updateWorkflowRunCountsMock: vi.fn(), clearExecutionCancellationMock: vi.fn(), buildTraceSpansMock: vi.fn(), @@ -102,6 +104,7 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { safeCompleteWithError: safeCompleteWithErrorMock, safeCompleteWithCancellation: safeCompleteWithCancellationMock, safeCompleteWithPause: safeCompleteWithPauseMock, + hasCompleted: hasCompletedMock, } const createSnapshot = () => ({ @@ -165,11 +168,12 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { mergeSubblockStateWithValuesMock.mockImplementation((blocks) => blocks) serializeWorkflowMock.mockReturnValue({ loops: {}, parallels: {} }) buildTraceSpansMock.mockReturnValue({ traceSpans: [{ id: 'span-1' }], totalDuration: 123 }) - safeStartMock.mockResolvedValue(undefined) + safeStartMock.mockResolvedValue(true) safeCompleteMock.mockResolvedValue(undefined) safeCompleteWithErrorMock.mockResolvedValue(undefined) safeCompleteWithCancellationMock.mockResolvedValue(undefined) safeCompleteWithPauseMock.mockResolvedValue(undefined) + hasCompletedMock.mockReturnValue(true) updateWorkflowRunCountsMock.mockResolvedValue(undefined) clearExecutionCancellationMock.mockResolvedValue(undefined) }) @@ -444,4 +448,77 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) }) + + it('does not mark core finalization when error completion never persists a log row', async () => { + const error = new Error('engine failed') + executorExecuteMock.mockRejectedValue(error) + hasCompletedMock.mockReturnValue(false) + const snapshot = { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-unfinalized', + }, + } + + await expect( + executeWorkflowCore({ + snapshot: snapshot as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe(error) + + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + expect(wasExecutionFinalizedByCore(error, 'execution-unfinalized')).toBe(false) + }) + + it('starts a minimal log session before error completion when setup fails early', async () => { + const envError = new Error('env lookup failed') + getPersonalAndWorkspaceEnvMock.mockRejectedValue(envError) + + await expect( + executeWorkflowCore({ + snapshot: createSnapshot() as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe(envError) + + expect(safeStartMock).toHaveBeenCalledTimes(1) + expect(safeStartMock).toHaveBeenCalledWith( + expect.objectContaining({ + userId: 'user-1', + workspaceId: 'workspace-1', + variables: {}, + }) + ) + expect(safeCompleteWithErrorMock).toHaveBeenCalledTimes(1) + expect(wasExecutionFinalizedByCore(envError, 'execution-1')).toBe(true) + }) + + it('skips core finalization when minimal error logging cannot start', async () => { + const envError = new Error('env lookup failed') + getPersonalAndWorkspaceEnvMock.mockRejectedValue(envError) + safeStartMock.mockResolvedValue(false) + const snapshot = { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-no-log-start', + }, + } + + await expect( + executeWorkflowCore({ + snapshot: snapshot as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe(envError) + + expect(safeStartMock).toHaveBeenCalledTimes(1) + expect(safeCompleteWithErrorMock).not.toHaveBeenCalled() + expect(wasExecutionFinalizedByCore(envError, 'execution-no-log-start')).toBe(false) + }) }) diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index 700cd726502..f4d3950458f 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -234,7 +234,7 @@ async function finalizeExecutionError(params: { traceSpans, }) - return true + return loggingSession.hasCompleted() } catch (postExecError) { logger.error(`[${requestId}] Post-execution error logging failed`, { error: postExecError, @@ -270,13 +270,14 @@ export async function executeWorkflowCore( } let processedInput = input || {} + let deploymentVersionId: string | undefined + let loggingStarted = false try { let blocks let edges: Edge[] let loops let parallels - let deploymentVersionId: string | undefined // Use workflowStateOverride if provided (for diff workflows) if (metadata.workflowStateOverride) { @@ -333,7 +334,7 @@ export async function executeWorkflowCore( // Use already-decrypted values for execution (no redundant decryption) const decryptedEnvVars: Record = { ...personalDecrypted, ...workspaceDecrypted } - await loggingSession.safeStart({ + loggingStarted = await loggingSession.safeStart({ userId, workspaceId: providedWorkspaceId, variables, @@ -520,12 +521,25 @@ export async function executeWorkflowCore( } catch (error: unknown) { logger.error(`[${requestId}] Execution failed:`, error) - const finalized = await finalizeExecutionError({ - error, - loggingSession, - executionId, - requestId, - }) + if (!loggingStarted) { + loggingStarted = await loggingSession.safeStart({ + userId, + workspaceId: providedWorkspaceId, + variables: {}, + triggerData: metadata.correlation ? { correlation: metadata.correlation } : undefined, + skipLogCreation, + deploymentVersionId, + }) + } + + const finalized = loggingStarted + ? await finalizeExecutionError({ + error, + loggingSession, + executionId, + requestId, + }) + : false if (finalized) { markExecutionFinalizedByCore(error, executionId) From 41d64c0901c5a9e07122ff1e6822e48b4667f049 Mon Sep 17 00:00:00 2001 From: Yusuf Mirza Altay Date: Fri, 13 Mar 2026 02:30:32 +0300 Subject: [PATCH 09/11] fix(async): clean stale finalization guards Scan all finalized execution ids during TTL cleanup so refreshed keys cannot keep expired guards alive, and cover the reused-id ordering regression. --- .../workflows/executor/execution-core.test.ts | 58 +++++++++++++++++++ .../lib/workflows/executor/execution-core.ts | 6 +- 2 files changed, 60 insertions(+), 4 deletions(-) diff --git a/apps/sim/lib/workflows/executor/execution-core.test.ts b/apps/sim/lib/workflows/executor/execution-core.test.ts index 5fcafa374b1..21c8a5b6b7a 100644 --- a/apps/sim/lib/workflows/executor/execution-core.test.ts +++ b/apps/sim/lib/workflows/executor/execution-core.test.ts @@ -382,6 +382,64 @@ describe('executeWorkflowCore terminal finalization sequencing', () => { expect(wasExecutionFinalizedByCore('engine failed', 'execution-fresh')).toBe(true) }) + it('removes expired finalized ids even when a reused id stays earlier in map order', async () => { + vi.useFakeTimers() + vi.setSystemTime(new Date('2026-03-13T00:00:00.000Z')) + + executorExecuteMock.mockRejectedValue('engine failed') + + await expect( + executeWorkflowCore({ + snapshot: { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-a', + }, + } as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + vi.setSystemTime(new Date('2026-03-13T00:01:00.000Z')) + + await expect( + executeWorkflowCore({ + snapshot: { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-b', + }, + } as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + vi.setSystemTime(new Date('2026-03-13T00:02:00.000Z')) + + await expect( + executeWorkflowCore({ + snapshot: { + ...createSnapshot(), + metadata: { + ...createSnapshot().metadata, + executionId: 'execution-a', + }, + } as any, + callbacks: {}, + loggingSession: loggingSession as any, + }) + ).rejects.toBe('engine failed') + + vi.setSystemTime(new Date('2026-03-13T00:06:01.000Z')) + + expect(wasExecutionFinalizedByCore('engine failed', 'execution-b')).toBe(false) + expect(wasExecutionFinalizedByCore('engine failed', 'execution-a')).toBe(true) + }) + it('falls back to error finalization when success finalization rejects', async () => { executorExecuteMock.mockResolvedValue({ success: true, diff --git a/apps/sim/lib/workflows/executor/execution-core.ts b/apps/sim/lib/workflows/executor/execution-core.ts index f4d3950458f..69610ff8018 100644 --- a/apps/sim/lib/workflows/executor/execution-core.ts +++ b/apps/sim/lib/workflows/executor/execution-core.ts @@ -122,11 +122,9 @@ const finalizedExecutionIds = new Map() function cleanupExpiredFinalizedExecutionIds(now = Date.now()): void { for (const [executionId, expiresAt] of finalizedExecutionIds.entries()) { - if (expiresAt > now) { - break + if (expiresAt <= now) { + finalizedExecutionIds.delete(executionId) } - - finalizedExecutionIds.delete(executionId) } } From ef63e9b4c6a3218013c3737d0d1cb871de3e185f Mon Sep 17 00:00:00 2001 From: test Date: Fri, 13 Mar 2026 10:12:45 +0300 Subject: [PATCH 10/11] fix(async): retry failed error finalization Allow error finalization to retry after a non-error completion and fallback both fail, and always persist failed/error semantics for completeWithError. --- .../logs/execution/logging-session.test.ts | 66 ++++++++++++++++++- .../sim/lib/logs/execution/logging-session.ts | 3 + 2 files changed, 67 insertions(+), 2 deletions(-) diff --git a/apps/sim/lib/logs/execution/logging-session.test.ts b/apps/sim/lib/logs/execution/logging-session.test.ts index 9be196d95e9..2f9bd2370f2 100644 --- a/apps/sim/lib/logs/execution/logging-session.test.ts +++ b/apps/sim/lib/logs/execution/logging-session.test.ts @@ -58,12 +58,13 @@ describe('LoggingSession completion retries', () => { vi.clearAllMocks() }) - it('keeps completion best-effort when full completion and fallback both fail', async () => { + it('keeps completion best-effort when a later error completion retries after full completion and fallback both fail', async () => { const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') completeWorkflowExecutionMock .mockRejectedValueOnce(new Error('success finalize failed')) .mockRejectedValueOnce(new Error('cost only failed')) + .mockResolvedValueOnce({}) await expect(session.safeComplete({ finalOutput: { ok: true } })).resolves.toBeUndefined() @@ -73,7 +74,8 @@ describe('LoggingSession completion retries', () => { }) ).resolves.toBeUndefined() - expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(3) + expect(session.hasCompleted()).toBe(true) }) it('reuses the settled completion promise for repeated completion attempts', async () => { @@ -90,6 +92,66 @@ describe('LoggingSession completion retries', () => { expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(2) }) + it('starts a new error completion attempt after a non-error completion and fallback both fail', async () => { + const session = new LoggingSession('workflow-1', 'execution-3', 'api', 'req-1') + + completeWorkflowExecutionMock + .mockRejectedValueOnce(new Error('success finalize failed')) + .mockRejectedValueOnce(new Error('cost only failed')) + .mockResolvedValueOnce({}) + + await expect(session.safeComplete({ finalOutput: { ok: true } })).resolves.toBeUndefined() + + await expect( + session.safeCompleteWithError({ + error: { message: 'late error finalize' }, + }) + ).resolves.toBeUndefined() + + expect(completeWorkflowExecutionMock).toHaveBeenCalledTimes(3) + expect(completeWorkflowExecutionMock).toHaveBeenLastCalledWith( + expect.objectContaining({ + executionId: 'execution-3', + finalOutput: { error: 'late error finalize' }, + }) + ) + expect(session.hasCompleted()).toBe(true) + }) + + it('persists failed error semantics when completeWithError receives non-error trace spans', async () => { + const session = new LoggingSession('workflow-1', 'execution-4', 'api', 'req-1') + const traceSpans = [ + { + id: 'span-1', + name: 'Block A', + type: 'tool', + duration: 25, + startTime: '2026-03-13T10:00:00.000Z', + endTime: '2026-03-13T10:00:00.025Z', + status: 'success', + }, + ] + + completeWorkflowExecutionMock.mockResolvedValue({}) + + await expect( + session.safeCompleteWithError({ + error: { message: 'persist me as failed' }, + traceSpans, + }) + ).resolves.toBeUndefined() + + expect(completeWorkflowExecutionMock).toHaveBeenCalledWith( + expect.objectContaining({ + executionId: 'execution-4', + finalOutput: { error: 'persist me as failed' }, + traceSpans, + level: 'error', + status: 'failed', + }) + ) + }) + it('marks paused completions as completed and deduplicates later attempts', async () => { const session = new LoggingSession('workflow-1', 'execution-1', 'api', 'req-1') diff --git a/apps/sim/lib/logs/execution/logging-session.ts b/apps/sim/lib/logs/execution/logging-session.ts index 7405477337f..d41b1eda069 100644 --- a/apps/sim/lib/logs/execution/logging-session.ts +++ b/apps/sim/lib/logs/execution/logging-session.ts @@ -409,6 +409,8 @@ export class LoggingSession { costSummary, finalOutput: { error: message }, traceSpans: spans, + level: 'error', + status: 'failed', }) this.completed = true @@ -919,6 +921,7 @@ export class LoggingSession { ) } catch (fallbackError) { this.completing = false + this.completionAttemptFailed = true logger.error( `[${this.requestId || 'unknown'}] Cost-only fallback also failed for execution ${this.executionId}:`, { error: fallbackError instanceof Error ? fallbackError.message : String(fallbackError) } From a72a6714329500357ff96112ac4b0f403dd1eee0 Mon Sep 17 00:00:00 2001 From: test Date: Fri, 13 Mar 2026 10:34:29 +0300 Subject: [PATCH 11/11] fix(webhooks): reuse preprocessing execution ids Thread preprocessing execution identity into queued webhook execution so both phases share the same correlation and logs. --- .../api/webhooks/trigger/[path]/route.test.ts | 35 ++- .../app/api/webhooks/trigger/[path]/route.ts | 2 + apps/sim/lib/webhooks/processor.test.ts | 219 ++++++++++++++++++ apps/sim/lib/webhooks/processor.ts | 36 ++- 4 files changed, 276 insertions(+), 16 deletions(-) create mode 100644 apps/sim/lib/webhooks/processor.test.ts diff --git a/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts b/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts index 4463ba5d04d..7938123e1d1 100644 --- a/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts +++ b/apps/sim/app/api/webhooks/trigger/[path]/route.test.ts @@ -355,9 +355,21 @@ vi.mock('@/lib/webhooks/processor', () => ({ return null } ), - checkWebhookPreprocessing: vi - .fn() - .mockResolvedValue({ error: null, actorUserId: 'test-user-id' }), + checkWebhookPreprocessing: vi.fn().mockResolvedValue({ + error: null, + actorUserId: 'test-user-id', + executionId: 'preprocess-execution-id', + correlation: { + executionId: 'preprocess-execution-id', + requestId: 'mock-request-id', + source: 'webhook', + workflowId: 'test-workflow-id', + webhookId: 'generic-webhook-id', + path: 'test-path', + provider: 'generic', + triggerType: 'webhook', + }, + }), formatProviderErrorResponse: vi.fn().mockImplementation((_webhook, error, status) => { const { NextResponse } = require('next/server') return NextResponse.json({ error }, { status }) @@ -516,7 +528,22 @@ describe('Webhook Trigger API Route', () => { expect(call[1]).toEqual(expect.objectContaining({ id: 'test-workflow-id' })) expect(call[2]).toEqual(expect.objectContaining({ event: 'test', id: 'test-123' })) expect(call[4]).toEqual( - expect.objectContaining({ requestId: 'mock-request-id', path: 'test-path' }) + expect.objectContaining({ + requestId: 'mock-request-id', + path: 'test-path', + actorUserId: 'test-user-id', + executionId: 'preprocess-execution-id', + correlation: { + executionId: 'preprocess-execution-id', + requestId: 'mock-request-id', + source: 'webhook', + workflowId: 'test-workflow-id', + webhookId: 'generic-webhook-id', + path: 'test-path', + provider: 'generic', + triggerType: 'webhook', + }, + }) ) }) diff --git a/apps/sim/app/api/webhooks/trigger/[path]/route.ts b/apps/sim/app/api/webhooks/trigger/[path]/route.ts index f8d0d8fb1b1..56304c3e850 100644 --- a/apps/sim/app/api/webhooks/trigger/[path]/route.ts +++ b/apps/sim/app/api/webhooks/trigger/[path]/route.ts @@ -144,6 +144,8 @@ export async function POST( requestId, path, actorUserId: preprocessResult.actorUserId, + executionId: preprocessResult.executionId, + correlation: preprocessResult.correlation, }) responses.push(response) } diff --git a/apps/sim/lib/webhooks/processor.test.ts b/apps/sim/lib/webhooks/processor.test.ts new file mode 100644 index 00000000000..20ae4408cd8 --- /dev/null +++ b/apps/sim/lib/webhooks/processor.test.ts @@ -0,0 +1,219 @@ +/** + * @vitest-environment node + */ + +import { createMockRequest } from '@sim/testing' +import { beforeEach, describe, expect, it, vi } from 'vitest' + +const { + mockUuidV4, + mockPreprocessExecution, + mockEnqueue, + mockGetJobQueue, + mockShouldExecuteInline, +} = vi.hoisted(() => ({ + mockUuidV4: vi.fn(), + mockPreprocessExecution: vi.fn(), + mockEnqueue: vi.fn(), + mockGetJobQueue: vi.fn(), + mockShouldExecuteInline: vi.fn(), +})) + +vi.mock('@sim/db', () => ({ + db: {}, + webhook: {}, + workflow: {}, + workflowDeploymentVersion: {}, +})) + +vi.mock('@sim/db/schema', () => ({ + credentialSet: {}, + subscription: {}, +})) + +vi.mock('@sim/logger', () => ({ + createLogger: vi.fn().mockReturnValue({ + info: vi.fn(), + warn: vi.fn(), + error: vi.fn(), + debug: vi.fn(), + }), +})) + +vi.mock('drizzle-orm', () => ({ + and: vi.fn(), + eq: vi.fn(), + isNull: vi.fn(), + or: vi.fn(), +})) + +vi.mock('uuid', () => ({ + v4: mockUuidV4, +})) + +vi.mock('@/lib/billing/subscriptions/utils', () => ({ + checkEnterprisePlan: vi.fn().mockReturnValue(true), + checkTeamPlan: vi.fn().mockReturnValue(true), +})) + +vi.mock('@/lib/core/async-jobs', () => ({ + getInlineJobQueue: vi.fn(), + getJobQueue: mockGetJobQueue, + shouldExecuteInline: mockShouldExecuteInline, +})) + +vi.mock('@/lib/core/config/feature-flags', () => ({ + isProd: false, +})) + +vi.mock('@/lib/core/security/encryption', () => ({ + safeCompare: vi.fn().mockReturnValue(true), +})) + +vi.mock('@/lib/environment/utils', () => ({ + getEffectiveDecryptedEnv: vi.fn().mockResolvedValue({}), +})) + +vi.mock('@/lib/execution/preprocessing', () => ({ + preprocessExecution: mockPreprocessExecution, +})) + +vi.mock('@/lib/webhooks/pending-verification', () => ({ + getPendingWebhookVerification: vi.fn(), + matchesPendingWebhookVerificationProbe: vi.fn().mockReturnValue(false), + requiresPendingWebhookVerification: vi.fn().mockReturnValue(false), +})) + +vi.mock('@/lib/webhooks/utils', () => ({ + convertSquareBracketsToTwiML: vi.fn((value: string) => value), +})) + +vi.mock('@/lib/webhooks/utils.server', () => ({ + handleSlackChallenge: vi.fn().mockReturnValue(null), + handleWhatsAppVerification: vi.fn().mockResolvedValue(null), + validateAttioSignature: vi.fn().mockReturnValue(true), + validateCalcomSignature: vi.fn().mockReturnValue(true), + validateCirclebackSignature: vi.fn().mockReturnValue(true), + validateFirefliesSignature: vi.fn().mockReturnValue(true), + validateGitHubSignature: vi.fn().mockReturnValue(true), + validateJiraSignature: vi.fn().mockReturnValue(true), + validateLinearSignature: vi.fn().mockReturnValue(true), + validateMicrosoftTeamsSignature: vi.fn().mockReturnValue(true), + validateTwilioSignature: vi.fn().mockResolvedValue(true), + validateTypeformSignature: vi.fn().mockReturnValue(true), + verifyProviderWebhook: vi.fn().mockReturnValue(null), +})) + +vi.mock('@/background/webhook-execution', () => ({ + executeWebhookJob: vi.fn().mockResolvedValue({ success: true }), +})) + +vi.mock('@/executor/utils/reference-validation', () => ({ + resolveEnvVarReferences: vi.fn((value: string) => value), +})) + +vi.mock('@/triggers/confluence/utils', () => ({ + isConfluencePayloadMatch: vi.fn().mockReturnValue(true), +})) + +vi.mock('@/triggers/constants', () => ({ + isPollingWebhookProvider: vi.fn((provider: string) => provider === 'gmail'), +})) + +vi.mock('@/triggers/github/utils', () => ({ + isGitHubEventMatch: vi.fn().mockReturnValue(true), +})) + +vi.mock('@/triggers/hubspot/utils', () => ({ + isHubSpotContactEventMatch: vi.fn().mockReturnValue(true), +})) + +vi.mock('@/triggers/jira/utils', () => ({ + isJiraEventMatch: vi.fn().mockReturnValue(true), +})) + +import { checkWebhookPreprocessing, queueWebhookExecution } from '@/lib/webhooks/processor' + +describe('webhook processor execution identity', () => { + beforeEach(() => { + vi.clearAllMocks() + mockPreprocessExecution.mockResolvedValue({ + success: true, + actorUserId: 'actor-user-1', + }) + mockEnqueue.mockResolvedValue('job-1') + mockGetJobQueue.mockResolvedValue({ enqueue: mockEnqueue }) + mockShouldExecuteInline.mockReturnValue(false) + mockUuidV4.mockReturnValue('generated-execution-id') + }) + + it('reuses preprocessing execution identity when queueing a polling webhook', async () => { + const preprocessingResult = await checkWebhookPreprocessing( + { + id: 'workflow-1', + userId: 'owner-1', + workspaceId: 'workspace-1', + }, + { + id: 'webhook-1', + path: 'incoming/gmail', + provider: 'gmail', + }, + 'request-1' + ) + + expect(preprocessingResult).toMatchObject({ + error: null, + actorUserId: 'actor-user-1', + executionId: 'generated-execution-id', + correlation: { + executionId: 'generated-execution-id', + requestId: 'request-1', + source: 'webhook', + workflowId: 'workflow-1', + webhookId: 'webhook-1', + path: 'incoming/gmail', + provider: 'gmail', + triggerType: 'webhook', + }, + }) + + await queueWebhookExecution( + { + id: 'webhook-1', + path: 'incoming/gmail', + provider: 'gmail', + providerConfig: {}, + blockId: 'block-1', + }, + { + id: 'workflow-1', + workspaceId: 'workspace-1', + }, + { event: 'message.received' }, + createMockRequest('POST', { event: 'message.received' }) as any, + { + requestId: 'request-1', + path: 'incoming/gmail', + actorUserId: preprocessingResult.actorUserId, + executionId: preprocessingResult.executionId, + correlation: preprocessingResult.correlation, + } + ) + + expect(mockUuidV4).toHaveBeenCalledTimes(1) + expect(mockEnqueue).toHaveBeenCalledWith( + 'webhook-execution', + expect.objectContaining({ + executionId: 'generated-execution-id', + requestId: 'request-1', + correlation: preprocessingResult.correlation, + }), + expect.objectContaining({ + metadata: expect.objectContaining({ + correlation: preprocessingResult.correlation, + }), + }) + ) + }) +}) diff --git a/apps/sim/lib/webhooks/processor.ts b/apps/sim/lib/webhooks/processor.ts index 225c3052c41..9bb5978b289 100644 --- a/apps/sim/lib/webhooks/processor.ts +++ b/apps/sim/lib/webhooks/processor.ts @@ -6,6 +6,7 @@ import { type NextRequest, NextResponse } from 'next/server' import { v4 as uuidv4 } from 'uuid' import { checkEnterprisePlan, checkTeamPlan } from '@/lib/billing/subscriptions/utils' import { getInlineJobQueue, getJobQueue, shouldExecuteInline } from '@/lib/core/async-jobs' +import type { AsyncExecutionCorrelation } from '@/lib/core/async-jobs/types' import { isProd } from '@/lib/core/config/feature-flags' import { safeCompare } from '@/lib/core/security/encryption' import { getEffectiveDecryptedEnv } from '@/lib/environment/utils' @@ -46,11 +47,15 @@ export interface WebhookProcessorOptions { path?: string webhookId?: string actorUserId?: string + executionId?: string + correlation?: AsyncExecutionCorrelation } export interface WebhookPreprocessingResult { error: NextResponse | null actorUserId?: string + executionId?: string + correlation?: AsyncExecutionCorrelation } function getExternalUrl(request: NextRequest): string { @@ -977,7 +982,12 @@ export async function checkWebhookPreprocessing( } } - return { error: null, actorUserId: preprocessResult.actorUserId } + return { + error: null, + actorUserId: preprocessResult.actorUserId, + executionId, + correlation, + } } catch (preprocessError) { logger.error(`[${requestId}] Error during webhook preprocessing:`, preprocessError) @@ -1204,17 +1214,19 @@ export async function queueWebhookExecution( return NextResponse.json({ error: 'Unable to resolve billing account' }, { status: 500 }) } - const executionId = uuidv4() - const correlation = { - executionId, - requestId: options.requestId, - source: 'webhook' as const, - workflowId: foundWorkflow.id, - webhookId: foundWebhook.id, - path: options.path || foundWebhook.path, - provider: foundWebhook.provider, - triggerType: 'webhook', - } + const executionId = options.executionId ?? uuidv4() + const correlation = + options.correlation ?? + ({ + executionId, + requestId: options.requestId, + source: 'webhook' as const, + workflowId: foundWorkflow.id, + webhookId: foundWebhook.id, + path: options.path || foundWebhook.path, + provider: foundWebhook.provider, + triggerType: 'webhook', + } satisfies AsyncExecutionCorrelation) const payload = { webhookId: foundWebhook.id,