Skip to content

Commit 5fb52a4

Browse files
committed
fix(tables,knowledge): recover abandoned dispatches and bound the sweep
Three defects measured in production this afternoon. A dispatcher killed by an OOM left `table_run_dispatches` at `dispatching` forever. Every terminal transition on that table is user- or flow-initiated, so nothing reclaimed the row: four dispatches were stranded in one afternoon, pinning each table's "X running" overlay and blocking re-runs, with no way to clear them from the product. The `table_run_dispatches_watchdog_idx` index has existed for this sweep since the table was created, unused. Liveness comes from a new `heartbeat_at`, stamped by the per-window writes that already advance `cursor` and `processed_count`, so a slow-but-live dispatch is spared however long it runs — the in-process path has no duration ceiling, so ageing from `requested_at` would reclaim live self-hosted work. The sweep reads `COALESCE(heartbeat_at, requested_at)` so rows written before the column stay reclaimable rather than NULL-false forever, and runs as the last arm of the existing stale-execution cron at the same 95-minute window its table-job sibling uses. Rows are cancelled, not completed: the scope never finished. The OOM itself is not a leak. Peak RSS is a flat plateau — 457 MB at 20-45s and 461 MB past 200s, so ten times the duration buys four megabytes — that has crept about two percent per release for a month, from 446 MB in late July to 545 MB, past the 512 MiB `small-1x` ceiling. CPU peaks at 0.19, so the larger preset is bought for RAM alone. `maxAttempts` never covered the kill either: Trigger.dev retries `TASK_PROCESS_OOM_KILLED` only when `retry.outOfMemory.machine` names a preset, and all four runs recorded `attempt_count = 1` while the docstring claimed they resumed from the persisted cursor. The connector stuck-document sweep dispatched without a bound. Its chunk size paced the loop but the candidate query had no limit, so one connector enqueued 2,959 documents in fifteen seconds onto the queue every workspace shares. Nothing was double-billed — those documents were genuinely unindexed — but one connector monopolized the queue, and each dispatch mints a fresh requestId, so the idempotency key differs every pass and none of it deduplicates. Candidates are now taken oldest-first and capped per sync; a deeper backlog is deferred to the next sync rather than dropped.
1 parent 4c41fc6 commit 5fb52a4

12 files changed

Lines changed: 20548 additions & 8 deletions

File tree

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

