Skip to content

Commit c2ca817

Browse files
committed
fix(schedules): stop reconciliation rewriting healthy carriers and index its scan
Follow-up hardening on the schedule recovery reconciliation. Reconciliation settled every carrier it examined, including ones that had already reached a terminal status and recorded their own outcome. Because the normal completion path never stamps the reconciled marker, each successful run's carrier was picked up on the next tick and rewritten: `completedAt` bumped, `error` nulled and `output` replaced with a recovery stub, all of which `GET /api/jobs/[jobId]` surfaces. A completed carrier whose execution log had aged out was additionally flipped to failed. Settle only carriers still in flight; a terminal one is owed schedule accounting and the marker, nothing more. The recovery scan matched no index. There was none on `async_jobs.updated_at`, and the unreconciled-terminal branch tested a jsonb extraction, so the whole OR fell back to a sequential scan and sort of `async_jobs` on every tick. Add the partial index, and spell the branch's status list and metadata key as SQL literals: Postgres cannot prove a parameterised predicate implies a literal index predicate, so a bound key would have left the new index unused. Irrecoverable carrier tombstones were exempted from retention with no secondary expiry, so the one class of row that can never reconcile grew without bound. Give them a longer bounded window instead. `WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN` had become a per-status budget when the stale-execution sweep gained its `redacting` pass, silently doubling the per-run cap. Share the budget across both passes, and add the matching partial indexes so the second pass keeps an index rather than seq-scanning. Also consolidates the carrier metadata keys, their predicates and the jsonb merge into one module -- the two routes were the writer and reader of the same keys with no shared symbol, so a rename type-checked clean while silently breaking retention.
1 parent 90f4238 commit c2ca817

11 files changed

Lines changed: 20379 additions & 128 deletions

File tree

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

Lines changed: 72 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -5,7 +5,16 @@ import { asyncJobs, tableJobs, workflowExecutionLogs } from '@sim/db/schema'
55
import { createLogger } from '@sim/logger'
66
import { createMockRequest, dbChainMockFns, queueTableRows, resetDbChainMock } from '@sim/testing'
77
import { beforeEach, describe, expect, it, vi } from 'vitest'
8-
import { MAX_JOB_DURATION_SECONDS, MIN_JOB_DURATION_SECONDS } from '@/lib/core/async-jobs'
8+
import {
9+
JOB_RETENTION_HOURS,
10+
MAX_JOB_DURATION_SECONDS,
11+
MIN_JOB_DURATION_SECONDS,
12+
} from '@/lib/core/async-jobs'
13+
import {
14+
SCHEDULE_CARRIER_IRRECOVERABLE_METADATA_KEY,
15+
SCHEDULE_CARRIER_IRRECOVERABLE_RETENTION_HOURS,
16+
SCHEDULE_CARRIER_RECONCILED_METADATA_KEY,
17+
} from '@/lib/workflows/schedules/carrier-metadata'
918

