Skip to content

Commit 54949cb

Browse files
committed
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.
1 parent 4e82583 commit 54949cb

30 files changed

Lines changed: 451 additions & 354 deletions

File tree

‎apps/sim/app/api/workflows/[id]/execute/route.ts‎

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1620,7 +1620,8 @@ async function handleExecutePost(
16201620
reqLogger,
16211621
'Non-SSE execution failed',
16221622
error,
1623-
loggingSession.projectDiagnosticError(error, { isTimeout: executionTimedOut })
1623+
loggingSession.projectDiagnosticError(error, { isTimeout: executionTimedOut }),
1624+
executionId
16241625
)
16251626

16261627
const executionResult = hasExecutionResult(error) ? error.executionResult : undefined
@@ -2427,7 +2428,8 @@ async function handleExecutePost(
24272428
reqLogger,
24282429
'SSE execution failed',
24292430
error,
2430-
loggingSession.projectDiagnosticError(error, { isTimeout })
2431+
loggingSession.projectDiagnosticError(error, { isTimeout }),
2432+
executionId
24312433
)
24322434

24332435
const executionResult = hasExecutionResult(error) ? error.executionResult : undefined

‎apps/sim/background/webhook-execution.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1276,7 +1276,8 @@ async function executeWebhookJobInternal(
12761276
workflowId: payload.workflowId,
12771277
executionId,
12781278
provider: payload.provider,
1279-
})
1279+
}),
1280+
executionId
12801281
)
12811282

12821283
// The finalized flag is set inside a fire-and-forget post-execution promise; await it so the

‎apps/sim/background/workflow-execution.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -311,7 +311,8 @@ export async function executeWorkflowJob(
311311
logger,
312312
`[${requestId}] Workflow execution failed: ${workflowId}`,
313313
error,
314-
loggingSession.projectDiagnosticError(error, { executionId })
314+
loggingSession.projectDiagnosticError(error, { executionId }),
315+
executionId
315316
)
316317

317318
if (error instanceof ExecutionTimeoutError) throw error

‎apps/sim/executor/execution/block-executor.test.ts‎

Lines changed: 69 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import { buildTraceSpans } from '@/lib/logs/execution/trace-spans/trace-spans'
1313
import { validateBlockType } from '@/ee/access-control/utils/permission-check'
1414
import { BlockType, EDGE } from '@/executor/constants'
1515
import type { DAGNode } from '@/executor/dag/builder'
16+
import { ChildWorkflowError } from '@/executor/errors/child-workflow-error'
1617
import { BlockExecutor } from '@/executor/execution/block-executor'
1718
import { ExecutionState } from '@/executor/execution/state'
1819
import type { BlockHandler, ExecutionContext } from '@/executor/types'
@@ -576,6 +577,74 @@ describe('BlockExecutor', () => {
576577
expect(state.getBlockOutput(block.id)).toEqual(output)
577578
})
578579

