Visitar URL original
improvement(logs): log each execution failure once at its owning boundary by waleedlatif1 · Pull Request #8872 · simstudioai/sim · GitHub
Skip to content
Merged
Show file tree
Hide file tree
Changes from 1 commit
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Prev Previous commit
Next Next commit
fix(logs): scope the logged mark to one propagation and attribute in-…
…process failures

Never mark a raw thrown value as logged: a persistent fault that rethrows one
object (a rejected dynamic import, a memoized rejected promise) was logged once
per process and then silenced everywhere. Only carriers created during the
propagation (the flattened tool failure output, the block error, a handler's
rebuilt error) carry the mark, and execution-level boundaries scope a raw
value's mark to their execution id.

Handlers that rebuild a failed tool result now call adoptToolFailure instead of
relying on the result output being copied by reference. The child workflow and
agent handlers no longer log failures the block executor logs with the block's
and run's identity. In-process operations are attributed to Sim (4xx user, 5xx
internal) rather than to a third party, only external HTTP failures log their
response body, a missing required field is the only serializer refusal at info,
and the size-limit and JSON-parse paths no longer log twice.
  • Loading branch information
waleedlatif1 committed Oct 10, 2026
commit 82120ab2e01d46af2d11e5ecfde372e9aad18c21
6 changes: 4 additions & 2 deletions apps/sim/app/api/workflows/[id]/execute/route.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1620,7 +1620,8 @@ async function handleExecutePost(
reqLogger,
'Non-SSE execution failed',
error,
loggingSession.projectDiagnosticError(error, { isTimeout: executionTimedOut })
loggingSession.projectDiagnosticError(error, { isTimeout: executionTimedOut }),
executionId
)

const executionResult = hasExecutionResult(error) ? error.executionResult : undefined
Expand Down Expand Up @@ -2427,7 +2428,8 @@ async function handleExecutePost(
reqLogger,
'SSE execution failed',
error,
loggingSession.projectDiagnosticError(error, { isTimeout })
loggingSession.projectDiagnosticError(error, { isTimeout }),
executionId
)

const executionResult = hasExecutionResult(error) ? error.executionResult : undefined
Expand Down
3 changes: 2 additions & 1 deletion apps/sim/background/webhook-execution.ts
Original file line number Diff line number Diff line change
Expand Up @@ -1276,7 +1276,8 @@ async function executeWebhookJobInternal(
workflowId: payload.workflowId,
executionId,
provider: payload.provider,
})
}),
executionId
)

// The finalized flag is set inside a fire-and-forget post-execution promise; await it so the
Expand Down
3 changes: 2 additions & 1 deletion apps/sim/background/workflow-execution.ts
Original file line number Diff line number Diff line change
Expand Up @@ -311,7 +311,8 @@ export async function executeWorkflowJob(
logger,
`[${requestId}] Workflow execution failed: ${workflowId}`,
error,
loggingSession.projectDiagnosticError(error, { executionId })
loggingSession.projectDiagnosticError(error, { executionId }),
executionId
)

if (error instanceof ExecutionTimeoutError) throw error
Expand Down
69 changes: 69 additions & 0 deletions apps/sim/executor/execution/block-executor.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans'
import { validateBlockType } from '@/ee/access-control/utils/permission-check'
import { BlockType, EDGE } from '@/executor/constants'
import type { DAGNode } from '@/executor/dag/builder'
import { ChildWorkflowError } from '@/executor/errors/child-workflow-error'
import { BlockExecutor } from '@/executor/execution/block-executor'
import { ExecutionState } from '@/executor/execution/state'
import type { BlockHandler, ExecutionContext } from '@/executor/types'
Expand Down Expand Up @@ -576,6 +577,74 @@ describe('BlockExecutor', () => {
expect(state.getBlockOutput(block.id)).toEqual(output)
})