1019
const { mockDeleteFile, mockVerifyCronAuth } = vi.hoisted(() => ({
1120
mockDeleteFile: vi.fn().mockResolvedValue(undefined),
@@ -62,6 +71,33 @@ function createRequest() {
6271
)
6372
}
6473

74+
/** Recursively renders a mocked drizzle fragment, expanding nested fragments. */
75+
function renderSql(fragment: unknown): string {
76+
if (fragment === null || fragment === undefined) return ''
77+
if (typeof fragment !== 'object') return String(fragment)
78+
const candidate = fragment as { rawSql?: string; strings?: string[]; values?: unknown[] }
79+
if (typeof candidate.rawSql === 'string') return candidate.rawSql
80+
if (!candidate.strings) return ''
81+
return candidate.strings
82+
.map((part, index) =>
83+
index < (candidate.values?.length ?? 0)
84+
? `${part}${renderSql(candidate.values?.[index])}`
85+
: part
86+
)
87+
.join('')
88+
}
89+
90+
/** Recursively collects the non-fragment bind values of a mocked fragment. */
91+
function collectSqlParams(fragment: unknown): unknown[] {
92+
if (!fragment || typeof fragment !== 'object') return []
93+
const candidate = fragment as { values?: unknown[] }
94+
if (!candidate.values) return []
95+
return candidate.values.flatMap((value) => {
96+
const nested = collectSqlParams(value)
97+
return nested.length > 0 ? nested : [value]
98+
})
99+
}
100+
65101
describe('stale execution cleanup deadline grace', () => {
66102
beforeEach(() => {
67103
vi.clearAllMocks()
@@ -237,10 +273,10 @@ describe('stale execution cleanup deadline grace', () => {
237273
flattenConditions(condition)
238274
)
239275
const reconciliationMarker = retentionConditions.find((condition) =>
240-
condition.toSQL?.().sql.includes('scheduleReconciled')
276+
renderSql(condition).includes(SCHEDULE_CARRIER_RECONCILED_METADATA_KEY)
241277
)
242278

243-
expect(reconciliationMarker?.toSQL?.().params).toContain(asyncJobs.metadata)
279+
expect(collectSqlParams(reconciliationMarker)).toContain(asyncJobs.metadata)
244280
expect(
245281
retentionConditions.some(
246282
(condition) =>
@@ -251,19 +287,47 @@ describe('stale execution cleanup deadline grace', () => {
251287
).toBe(true)
252288
})
253289

254-
it('retains irrecoverable schedule carrier tombstones indefinitely', async () => {
290+
it('spells carrier metadata keys as SQL literals so the partial index matches', async () => {
291+
const response = await GET(createRequest())
292+
293+
expect(response.status).toBe(200)
294+
const reconciliationMarker = dbChainMockFns.where.mock.calls
295+
.flatMap(([condition]) => flattenConditions(condition))
296+
.find((condition) => renderSql(condition).includes(SCHEDULE_CARRIER_RECONCILED_METADATA_KEY))
297+
298+
expect(renderSql(reconciliationMarker)).toContain(
299+
`'${SCHEDULE_CARRIER_RECONCILED_METADATA_KEY}'`
300+
)
301+
expect(collectSqlParams(reconciliationMarker)).not.toContain(
302+
SCHEDULE_CARRIER_RECONCILED_METADATA_KEY
303+
)
304+
})
305+
306+
it('deletes irrecoverable schedule carrier tombstones once their longer window lapses', async () => {
255307
const response = await GET(createRequest())
256308

257309
expect(response.status).toBe(200)
258310
const retentionConditions = dbChainMockFns.where.mock.calls.flatMap(([condition]) =>
259311
flattenConditions(condition)
260312
)
261313
const irrecoverableExclusion = retentionConditions.find((condition) =>
262-
condition.toSQL?.().sql.includes('scheduleRecoveryIrrecoverable')
314+
renderSql(condition).includes(SCHEDULE_CARRIER_IRRECOVERABLE_METADATA_KEY)
263315
)
264316

265-
expect(irrecoverableExclusion?.toSQL?.().sql).toContain("<> 'true'")
266-
expect(irrecoverableExclusion?.toSQL?.().params).toContain(asyncJobs.metadata)
317+
expect(renderSql(irrecoverableExclusion)).toContain("<> 'true'")
318+
expect(collectSqlParams(irrecoverableExclusion)).toContain(asyncJobs.metadata)
319+
320+
const tombstoneWindow = retentionConditions.filter(
321+
(condition) =>
322+
condition.type === 'lt' &&
323+
condition.left === asyncJobs.completedAt &&
324+
condition.right instanceof Date
325+
)
326+
const oldest = Math.min(...tombstoneWindow.map(({ right }) => (right as Date).getTime()))
327+
const newest = Math.max(...tombstoneWindow.map(({ right }) => (right as Date).getTime()))
328+
expect(newest - oldest).toBe(
329+
(SCHEDULE_CARRIER_IRRECOVERABLE_RETENTION_HOURS - JOB_RETENTION_HOURS) * 60 * 60 * 1000
330+
)
267331
})
268332

269333
it('keeps table-job heartbeat cleanup independent from workflow timeout policy', async () => {
@@ -382,7 +446,7 @@ describe('stale execution cleanup deadline grace', () => {
382446
expect(mockDeleteFile).toHaveBeenCalledTimes(1000)
383447

384448
const limits = dbChainMockFns.limit.mock.calls.map(([limit]) => limit)
385-
expect(limits.filter((limit) => limit === 100)).toHaveLength(21)
449+
expect(limits.filter((limit) => limit === 100)).toHaveLength(20)
386450
expect(limits.filter((limit) => limit === 1000)).toHaveLength(30)
387451
expect(limits.filter((limit) => limit === 2000)).toHaveLength(11)
388452

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

Lines changed: 37 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -17,6 +17,7 @@ import {
1717
JOB_STATUS,
1818
MAX_JOB_DURATION_SECONDS,
1919
MIN_JOB_DURATION_SECONDS,
20+
TERMINAL_JOB_STATUSES,
2021
} from '@/lib/core/async-jobs'
2122
import {
2223
getExecutionReservationTtlMs,
@@ -26,7 +27,14 @@ import {
2627
import { withRouteHandler } from '@/lib/core/utils/with-route-handler'
2728
import type { DbTransaction } from '@/lib/db/types'
2829
import { elapsedDurationMsSql } from '@/lib/logs/execution/duration'
30+
import { STALE_SWEEPABLE_EXECUTION_STATUSES } from '@/lib/logs/types'
2931
import { deleteFile } from '@/lib/uploads/core/storage-service'
32+
import {
33+
carrierNotIrrecoverableSql,
34+
carrierReconciledSql,
35+
SCHEDULE_CARRIER_IRRECOVERABLE_RETENTION_HOURS,
36+
} from '@/lib/workflows/schedules/carrier-metadata'
37+
import { SCHEDULE_EXECUTION_QUEUE_NAME } from '@/lib/workflows/schedules/execution-limits'
3038

3139
const logger = createLogger('CleanupStaleExecutions')
3240

@@ -152,12 +160,17 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
152160
EXTRACT(EPOCH FROM (${cleanupTimestamp} - ${workflowExecutionLogs.startedAt})) / 60
153161
)::integer`
154162
const totalDurationMs = elapsedDurationMsSql(now)
155-
for (const executionStatus of ['running', 'redacting'] as const) {
163+
/**
164+
* Swept one status at a time so each pass stays on its own partial index;
165+
* `status IN (...)` would match neither. The row budget is shared across
166+
* both passes so the per-run cap keeps meaning what its name says.
167+
*/
168+
let workflowRowsConsidered = 0
169+
for (const executionStatus of STALE_SWEEPABLE_EXECUTION_STATUSES) {
156170
const staleExecutionPredicate = and(
157171
eq(workflowExecutionLogs.status, executionStatus),
158172
staleExecutionTimePredicate
159173
)
160-
let workflowRowsConsidered = 0
161174
while (workflowRowsConsidered < WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN) {
162175
const limit = Math.min(
163176
WORKFLOW_EXECUTION_MUTATION_BATCH_SIZE,
@@ -216,16 +229,12 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
216229
workflowRowsConsidered += candidates.length
217230
if (candidates.length < limit) break
218231
}
232+
}
219233

220-
if (workflowRowsConsidered >= WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN) {
221-
logger.info(
222-
'Deferred remaining stale workflow executions after reaching the per-run cap',
223-
{
224-
status: executionStatus,
225-
maxRowsPerRun: WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN,
226-
}
227-
)
228-
}
234+
if (workflowRowsConsidered >= WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN) {
235+
logger.info('Deferred remaining stale workflow executions after reaching the per-run cap', {
236+
maxRowsPerRun: WORKFLOW_EXECUTION_MAX_ROWS_PER_RUN,
237+
})
229238
}
230239
} catch (error) {
231240
logger.error('Failed to clean up stale workflow executions:', {
@@ -260,7 +269,7 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
260269
END`
261270
const staleProcessingPredicate = and(
262271
eq(asyncJobs.status, JOB_STATUS.PROCESSING),
263-
ne(asyncJobs.type, 'schedule-execution'),
272+
ne(asyncJobs.type, SCHEDULE_EXECUTION_QUEUE_NAME),
264273
staleProcessingDurationPredicate
265274
)
266275
const staleProcessingResult = await runBatchedMutation({
@@ -403,7 +412,7 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
403412
try {
404413
const stalePendingPredicate = and(
405414
eq(asyncJobs.status, JOB_STATUS.PENDING),
406-
ne(asyncJobs.type, 'schedule-execution'),
415+
ne(asyncJobs.type, SCHEDULE_EXECUTION_QUEUE_NAME),
407416
lt(asyncJobs.createdAt, stalePendingThreshold)
408417
)
409418
const stalePendingResult = await runBatchedMutation({
@@ -445,16 +454,27 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
445454
}
446455

447456
const retentionThreshold = new Date(Date.now() - JOB_RETENTION_HOURS * 60 * 60 * 1000)
457+
const irrecoverableCarrierRetentionThreshold = new Date(
458+
Date.now() - SCHEDULE_CARRIER_IRRECOVERABLE_RETENTION_HOURS * 60 * 60 * 1000
459+
)
448460
let asyncJobsDeleted = 0
449461

450462
try {
451463
const retainedJobPredicate = and(
452-
inArray(asyncJobs.status, [JOB_STATUS.COMPLETED, JOB_STATUS.FAILED, JOB_STATUS.CANCELLED]),
464+
inArray(asyncJobs.status, TERMINAL_JOB_STATUSES),
453465
or(
454-
ne(asyncJobs.type, 'schedule-execution'),
466+
ne(asyncJobs.type, SCHEDULE_EXECUTION_QUEUE_NAME),
467+
/**
468+
* Schedule recovery owns a carrier until it stamps the reconciled
469+
* marker, so retention waits for it rather than deleting an
470+
* occurrence that has not been accounted for yet.
471+
*/
455472
and(
456-
sql`${asyncJobs.metadata}->>'scheduleReconciled' = 'true'`,
457-
sql`COALESCE(${asyncJobs.metadata}->>'scheduleRecoveryIrrecoverable', 'false') <> 'true'`
473+
carrierReconciledSql(asyncJobs.metadata),
474+
or(
475+
carrierNotIrrecoverableSql(asyncJobs.metadata),
476+
lt(asyncJobs.completedAt, irrecoverableCarrierRetentionThreshold)
477+
)
458478
)
459479
),
460480
lt(asyncJobs.completedAt, retentionThreshold)

apps/sim/app/api/schedules/execute/route.test.ts

Lines changed: 30 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -620,8 +620,11 @@ describe('Scheduled Workflow Execution API Route', () => {
620620

621621
await runScheduleTick('test-request-id')
622622

623+
expect(dbChainMockFns.set).not.toHaveBeenCalledWith(
624+
expect.objectContaining({ status: expect.anything() })
625+
)
623626
expect(dbChainMockFns.set).toHaveBeenCalledWith(
624-
expect.objectContaining({ status: 'cancelled', error: 'Cancelled' })
627+
expect.objectContaining({ metadata: expect.anything() })
625628
)
626629
expect(mockApplyScheduleCancellationUpdate).toHaveBeenCalledOnce()
627630
expect(mockExecuteScheduleJob).not.toHaveBeenCalled()
@@ -651,8 +654,8 @@ describe('Scheduled Workflow Execution API Route', () => {
651654

652655
await runScheduleTick('test-request-id')
653656

654-
expect(dbChainMockFns.set).toHaveBeenCalledWith(
655-
expect.objectContaining({ status: 'cancelled', error: 'Cancelled' })
657+
expect(dbChainMockFns.set).not.toHaveBeenCalledWith(
658+
expect.objectContaining({ status: expect.anything() })
656659
)
657660
expect(mockApplyScheduleSuccessUpdate).toHaveBeenCalledOnce()
658661
expect(mockApplyScheduleCancellationUpdate).not.toHaveBeenCalled()
@@ -800,6 +803,30 @@ describe('Scheduled Workflow Execution API Route', () => {
800803

801804
await runScheduleTick('test-request-id')
802805

806+
expect(dbChainMockFns.set).not.toHaveBeenCalledWith(
807+
expect.objectContaining({ status: expect.anything() })
808+
)
809+
expect(dbChainMockFns.set).toHaveBeenCalledWith(
810+
expect.objectContaining({ metadata: expect.anything(), updatedAt: expect.any(Date) })
811+
)
812+
expect(mockApplyScheduleFailureUpdate).not.toHaveBeenCalled()
813+
expect(mockExecuteScheduleJob).not.toHaveBeenCalled()
814+
})
815+
816+
it('settles a malformed in-flight carrier before marking it irrecoverable', async () => {
817+
mockShouldExecuteInline.mockReturnValue(true)
818+
mockProcessingCounts(0, 0)
819+
orderByLimitMock.mockResolvedValueOnce([
820+
{
821+
id: 'malformed-job-id',
822+
status: 'processing',
823+
payload: { workflowId: 'workflow-1' },
824+
},
825+
])
826+
dbChainMockFns.returning.mockResolvedValueOnce([{ id: 'malformed-job-id' }])
827+
828+
await runScheduleTick('test-request-id')
829+
803830
expect(dbChainMockFns.set).toHaveBeenCalledWith(
804831
expect.objectContaining({ status: 'failed', completedAt: expect.any(Date) })
805832
)

0 commit comments

Comments
 (0)