Skip to content

Commit 95e763e

Browse files
committed
fix(webhooks): restore terminal log on failed requeue and make retry backoff abort-aware
1 parent 4c35a7b commit 95e763e

5 files changed

Lines changed: 147 additions & 46 deletions

File tree

apps/sim/background/webhook-execution.test.ts

Lines changed: 12 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -661,7 +661,7 @@ describe('executeWebhookJob fault vs error handling', () => {
661661
expect(loggingSessionMockFns.mockSafeCompleteWithError).toHaveBeenCalled()
662662
})
663663

664-
it('faults the run when the requeue enqueue itself fails', async () => {
664+
it('faults the run and restores the terminal log row when the requeue enqueue itself fails', async () => {
665665
executionPreprocessingMockFns.mockPreprocessExecution.mockResolvedValueOnce({
666666
success: false,
667667
error: {
@@ -675,5 +675,16 @@ describe('executeWebhookJob fault vs error handling', () => {
675675
await expect(executeWebhookJob(payload)).rejects.toThrow(
676676
'Internal error while fetching workflow'
677677
)
678+
679+
// The retry-bound attempt suppressed its failure row; a failed requeue means
680+
// no retry will run, so the terminal row must be written before faulting.
681+
expect(loggingSessionMockFns.mockSafeStart).toHaveBeenCalledWith(
682+
expect.objectContaining({ userId: 'user-1', workspaceId: 'workspace-1' })
683+
)
684+
expect(loggingSessionMockFns.mockSafeCompleteWithError).toHaveBeenCalledWith(
685+
expect.objectContaining({
686+
error: expect.objectContaining({ message: 'Internal error while fetching workflow' }),
687+
})
688+
)
678689
})
679690
})

apps/sim/background/webhook-execution.ts

Lines changed: 67 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@ import { db } from '@sim/db'
22
import { account, webhook } from '@sim/db/schema'
33
import { createLogger, runWithRequestContext } from '@sim/logger'
44
import { toError } from '@sim/utils/errors'
5-
import { sleep } from '@sim/utils/helpers'
5+
import { interruptibleSleep } from '@sim/utils/helpers'
66
import { generateId } from '@sim/utils/id'
77
import { isRecordLike } from '@sim/utils/object'
88
import { backoffWithJitter } from '@sim/utils/retry'
@@ -377,11 +377,12 @@ async function requeueWebhookExecutionAfterSetupFailure(
377377
/**
378378
* The database backend executes jobs only through an in-process runner
379379
* and does not apply `delayMs` to it, so the runner sleeps out the
380-
* backoff itself; the trigger.dev backend ignores this field and delays
380+
* backoff itself (abort-aware, so cancellation and shutdown don't wait
381+
* out the timer); the trigger.dev backend ignores this field and delays
381382
* server-side.
382383
*/
383384
runner: async (_queuedPayload: unknown, signal: AbortSignal) => {
384-
await sleep(delayMs)
385+
await interruptibleSleep(delayMs, signal)
385386
if (signal.aborted) return undefined
386387
return executeWebhookJob(retryPayload, signal)
387388
},
@@ -418,6 +419,54 @@ async function requeueWebhookExecutionAfterSetupFailure(
418419
}
419420
}
420421

422+
/**
423+
* Restores the terminal failed execution-log row for a setup failure whose
424+
* replacement enqueue failed. Attempts headed for a requeue suppress their
425+
* failure row so the retry can reuse the execution id; once the requeue is
426+
* known to have failed, no retry will run, so the row must be written here or
427+
* the delivery faults without any execution record. Best-effort by design:
428+
* the same infrastructure outage that broke setup may also break this write,
429+
* in which case the faulted run remains the only signal — matching how
430+
* preprocessing's own error logging degrades.
431+
*/
432+
async function recordSetupFailureWithoutRequeue(
433+
payload: WebhookExecutionPayload,
434+
correlation: AsyncExecutionCorrelation,
435+
error: RetryableSetupError
436+
): Promise<void> {
437+
try {
438+
const loggingSession = new LoggingSession(
439+
payload.workflowId,
440+
correlation.executionId,
441+
payload.provider,
442+
correlation.requestId
443+
)
444+
await loggingSession.safeStart({
445+
userId: payload.userId,
446+
workspaceId: payload.workspaceId,
447+
variables: {},
448+
triggerData: { correlation },
449+
})
450+
await loggingSession.safeCompleteWithError({
451+
error: {
452+
message: error.message,
453+
stackTrace: undefined,
454+
},
455+
traceSpans: [],
456+
skipCost: true,
457+
})
458+
} catch (loggingError) {
459+
logger.error(
460+
`[${correlation.requestId}] Failed to record webhook setup failure after requeue failure`,
461+
{
462+
workflowId: payload.workflowId,
463+
executionId: correlation.executionId,
464+
error: loggingError,
465+
}
466+
)
467+
}
468+
}
469+
421470
export async function executeWebhookJob(
422471
payload: WebhookExecutionPayload,
423472
externalAbortSignal?: AbortSignal
@@ -513,23 +562,23 @@ export async function executeWebhookJob(
513562
* A typed setup failure certifies no block ran and the idempotency
514563
* claim was released, so requeueing the same delivery cannot double
515564
* run it; the retry re-admits usage and re-claims from scratch. When
516-
* the requeue enqueue itself fails, fall through to the throw so the
517-
* run fails loudly rather than dropping the delivery silently.
565+
* the requeue enqueue itself fails, restore the terminal failure row
566+
* the retry-bound attempt suppressed, then fall through to the throw
567+
* so the run fails loudly rather than dropping the delivery silently.
518568
*/
519-
if (
520-
isRetryableSetupError(error) &&
521-
hasRemainingWebhookInfraRetry(payload) &&
522-
(await requeueWebhookExecutionAfterSetupFailure(payload, correlation, error))
523-
) {
524-
return {
525-
success: false,
526-
requeued: true,
527-
workflowId: payload.workflowId,
528-
executionId,
529-
output: {},
530-
executedAt: new Date().toISOString(),
531-
provider: payload.provider,
569+
if (isRetryableSetupError(error) && hasRemainingWebhookInfraRetry(payload)) {
570+
if (await requeueWebhookExecutionAfterSetupFailure(payload, correlation, error)) {
571+
return {
572+
success: false,
573+
requeued: true,
574+
workflowId: payload.workflowId,
575+
executionId,
576+
output: {},
577+
executedAt: new Date().toISOString(),
578+
provider: payload.provider,
579+
}
532580
}
581+
await recordSetupFailureWithoutRequeue(payload, correlation, error)
533582
}
534583
throw error
535584
}

apps/sim/lib/core/rate-limiter/hosted-key/hosted-key-rate-limiter.ts

Lines changed: 1 addition & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
import { createLogger } from '@sim/logger'
2-
import { sleep } from '@sim/utils/helpers'
2+
import { interruptibleSleep } from '@sim/utils/helpers'
33
import { generateShortId } from '@sim/utils/id'
44
import { getMaxExecutionTimeout } from '@/lib/core/execution-limits'
55
import {
@@ -53,31 +53,6 @@ const MIN_QUEUE_RETRY_DELAY_MS = 50
5353
*/
5454
const QUEUE_HEAD_POLL_MS = 200
5555

56-
/**
57-
* Sleep for `ms`, resolving early if `signal` aborts. Cleans up its own timer and listener
58-
* so neither leaks. Callers don't need to distinguish an early (aborted) return from a normal
59-
* one — the surrounding wait loop re-checks its budget immediately after and bails when the
60-
* signal has fired. Falls back to a plain sleep when no signal is provided.
61-
*/
62-
function interruptibleSleep(ms: number, signal?: AbortSignal): Promise<void> {
63-
if (!signal) return sleep(ms)
64-
if (signal.aborted) return Promise.resolve()
65-
return new Promise<void>((resolve) => {
66-
const onAbort = () => {
67-
clearTimeout(timer)
68-
signal.removeEventListener('abort', onAbort)
69-
resolve()
70-
}
71-
const timer = setTimeout(() => {
72-
signal.removeEventListener('abort', onAbort)
73-
resolve()
74-
}, ms)
75-
signal.addEventListener('abort', onAbort, { once: true })
76-
// Catch an abort that fired between the guard above and addEventListener.
77-
if (signal.aborted) onAbort()
78-
})
79-
}
80-
8156
/**
8257
* Resolves env var names for a hosted-key prefix. Numbered pools use a
8358
* `{PREFIX}_COUNT` env var. Deployments that still provide one legacy singular

packages/utils/src/helpers.test.ts

Lines changed: 42 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,7 +2,7 @@
22
* @vitest-environment node
33
*/
44
import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'
5-
import { chunkArray, noop, sleep } from './helpers.js'
5+
import { chunkArray, interruptibleSleep, noop, sleep } from './helpers.js'
66

77
describe('sleep', () => {
88
beforeEach(() => {
@@ -30,6 +30,47 @@ describe('sleep', () => {
3030
})
3131
})
3232

33+
describe('interruptibleSleep', () => {
34+
beforeEach(() => {
35+
vi.useFakeTimers()
36+
})
37+
38+
afterEach(() => {
39+
vi.useRealTimers()
40+
})
41+
42+
it('resolves after the delay when no signal is provided', async () => {
43+
const promise = interruptibleSleep(1000)
44+
vi.advanceTimersByTime(1000)
45+
await expect(promise).resolves.toBeUndefined()
46+
})
47+
48+
it('resolves after the delay when the signal never aborts', async () => {
49+
const controller = new AbortController()
50+
const promise = interruptibleSleep(1000, controller.signal)
51+
vi.advanceTimersByTime(1000)
52+
await expect(promise).resolves.toBeUndefined()
53+
})
54+
55+
it('resolves early when the signal aborts mid-sleep', async () => {
56+
const controller = new AbortController()
57+
let resolved = false
58+
interruptibleSleep(60_000, controller.signal).then(() => {
59+
resolved = true
60+
})
61+
vi.advanceTimersByTime(1)
62+
controller.abort()
63+
await Promise.resolve()
64+
expect(resolved).toBe(true)
65+
})
66+
67+
it('resolves immediately for an already-aborted signal', async () => {
68+
const controller = new AbortController()
69+
controller.abort()
70+
await expect(interruptibleSleep(60_000, controller.signal)).resolves.toBeUndefined()
71+
})
72+
})
73+
3374
describe('noop', () => {
3475
it('is a function', () => {
3576
expect(typeof noop).toBe('function')

packages/utils/src/helpers.ts

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -6,6 +6,31 @@ export function sleep(ms: number): Promise<void> {
66
return new Promise((resolve) => setTimeout(resolve, ms))
77
}
88

9+
/**
10+
* Sleep for `ms`, resolving early if `signal` aborts. Cleans up its own timer and listener
11+
* so neither leaks. Callers don't need to distinguish an early (aborted) return from a normal
12+
* one — the surrounding wait loop re-checks its budget or the signal immediately after and
13+
* bails when it has fired. Falls back to a plain sleep when no signal is provided.
14+
*/
15+
export function interruptibleSleep(ms: number, signal?: AbortSignal): Promise<void> {
16+
if (!signal) return sleep(ms)
17+
if (signal.aborted) return Promise.resolve()
18+
return new Promise<void>((resolve) => {
19+
const onAbort = () => {
20+
clearTimeout(timer)
21+
signal.removeEventListener('abort', onAbort)
22+
resolve()
23+
}
24+
const timer = setTimeout(() => {
25+
signal.removeEventListener('abort', onAbort)
26+
resolve()
27+
}, ms)
28+
signal.addEventListener('abort', onAbort, { once: true })
29+
// Catch an abort that fired between the guard above and addEventListener.
30+
if (signal.aborted) onAbort()
31+
})
32+
}
33+
934
/** No-operation function for use as default callback. */
1035
export const noop = () => {}
1136

0 commit comments

Comments
 (0)