Skip to content
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
2 changes: 1 addition & 1 deletion packages/cli/src/commands/test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -75,7 +75,7 @@ export default class Test extends AuthCommand {
}),
'timeout': Flags.integer({
default: DEFAULT_CHECK_RUN_TIMEOUT_SECONDS,
description: 'A timeout (in seconds) to wait for checks to complete.',
description: 'A timeout (in seconds) to wait for each check result once the check starts running. Checks awaiting scheduling get additional headroom for the server-side dispatch stagger.',
}),
'verbose': Flags.boolean({
char: 'v',
Expand Down
2 changes: 1 addition & 1 deletion packages/cli/src/commands/trigger.ts
Original file line number Diff line number Diff line change
Expand Up @@ -62,7 +62,7 @@ export default class Trigger extends AuthCommand {
}),
'timeout': Flags.integer({
default: DEFAULT_CHECK_RUN_TIMEOUT_SECONDS,
description: 'A timeout (in seconds) to wait for checks to complete.',
description: 'A timeout (in seconds) to wait for each check result once the check starts running. Checks awaiting scheduling get additional headroom for the server-side dispatch stagger.',
}),
'verbose': Flags.boolean({
char: 'v',
Expand Down
64 changes: 64 additions & 0 deletions packages/cli/src/services/__tests__/abstract-check-runner.spec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -375,3 +375,67 @@ describe('AbstractCheckRunner — scheduling watch', () => {
expect(errors[0].code).toEqual('ABANDONED')
})
})

describe('AbstractCheckRunner — per-check timeouts vs scheduling delay', () => {
const TIMEOUT_SECONDS = 60
const MAX_SCHEDULING_DELAY_SECONDS = 900

beforeEach(() => {
vi.useFakeTimers()
})

afterEach(() => {
vi.useRealTimers()
})

function makeArmedRunner () {
const runner = new StubCheckRunner('acc-1', TIMEOUT_SECONDS, false)
runner.checks = new Map([['seq-1', { check: {} }]])
const failures: string[] = []
runner.on(Events.CHECK_FAILED, (_sequenceId, _check, message) => failures.push(message))
;(runner as any).setAllTimeouts()
return { runner, failures }
}

it('does not time out a not-yet-started check before the scheduling-delay headroom elapses', async () => {
const { runner, failures } = makeArmedRunner()

// The backend may hold a check in an SQS delay slot for up to 900s on
// large staggered sessions: the plain execution timeout alone must not
// fail a check that has not started yet.
await vi.advanceTimersByTimeAsync((TIMEOUT_SECONDS + MAX_SCHEDULING_DELAY_SECONDS) * 1000 - 1000)
expect(failures).toHaveLength(0)

await vi.advanceTimersByTimeAsync(2000)
expect(failures).toHaveLength(1)
expect(failures[0]).toContain('did not start')
;(runner as any).disableAllTimeouts()
})

it('re-arms to the plain execution timeout once the check starts', async () => {
const { runner, failures } = makeArmedRunner()

await (runner as any).processMessage('seq-1', 'run-start', {})

await vi.advanceTimersByTimeAsync(TIMEOUT_SECONDS * 1000 - 1000)
expect(failures).toHaveLength(0)

await vi.advanceTimersByTimeAsync(2000)
expect(failures).toHaveLength(1)
expect(failures[0]).toContain(`Reached timeout of ${TIMEOUT_SECONDS} seconds`)
;(runner as any).disableAllTimeouts()
})

it('a final result before the timeout produces no failure', async () => {
const { runner, failures } = makeArmedRunner()
const successes: string[] = []
runner.on(Events.CHECK_SUCCESSFUL, sequenceId => successes.push(sequenceId))

await (runner as any).processMessage('seq-1', 'run-start', {})
await (runner as any).processMessage('seq-1', 'result', { result: {}, resultType: 'FINAL' })

await vi.advanceTimersByTimeAsync((TIMEOUT_SECONDS + MAX_SCHEDULING_DELAY_SECONDS) * 1000)
expect(failures).toHaveLength(0)
expect(successes).toEqual(['seq-1'])
})
})
89 changes: 68 additions & 21 deletions packages/cli/src/services/abstract-check-runner.ts
Original file line number Diff line number Diff line change
Expand Up @@ -48,6 +48,19 @@ export const DEFAULT_PLAYWRIGHT_CHECK_RUN_TIMEOUT_SECONDS = 1200

const DEFAULT_SCHEDULING_DELAY_EXCEEDED_MS = 20000

// The backend staggers large sessions with SQS DelaySeconds and widens its
// batches so no check is ever delayed beyond SQS's 15-minute ceiling. Until a
// check's run-start message arrives, its timer must allow for that worst-case
// queue delay on top of the execution timeout — otherwise the timer expires
// for checks the server has not started yet. Once the check starts, the timer
// is re-armed to the plain execution timeout.
//
// The 900s ceiling is a backend contract (the dispatch stagger is capped at
// SQS's DelaySeconds maximum; RED-814 records where the backend enforces
// it). If the backend's stagger ceiling ever changes, this constant must
// follow.
const MAX_SCHEDULING_DELAY_SECONDS = 900

function schedulingFailedError (operation: TestSessionSchedulingOperation): TestSessionSchedulingFailedError {
return new TestSessionSchedulingFailedError(
operation.error?.message ?? 'The test session could not be scheduled.',
Expand Down Expand Up @@ -277,6 +290,13 @@ export default abstract class AbstractCheckRunner extends EventEmitter {

const { check } = this.checks.get(sequenceId)!
if (subtopic === 'run-start') {
// The check is running: drop the scheduling-delay headroom so --timeout
// measures execution from here on. A retry attempt re-arms the timer
// again, giving each attempt a fresh execution window; the retry's
// backoff delay runs against the previous attempt's window, without
// extra headroom — no worse than the pre-existing behavior where all
// attempts and backoffs shared a single window from run start.
this.restartTimeoutForExecution(sequenceId, check)
this.emit(Events.CHECK_INPROGRESS, check, sequenceId)
} else if (subtopic === 'result') {
const { result, testResultId, resultType } = message
Expand Down Expand Up @@ -344,28 +364,55 @@ export default abstract class AbstractCheckRunner extends EventEmitter {
})
}

private executionTimeoutSeconds (check: any): number {
// Playwright checks can take longer; bump the default (only) accordingly.
return (check instanceof PlaywrightCheck && this.timeout === DEFAULT_CHECK_RUN_TIMEOUT_SECONDS)
? DEFAULT_PLAYWRIGHT_CHECK_RUN_TIMEOUT_SECONDS
: this.timeout
}

private armTimeout (sequenceId: SequenceId, check: any, seconds: number, hasStarted: boolean) {
this.timeouts.set(sequenceId, setTimeout(() => {
this.timeouts.delete(sequenceId)
let errorMessage = hasStarted
? `Reached timeout of ${seconds} seconds waiting for check result.`
: `Check did not start within ${seconds} seconds (execution timeout plus the maximum scheduling delay).`
// Playwright checks can take longer.
// We should point the user to the --timeout flag in that case.
if (check instanceof PlaywrightCheck) {
errorMessage += ' Use a custom timeout with --timeout'
} else if (this.timeout === DEFAULT_CHECK_RUN_TIMEOUT_SECONDS) {
// Checkly should always report a result within 240s of a check
// starting, and a check that never started at all is even more likely
// a Checkly-side problem. If the default timeout was used, point the
// user to the status page and support email.
errorMessage += ' Checkly may be experiencing problems. Please check https://is.checkly.online or reach out to support@checklyhq.com.'
}
this.emit(Events.CHECK_FAILED, sequenceId, check, errorMessage)
this.emit(Events.CHECK_FINISHED, check)
}, seconds * 1000),
)
}

private setAllTimeouts () {
Array.from(this.checks.entries()).forEach(([sequenceId, { check }]) => {
const checkTimeout = (check instanceof PlaywrightCheck && this.timeout === DEFAULT_CHECK_RUN_TIMEOUT_SECONDS)
? DEFAULT_PLAYWRIGHT_CHECK_RUN_TIMEOUT_SECONDS
: this.timeout
this.timeouts.set(sequenceId, setTimeout(() => {
this.timeouts.delete(sequenceId)
let errorMessage = `Reached timeout of ${checkTimeout} seconds waiting for check result.`
// Playwright checks can take longer.
// We should point the user to the --timeout flag in that case.
if (check instanceof PlaywrightCheck) {
errorMessage += ' Use a custom timeout with --timeout'
} else if (this.timeout === DEFAULT_CHECK_RUN_TIMEOUT_SECONDS) {
// Checkly should always report a result within 240s.
// If the default timeout was used, we should point the user to the status page and support email.
errorMessage += ' Checkly may be experiencing problems. Please check https://is.checkly.online or reach out to support@checklyhq.com.'
}
this.emit(Events.CHECK_FAILED, sequenceId, check, errorMessage)
this.emit(Events.CHECK_FINISHED, check)
}, checkTimeout * 1000),
)
})
// Pre-start timers carry scheduling-delay headroom: a check at the tail
// of a large staggered session may legitimately sit in a delay slot for
// up to MAX_SCHEDULING_DELAY_SECONDS before it runs. The timer is
// re-armed to the plain execution timeout when run-start arrives (see
// processMessage). Every check must keep a `timeouts` entry from run
// start — processMessage treats a missing entry as "already timed out"
// and drops the check's messages.
Array.from(this.checks.entries()).forEach(([sequenceId, { check }]) =>
this.armTimeout(sequenceId, check, this.executionTimeoutSeconds(check) + MAX_SCHEDULING_DELAY_SECONDS, false))
}

private restartTimeoutForExecution (sequenceId: SequenceId, check: any) {
if (!this.timeouts.has(sequenceId)) {
// Already timed out; do not resurrect the check.
return
}
this.disableTimeout(sequenceId)
this.armTimeout(sequenceId, check, this.executionTimeoutSeconds(check), true)
}

private disableAllTimeouts () {
Expand Down
Loading