Skip to content

Commit 3ff0dba

Browse files
committed
fix(execution): align timeout cleanup semantics
1 parent 78c5e8b commit 3ff0dba

10 files changed

Lines changed: 278 additions & 45 deletions

File tree

apps/sim/app/api/cron/cleanup-stale-executions/route.test.ts

Lines changed: 40 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,7 @@
44
import { asyncJobs, workflowExecutionLogs } from '@sim/db/schema'
55
import { createMockRequest, dbChainMockFns, queueTableRows, resetDbChainMock } from '@sim/testing'
66
import { beforeEach, describe, expect, it, vi } from 'vitest'
7+
import { MAX_JOB_DURATION_SECONDS, MIN_JOB_DURATION_SECONDS } from '@/lib/core/async-jobs'
78

89
const { mockDeleteFile, mockVerifyCronAuth } = vi.hoisted(() => ({
910
mockDeleteFile: vi.fn().mockResolvedValue(undefined),
@@ -20,6 +21,7 @@ interface MockCondition {
2021
conditions?: unknown[]
2122
left?: unknown
2223
right?: unknown
24+
toSQL?: () => { sql: string; params: unknown[] }
2325
}
2426

2527
function flattenConditions(condition: unknown): MockCondition[] {
@@ -77,12 +79,28 @@ describe('stale execution cleanup deadline grace', () => {
7779
expectedThreshold,
7880
expectedThreshold,
7981
])
82+
83+
const executionUpdateIndex = dbChainMockFns.update.mock.calls.findIndex(
84+
([table]) => table === workflowExecutionLogs
85+
)
86+
const update = dbChainMockFns.set.mock.calls[executionUpdateIndex]?.[0] as {
87+
executionData: { toSQL: () => { sql: string; params: unknown[] } }
88+
}
89+
const errorExpression = update.executionData.toSQL()
90+
91+
expect(errorExpression.sql).toContain('CASE')
92+
expect(errorExpression.sql).toContain('IS NOT NULL')
93+
expect(errorExpression.params).toContain(workflowExecutionLogs.executionDeadlineAt)
94+
expect(errorExpression.params).toContain('Execution timed out')
95+
expect(errorExpression.params).toContain(
96+
'Execution terminated: worker timeout or crash after 70 minutes'
97+
)
8098
} finally {
8199
vi.useRealTimers()
82100
}
83101
})
84102

85-
it('reports a configured job duration cap while preserving the generic stale fallback', async () => {
103+
it('reports a worker cleanup deadline while preserving the generic stale fallback', async () => {
86104
const response = await GET(createRequest())
87105

88106
expect(response.status).toBe(200)
@@ -95,12 +113,29 @@ describe('stale execution cleanup deadline grace', () => {
95113
error: { toSQL: () => { sql: string; params: unknown[] } }
96114
}
97115
const errorExpression = update.error.toSQL()
116+
const maxDurationGuard = errorExpression.params.find(
117+
(value): value is { toSQL: () => { sql: string; params: unknown[] } } =>
118+
typeof value === 'object' && value !== null && 'toSQL' in value
119+
)
120+
const durationPredicate = dbChainMockFns.where.mock.calls
121+
.flatMap(([condition]) => flattenConditions(condition))
122+
.find((condition) => condition.toSQL?.().sql.includes("interval '1 second'"))
123+
?.toSQL?.()
98124

99125
expect(errorExpression.sql).toContain("->>'maxDurationSeconds'")
100-
expect(errorExpression.sql).toContain(
101-
"'Job terminated: exceeded configured maximum duration of '"
102-
)
103-
expect(errorExpression.sql).toContain("|| ' seconds'")
126+
const guardExpression = maxDurationGuard?.toSQL()
127+
expect(guardExpression?.sql).toContain("jsonb_typeof(?->'maxDurationSeconds') = 'number'")
128+
expect(guardExpression?.sql).toContain('>=')
129+
expect(guardExpression?.sql).toContain('trunc(')
130+
expect(guardExpression?.sql).toContain('<=')
131+
expect(guardExpression?.params).toContain(MAX_JOB_DURATION_SECONDS)
132+
expect(guardExpression?.params).toContain(MIN_JOB_DURATION_SECONDS)
133+
expect(durationPredicate?.sql).toContain('CASE')
134+
expect(durationPredicate?.sql).toContain('ELSE')
135+
expect(durationPredicate?.sql).toContain('::double precision')
136+
expect(errorExpression.sql).toContain("'Job terminated: stuck in processing for more than '")
137+
expect(errorExpression.sql).toContain("|| ' seconds (worker cleanup deadline)'")
138+
expect(errorExpression.sql).not.toContain('configured maximum duration')
104139
expect(errorExpression.params).toContainEqual(
105140
expect.stringMatching(/^Job terminated: stuck in processing for more than \d+ minutes$/)
106141
)

apps/sim/app/api/cron/cleanup-stale-executions/route.ts

Lines changed: 33 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -11,9 +11,16 @@ import { and, eq, exists, gt, inArray, isNull, lt, or, sql } from 'drizzle-orm'
1111
import { alias } from 'drizzle-orm/pg-core'
1212
import { type NextRequest, NextResponse } from 'next/server'
1313
import { verifyCronAuth } from '@/lib/auth/internal'
14-
import { JOB_PENDING_RETENTION_HOURS, JOB_RETENTION_HOURS, JOB_STATUS } from '@/lib/core/async-jobs'
14+
import {
15+
JOB_PENDING_RETENTION_HOURS,
16+
JOB_RETENTION_HOURS,
17+
JOB_STATUS,
18+
MAX_JOB_DURATION_SECONDS,
19+
MIN_JOB_DURATION_SECONDS,
20+
} from '@/lib/core/async-jobs'
1521
import {
1622
getExecutionReservationTtlMs,
23+
getTimeoutErrorMessage,
1724
RESERVATION_TTL_BUFFER_MS,
1825
} from '@/lib/core/execution-limits'
1926
import { withRouteHandler } from '@/lib/core/utils/with-route-handler'
@@ -24,6 +31,7 @@ const logger = createLogger('CleanupStaleExecutions')
2431
const STALE_THRESHOLD_MS = getExecutionReservationTtlMs()
2532
const STALE_THRESHOLD_MINUTES = Math.ceil(STALE_THRESHOLD_MS / 60000)
2633
const GENERIC_STALE_PROCESSING_ERROR = `Job terminated: stuck in processing for more than ${STALE_THRESHOLD_MINUTES} minutes`
34+
const EXECUTION_DEADLINE_ERROR = getTimeoutErrorMessage(undefined)
2735
const MAX_INT32 = 2_147_483_647
2836
/** Terminal table-jobs older than this are pruned; only the latest job per table is ever read. */
2937
const TABLE_JOB_RETENTION_HOURS = 24
@@ -142,7 +150,13 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
142150
executionData: sql`jsonb_set(
143151
COALESCE(execution_data, '{}'::jsonb),
144152
ARRAY['error'],
145-
to_jsonb(${`Execution terminated: worker timeout or crash after ${staleDurationMinutes} minutes`}::text)
153+
to_jsonb(
154+
CASE
155+
WHEN ${workflowExecutionLogs.executionDeadlineAt} IS NOT NULL
156+
THEN ${EXECUTION_DEADLINE_ERROR}::text
157+
ELSE ${`Execution terminated: worker timeout or crash after ${staleDurationMinutes} minutes`}::text
158+
END
159+
)
146160
)`,
147161
})
148162
.where(
@@ -187,18 +201,22 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
187201
let asyncJobsMarkedFailed = 0
188202

189203
try {
204+
const hasPositiveMaxDuration = sql<boolean>`CASE
205+
WHEN jsonb_typeof(${asyncJobs.metadata}->'maxDurationSeconds') = 'number'
206+
THEN (${asyncJobs.metadata}->>'maxDurationSeconds')::numeric >= ${MIN_JOB_DURATION_SECONDS}
207+
AND (${asyncJobs.metadata}->>'maxDurationSeconds')::numeric <= ${MAX_JOB_DURATION_SECONDS}
208+
AND trunc((${asyncJobs.metadata}->>'maxDurationSeconds')::numeric)
209+
= (${asyncJobs.metadata}->>'maxDurationSeconds')::numeric
210+
ELSE FALSE
211+
END`
212+
const staleProcessingDurationPredicate = sql<boolean>`CASE
213+
WHEN ${hasPositiveMaxDuration}
214+
THEN ${asyncJobs.startedAt} + ((${asyncJobs.metadata}->>'maxDurationSeconds')::double precision * interval '1 second') < ${now}
215+
ELSE ${asyncJobs.startedAt} < ${staleThreshold}
216+
END`
190217
const staleProcessingPredicate = and(
191218
eq(asyncJobs.status, JOB_STATUS.PROCESSING),
192-
or(
193-
and(
194-
sql`jsonb_typeof(${asyncJobs.metadata}->'maxDurationSeconds') = 'number'`,
195-
sql`${asyncJobs.startedAt} + ((${asyncJobs.metadata}->>'maxDurationSeconds')::double precision * interval '1 second') < ${now}`
196-
),
197-
and(
198-
sql`jsonb_typeof(${asyncJobs.metadata}->'maxDurationSeconds') IS DISTINCT FROM 'number'`,
199-
lt(asyncJobs.startedAt, staleThreshold)
200-
)
201-
)
219+
staleProcessingDurationPredicate
202220
)
203221
const staleProcessingResult = await runBatchedMutation({
204222
batchSize: STATE_MUTATION_BATCH_SIZE,
@@ -216,10 +234,10 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
216234
status: JOB_STATUS.FAILED,
217235
completedAt: new Date(),
218236
error: sql<string>`CASE
219-
WHEN jsonb_typeof(${asyncJobs.metadata}->'maxDurationSeconds') = 'number'
220-
THEN 'Job terminated: exceeded configured maximum duration of '
237+
WHEN ${hasPositiveMaxDuration}
238+
THEN 'Job terminated: stuck in processing for more than '
221239
|| (${asyncJobs.metadata}->>'maxDurationSeconds')
222-
|| ' seconds'
240+
|| ' seconds (worker cleanup deadline)'
223241
ELSE ${GENERIC_STALE_PROCESSING_ERROR}
224242
END`,
225243
updatedAt: new Date(),

apps/sim/executor/handlers/workflow/workflow-handler.test.ts

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,7 @@ import {
66
resetEnvironmentUtilsMock,
77
} from '@sim/testing'
88
import { afterAll, beforeAll, beforeEach, describe, expect, it, type Mock, vi } from 'vitest'
9+
import { createTimeoutAbortController, getExecutionDeadlineAt } from '@/lib/core/execution-limits'
910
import { getBlock } from '@/blocks/registry'
1011
import { BlockType } from '@/executor/constants'
1112
import { BoundarySafeError } from '@/executor/errors/boundary'
@@ -39,6 +40,7 @@ const {
3940
mockSafeCompleteWithError,
4041
mockSafeCompleteWithCancellation,
4142
mockSetResolvedSecretTraceRegistry,
43+
mockSetExecutionDeadlineAt,
4244
mockSetTraceLargeValueAccess,
4345
mockDispose,
4446
executorOptions,
@@ -57,6 +59,7 @@ const {
5759
mockSafeCompleteWithError: vi.fn(),
5860
mockSafeCompleteWithCancellation: vi.fn(),
5961
mockSetResolvedSecretTraceRegistry: vi.fn(),
62+
mockSetExecutionDeadlineAt: vi.fn(),
6063
mockSetTraceLargeValueAccess: vi.fn(),
6164
mockDispose: vi.fn(),
6265
executorOptions: [] as Array<Record<string, any>>,
@@ -72,6 +75,7 @@ vi.mock('@/lib/logs/execution/logging-session', () => ({
7275
safeComplete = mockSafeComplete
7376
safeCompleteWithError = mockSafeCompleteWithError
7477
safeCompleteWithCancellation = mockSafeCompleteWithCancellation
78+
setExecutionDeadlineAt = mockSetExecutionDeadlineAt
7579
setResolvedSecretTraceRegistry = mockSetResolvedSecretTraceRegistry
7680
setTraceLargeValueAccess = mockSetTraceLargeValueAccess
7781
onBlockStart = vi.fn()
@@ -1162,6 +1166,27 @@ describe('WorkflowBlockHandler', () => {
11621166
})
11631167
})
11641168

1169+
it('persists the parent deadline before starting the child session', async () => {
1170+
const timeoutController = createTimeoutAbortController(60_000)
1171+
1172+
try {
1173+
await handler.execute(
1174+
customBlockContext({ abortSignal: timeoutController.signal }),
1175+
customBlock(),
1176+
{}
1177+
)
1178+
1179+
expect(mockSetExecutionDeadlineAt).toHaveBeenCalledWith(
1180+
getExecutionDeadlineAt(timeoutController.signal)
1181+
)
1182+
expect(mockSetExecutionDeadlineAt.mock.invocationCallOrder[0]).toBeLessThan(
1183+
mockSafeStart.mock.invocationCallOrder[0]
1184+
)
1185+
} finally {
1186+
timeoutController.cleanup()
1187+
}
1188+
})
1189+
11651190
it('admits against the source payer before executing', async () => {
11661191
await handler.execute(customBlockContext(), customBlock(), {})
11671192

apps/sim/executor/handlers/workflow/workflow-handler.ts

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -3,6 +3,7 @@ import { findCause, getErrorMessage, toError } from '@sim/utils/errors'
33
import { generateId } from '@sim/utils/id'
44
import { isRecordLike } from '@sim/utils/object'
55
import { resolveBillingAttribution } from '@/lib/billing/core/billing-attribution'
6+
import { getExecutionDeadlineAt } from '@/lib/core/execution-limits'
67
import { getPersonalAndWorkspaceEnv } from '@/lib/environment/utils'
78
import { buildNextCallChain, validateCallChain } from '@/lib/execution/call-chain'
89
import { LoggingSession } from '@/lib/logs/execution/logging-session'
@@ -480,6 +481,7 @@ export class WorkflowBlockHandler implements BlockHandler {
480481
// child is part of that same logical run and must not add a second.
481482
{ baseExecutionCharge: 0 }
482483
)
484+
childSession.setExecutionDeadlineAt(getExecutionDeadlineAt(ctx.abortSignal))
483485
childSession.setResolvedSecretTraceRegistry(childResolvedSecretTraceRegistry)
484486
const correlation = buildCustomBlockCorrelation({
485487
invokerExecutionId: ctx.executionId,

apps/sim/lib/core/async-jobs/backends/database.test.ts

Lines changed: 85 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -25,7 +25,11 @@ vi.mock('@sim/db', () => ({
2525
}))
2626

2727
import { DatabaseJobQueue } from '@/lib/core/async-jobs/backends/database'
28-
import { AsyncJobEnqueueError } from '@/lib/core/async-jobs/types'
28+
import {
29+
AsyncJobEnqueueError,
30+
MAX_JOB_DURATION_SECONDS,
31+
MIN_JOB_DURATION_SECONDS,
32+
} from '@/lib/core/async-jobs/types'
2933

3034
const EXISTING_JOB = {
3135
id: 'workflow:1',
@@ -112,6 +116,52 @@ describe('DatabaseJobQueue enqueue', () => {
112116
})
113117
)
114118
})
119+
120+
it.each([0, -1, 1.5, 4, MAX_JOB_DURATION_SECONDS + 1, Number.POSITIVE_INFINITY])(
121+
'rejects invalid maxDurationSeconds %s before inserting',
122+
async (maxDurationSeconds) => {
123+
const queue = new DatabaseJobQueue()
124+
125+
const error = await queue
126+
.enqueue('workflow-execution', {}, { maxDurationSeconds })
127+
.catch((cause: unknown) => cause)
128+
129+
expect(error).toMatchObject({ acceptance: 'rejected', retryable: false })
130+
expect(dbChainMockFns.insert).not.toHaveBeenCalled()
131+
}
132+
)
133+
134+
it('accepts the five-second minimum duration', async () => {
135+
const queue = new DatabaseJobQueue()
136+
137+
await queue.enqueue(
138+
'workflow-execution',
139+
{},
140+
{
141+
maxDurationSeconds: MIN_JOB_DURATION_SECONDS,
142+
}
143+
)
144+
145+
expect(dbChainMockFns.values).toHaveBeenCalledWith(
146+
expect.objectContaining({
147+
metadata: { maxDurationSeconds: MIN_JOB_DURATION_SECONDS },
148+
})
149+
)
150+
})
151+
152+
it('does not allow caller metadata to impersonate the reserved duration field', async () => {
153+
const queue = new DatabaseJobQueue()
154+
155+
await queue.enqueue(
156+
'workflow-execution',
157+
{},
158+
{
159+
metadata: { maxDurationSeconds: -1 },
160+
}
161+
)
162+
163+
expect(dbChainMockFns.values).toHaveBeenCalledWith(expect.objectContaining({ metadata: {} }))
164+
})
115165
})
116166

117167
describe('DatabaseJobQueue batchEnqueueAndWait', () => {
@@ -146,6 +196,20 @@ describe('DatabaseJobQueue batchEnqueueAndWait', () => {
146196
expect(maxInFlight).toBe(2)
147197
})
148198

199+
it('rejects every invalid duration before starting any runner', async () => {
200+
const queue = new DatabaseJobQueue()
201+
const runner = vi.fn()
202+
203+
await expect(
204+
queue.batchEnqueueAndWait('workflow-execution', [
205+
{ payload: {}, options: { maxDurationSeconds: 60, runner } },
206+
{ payload: {}, options: { maxDurationSeconds: 1.5, runner } },
207+
])
208+
).rejects.toMatchObject({ acceptance: 'rejected', retryable: false })
209+
210+
expect(runner).not.toHaveBeenCalled()
211+
})
212+
149213
it('aborts an in-process runner by execution ID', async () => {
150214
const queue = new DatabaseJobQueue()
151215
let resolveStarted: (() => void) | undefined
@@ -258,6 +322,26 @@ describe('DatabaseJobQueue batchEnqueueAndWait', () => {
258322
})
259323
})
260324

325+
describe('DatabaseJobQueue batchEnqueue', () => {
326+
beforeEach(() => {
327+
vi.clearAllMocks()
328+
resetDbChainMock()
329+
})
330+
331+
it('validates every row before inserting the batch', async () => {
332+
const queue = new DatabaseJobQueue()
333+
334+
await expect(
335+
queue.batchEnqueue('workflow-execution', [
336+
{ payload: {}, options: { maxDurationSeconds: 60 } },
337+
{ payload: {}, options: { maxDurationSeconds: 1.5 } },
338+
])
339+
).rejects.toMatchObject({ acceptance: 'rejected', retryable: false })
340+
341+
expect(dbChainMockFns.insert).not.toHaveBeenCalled()
342+
})
343+
})
344+
261345
describe('DatabaseJobQueue inline claims', () => {
262346
beforeEach(() => {
263347
vi.clearAllMocks()

0 commit comments

Comments
 (0)