function failBlockWith(thrown: unknown) {
const block = createBlock()
const workflow: SerializedWorkflow = {
version: '1',
blocks: [block],
connections: [],
loops: {},
parallels: {},
}
const state = new ExecutionState()
const resolver = new VariableResolver(workflow, {}, state)
const handler: BlockHandler = {
canHandle: () => true,
execute: async () => {
throw thrown
},
}
const executor = new BlockExecutor([handler], resolver, {}, state)
const ctx = createContext(state)
ctx.resolvedSecretTraceRegistry = new ResolvedSecretTraceRegistry([])
return executor.execute(ctx, createNode(block), block).catch((error) => error)
}

function blockFailureLogsSince(loggerIndex: number) {
const loggers = new Set<{ error: { mock: { calls: unknown[][] } } }>(
blockExecutorBaseLogger.withMetadata.mock.results
.slice(loggerIndex)
.map((result: { value: { error: { mock: { calls: unknown[][] } } } }) => result.value)
)
return [...loggers].flatMap((logger) =>
logger.error.mock.calls.filter(([message]) => message === 'Block execution failed')
)
}

it('logs every block failure that rethrows one persistent object, not just the first', async () => {
/** A rejected dynamic `import()` or memoized rejected promise rethrows the same object. */
const persistentFault = new Error('handler module failed to load')
const loggerIndex = blockExecutorBaseLogger.withMetadata.mock.results.length

await failBlockWith(persistentFault)
await failBlockWith(persistentFault)

expect(blockFailureLogsSince(loggerIndex)).toHaveLength(2)
})

it('logs an internal child workflow fault with the block and run identity', async () => {
const loggerIndex = blockExecutorBaseLogger.withMetadata.mock.results.length

await failBlockWith(
new ChildWorkflowError({
message: '"Child" failed: child load blew up',
childWorkflowName: 'Child',
cause: new TypeError('child load blew up'),
})
)

const [[, logged]] = blockFailureLogsSince(loggerIndex)
expect(logged).toEqual(
expect.objectContaining({
blockId: 'function-block-1',
executionId: 'execution-1',
workflowId: 'workflow-1',
error: '"Child" failed: child load blew up',
failureKind: 'internal',
})
)
})

