Skip to content

Commit c26b83b

Browse files
committed
fix(redis): keep the existing admission when a reservation refresh throws
The refresh extends the local reservation and the pointer as separate Redis mutations, so an exception does not prove the slot went unrefreshed — and a client-side command timeout can abandon a call the server still applied. Re-admitting on that ambiguity spends another rate-limit token and can reject a run that still holds a valid slot. Only a `false` return proves the reservation is gone, so only that repeats admission. Also corrects the timeout comments: the multi-second gap before a connection becomes usable is the connect callback waiting on a saturated event loop, not a slow handshake — the INFO round-trip that follows completes in ~10ms.
1 parent 0d9f4dd commit c26b83b

3 files changed

Lines changed: 78 additions & 21 deletions

File tree

apps/sim/background/async-preprocessing-correlation.test.ts

Lines changed: 45 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -771,4 +771,49 @@ describe('async preprocessing correlation threading', () => {
771771
})
772772
)
773773
})
774+
775+
it('keeps the enqueuer admission when a reservation refresh throws', async () => {
776+
// A throw is ambiguous: the refresh mutates the local reservation and the
777+
// pointer separately, so it can fail after the slot's TTL was extended.
778+
mockRefreshExecutionSlotExpiry.mockRejectedValueOnce(new Error('Command timed out'))
779+
mockPreprocessExecution.mockResolvedValueOnce({
780+
success: true,
781+
actorUserId: 'actor-1',
782+
workflowRecord: {
783+
id: 'workflow-1',
784+
userId: 'owner-1',
785+
workspaceId: 'workspace-1',
786+
variables: {},
787+
},
788+
billingAttribution,
789+
executionTimeout: {},
790+
})
791+
mockExecuteWorkflowCore.mockResolvedValueOnce({
792+
success: true,
793+
status: 'success',
794+
output: { ok: true },
795+
metadata: { duration: 10, userId: 'actor-1' },
796+
})
797+
798+
await expect(
799+
executeWorkflowJob({
800+
principal,
801+
workflowId: 'workflow-1',
802+
userId: 'actor-1',
803+
workspaceId: 'workspace-1',
804+
billingAttribution,
805+
triggerType: 'api',
806+
executionId: 'execution-refresh-throw',
807+
requestId: 'request-refresh-throw',
808+
admissionCompleted: true,
809+
executionTimeoutMs: 60_000,
810+
})
811+
).resolves.toEqual(expect.objectContaining({ success: true }))
812+
813+
// Re-admitting would spend another rate-limit token and could reject a run
814+
// that still holds a valid slot.
815+
expect(mockPreprocessExecution).toHaveBeenCalledWith(
816+
expect.objectContaining({ checkRateLimit: false, skipUsageLimits: true })
817+
)
818+
})
774819
})

apps/sim/background/workflow-execution.ts

