Skip to content

Commit 2fc2008

Browse files
authored
fix(mothership): close the scheduled-job review gaps (#9345)
* fix(mothership): close the scheduled-job review gaps - dispatch one attempt at a time per occurrence, so a skip or block never closes a live run's record - brief each occurrence with the run number fixed at its claim, not the job's moving count - report an automatic turn-off only when this failure turned the job off, not one a person already turned off - mark a deadline stop after it is delivered, so a crash before then delivers it again - state the run's spend cap only where hosted billing enforces it - recover an invalid index left by an interrupted build in the job migration, as 0435 does - give PlanUsageLimitDisplay a props interface * fix(mothership): record why a run stops before delivering the stop, and redeliver one an earlier pass did not finish
1 parent 7d1b047 commit 2fc2008

9 files changed

Lines changed: 215 additions & 31 deletions

File tree

‎apps/sim/app/workspace/[workspaceId]/home/components/message-content/components/special-tags/special-tags.tsx‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3478,8 +3478,12 @@ function JobRunBudgetDisplay({ message }: JobRunBudgetDisplayProps) {
34783478
)
34793479
}
34803480

3481+
interface PlanUsageLimitDisplayProps {
3482+
data: UsageUpgradeTagData
3483+
}
3484+
34813485
/** The payer's plan limit: the card links to where the plan or the limit can change. */
3482-
function PlanUsageLimitDisplay({ data }: { data: UsageUpgradeTagData }) {
3486+
function PlanUsageLimitDisplay({ data }: PlanUsageLimitDisplayProps) {
34833487
const { data: session } = useSession()
34843488
const hostContext = useOptionalWorkspaceHostContext()
34853489
const organizationContext = useOptionalOrganizationContext()

‎apps/sim/lib/mothership/jobs/brief.ts‎

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ const BRIEF_SUMMARY_CHARS = 400
99

1010
type JobBriefSchedule = Pick<
1111
JobRun,
12-
'scheduleId' | 'jobTitle' | 'prompt' | 'successCondition' | 'lifecycle' | 'maxRuns' | 'runCount'
12+
'scheduleId' | 'jobTitle' | 'prompt' | 'successCondition' | 'lifecycle' | 'maxRuns' | 'runNumber'
1313
>
1414

1515
/**
@@ -20,7 +20,7 @@ type JobBriefSchedule = Pick<
2020
export async function buildJobBrief(
2121
schedule: JobBriefSchedule,
2222
occurrenceAt: Date,
23-
runBudgetUsd: number
23+
runBudgetUsd: number | null
2424
): Promise<string> {
2525
const recent = await db
2626
.select({
@@ -40,8 +40,8 @@ export async function buildJobBrief(
4040
.limit(BRIEF_RECENT_RUNS)
4141

4242
const run = schedule.maxRuns
43-
? `Run ${schedule.runCount} of ${schedule.maxRuns}`
44-
: `Run ${schedule.runCount}`
43+
? `Run ${schedule.runNumber} of ${schedule.maxRuns}`
44+
: `Run ${schedule.runNumber}`
4545
return [
4646
`Job: ${schedule.jobTitle ?? 'Untitled job'} (${run}, scheduled for ${occurrenceAt.toISOString()})`,
4747
`Task:\n${schedule.prompt ?? ''}`,
@@ -59,7 +59,7 @@ export async function buildJobBrief(
5959
)
6060
.join('\n')}`
6161
: 'This is the first run.',
62-
`This run may spend up to $${runBudgetUsd.toFixed(2)}.`,
62+
runBudgetUsd === null ? '' : `This run may spend up to $${runBudgetUsd.toFixed(2)}.`,
6363
]
6464
.filter((part) => part.length > 0)
6565
.join('\n\n')

‎apps/sim/lib/mothership/jobs/claim.ts‎

Lines changed: 2 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -84,6 +84,8 @@ export async function claimDueJobOccurrences(
8484
status: 'queued',
8585
trigger: JOB_RUN_TRIGGER,
8686
startedAt: now,
87+
/** Fixed at claim: the schedule's count moves on as later occurrences are claimed. */
88+
executionData: { runNumber: runCount },
8789
})
8890
.onConflictDoNothing()
8991
await tx