it('does not soft-succeed non-agent blocks on user AbortError', async () => {
const block = createBlock()
const workflow: SerializedWorkflow = {
Expand Down
17 changes: 12 additions & 5 deletions apps/sim/executor/execution/engine.ts
Original file line number Diff line number Diff line change
Expand Up @@ -201,7 +201,8 @@ export class ExecutionEngine {
this.execLogger,
'Execution failed',
error,
projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry)
projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
this.context.executionId
)

const executionResult: ExecutionResult = {
Expand Down Expand Up @@ -484,10 +485,16 @@ export class ExecutionEngine {
* Block failures were logged by the block executor. This catches a completion-handling
* fault, which only this frame sees when a concurrent failure already won `executionError`.
*/
logFailureOnce(this.execLogger, 'Node execution failed', error, {
nodeId,
...projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
})
logFailureOnce(
this.execLogger,
'Node execution failed',
error,
{
nodeId,
...projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
},
this.context.executionId
)
throw error
}
}
Expand Down
70 changes: 0 additions & 70 deletions apps/sim/executor/handlers/agent/agent-handler.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3224,83 +3224,13 @@ describe('AgentBlockHandler', () => {
ctx: ExecutionContext,
tools: Array<Record<string, unknown>>
) => Promise<unknown[]>
handleExecutionError: (
error: unknown,
startTime: number,
provider: string,
model: string,
ctx: ExecutionContext,
block: SerializedBlock
) => void
processStructuredResponse: (
result: Record<string, unknown>,
responseFormat: unknown,
ctx: ExecutionContext
) => Record<string, unknown>
}

it('projects provider errors and internal runtime identifiers before logging', () => {
const registry = new ResolvedSecretTraceRegistry([
{
name: 'TOKEN',
plaintext: 'diagnostic-secret',
encryptedValue: 'encrypted-diagnostic-secret',
},
])
registry.recordResolved('TOKEN', 'diagnostic-secret')
const ctx = { ...mockContext, resolvedSecretTraceRegistry: registry }

privateHandler().handleExecutionError(
new Error('failed with diagnostic-secret __var_TOKEN __sim_runtime_test_1'),
Date.now(),
'diagnostic-secret',
'__var_TOKEN',
ctx,
mockBlock
)

const serializedCalls = JSON.stringify(mockAgentLogger.error.mock.calls)
expect(serializedCalls).not.toContain('diagnostic-secret')
expect(serializedCalls).not.toContain('__var_')
expect(serializedCalls).not.toContain('__sim_')
expect(mockAgentLogger.error).toHaveBeenCalledWith(
'Error executing provider request',
expect.objectContaining({
provider: '{{TOKEN}}',
model: '{{TOKEN}}',
errorMessage: 'failed with {{TOKEN}} {{TOKEN}} [RUNTIME_BINDING]',
})
)
})

it('fails closed to structural provider diagnostics without a complete registry', () => {
const ctx = { ...mockContext, resolvedSecretTraceRegistry: undefined }

privateHandler().handleExecutionError(
new Error('untracked-secret __var_TOKEN __sim_runtime_test_1'),
Date.now(),
'untracked-secret',
'__var_TOKEN',
ctx,
mockBlock
)

const metadata = mockAgentLogger.error.mock.calls.at(-1)?.[1]
expect(metadata).toEqual(
expect.objectContaining({
workflowId: mockContext.workflowId,
blockId: mockBlock.id,
errorType: 'error',
})
)
expect(metadata).not.toHaveProperty('provider')
expect(metadata).not.toHaveProperty('model')
expect(metadata).not.toHaveProperty('errorMessage')
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('untracked-secret')
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('__var_')
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('__sim_')
})

it('projects tool diagnostics without logging code or raw params', async () => {
const registry = new ResolvedSecretTraceRegistry([
{
Expand Down
69 changes: 14 additions & 55 deletions apps/sim/executor/handlers/agent/agent-handler.ts
Original file line number Diff line number Diff line change
Expand Up @@ -2,7 +2,7 @@ import { createLogger } from '@sim/logger'
import { getErrorMessage, toError } from '@sim/utils/errors'
import { isPlainRecord, omit } from '@sim/utils/object'
import { truncate } from '@sim/utils/string'
import { logFailureOnce, markFailureKind, markFailureLogged } from '@/lib/core/errors/failure-log'
import { isProviderKeyRejection, markFailureKind } from '@/lib/core/errors/failure-log'
import { normalizeStringRecord, normalizeWorkflowVariables } from '@/lib/core/utils/records'
import {
projectModelSchemaAnnotations,
Expand Down Expand Up @@ -308,9 +308,6 @@ function isTransportTimeout(error: unknown): boolean {
return false
}

/**
* Handler for Agent blocks that process LLM requests with optional tools.
*/
/**
* The user-facing message for a provider request that never got an answer, or null when the
* provider did answer. The original message is appended for timeouts rather than replaced:
Expand All @@ -330,11 +327,9 @@ function describeProviderTransportFailure(error: Error): string | null {
return null
}

function isAmbiguousProviderKeyRejection(error: unknown): boolean {
const status = (error as { status?: unknown } | null)?.status
return status === 401 || status === 402 || status === 403
}

/**
* Handler for Agent blocks that process LLM requests with optional tools.
*/
export class AgentBlockHandler implements BlockHandler {
canHandle(block: SerializedBlock): boolean {
return block.metadata?.id === BlockType.AGENT
Expand Down Expand Up @@ -2964,7 +2959,6 @@ export class AgentBlockHandler implements BlockHandler {
): Promise<BlockOutput | StreamingExecution> {
const providerId = providerRequest.provider
const model = providerRequest.model
const providerStartTime = Date.now()

try {
let finalApiKey: string | undefined = providerRequest.apiKey
Expand Down Expand Up @@ -3050,11 +3044,8 @@ export class AgentBlockHandler implements BlockHandler {
} catch (error) {
const errorRegistry = this.createErrorRegistry(providerErrorRegistry, modelRuntimeRegistry)
ctx.errorResolvedSecretTraceRegistry = errorRegistry
const diagnosticCtx = errorRegistry
? { ...ctx, resolvedSecretTraceRegistry: errorRegistry }
: ctx
try {
this.handleExecutionError(error, providerStartTime, providerId, model, diagnosticCtx, block)
this.handleExecutionError(error)
} finally {
if (modelRuntimeRegistry) {
ctx.resolvedSecretTraceRegistry = modelRuntimeRegistry.forkForPropagatedEntries()
Expand All @@ -3075,50 +3066,18 @@ export class AgentBlockHandler implements BlockHandler {
return errorRegistry
}

private handleExecutionError(
error: any,
startTime: number,
provider: string,
model: string,
ctx: ExecutionContext,
block: SerializedBlock
) {
const executionTime = Date.now() - startTime
/**
* Attributes a provider failure and rewrites a transport failure into a message the author can
* act on. The block executor owns the log line, with the block's and run's identity.
*/
private handleExecutionError(error: unknown) {
const transportFailure = error instanceof Error ? describeProviderTransportFailure(error) : null
if (transportFailure) {
markFailureKind(error, 'third_party_server')
} else if (isAmbiguousProviderKeyRejection(error)) {
/** The handler cannot tell a hosted provider key (ours) from the author's own. */
markFailureKind(error, 'internal')
throw markFailureKind(new Error(transportFailure), 'third_party_server')
}

logFailureOnce(
logger,
'Error executing provider request',
error,
projectAgentDiagnosticMetadata(
ctx,
{
executionTime,
provider,
model,
workflowId: ctx.workflowId,
blockId: block.id,
...getErrorDiagnosticMetadata(error),
},
{
executionTime,
workflowId: ctx.workflowId,
blockId: block.id,
...getErrorDiagnosticFallback(error),
}
)
)

if (transportFailure) {
const replacement = new Error(transportFailure)
markFailureLogged(replacement)
throw replacement
/** The handler cannot tell a hosted provider key (Sim's) from the author's own. */
if (isProviderKeyRejection((error as { status?: unknown } | null)?.status)) {
markFailureKind(error, 'internal')
}
}

Expand Down
3 changes: 2 additions & 1 deletion apps/sim/executor/handlers/api/api-handler.ts
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
import { adoptToolFailure } from '@/lib/core/errors/failure-log'
import { BlockType, HTTP } from '@/executor/constants'
import type { BlockHandler, ExecutionContext } from '@/executor/types'
import type { SerializedBlock } from '@/serializer/types'
Expand Down Expand Up @@ -124,7 +125,7 @@ export class ApiBlockHandler implements BlockHandler {
timestamp: new Date().toISOString(),
})

throw error
throw adoptToolFailure(error, result)
}

return result.output
Expand Down
8 changes: 6 additions & 2 deletions apps/sim/executor/handlers/condition/condition-handler.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,6 @@
import { createLogger } from '@sim/logger'
import { getErrorMessage, toError } from '@sim/utils/errors'
import { adoptToolFailure } from '@/lib/core/errors/failure-log'
import { normalizeStringRecord, normalizeWorkflowVariables } from '@/lib/core/utils/records'
import {
isNonRetryableExecutionError,
Expand Down Expand Up @@ -293,9 +294,12 @@ async function evaluateSingleCondition(

if (!result.success) {
if (result.retryable === false) {
throw new NonRetryableExecutionError(result.error ?? 'Condition evaluation is indeterminate')
throw adoptToolFailure(
new NonRetryableExecutionError(result.error ?? 'Condition evaluation is indeterminate'),
result
)
}
throw new Error(result.error ?? 'Condition evaluation failed')
throw adoptToolFailure(new Error(result.error ?? 'Condition evaluation failed'), result)
Comment thread
waleedlatif1 marked this conversation as resolved.
Resolved
Comment thread
waleedlatif1 marked this conversation as resolved.
Resolved
}

return Boolean(result.output?.result)
Expand Down
Loading