From a1f7ec7255919b96dc5328760db20f1deb37768c Mon Sep 17 00:00:00 2001 From: Gray Gilmore Date: Thu, 23 Apr 2026 14:58:49 -0700 Subject: [PATCH] Fix Retry-After unit conversion and add jitter to retry delays The HTTP Retry-After header is expressed in seconds (RFC 9110) but was being passed directly to setTimeout, which takes milliseconds. A server sending Retry-After: 2 caused the CLI to wait 2 ms instead of 2 seconds, triggering near-instant retry storms against upstream throttles. This was especially painful against the theme-kit-access proxy and Core Admin API, where parallel bulk theme uploads would retry in lockstep with no effective backoff. Retry-After values are now parsed as seconds and converted to ms before being used as a delay. Parallel retries also now receive +/-20% uniform random jitter via a new applyRetryJitterMs helper, which breaks up the lockstep pattern that caused thundering-herd retries against the same upstream throttle window. --- packages/cli-kit/src/private/node/api.test.ts | 179 +++++++++++++++++- packages/cli-kit/src/private/node/api.ts | 28 ++- 2 files changed, 201 insertions(+), 6 deletions(-) diff --git a/packages/cli-kit/src/private/node/api.test.ts b/packages/cli-kit/src/private/node/api.test.ts index 5dd325be6ca..655d6ec78ab 100644 --- a/packages/cli-kit/src/private/node/api.test.ts +++ b/packages/cli-kit/src/private/node/api.test.ts @@ -1,4 +1,4 @@ -import {retryAwareRequest, isNetworkError, isTransientNetworkError} from './api.js' +import {applyRetryJitterMs, retryAwareRequest, isNetworkError, isTransientNetworkError} from './api.js' import {recordRetry} from '../../public/node/analytics.js' import {ClientError} from 'graphql-request' import {describe, test, vi, expect, beforeEach, afterEach} from 'vitest' @@ -7,13 +7,21 @@ vi.mock('../../public/node/analytics.js', () => ({ recordRetry: vi.fn(), })) +// Pins Math.random so jitter multiplies the base delay by exactly 1.0 (the midpoint of the ±20% band). +// Individual tests that need a different multiplier spy on Math.random directly. +const MIDPOINT_RANDOM_VALUE = 0.5 + describe('retryAwareRequest', () => { + let randomSpy: ReturnType + beforeEach(() => { vi.useFakeTimers() + randomSpy = vi.spyOn(Math, 'random').mockReturnValue(MIDPOINT_RANDOM_VALUE) }) afterEach(() => { vi.useRealTimers() + randomSpy.mockRestore() }) test('handles retries', async () => { @@ -88,7 +96,9 @@ describe('retryAwareRequest', () => { expect(mockRequestFn).toHaveBeenCalledTimes(4) expect(mockScheduleDelayFn).toHaveBeenCalledTimes(2) - expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(1, expect.anything(), 200) + // Retry-After: 200 seconds -> 200_000 ms; jitter pinned to midpoint (1.0x). + expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(1, expect.anything(), 200_000) + // defaultDelayMs: 500 ms; jitter pinned to midpoint (1.0x). expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(2, expect.anything(), 500) }) @@ -602,6 +612,171 @@ describe('retryAwareRequest', () => { expect(recordRetry).toHaveBeenCalledTimes(1) expect(recordRetry).toHaveBeenCalledWith('https://themes.example.com/auth', 'http-retry-1:can-retry:') }) + + test('parses Retry-After header as seconds and converts to milliseconds', async () => { + const rateLimitedResponse = { + status: 200, + errors: [ + { + extensions: { + code: '429', + }, + } as any, + ], + headers: new Headers({'retry-after': '2'}), + } + + const successResponse = { + status: 200, + data: {ok: true}, + headers: new Headers(), + } + + const mockRequestFn = vi + .fn() + .mockImplementationOnce(() => { + throw new ClientError(rateLimitedResponse, {query: ''}) + }) + .mockImplementation(() => Promise.resolve(successResponse)) + + const mockScheduleDelayFn = vi.fn((fn) => fn()) + + const result = retryAwareRequest( + { + request: mockRequestFn, + url: 'https://example.com', + useNetworkLevelRetry: true, + maxRetryTimeMs: 10_000, + }, + undefined, + {scheduleDelay: mockScheduleDelayFn}, + ) + await vi.runAllTimersAsync() + await expect(result).resolves.toEqual(successResponse) + + // Retry-After: 2 -> 2000 ms (not 2 ms). Jitter pinned to midpoint (1.0x) via Math.random mock. + expect(mockScheduleDelayFn).toHaveBeenCalledTimes(1) + expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(1, expect.anything(), 2000) + }) + + test('uses DEFAULT_RETRY_DELAY_MS when Retry-After header is absent and no caller default', async () => { + const rateLimitedResponse = { + status: 200, + errors: [{extensions: {code: '429'}} as any], + headers: new Headers(), + } + + const successResponse = { + status: 200, + data: {ok: true}, + headers: new Headers(), + } + + const mockRequestFn = vi + .fn() + .mockImplementationOnce(() => { + throw new ClientError(rateLimitedResponse, {query: ''}) + }) + .mockImplementation(() => Promise.resolve(successResponse)) + + const mockScheduleDelayFn = vi.fn((fn) => fn()) + + const result = retryAwareRequest( + { + request: mockRequestFn, + url: 'https://example.com', + useNetworkLevelRetry: true, + maxRetryTimeMs: 10_000, + }, + undefined, + {scheduleDelay: mockScheduleDelayFn}, + ) + await vi.runAllTimersAsync() + await expect(result).resolves.toEqual(successResponse) + + // No Retry-After, no defaultDelayMs -> falls back to DEFAULT_RETRY_DELAY_MS (1000). + // Jitter pinned to midpoint (1.0x) via Math.random mock. + expect(mockScheduleDelayFn).toHaveBeenCalledTimes(1) + expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(1, expect.anything(), 1000) + }) + + test('applies jitter multiplier from Math.random to retry delay', async () => { + // Math.random() = 0.0 -> multiplier = 0.8 (lower bound). + randomSpy.mockReturnValue(0) + + const rateLimitedResponse = { + status: 200, + errors: [{extensions: {code: '429'}} as any], + headers: new Headers(), + } + + const successResponse = { + status: 200, + data: {ok: true}, + headers: new Headers(), + } + + const mockRequestFn = vi + .fn() + .mockImplementationOnce(() => { + throw new ClientError(rateLimitedResponse, {query: ''}) + }) + .mockImplementation(() => Promise.resolve(successResponse)) + + const mockScheduleDelayFn = vi.fn((fn) => fn()) + + const result = retryAwareRequest( + { + request: mockRequestFn, + url: 'https://example.com', + useNetworkLevelRetry: true, + maxRetryTimeMs: 10_000, + }, + undefined, + {defaultDelayMs: 1000, scheduleDelay: mockScheduleDelayFn}, + ) + await vi.runAllTimersAsync() + await expect(result).resolves.toEqual(successResponse) + + // 1000 * 0.8 = 800. + expect(mockScheduleDelayFn).toHaveBeenNthCalledWith(1, expect.anything(), 800) + }) +}) + +describe('applyRetryJitterMs', () => { + test('returns the lower bound (0.8x) when random() is 0', () => { + expect(applyRetryJitterMs(1000, () => 0)).toBe(800) + }) + + test('returns the upper bound (~1.2x) when random() approaches 1', () => { + // Math.random() returns [0, 1). Using 0.9999... exercises the top of the range. + const nearOne = 1 - Number.EPSILON + expect(applyRetryJitterMs(1000, () => nearOne)).toBeCloseTo(1200, 5) + }) + + test('returns the midpoint (1.0x) when random() is 0.5', () => { + expect(applyRetryJitterMs(1000, () => 0.5)).toBe(1000) + }) + + test('keeps output within [0.8x, 1.2x] across the random range', () => { + const baseDelayMs = 2500 + const samples = [0, 0.1, 0.25, 0.5, 0.75, 0.9, 0.9999] + for (const randomValue of samples) { + const jittered = applyRetryJitterMs(baseDelayMs, () => randomValue) + expect(jittered).toBeGreaterThanOrEqual(baseDelayMs * 0.8) + expect(jittered).toBeLessThanOrEqual(baseDelayMs * 1.2) + } + }) + + test('defaults to Math.random when no generator is passed', () => { + const spy = vi.spyOn(Math, 'random').mockReturnValue(0.5) + try { + expect(applyRetryJitterMs(1000)).toBe(1000) + expect(spy).toHaveBeenCalled() + } finally { + spy.mockRestore() + } + }) }) describe('isTransientNetworkError', () => { diff --git a/packages/cli-kit/src/private/node/api.ts b/packages/cli-kit/src/private/node/api.ts index 044dd0abfb2..0fa97f62685 100644 --- a/packages/cli-kit/src/private/node/api.ts +++ b/packages/cli-kit/src/private/node/api.ts @@ -15,6 +15,20 @@ export const allAPIs: API[] = ['admin', 'storefront-renderer', 'partners', 'busi const DEFAULT_RETRY_DELAY_MS = 1000 const DEFAULT_RETRY_LIMIT = 10 +const MS_PER_SECOND = 1000 +const RETRY_JITTER_LOWER_BOUND = 0.8 +const RETRY_JITTER_UPPER_BOUND = 1.2 + +/** + * Applies uniform random jitter in the range [RETRY_JITTER_LOWER_BOUND, RETRY_JITTER_UPPER_BOUND] + * to a retry delay. Breaks up lockstep retries from parallel requests that would otherwise + * produce a thundering herd against the same upstream throttle window. + */ +export function applyRetryJitterMs(delayMs: number, random: () => number = Math.random): number { + const jitterRange = RETRY_JITTER_UPPER_BOUND - RETRY_JITTER_LOWER_BOUND + const multiplier = RETRY_JITTER_LOWER_BOUND + random() * jitterRange + return delayMs * multiplier +} export type NetworkRetryBehaviour = | { @@ -197,7 +211,11 @@ async function makeVerboseRequest( let delayMs: number | undefined try { - delayMs = responseHeaders['retry-after'] ? Number.parseInt(responseHeaders['retry-after'], 10) : undefined + // The HTTP Retry-After header is expressed in seconds; setTimeout takes milliseconds. + const retryAfterSeconds = responseHeaders['retry-after'] + ? Number.parseInt(responseHeaders['retry-after'], 10) + : undefined + delayMs = retryAfterSeconds === undefined ? undefined : retryAfterSeconds * MS_PER_SECOND // eslint-disable-next-line no-catch-all/no-catch-all } catch { // ignore errors in extracting retry-after header @@ -388,14 +406,16 @@ ${result.sanitizedHeaders} } // prefer to wait based on a header if given; the caller's preference if not; and a default if neither. - const retryDelayMs = result.delayMs ?? retryOptions.defaultDelayMs ?? DEFAULT_RETRY_DELAY_MS - outputDebug(`Scheduling retry request #${retriesUsed} to ${result.sanitizedUrl} in ${retryDelayMs} ms`) + const baseRetryDelayMs = result.delayMs ?? retryOptions.defaultDelayMs ?? DEFAULT_RETRY_DELAY_MS + // Jitter prevents parallel retries from synchronising on the same upstream throttle window. + const jitteredRetryDelayMs = applyRetryJitterMs(baseRetryDelayMs) + outputDebug(`Scheduling retry request #${retriesUsed} to ${result.sanitizedUrl} in ${jitteredRetryDelayMs} ms`) // eslint-disable-next-line no-await-in-loop result = await new Promise>((resolve) => { retryOptions.scheduleDelay(() => { resolve(makeVerboseRequest(requestOptions)) - }, retryDelayMs) + }, jitteredRetryDelayMs) }) } }