‎apps/sim/lib/mothership/jobs/dispatch.ts‎

Lines changed: 29 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1,10 +1,12 @@
11
import { createLogger } from '@sim/logger'
2-
import { getErrorMessage } from '@sim/utils/errors'
2+
import { getErrorMessage, toError } from '@sim/utils/errors'
3+
import { generateShortId } from '@sim/utils/id'
34
import {
45
checkAttributedUsageLimits,
56
resolveBillingAttribution,
67
} from '@/lib/billing/core/attribution'
78
import { isHosted } from '@/lib/core/config/env-flags'
9+
import { acquireLock, releaseLock } from '@/lib/core/config/redis'
810
import { asOrchestrationError } from '@/lib/core/orchestration/types'
911
import { buildJobBrief } from '@/lib/mothership/jobs/brief'
1012
import { jobRunBudgetUsd } from '@/lib/mothership/jobs/budget'
@@ -26,6 +28,8 @@ const logger = createLogger('MothershipJobDispatch')
2628

2729
/** A queued occurrence whose start failed this many times ends as failed instead of retrying. */
2830
const MAX_JOB_DISPATCH_ATTEMPTS = 5
31+
/** Outlasts one dispatch (its reads and the turn's admission), so an attempt never overlaps another. */
32+
const JOB_DISPATCH_LOCK_SECONDS = 120
2933