Lines changed: 41 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -31,6 +31,7 @@ import {
3131
STALE_SWEEPABLE_EXECUTION_STATUSES,
3232
type StaleSweepableExecutionStatus,
3333
} from '@/lib/logs/types'
34+
import { cancelStaleDispatches } from '@/lib/table/dispatcher'
3435
import { deleteFile } from '@/lib/uploads/core/storage-service'
3536
import {
3637
carrierNotIrrecoverableSql,
@@ -52,6 +53,16 @@ const EXECUTION_DEADLINE_ERROR = getTimeoutErrorMessage(undefined)
5253
const TABLE_JOB_STALE_THRESHOLD_MINUTES = 95
5354
/** Terminal table-jobs older than this are pruned; only the latest job per table is ever read. */
5455
const TABLE_JOB_RETENTION_HOURS = 24
56+
/**
57+
* A table run dispatch whose holder has not made progress for this long is
58+
* treated as dead. Same shape and window as the table-job threshold above: the
59+
* 90-minute Trigger.dev task ceiling (`maxDuration` in `trigger.config.ts`) plus
60+
* five minutes of cleanup grace, measured from the dispatcher's own per-window
61+
* heartbeat rather than from when the run was requested.
62+
*/
63+
const TABLE_DISPATCH_STALE_THRESHOLD_MINUTES = 95
64+
/** Per-run ceiling on reaped dispatches, so one tick cannot fan out unbounded SSE. */
65+
const TABLE_DISPATCH_MAX_PER_RUN = 200
5566
/**
5667
* Terminal deployment operations older than this are pruned. Every reader of
5768
* this table is latest-generation-only, and idempotency keys only need to
@@ -144,6 +155,9 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
144155
const staleTableJobThreshold = new Date(
145156
now.getTime() - TABLE_JOB_STALE_THRESHOLD_MINUTES * 60 * 1000
146157
)
158+
const staleDispatchThreshold = new Date(
159+
now.getTime() - TABLE_DISPATCH_STALE_THRESHOLD_MINUTES * 60 * 1000
160+
)
147161

148162
let staleExecutionsFound = 0
149163
let cleaned = 0
@@ -604,6 +618,29 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
604618
})
605619
}
606620

621+
/**
622+
* Cancel table run dispatches abandoned by a dead dispatcher. Nothing else
623+
* reclaims them — every other terminal transition is user- or flow-initiated
624+
* — so a dispatcher killed mid-loop left the row `dispatching` forever and
625+
* the client's "X running" overlay with it. Ages from the dispatcher's
626+
* per-window heartbeat, so a slow-but-live dispatch is spared.
627+
*/
628+
let staleDispatchesCancelled = 0
629+
try {
630+
staleDispatchesCancelled = (
631+
await cancelStaleDispatches(staleDispatchThreshold, TABLE_DISPATCH_MAX_PER_RUN)
632+
).length
633+
if (staleDispatchesCancelled > 0) {
634+
logger.warn(`Cancelled ${staleDispatchesCancelled} abandoned table run dispatches`, {
635+
thresholdMinutes: TABLE_DISPATCH_STALE_THRESHOLD_MINUTES,
636+
})
637+
}
638+
} catch (error) {
639+
logger.error('Failed to cancel abandoned table run dispatches:', {
640+
error: toError(error).message,
641+
})
642+
}
643+
607644
return NextResponse.json({
608645
success: true,
609646
executions: {
@@ -622,6 +659,10 @@ export const GET = withRouteHandler(async (request: NextRequest) => {
622659
tableJobs: {
623660
staleMarkedFailed: staleTableJobsMarkedFailed,
624661
},
662+
tableRunDispatches: {
663+
staleCancelled: staleDispatchesCancelled,
664+
thresholdMinutes: TABLE_DISPATCH_STALE_THRESHOLD_MINUTES,
665+
},
625666
deploymentOperations: {
626667
pruned: deploymentOperationsPruned,
627668
retentionDays: DEPLOYMENT_OPERATION_RETENTION_DAYS,
Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,37 @@
1+
/**
2+
* @vitest-environment node
3+
*/
4+
import { describe, expect, it, vi } from 'vitest'
5+
6+
const { mockTask } = vi.hoisted(() => ({
7+
mockTask: vi.fn((config) => config),
8+
}))
9+
10+
vi.mock('@trigger.dev/sdk', () => ({ task: mockTask }))
11+
vi.mock('@/lib/table/dispatcher', () => ({
12+
runDispatcherToCompletion: vi.fn(),
13+
}))
14+
15+
import { tableRunDispatcherTask } from '@/background/table-run-dispatcher'
16+
17+
describe('table-run-dispatcher task configuration', () => {
18+
/**
19+
* Peak RSS is a flat 457-464 MB plateau independent of run length, and it has
20+
* crept ~2% per release — 446 MB in late July to 545 MB, past the 512 MiB
21+
* `small-1x` ceiling, which killed four runs in one afternoon.
22+
*/
23+
it('runs on a preset whose memory clears the observed plateau', () => {
24+
expect(tableRunDispatcherTask.machine).toBe('small-2x')
25+
})
26+
27+
/**
28+
* `maxAttempts` alone does NOT cover `TASK_PROCESS_OOM_KILLED` — Trigger.dev
29+
* retries an OOM only when `retry.outOfMemory.machine` names a larger preset.
30+
* Every one of the four killed runs recorded `attempt_count = 1`, so the
31+
* documented "retries and resumes from the persisted cursor" never happened.
32+
*/
33+
it('escalates to a larger machine on an out-of-memory kill', () => {
34+
expect(tableRunDispatcherTask.retry?.outOfMemory?.machine).toBe('medium-1x')
35+
expect(tableRunDispatcherTask.retry?.maxAttempts).toBe(3)
36+
})
37+
})

apps/sim/background/table-run-dispatcher.ts

Lines changed: 19 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -17,13 +17,28 @@ export interface TableRunDispatcherPayload {
1717
* dispatcher loop for the dispatch's entire lifetime — each iteration
1818
* processes a window of cells via `batchTriggerAndWait`, which checkpoints
1919
* the parent via CRIU during the wait so we don't pay compute while cells
20-
* execute. The cursor is persisted in DB; if this run crashes, trigger.dev
21-
* retries and the next attempt resumes from the persisted cursor.
20+
* execute. The cursor is persisted in DB, so an attempt that starts after a
21+
* crash resumes from it rather than replaying the dispatch.
22+
*
23+
* `maxAttempts` alone does NOT cover an OOM: Trigger.dev retries
24+
* `TASK_PROCESS_OOM_KILLED` only when `retry.outOfMemory.machine` names a
25+
* larger preset. Four runs were killed this way and every one recorded
26+
* `attempt_count = 1` — no retry happened, and the dispatch row was left
27+
* `dispatching` forever. The escalating preset is what makes the documented
28+
* resume actually reachable; the cleanup sweep is the backstop for a dispatch
29+
* whose holder dies without one.
2230
*/
2331
export const tableRunDispatcherTask = task({
2432
id: 'table-run-dispatcher',
25-
machine: 'small-1x',
26-
retry: { maxAttempts: 3 },
33+
/**
34+
* Memory, not CPU. Peak RSS sits at a flat 457-464 MB plateau regardless of
35+
* run length (10x the duration moves it ~4 MB), and it has crept ~2% per
36+
* release for a month — 446 MB in late July to 545 MB, past the 512 MiB
37+
* `small-1x` ceiling. Meanwhile CPU utilization peaks at 0.19 and sits at
38+
* 0.03 for p90, so the larger preset is bought for its RAM.
39+
*/
40+
machine: 'small-2x',
41+
retry: { maxAttempts: 3, outOfMemory: { machine: 'medium-1x' } },
2742
queue: {
2843
name: 'table-run-dispatcher',
2944
concurrencyLimit: 8,

apps/sim/lib/knowledge/connectors/sync-engine.test.ts

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2074,6 +2074,46 @@ describe('executeSync hard-delete reconciliation', () => {
20742074
expect(calls.flatMap((call) => call[0] as string[])).toEqual(missingIds)
20752075
})
20762076

2077+
it('bounds and orders the stuck-document sweep instead of draining a backlog at once', async () => {
2078+
const { executeSync, STUCK_RETRY_MAX_CANDIDATES_PER_SYNC } = await import(
2079+
'@/lib/knowledge/connectors/sync-engine'
2080+
)
2081+
const { hardDeleteDocuments } = await import('@/lib/knowledge/documents/service')
2082+
2083+
primeReconciliation()
2084+
vi.mocked(hardDeleteDocuments).mockResolvedValue(0)
2085+
/**
2086+
* Every batch and the post-batch check re-read the connector to confirm the
2087+
* sync target still exists; without enough rows the run exits as
2088+
* connector-deleted before the sweep it is meant to exercise.
2089+
*/
2090+
for (let i = 0; i < 40; i++) {
2091+
queueTableRows(schemaMock.knowledgeConnector, [
2092+
{ connectorArchivedAt: null, connectorDeletedAt: null, kbDeletedAt: null },
2093+
])
2094+
}
2095+
// The sweep's own candidate read: no stuck documents, so it dispatches none.
2096+
queueTableRows(schemaMock.document, [])
2097+
2098+
await executeSync('c-1', {
2099+
billingAttribution: { workspaceId: 'ws-1' } as never,
2100+
fullSync: true,
2101+
})
2102+
2103+
/**
2104+
* The dispatch loop's chunk size paced the sweep but never bounded it — the
2105+
* candidate query had no limit, so one connector enqueued its entire backlog
2106+
* (2,959 documents in fifteen seconds) onto the queue every workspace shares.
2107+
*/
2108+
expect(dbChainMockFns.limit).toHaveBeenCalledWith(STUCK_RETRY_MAX_CANDIDATES_PER_SYNC)
2109+
/**
2110+
* Ordered, so the bound takes the most overdue documents first and can never
2111+
* starve one indefinitely. An unordered limit takes an arbitrary subset each
2112+
* sync, which is a cap that silently loses work rather than deferring it.
2113+
*/
2114+
expect(dbChainMockFns.orderBy).toHaveBeenCalled()
2115+
})
2116+
20772117
it('releases the lock when it errors a connector whose knowledge base is gone', async () => {
20782118
const { executeSync } = await import('@/lib/knowledge/connectors/sync-engine')
20792119

apps/sim/lib/knowledge/connectors/sync-engine.ts

Lines changed: 40 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,7 +10,20 @@ import { createLogger } from '@sim/logger'
1010
import { getErrorMessage, toError } from '@sim/utils/errors'
1111
import { generateId } from '@sim/utils/id'
1212
import { randomInt } from '@sim/utils/random'
13-
import { and, desc, eq, exists, gt, inArray, isNotNull, isNull, lt, ne, sql } from 'drizzle-orm'
13+
import {
14+
and,
15+
asc,
16+
desc,
17+
eq,
18+
exists,
19+
gt,
20+
inArray,
21+
isNotNull,
22+
isNull,
23+
lt,
24+
ne,
25+
sql,
26+
} from 'drizzle-orm'
1427
import { decryptApiKey } from '@/lib/api-key/crypto'
1528
import {
1629
assertBillingAttributionSnapshot,
@@ -94,6 +107,25 @@ const MAX_SAFE_TITLE_LENGTH = 200
94107
*/
95108
const STUCK_RETRY_DISPATCH_CHUNK_SIZE = 25
96109

110+
/**
111+
* How many stuck-document candidates one sync will consider.
112+
*
113+
* {@link STUCK_RETRY_DISPATCH_CHUNK_SIZE} paces the dispatch loop but does not
114+
* bound it — the candidate query had no limit, so a connector carrying a large
115+
* backlog dispatched the whole thing at once. One did: 2,959 documents enqueued
116+
* in fifteen seconds onto a queue every workspace shares, at
117+
* {@link PROCESSING_QUEUE_CONCURRENCY} concurrent runs. Nothing was
118+
* double-billed — those documents were genuinely unindexed — but one connector
119+
* monopolized the queue, and each dispatch mints a fresh `requestId`, so the
120+
* Trigger.dev idempotency key differs every pass and none of it deduplicates.
121+
*
122+
* 200 keeps a single sync's contribution to roughly ten minutes of queue
123+
* occupancy at the default concurrency. A backlog larger than this is not
124+
* dropped: candidates are taken oldest-first and whatever is left stays
125+
* eligible, so consecutive syncs drain it steadily instead of in one burst.
126+
*/
127+
export const STUCK_RETRY_MAX_CANDIDATES_PER_SYNC = 200
128+
97129
/**
98130
* How many documents reconciliation hard-deletes per call.
99131
*
@@ -2312,6 +2344,13 @@ export async function executeSync(
23122344
isNull(document.deletedAt)
23132345
)
23142346
)
2347+
/**
2348+
* Oldest first, so the most overdue documents drain before newer ones and
2349+
* the bound below can never starve a document indefinitely. Without an
2350+
* order the limit would take an arbitrary subset each sync.
2351+
*/
2352+
.orderBy(asc(document.uploadedAt))
2353+
.limit(STUCK_RETRY_MAX_CANDIDATES_PER_SYNC)
23152354
const stuckDocs = sweepCandidates
23162355
.filter((row): row is typeof row & { processingStatus: DocumentProcessingStatus } =>
23172356
isDocumentProcessingStatus(row.processingStatus)

apps/sim/lib/table/dispatcher.ts

Lines changed: 104 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -407,7 +407,10 @@ export async function dispatcherStep(
407407
if (dispatch.status === 'pending') {
408408
await db
409409
.update(tableRunDispatches)
410-
.set({ status: 'dispatching' })
410+
// Opens the heartbeat at the instant a holder takes the dispatch, so the
411+
// cleanup sweep ages it from that rather than from `requested_at`, which
412+
// was stamped when the run was merely requested.
413+
.set({ status: 'dispatching', heartbeatAt: new Date() })
411414
.where(eq(tableRunDispatches.id, dispatchId))
412415
// Announce the dispatch the moment it starts — before the first window's
413416
// cells finish. Without this, auto-fired and capped dispatches (no client-
@@ -672,7 +675,10 @@ export async function dispatcherStep(
672675
async function incrementProcessedCount(dispatchId: string, delta: number): Promise<void> {
673676
await db
674677
.update(tableRunDispatches)
675-
.set({ processedCount: sql`${tableRunDispatches.processedCount} + ${delta}` })
678+
.set({
679+
processedCount: sql`${tableRunDispatches.processedCount} + ${delta}`,
680+
heartbeatAt: new Date(),
681+
})
676682
.where(eq(tableRunDispatches.id, dispatchId))
677683
}
678684

@@ -724,7 +730,7 @@ async function stampQueuedForBatch(
724730
async function advanceCursor(dispatchId: string, newCursor: number): Promise<void> {
725731
await db
726732
.update(tableRunDispatches)
727-
.set({ cursor: newCursor })
733+
.set({ cursor: newCursor, heartbeatAt: new Date() })
728734
.where(eq(tableRunDispatches.id, dispatchId))
729735
}
730736

@@ -781,6 +787,101 @@ export async function completeDispatchIfActive(dispatchId: string): Promise<bool
781787
return transitioned.length > 0
782788
}
783789

790+
/**
791+
* Cancels dispatches whose holder died without reaching a terminal state.
792+
*
793+
* `table_run_dispatches` had no reaper: the only paths to a terminal status are
794+
* user- or flow-initiated ({@link cancelDispatchById},
795+
* {@link completeDispatchIfActive}, {@link markActiveDispatchesCancelled}), so a
796+
* dispatcher killed mid-loop left its row `dispatching` forever — pinning the
797+
* client's "X running" overlay and blocking re-runs of that table. Four rows
798+
* were stranded this way by a single afternoon of OOM kills, and nothing in the
799+
* product could clear them. The `table_run_dispatches_watchdog_idx` index has
800+
* existed since the table was created for exactly this sweep, unused.
801+
*
802+
* Liveness comes from `heartbeatAt`, which the per-window `advanceCursor` and
803+
* `incrementProcessedCount` writes stamp, so a slow-but-live dispatch is spared
804+
* however long it runs. That matters because the in-process path
805+
* (`isTriggerDevEnabled === false`) has no duration ceiling at all — ageing from
806+
* `requestedAt` would reclaim live self-hosted work. `COALESCE` keeps rows
807+
* written before the column existed reclaimable rather than NULL-false forever.
808+
*
809+
* Cancelled rather than completed: the dispatch did not finish its scope, and
810+
* reporting it complete would tell the user work happened that did not. The
811+
* cursor is left in place, so a re-run resumes rather than replays.
812+
*/
813+
export async function cancelStaleDispatches(
814+
staleBefore: Date,
815+
limit: number
816+
): Promise<DispatchRow[]> {
817+
const isStale = () =>
818+
and(
819+
inArray(tableRunDispatches.status, [...ACTIVE_DISPATCH_STATUSES]),
820+
sql`COALESCE(${tableRunDispatches.heartbeatAt}, ${tableRunDispatches.requestedAt}) < ${sql.param(staleBefore, tableRunDispatches.heartbeatAt)}`
821+
)
822+
823+
// Claimed as explicit ids first, then updated by id, so the bound is evaluated
824+
// exactly once — the pattern every other bulk cleanup in this codebase uses.
825+
// The update re-asserts staleness, so a dispatch that finished in between is
826+
// left alone rather than cancelled out from under its own terminal write.
827+
const claimed = await db
828+
.select({ id: tableRunDispatches.id })
829+
.from(tableRunDispatches)
830+
.where(isStale())
831+
.limit(limit)
832+
if (claimed.length === 0) return []
833+
834+
const cancelled = await db
835+
.update(tableRunDispatches)
836+
.set({ status: 'cancelled', cancelledAt: new Date() })
837+
.where(
838+
and(
839+
isStale(),
840+
inArray(
841+
tableRunDispatches.id,
842+
claimed.map(({ id }) => id)
843+
)
844+
)
845+
)
846+
.returning()
847+
848+
const dispatches = cancelled.map((row) => ({
849+
id: row.id,
850+
tableId: row.tableId,
851+
workspaceId: row.workspaceId,
852+
requestId: row.requestId,
853+
mode: row.mode as DispatchMode,
854+
scope: row.scope as DispatchScope,
855+
status: 'cancelled' as DispatchStatus,
856+
cursor: row.cursor,
857+
limit: (row.limit as DispatchLimit | null) ?? null,
858+
processedCount: row.processedCount,
859+
isManualRun: row.isManualRun,
860+
triggeredByUserId: row.triggeredByUserId,
861+
requestedAt: row.requestedAt,
862+
}))
863+
864+
// Same terminal event every other cancel path emits — without it the row goes
865+
// terminal in the database while the client overlay stays stuck, which is the
866+
// symptom this function exists to clear.
867+
await Promise.all(
868+
dispatches.map((d) =>
869+
appendTableEvent({
870+
kind: 'dispatch',
871+
tableId: d.tableId,
872+
dispatchId: d.id,
873+
status: 'cancelled',
874+
scope: d.scope,
875+
cursor: d.cursor,
876+
mode: d.mode,
877+
isManualRun: d.isManualRun,
878+
})
879+
)
880+
)
881+
882+
return dispatches
883+
}
884+
784885
/** Mark every active dispatch on this table as cancelled. Single atomic
785886
* UPDATE so the dispatcher's next iteration observes the cancel. Returns the
786887
* dispatches that were cancelled so the caller can emit per-dispatch SSE

0 commit comments

Comments
 (0)