Skip to content

Commit cff97b2

Browse files
authored
fix(mothership): back off the transport poll instead of retrying every second (#9945)
* fix(mothership): back off the transport poll instead of retrying every second * fix(mothership): end a transport outage only after the whole poll iteration succeeds
1 parent f961415 commit cff97b2

2 files changed

Lines changed: 128 additions & 7 deletions

File tree

‎apps/sim/lib/mothership/transport/receiver.test.ts‎

Lines changed: 75 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -29,7 +29,7 @@ import { receiveSimControls, startSimReceivers } from '@/lib/mothership/transpor
2929
const mocks = {
3030
fetch: mothershipGoFetchMockFns.mockFetchGo,
3131
execute,
32-
sleep: utilsHelpersMockFns.mockSleep,
32+
sleep: utilsHelpersMockFns.mockInterruptibleSleep,
3333
}
3434

3535
function request() {
@@ -232,3 +232,77 @@ describe('outbound receiver lifecycle', () => {
232232
}
233233
)
234234
})
235+
236+
describe('outbound receiver backoff', () => {
237+
const logger = () => getMockLogger('MothershipTransportReceiver')
238+
239+
beforeEach(() => {
240+
vi.resetAllMocks()
241+
mocks.sleep.mockResolvedValue(undefined)
242+
})
243+
244+
/** Runs the receiver over scripted poll outcomes and returns each wait it took. */
245+
async function delaysFor(outcomes: (() => Response)[]): Promise<number[]> {
246+
const controller = new AbortController()
247+
let polls = 0
248+
mocks.fetch.mockImplementation(async () => {
249+
const next = outcomes[polls++]
250+
if (next) return next()
251+
controller.abort()
252+
throw new Error('shutdown')
253+
})
254+
await receiveSimControls('https://worker.test', 'a'.repeat(64), controller.signal)
255+
for (const [, signal] of mocks.sleep.mock.calls) expect(signal).toBe(controller.signal)
256+
return mocks.sleep.mock.calls.map(([ms]) => ms)
257+
}
258+
259+
const refused = (status: number) => () => new Response(null, { status })
260+
const lost = () => {
261+
throw new Error('connection lost')
262+
}
263+
const empty = () => Response.json({ requests: [] })
264+
265+
it.each([401, 403])(
266+
'waits minutes, not seconds, between polls the worker refuses (%i)',
267+
async (status) => {
268+
const delays = await delaysFor(Array.from({ length: 8 }, () => refused(status)))
269+
expect(delays).toHaveLength(8)
270+
expect(Math.min(...delays)).toBeGreaterThanOrEqual(24_000)
271+
expect(delays[7]).toBeGreaterThanOrEqual(480_000)
272+
expect(Math.max(...delays)).toBeLessThanOrEqual(720_000)
273+
expect(logger().warn).toHaveBeenCalledOnce()
274+
}
275+
)
276+
277+
it('backs off transient failures to a ceiling under the 5 s run-control deadline, warning once', async () => {
278+
const delays = await delaysFor(Array.from({ length: 8 }, () => lost))
279+
expect(delays[0]).toBeLessThanOrEqual(1200)
280+
expect(delays[7]).toBeGreaterThanOrEqual(3200)
281+
expect(Math.max(...delays)).toBeLessThan(5000)
282+
expect(logger().warn).toHaveBeenCalledOnce()
283+
})
284+
285+
it('starts over after a poll succeeds and says it reconnected', async () => {
286+
const delays = await delaysFor([lost, lost, lost, empty, lost])
287+
expect(delays).toHaveLength(4)
288+
expect(delays[2]).toBeGreaterThanOrEqual(3200)
289+
expect(delays[3]).toBeLessThanOrEqual(1200)
290+
expect(logger().warn).toHaveBeenCalledTimes(2)
291+
expect(logger().info).toHaveBeenCalledOnce()
292+
})
293+
294+
it('keeps backing off while polls succeed but their batches cannot be read', async () => {
295+
const malformed = () => Response.json({ requests: 'not a list' })
296+
const delays = await delaysFor(Array.from({ length: 5 }, () => malformed))
297+
expect(delays[4]).toBeGreaterThanOrEqual(3200)
298+
expect(logger().warn).toHaveBeenCalledOnce()
299+
expect(logger().info).not.toHaveBeenCalled()
300+
})
301+
302+
it('warns again, and backs off from the start, when an outage turns into a refused key', async () => {
303+
const delays = await delaysFor([lost, lost, lost, refused(401), refused(401)])
304+
expect(delays[3]).toBeLessThanOrEqual(36_000)
305+
expect(delays[4]).toBeGreaterThanOrEqual(48_000)
306+
expect(logger().warn).toHaveBeenCalledTimes(2)
307+
})
308+
})