3034
type JobDispatchOutcome =
3135
| 'started'
@@ -67,6 +71,27 @@ async function block(run: JobRun, summary: string): Promise<JobDispatchOutcome>
6771
* skipped rather than queued behind it.
6872
*/
6973
export async function dispatchJobOccurrence(executionId: string): Promise<JobDispatchOutcome> {
74+
/**
75+
* One attempt at a time per occurrence (a tick's and the reconciler's can meet): a skip or
76+
* block decided while another attempt admits the turn would close the record of a live run.
77+
*/
78+
const lock = `mothership:job-dispatch:${executionId}`
79+
const holder = generateShortId()
80+
if (!(await acquireLock(lock, holder, JOB_DISPATCH_LOCK_SECONDS, { reclaimOnFailure: true })))
81+
return 'already_started'
82+
try {
83+
return await dispatchQueuedOccurrence(executionId)
84+
} finally {
85+
await releaseLock(lock, holder).catch((error) =>
86+
logger.warn('Job dispatch lock release failed; it expires', {
87+
executionId,
88+
error: toError(error).message,
89+
})
90+
)
91+
}
92+
}
93+
94+
async function dispatchQueuedOccurrence(executionId: string): Promise<JobDispatchOutcome> {
7095
const run = await loadJobRun(executionId)
7196
if (!run || run.status !== 'queued' || !run.occurrenceAt) return 'not_queued'
7297
const { userId, workspaceId, chatId } = run
@@ -85,7 +110,9 @@ export async function dispatchJobOccurrence(executionId: string): Promise<JobDis
85110
return 'skipped_budget'
86111
}
87112
}
88-
const message = await buildJobBrief(run, run.occurrenceAt, jobRunBudgetUsd(run.runBudgetUsd))
113+
/** The run's spend cap is enforced through hosted billing callbacks, so only there is it stated. */
114+
const runBudgetUsd = isHosted ? jobRunBudgetUsd(run.runBudgetUsd) : null
115+
const message = await buildJobBrief(run, run.occurrenceAt, runBudgetUsd)
89116
const start = await startUnattendedTurn({
90117
userId,
91118
workspaceId,

‎apps/sim/lib/mothership/jobs/finalize.ts‎

Lines changed: 9 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -48,12 +48,18 @@ async function settleJobSchedule(
4848
.set({
4949
failedCount: sql`${workflowSchedule.failedCount} + 1`,
5050
lastFailedAt: new Date(),
51-
status: sql`CASE WHEN ${workflowSchedule.failedCount} + 1 >= ${MAX_CONSECUTIVE_JOB_FAILURES} AND ${workflowSchedule.status} = 'active' THEN 'disabled' ELSE ${workflowSchedule.status} END`,
5251
updatedAt: new Date(),
5352
})
5453
.where(eq(workflowSchedule.id, scheduleId))
55-
.returning({ status: workflowSchedule.status, failedCount: workflowSchedule.failedCount })
56-
return schedule?.status === 'disabled' && schedule.failedCount === MAX_CONSECUTIVE_JOB_FAILURES
54+
.returning({ failedCount: workflowSchedule.failedCount })
55+
if (!schedule || schedule.failedCount < MAX_CONSECUTIVE_JOB_FAILURES) return false
56+
/** Only a job still on is turned off here; one a person already turned off is not reported. */
57+
const disabled = await tx
58+
.update(workflowSchedule)
59+
.set({ status: 'disabled', updatedAt: new Date() })
60+
.where(and(eq(workflowSchedule.id, scheduleId), eq(workflowSchedule.status, 'active')))
61+
.returning({ id: workflowSchedule.id })
62+
return disabled.length > 0
5763
}
5864

5965
/** The turn's last assistant text, as the summary of a run that reported no outcome. */

‎apps/sim/lib/mothership/jobs/lane.integration.ts‎

Lines changed: 98 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -108,6 +108,10 @@ vi.mock('@/lib/mothership/jobs/reconcile', async (importOriginal) => {
108108
return { ...actual, reconcileJobRuns: vi.fn(actual.reconcileJobRuns) }
109109
})
110110
vi.mock('@/lib/core/config/feature-flags', () => featureFlagsMock)
111+
/** Spied so a test can tell an automatic turn-off, which emails the job's people, from none. */
112+
vi.mock('@/lib/workflows/schedules/disable-notifications', () => ({
113+
notifyScheduleAutoDisabled: vi.fn(async () => {}),
114+
}))
111115

112116
const { controllers } = vi.hoisted(() => ({ controllers: new Map<string, AbortController>() }))
113117
vi.mock('@/lib/mothership/request/session/abort', async (importOriginal) => {
@@ -136,7 +140,12 @@ import { sleep } from '@sim/utils/helpers'
136140
import { generateId } from '@sim/utils/id'
137141
import { eq, inArray, sql } from 'drizzle-orm'
138142
import { resolveBillingAttribution } from '@/lib/billing/core/attribution'
139-
import { closeRedisConnection, getRedisClient } from '@/lib/core/config/redis'
143+
import {
144+
acquireLock,
145+
closeRedisConnection,
146+
getRedisClient,
147+
releaseLock,
148+
} from '@/lib/core/config/redis'
140149
import { ABANDONED_RUN_CURSOR_KEY } from '@/lib/mothership/async-runs/orphaned-runs'
141150
import { chatPubSub } from '@/lib/mothership/chat-status'
142151
import { recordJobRunSpend } from '@/lib/mothership/jobs/budget'
@@ -152,6 +161,7 @@ import {
152161
chatStreamLockKey,
153162
StreamControllerSupersededError,
154163
} from '@/lib/mothership/request/session/controller-lease'
164+
import { notifyScheduleAutoDisabled } from '@/lib/workflows/schedules/disable-notifications'
155165

156166
interface QueryPlan {
157167
'Node Type': string
@@ -542,6 +552,88 @@ describe.runIf(Boolean(redisUrl))('the scheduled job lane', () => {
542552
worker.open.delete(occurrenceId)
543553
}, 60_000)
544554

555+
it('delivers a time-limit Stop an earlier pass recorded but died delivering, before finalizing', async () => {
556+
const { scheduleId, occurrenceId } = await seedJob()
557+
worker.legs.set(occurrenceId, [{ text: 'Still triaging. ', mode: 'hang' }])
558+
await runJobLane(new Date())
559+
await waitFor(async () => worker.open.has(occurrenceId), 'the first leg')
560+
/** What a pass leaves when it dies after recording why the run stops, before delivering it. */
561+
await db
562+
.update(jobExecutionLogs)
563+
.set({ executionData: sql`jsonb_build_object('deadlineStopRequestedAt', now())` })
564+
.where(eq(jobExecutionLogs.executionId, occurrenceId))
565+
566+
await reconcileUntilSettled(occurrenceId)
567+
568+
expect(
569+
worker.requests.filter(
570+
(request) =>
571+
request.path === '/api/streams/explicit-abort' && request.body.messageId === occurrenceId
572+
)
573+
).toHaveLength(1)
574+
expect(await runsOf(scheduleId)).toEqual([
575+
expect.objectContaining({
576+
outcome: 'interrupted',
577+
summary: 'Stopped at the run time limit.',
578+
}),
579+
])
580+
worker.open.get(occurrenceId)?.response.end()
581+
worker.open.delete(occurrenceId)
582+
}, 60_000)
583+
584+
it('does not report a job a person turned off as turned off by its failures', async () => {
585+
vi.mocked(notifyScheduleAutoDisabled).mockClear()
586+
const { scheduleId, occurrenceId } = await seedJob()
587+
worker.legs.set(occurrenceId, [{ text: 'Still triaging. ', mode: 'hang' }])
588+
await runJobLane(new Date())
589+
await waitFor(async () => worker.open.has(occurrenceId), 'the first leg')
590+
/** Off by hand with two failures behind it, while this run is still live. */
591+
await db
592+
.update(workflowSchedule)
593+
.set({ status: 'disabled', failedCount: 2 })
594+
.where(eq(workflowSchedule.id, scheduleId))
595+
596+
await reconcileJobRuns(new Date(Date.now() + 6 * 60 * 60_000 + 60_000))
597+
await reconcileUntilSettled(occurrenceId)
598+
599+
expect(await schedule(scheduleId)).toMatchObject({ status: 'disabled', failedCount: 3 })
600+
expect(notifyScheduleAutoDisabled).not.toHaveBeenCalled()
601+
worker.open.get(occurrenceId)?.response.end()
602+
worker.open.delete(occurrenceId)
603+
}, 60_000)
604+
605+
it('briefs a retried occurrence with its own run number, not the job count a later claim moved', async () => {
606+
const { scheduleId, occurrenceId } = await seedJob()
607+
await claimDueJobOccurrences(new Date(), 10)
608+
const later = await dueAgain(scheduleId)
609+
await claimDueJobOccurrences(new Date(), 10)
610+
expect(await schedule(scheduleId)).toMatchObject({ runCount: 2 })
611+
612+
for (const id of [occurrenceId, later]) {
613+
await dispatchJobOccurrence(id)
614+
await reconcileUntilSettled(id)
615+
}
616+
617+
expect(legsFor(occurrenceId)[0]?.body.message).toContain('(Run 1, scheduled for')
618+
expect(legsFor(later)[0]?.body.message).toContain('(Run 2, scheduled for')
619+
})
620+
621+
it('leaves an occurrence another attempt is dispatching to that attempt', async () => {
622+
const { scheduleId, occurrenceId } = await seedJob()
623+
await claimDueJobOccurrences(new Date(), 10)
624+
const lock = `mothership:job-dispatch:${occurrenceId}`
625+
expect(await acquireLock(lock, 'another-attempt', 60)).toBe(true)
626+
try {
627+
expect(await dispatchJobOccurrence(occurrenceId)).toBe('already_started')
628+
expect(legsFor(occurrenceId)).toHaveLength(0)
629+
expect(await runsOf(scheduleId)).toEqual([expect.objectContaining({ status: 'queued' })])
630+
} finally {
631+
await releaseLock(lock, 'another-attempt')
632+
}
633+
expect(await dispatchJobOccurrence(occurrenceId)).toBe('started')
634+
await reconcileUntilSettled(occurrenceId)
635+
})
636+
545637
it('runs a one-shot job once and completes it', async () => {
546638
const { scheduleId, occurrenceId } = await seedJob({ cronExpression: null })
547639
await runJobLane(new Date())
@@ -682,6 +774,7 @@ describe.runIf(Boolean(redisUrl))('the scheduled job lane', () => {
682774
})
683775

684776
it('turns a job off after three failed runs in a row, and a verdict clears the streak', async () => {
777+
vi.mocked(notifyScheduleAutoDisabled).mockClear()
685778
const { scheduleId, occurrenceId } = await seedJob()
686779
const fail = (id: string) =>
687780
worker.legs.set(
@@ -710,6 +803,10 @@ describe.runIf(Boolean(redisUrl))('the scheduled job lane', () => {
710803
}
711804
const outcomes = (await runsOf(scheduleId)).map((run) => run.outcome).sort()
712805
expect(outcomes).toEqual(['failed', 'failed', 'failed', 'failed', 'not_met'])
806+
expect(notifyScheduleAutoDisabled).toHaveBeenCalledExactlyOnceWith({
807+
scheduleId,
808+
reason: 'consecutive_failures',
809+
})
713810

714811
await dueAgain(scheduleId)
715812
await runJobLane(new Date())

‎apps/sim/lib/mothership/jobs/reconcile.ts‎

Lines changed: 37 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -46,8 +46,8 @@ const admittedBillingRequestId = sql<
4646

4747
/**
4848
* Open records that need this pass, oldest first. Every queued record does; a running one only
49-
* once its turn ended or its run row is gone, its time limit passed without a Stop, or its
50-
* spend-cap link is missing, so a backlog of healthy long runs never hides the ones that finished.
49+
* once its turn ended or its run row is gone, its time limit passed without a Stop, its Stop's
50+
* delivery never finished, or its spend-cap link is missing, so a backlog of healthy long runs never hides the ones that finished.
5151
*/
5252
function openJobRuns(status: OpenJobRunStatus, now: Date) {
5353
const needsAction =
@@ -60,6 +60,7 @@ function openJobRuns(status: OpenJobRunStatus, now: Date) {
6060
lte(jobExecutionLogs.startedAt, new Date(now.getTime() - JOB_RUN_TIME_LIMIT_MS)),
6161
sql`${jobExecutionLogs.executionData}->>'deadlineStopRequestedAt' IS NULL`
6262
),
63+
sql`${jobExecutionLogs.executionData}->>'deadlineStopRequestedAt' IS NOT NULL AND ${jobExecutionLogs.executionData}->>'deadlineStopDeliveredAt' IS NULL`,
6364
and(isNull(jobExecutionLogs.billingRequestId), isNotNull(admittedBillingRequestId))
6465
)
6566
return db
@@ -70,6 +71,9 @@ function openJobRuns(status: OpenJobRunStatus, now: Date) {
7071
deadlineStopRequestedAt: sql<
7172
string | null
7273
>`${jobExecutionLogs.executionData}->>'deadlineStopRequestedAt'`,
74+
deadlineStopDeliveredAt: sql<
75+
string | null
76+
>`${jobExecutionLogs.executionData}->>'deadlineStopDeliveredAt'`,
7377
billingRequestId: jobExecutionLogs.billingRequestId,
7478
admittedBillingRequestId,
7579
scheduleId: jobExecutionLogs.scheduleId,
@@ -89,8 +93,9 @@ function openJobRuns(status: OpenJobRunStatus, now: Date) {
8993
* Drives every open occurrence to an end, so no crash leaves one queued or running forever:
9094
* a queued record whose dispatch was lost is dispatched again under the same id (the turn is
9195
* admitted at most once, so a retry of one that did start only finds it); a record whose turn
92-
* ended is finalized; one past the time limit is stopped and finalized once it settles; one
93-
* whose job was deleted before it started is ended. A run whose spend-cap link was lost (its
96+
* ended is finalized; one past the time limit is stopped and finalized once it settles, its
97+
* Stop delivered again first if an earlier pass died delivering it; one whose job was deleted
98+
* before it started is ended. A run whose spend-cap link was lost (its
9499
* process died between recording the billing admission and the link) gets it back.
95100
*/
96101
export async function reconcileJobRuns(now: Date): Promise<void> {
@@ -121,22 +126,23 @@ export async function reconcileJobRuns(now: Date): Promise<void> {
121126
if (!row.billingRequestId && row.admittedBillingRequestId) {
122127
await recordJobRunBillingRequest(row.executionId, row.admittedBillingRequestId)
123128
}
124-
if (TERMINAL_RUN_STATUSES.includes(row.runStatus)) {
125-
await finalizeJobRun(row.executionId)
126-
} else if (
129+
const ended = TERMINAL_RUN_STATUSES.includes(row.runStatus)
130+
/** A Stop whose delivery never finished is delivered before the run is finalized. */
131+
const undelivered =
132+
row.deadlineStopRequestedAt !== null && row.deadlineStopDeliveredAt === null
133+
const overdue =
134+
!ended &&
127135
!row.deadlineStopRequestedAt &&
128-
row.userId &&
129-
row.workspaceId &&
130-
row.chatId &&
131136
now.getTime() - row.startedAt.getTime() >= JOB_RUN_TIME_LIMIT_MS
132-
) {
137+
if ((undelivered || overdue) && row.userId && row.workspaceId && row.chatId) {
133138
await stopAtTimeLimit({
134139
executionId: row.executionId,
135140
userId: row.userId,
136141
workspaceId: row.workspaceId,
137142
chatId: row.chatId,
138143
})
139144
}
145+
if (ended) await finalizeJobRun(row.executionId)
140146
} catch (error) {
141147
logger.warn('Job run could not be reconciled; the next pass retries', {
142148
executionId: row.executionId,
@@ -161,13 +167,12 @@ async function stopAtTimeLimit(run: {
161167
})
162168
/** A run outside the job's scope records no Stop, so nothing is delivered to it. */
163169
if (!stopped || stopped.workspaceId !== run.workspaceId || stopped.chatId !== run.chatId) return
164-
/** Marked once the Stop is durable, so a pass that fails before it stops the run again. */
165-
await db
166-
.update(jobExecutionLogs)
167-
.set({
168-
executionData: sql`jsonb_set(${jobExecutionLogs.executionData}, '{deadlineStopRequestedAt}', to_jsonb(now()))`,
169-
})
170-
.where(eq(jobExecutionLogs.executionId, run.executionId))
170+
/**
171+
* Why the run stopped is recorded before delivery, so its summary survives a crash; delivery
172+
* is marked separately once done, and a pass that finds it unmarked delivers again (requesting
173+
* and delivering a Stop are idempotent), so the run's client workflows and sandbox work end.
174+
*/
175+
await markDeadlineStop(run.executionId, 'deadlineStopRequestedAt')
171176
await deliverRunStop(
172177
{
173178
id: stopped.id,
@@ -178,5 +183,19 @@ async function stopAtTimeLimit(run: {
178183
},
179184
readStoppedRunWork(run.executionId, run.userId)
180185
)
186+
await markDeadlineStop(run.executionId, 'deadlineStopDeliveredAt')
181187
logger.info('Stopped a job run at its time limit', { executionId: run.executionId })
182188
}
189+
190+
/** Records a step of the time-limit Stop once; a repeated pass keeps the first time. */
191+
async function markDeadlineStop(
192+
executionId: string,
193+
step: 'deadlineStopRequestedAt' | 'deadlineStopDeliveredAt'
194+
): Promise<void> {
195+
await db
196+
.update(jobExecutionLogs)
197+
.set({
198+
executionData: sql`jsonb_set(${jobExecutionLogs.executionData}, ${`{${step}}`}::text[], COALESCE(${jobExecutionLogs.executionData}->${step}, to_jsonb(now())))`,
199+
})
200+
.where(eq(jobExecutionLogs.executionId, executionId))
201+
}

0 commit comments

Comments
 (0)