Lines changed: 17 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -165,15 +165,6 @@ export async function executeWorkflowJob(
165165
const executionDeadlineAt = getExecutionDeadlineAt(timeoutController.signal)?.getTime()
166166
let admissionCompleted = payload.admissionCompleted === true
167167
if (admissionCompleted && executionDeadlineAt !== undefined) {
168-
/**
169-
* A refresh that *returns* false already degrades into repeating usage
170-
* admission below. A refresh that *throws* — a Redis timeout on the first
171-
* command this fresh worker process issues — used to kill the run here,
172-
* before the logging session exists, so the execution left no log row at
173-
* all and simply vanished from the workspace's logs. Route both outcomes
174-
* into the same re-admission path: preprocessing owns the reservation
175-
* retry, and any failure it hits is recorded against a live session.
176-
*/
177168
try {
178169
admissionCompleted = await refreshExecutionSlotExpiry(
179170
executionId,
@@ -186,8 +177,23 @@ export async function executeWorkflowJob(
186177
})
187178
}
188179
} catch (error) {
189-
admissionCompleted = false
190-
logger.warn('Reservation refresh failed; repeating usage admission', {
180+
/**
181+
* Only a `false` return proves the reservation is gone, and that is the
182+
* one outcome re-admission is right for. A throw does not: the refresh
183+
* is several separate Redis mutations, so it can fail after the slot's
184+
* TTL was already extended, and a client-side command timeout abandons
185+
* a call the server may still have applied. Re-admitting on that
186+
* ambiguity would spend another rate-limit token and could reject a run
187+
* that still holds a perfectly valid slot, so keep the admission the
188+
* enqueuing surface already completed.
189+
*
190+
* Worst case the slot lapses before the run ends, which under-counts
191+
* concurrency for this one execution; the later release is already a
192+
* no-op when the reservation is gone. Previously this threw before the
193+
* logging session existed, so the run left no log row at all and simply
194+
* vanished from the workspace's logs.
195+
*/
196+
logger.warn('Reservation refresh failed; continuing on the existing admission', {
191197
workflowId,
192198
executionId,
193199
error: toError(error).message,

apps/sim/lib/core/config/redis.ts

Lines changed: 16 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -49,9 +49,13 @@ const REDIS_CONNECT_TIMEOUT_MS = 10_000
4949
* never received the command, with a stack containing only ioredis timer
5050
* frames.
5151
*
52-
* Production handshakes to ElastiCache measure 2-6s when several connections
53-
* are opened at once, so a 5s command timeout failed roughly 3% of cold-start
54-
* commands on Trigger.dev workers, which open a fresh connection per run.
52+
* The gap between opening a connection and servicing its `connect` callback is
53+
* measured in seconds during an initialization burst — not because the network
54+
* or the server is slow (the `INFO` round-trip that follows completes in ~10ms,
55+
* and the server sits near-idle), but because the callback cannot run while the
56+
* main thread is saturated. This deadline is wall-clock, so it spans that delay
57+
* whether the cause is the network or a busy event loop, which is exactly why it
58+
* has to leave room beyond the connect budget.
5559
*/
5660
export const REDIS_COMMAND_TIMEOUT_MS = 15_000
5761

@@ -262,18 +266,20 @@ export function getRedisClient(): Redis | null {
262266
* issued: ioredis arms it in `sendCommand` before it checks whether the socket
263267
* is writable, so the budget covers handshake and offline-queue wait as well as
264268
* execution. A process whose first command lands on a cold client therefore
265-
* spends most of that budget on the TLS handshake, which measures 2-6s against
266-
* ElastiCache when several connections open at once.
269+
* spends that budget waiting for the connection rather than running the command.
267270
*
268-
* Warming at process start moves that cost off the first command's clock, which
269-
* is the connection-reuse practice AWS recommends: establishing a TCP+TLS
270-
* connection is far more expensive than the commands that run over it, so it
271-
* should be paid once per process rather than once per unit of work.
271+
* Warming separates the two: the wait becomes connection setup, bounded by
272+
* `connectTimeout`, instead of eating a command's deadline. It also follows the
273+
* connection-reuse practice AWS recommends — establishing a connection costs far
274+
* more than the commands that run over it, so it belongs once per process rather
275+
* than once per unit of work. Note this does not make the connection ready any
276+
* sooner when the delay is a saturated event loop rather than the network; it
277+
* only stops that delay from being charged to a command.
272278
*
273279
* Best effort by design — resolves rather than rejects on failure, and is
274280
* bounded by the connect budget, so neither a degraded Redis nor a missing
275281
* configuration can stop a process from starting. Callers that skip warming
276-
* still work; they just pay the handshake on their first command as before.
282+
* still work; they just wait on their first command as before.
277283
*
278284
* Memoized per client: a warm process returns immediately, and a forced
279285
* reconnect clears it so the replacement connection is warmed in turn.

0 commit comments

Comments
 (0)