580+
function failBlockWith(thrown: unknown) {
581+
const block = createBlock()
582+
const workflow: SerializedWorkflow = {
583+
version: '1',
584+
blocks: [block],
585+
connections: [],
586+
loops: {},
587+
parallels: {},
588+
}
589+
const state = new ExecutionState()
590+
const resolver = new VariableResolver(workflow, {}, state)
591+
const handler: BlockHandler = {
592+
canHandle: () => true,
593+
execute: async () => {
594+
throw thrown
595+
},
596+
}
597+
const executor = new BlockExecutor([handler], resolver, {}, state)
598+
const ctx = createContext(state)
599+
ctx.resolvedSecretTraceRegistry = new ResolvedSecretTraceRegistry([])
600+
return executor.execute(ctx, createNode(block), block).catch((error) => error)
601+
}
602+
603+
function blockFailureLogsSince(loggerIndex: number) {
604+
const loggers = new Set<{ error: { mock: { calls: unknown[][] } } }>(
605+
blockExecutorBaseLogger.withMetadata.mock.results
606+
.slice(loggerIndex)
607+
.map((result: { value: { error: { mock: { calls: unknown[][] } } } }) => result.value)
608+
)
609+
return [...loggers].flatMap((logger) =>
610+
logger.error.mock.calls.filter(([message]) => message === 'Block execution failed')
611+
)
612+
}
613+
614+
it('logs every block failure that rethrows one persistent object, not just the first', async () => {
615+
/** A rejected dynamic `import()` or memoized rejected promise rethrows the same object. */
616+
const persistentFault = new Error('handler module failed to load')
617+
const loggerIndex = blockExecutorBaseLogger.withMetadata.mock.results.length
618+
619+
await failBlockWith(persistentFault)
620+
await failBlockWith(persistentFault)
621+
622+
expect(blockFailureLogsSince(loggerIndex)).toHaveLength(2)
623+
})
624+
625+
it('logs an internal child workflow fault with the block and run identity', async () => {
626+
const loggerIndex = blockExecutorBaseLogger.withMetadata.mock.results.length
627+
628+
await failBlockWith(
629+
new ChildWorkflowError({
630+
message: '"Child" failed: child load blew up',
631+
childWorkflowName: 'Child',
632+
cause: new TypeError('child load blew up'),
633+
})
634+
)
635+
636+
const [[, logged]] = blockFailureLogsSince(loggerIndex)
637+
expect(logged).toEqual(
638+
expect.objectContaining({
639+
blockId: 'function-block-1',
640+
executionId: 'execution-1',
641+
workflowId: 'workflow-1',
642+
error: '"Child" failed: child load blew up',
643+
failureKind: 'internal',
644+
})
645+
)
646+
})
647+
579648
it('does not soft-succeed non-agent blocks on user AbortError', async () => {
580649
const block = createBlock()
581650
const workflow: SerializedWorkflow = {

‎apps/sim/executor/execution/engine.ts‎

Lines changed: 12 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -201,7 +201,8 @@ export class ExecutionEngine {
201201
this.execLogger,
202202
'Execution failed',
203203
error,
204-
projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry)
204+
projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
205+
this.context.executionId
205206
)
206207

207208
const executionResult: ExecutionResult = {
@@ -484,10 +485,16 @@ export class ExecutionEngine {
484485
* Block failures were logged by the block executor. This catches a completion-handling
485486
* fault, which only this frame sees when a concurrent failure already won `executionError`.
486487
*/
487-
logFailureOnce(this.execLogger, 'Node execution failed', error, {
488-
nodeId,
489-
...projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
490-
})
488+
logFailureOnce(
489+
this.execLogger,
490+
'Node execution failed',
491+
error,
492+
{
493+
nodeId,
494+
...projectResolvedSecretDiagnosticError(error, this.context.resolvedSecretTraceRegistry),
495+
},
496+
this.context.executionId
497+
)
491498
throw error
492499
}
493500
}

‎apps/sim/executor/handlers/agent/agent-handler.test.ts‎

Lines changed: 0 additions & 70 deletions
Original file line numberDiff line numberDiff line change
@@ -3224,83 +3224,13 @@ describe('AgentBlockHandler', () => {
32243224
ctx: ExecutionContext,
32253225
tools: Array<Record<string, unknown>>
32263226
) => Promise<unknown[]>
3227-
handleExecutionError: (
3228-
error: unknown,
3229-
startTime: number,
3230-
provider: string,
3231-
model: string,
3232-
ctx: ExecutionContext,
3233-
block: SerializedBlock
3234-
) => void
32353227
processStructuredResponse: (
32363228
result: Record<string, unknown>,
32373229
responseFormat: unknown,
32383230
ctx: ExecutionContext
32393231
) => Record<string, unknown>
32403232
}
32413233

3242-
it('projects provider errors and internal runtime identifiers before logging', () => {
3243-
const registry = new ResolvedSecretTraceRegistry([
3244-
{
3245-
name: 'TOKEN',
3246-
plaintext: 'diagnostic-secret',
3247-
encryptedValue: 'encrypted-diagnostic-secret',
3248-
},
3249-
])
3250-
registry.recordResolved('TOKEN', 'diagnostic-secret')
3251-
const ctx = { ...mockContext, resolvedSecretTraceRegistry: registry }
3252-
3253-
privateHandler().handleExecutionError(
3254-
new Error('failed with diagnostic-secret __var_TOKEN __sim_runtime_test_1'),
3255-
Date.now(),
3256-
'diagnostic-secret',
3257-
'__var_TOKEN',
3258-
ctx,
3259-
mockBlock
3260-
)
3261-
3262-
const serializedCalls = JSON.stringify(mockAgentLogger.error.mock.calls)
3263-
expect(serializedCalls).not.toContain('diagnostic-secret')
3264-
expect(serializedCalls).not.toContain('__var_')
3265-
expect(serializedCalls).not.toContain('__sim_')
3266-
expect(mockAgentLogger.error).toHaveBeenCalledWith(
3267-
'Error executing provider request',
3268-
expect.objectContaining({
3269-
provider: '{{TOKEN}}',
3270-
model: '{{TOKEN}}',
3271-
errorMessage: 'failed with {{TOKEN}} {{TOKEN}} [RUNTIME_BINDING]',
3272-
})
3273-
)
3274-
})
3275-
3276-
it('fails closed to structural provider diagnostics without a complete registry', () => {
3277-
const ctx = { ...mockContext, resolvedSecretTraceRegistry: undefined }
3278-
3279-
privateHandler().handleExecutionError(
3280-
new Error('untracked-secret __var_TOKEN __sim_runtime_test_1'),
3281-
Date.now(),
3282-
'untracked-secret',
3283-
'__var_TOKEN',
3284-
ctx,
3285-
mockBlock
3286-
)
3287-
3288-
const metadata = mockAgentLogger.error.mock.calls.at(-1)?.[1]
3289-
expect(metadata).toEqual(
3290-
expect.objectContaining({
3291-
workflowId: mockContext.workflowId,
3292-
blockId: mockBlock.id,
3293-
errorType: 'error',
3294-
})
3295-
)
3296-
expect(metadata).not.toHaveProperty('provider')
3297-
expect(metadata).not.toHaveProperty('model')
3298-
expect(metadata).not.toHaveProperty('errorMessage')
3299-
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('untracked-secret')
3300-
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('__var_')
3301-
expect(JSON.stringify(mockAgentLogger.error.mock.calls)).not.toContain('__sim_')
3302-
})
3303-
33043234
it('projects tool diagnostics without logging code or raw params', async () => {
33053235
const registry = new ResolvedSecretTraceRegistry([
33063236
{

‎apps/sim/executor/handlers/agent/agent-handler.ts‎

Lines changed: 14 additions & 55 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@ import { createLogger } from '@sim/logger'
22
import { getErrorMessage, toError } from '@sim/utils/errors'
33
import { isPlainRecord, omit } from '@sim/utils/object'
44
import { truncate } from '@sim/utils/string'
5-
import { logFailureOnce, markFailureKind, markFailureLogged } from '@/lib/core/errors/failure-log'
5+
import { isProviderKeyRejection, markFailureKind } from '@/lib/core/errors/failure-log'
66
import { normalizeStringRecord, normalizeWorkflowVariables } from '@/lib/core/utils/records'
77
import {
88
projectModelSchemaAnnotations,
@@ -308,9 +308,6 @@ function isTransportTimeout(error: unknown): boolean {
308308
return false
309309
}
310310

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

333-
function isAmbiguousProviderKeyRejection(error: unknown): boolean {
334-
const status = (error as { status?: unknown } | null)?.status
335-
return status === 401 || status === 402 || status === 403
336-
}
337-
330+
/**
331+
* Handler for Agent blocks that process LLM requests with optional tools.
332+
*/
338333
export class AgentBlockHandler implements BlockHandler {
339334
canHandle(block: SerializedBlock): boolean {
340335
return block.metadata?.id === BlockType.AGENT
@@ -2964,7 +2959,6 @@ export class AgentBlockHandler implements BlockHandler {
29642959
): Promise<BlockOutput | StreamingExecution> {
29652960
const providerId = providerRequest.provider
29662961
const model = providerRequest.model
2967-
const providerStartTime = Date.now()
29682962

29692963
try {
29702964
let finalApiKey: string | undefined = providerRequest.apiKey
@@ -3050,11 +3044,8 @@ export class AgentBlockHandler implements BlockHandler {
30503044
} catch (error) {
30513045
const errorRegistry = this.createErrorRegistry(providerErrorRegistry, modelRuntimeRegistry)
30523046
ctx.errorResolvedSecretTraceRegistry = errorRegistry
3053-
const diagnosticCtx = errorRegistry
3054-
? { ...ctx, resolvedSecretTraceRegistry: errorRegistry }
3055-
: ctx
30563047
try {
3057-
this.handleExecutionError(error, providerStartTime, providerId, model, diagnosticCtx, block)
3048+
this.handleExecutionError(error)
30583049
} finally {
30593050
if (modelRuntimeRegistry) {
30603051
ctx.resolvedSecretTraceRegistry = modelRuntimeRegistry.forkForPropagatedEntries()
@@ -3075,50 +3066,18 @@ export class AgentBlockHandler implements BlockHandler {
30753066
return errorRegistry
30763067
}
30773068

3078-
private handleExecutionError(
3079-
error: any,
3080-
startTime: number,
3081-
provider: string,
3082-
model: string,
3083-
ctx: ExecutionContext,
3084-
block: SerializedBlock
3085-
) {
3086-
const executionTime = Date.now() - startTime
3069+
/**
3070+
* Attributes a provider failure and rewrites a transport failure into a message the author can
3071+
* act on. The block executor owns the log line, with the block's and run's identity.
3072+
*/
3073+
private handleExecutionError(error: unknown) {
30873074
const transportFailure = error instanceof Error ? describeProviderTransportFailure(error) : null
30883075
if (transportFailure) {
3089-
markFailureKind(error, 'third_party_server')
3090-
} else if (isAmbiguousProviderKeyRejection(error)) {
3091-
/** The handler cannot tell a hosted provider key (ours) from the author's own. */
3092-
markFailureKind(error, 'internal')
3076+
throw markFailureKind(new Error(transportFailure), 'third_party_server')
30933077
}
3094-
3095-
logFailureOnce(
3096-
logger,
3097-
'Error executing provider request',
3098-
error,
3099-
projectAgentDiagnosticMetadata(
3100-
ctx,
3101-
{
3102-
executionTime,
3103-
provider,
3104-
model,
3105-
workflowId: ctx.workflowId,
3106-
blockId: block.id,
3107-
...getErrorDiagnosticMetadata(error),
3108-
},
3109-
{
3110-
executionTime,
3111-
workflowId: ctx.workflowId,
3112-
blockId: block.id,
3113-
...getErrorDiagnosticFallback(error),
3114-
}
3115-
)
3116-
)
3117-
3118-
if (transportFailure) {
3119-
const replacement = new Error(transportFailure)
3120-
markFailureLogged(replacement)
3121-
throw replacement
3078+
/** The handler cannot tell a hosted provider key (Sim's) from the author's own. */
3079+
if (isProviderKeyRejection((error as { status?: unknown } | null)?.status)) {
3080+
markFailureKind(error, 'internal')
31223081
}
31233082
}
31243083

‎apps/sim/executor/handlers/api/api-handler.ts‎

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,3 +1,4 @@
1+
import { adoptToolFailure } from '@/lib/core/errors/failure-log'
12
import { BlockType, HTTP } from '@/executor/constants'
23
import type { BlockHandler, ExecutionContext } from '@/executor/types'
34
import type { SerializedBlock } from '@/serializer/types'
@@ -124,7 +125,7 @@ export class ApiBlockHandler implements BlockHandler {
124125
timestamp: new Date().toISOString(),
125126
})
126127

127-
throw error
128+
throw adoptToolFailure(error, result)
128129
}
129130

130131
return result.output

‎apps/sim/executor/handlers/condition/condition-handler.ts‎

Lines changed: 6 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
import { createLogger } from '@sim/logger'
22
import { getErrorMessage, toError } from '@sim/utils/errors'
3+
import { adoptToolFailure } from '@/lib/core/errors/failure-log'
34
import { normalizeStringRecord, normalizeWorkflowVariables } from '@/lib/core/utils/records'
45
import {
56
isNonRetryableExecutionError,
@@ -293,9 +294,12 @@ async function evaluateSingleCondition(
293294

294295
if (!result.success) {
295296
if (result.retryable === false) {
296-
throw new NonRetryableExecutionError(result.error ?? 'Condition evaluation is indeterminate')
297+
throw adoptToolFailure(
298+
new NonRetryableExecutionError(result.error ?? 'Condition evaluation is indeterminate'),
299+
result
300+
)
297301
}
298-
throw new Error(result.error ?? 'Condition evaluation failed')
302+
throw adoptToolFailure(new Error(result.error ?? 'Condition evaluation failed'), result)
299303
}
300304

301305
return Boolean(result.output?.result)

0 commit comments

Comments
 (0)