‎apps/sim/lib/mothership/transport/receiver.ts‎

Lines changed: 53 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,6 +1,7 @@
11
import { createLogger } from '@sim/logger'
22
import { getErrorMessage } from '@sim/utils/errors'
3-
import { sleep } from '@sim/utils/helpers'
3+
import { interruptibleSleep } from '@sim/utils/helpers'
4+
import { type BackoffOptions, backoffWithJitter } from '@sim/utils/retry'
45
import { truncate } from '@sim/utils/string'
56
import { env } from '@/lib/core/config/env'
67
import { isMothershipBenchmarkEnabled } from '@/lib/core/config/env-flags'
@@ -22,6 +23,25 @@ import { executeSimControl } from '@/lib/mothership/transport/control'
2223
const logger = createLogger('MothershipTransportReceiver')
2324
const receivers = new Map<string, AbortController>()
2425

26+
/**
27+
* A lost connection or a worker deploy: retry within a second, slowing to 4 s, so with jitter a
28+
* healthy deployment is back inside the worker's 5 s run-control deadline.
29+
*/
30+
const TRANSIENT_BACKOFF: BackoffOptions = { baseMs: 1000, maxMs: 4000 }
31+
/**
32+
* The worker rejected this deployment's key, which only an operator can fix: start at 30 s and
33+
* slow to 10 minutes, so a misconfigured deployment polls a few hundred times a day, not every
34+
* second, and still reconnects on its own once the key is accepted.
35+
*/
36+
const REFUSED_BACKOFF: BackoffOptions = { baseMs: 30_000, maxMs: 600_000 }
37+
38+
/** The worker refused this deployment's key (401/403), as opposed to failing to answer. */
39+
class TransportKeyRefused extends Error {
40+
constructor(readonly status: number) {
41+
super(`Transport key refused (HTTP ${status})`)
42+
}
43+
}
44+
2545
interface ReceivedControl {
2646
id: string
2747
answer: () => Promise<SimControlResult>
@@ -61,6 +81,8 @@ export async function receiveSimControls(
6181
channelId: string,
6282
signal: AbortSignal
6383
): Promise<void> {
84+
let failures = 0
85+
let outage: 'disconnected' | 'key_refused' | undefined
6486
while (!signal.aborted) {
6587
let phase: 'poll' | 'parse' | 'reply' = 'poll'
6688
try {
@@ -75,6 +97,9 @@ export async function receiveSimControls(
7597
})
7698
if (!response.ok) {
7799
await response.body?.cancel()
100+
if (response.status === 401 || response.status === 403) {
101+
throw new TransportKeyRefused(response.status)
102+
}
78103
throw new Error(`Transport poll refused (HTTP ${response.status})`)
79104
}
80105
phase = 'parse'
@@ -101,13 +126,35 @@ export async function receiveSimControls(
101126
)
102127
const failed = replies.find((reply) => reply.status === 'rejected')
103128
if (failed?.status === 'rejected') throw failed.reason
129+
// Only a whole iteration (poll, batch, replies) ends an outage.
130+
if (outage) {
131+
logger.info('Sim transport reconnected')
132+
outage = undefined
133+
}
104134
} catch (error) {
105135
if (signal.aborted) return
106-
logger.warn('Sim transport disconnected; reconnecting', {
107-
phase,
108-
error: getErrorMessage(error),
109-
})
110-
await sleep(1000)
136+
const keyRefused = error instanceof TransportKeyRefused
137+
const kind = keyRefused ? 'key_refused' : 'disconnected'
138+
// One line per outage, and again only when it changes kind, not one per retry.
139+
if (outage !== kind) {
140+
outage = kind
141+
failures = 0
142+
if (keyRefused) {
143+
logger.warn('Sim transport key refused by the worker; check COPILOT_API_KEY', {
144+
status: error.status,
145+
})
146+
} else {
147+
logger.warn('Sim transport disconnected; reconnecting', {
148+
phase,
149+
error: getErrorMessage(error),
150+
})
151+
}
152+
}
153+
failures++
154+
await interruptibleSleep(
155+
backoffWithJitter(failures, null, keyRefused ? REFUSED_BACKOFF : TRANSIENT_BACKOFF),
156+
signal
157+
)
111158
}
112159
}
113160
}

0 commit comments

Comments
 (0)