Skip to content
Merged
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
128 changes: 76 additions & 52 deletions src/proxy/proxy-manager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -691,64 +691,88 @@ export class ProxyManager extends EventEmitter implements IProxyManager {
const delays = [500, 1000, 2000, 4000, 8000]; // More generous backoff for Windows CI
let lastError: Error | undefined;

for (let attempt = 0; attempt <= maxRetries; attempt++) {
const timeoutMs = delays[Math.min(attempt, delays.length - 1)];

try {
const received = await new Promise<boolean>((resolve, reject) => {
let resolved = false;

const handler = () => {
if (resolved) return;
resolved = true;
// Detach on success too — this listener is registered with on(),
// and each un-removed acknowledgment handler would otherwise stay
// on the manager for its lifetime (issue #420).
cleanup();
resolve(true);
};

const cleanup = () => {
this.removeListener('init-received', handler);
if (timer) clearTimeout(timer);
};

this.on('init-received', handler);

const timer = setTimeout(() => {
if (resolved) return;
resolved = true;
this.removeListener('init-received', handler);
resolve(false);
}, timeoutMs);

try {
this.sendCommand(initCommand);
} catch (error) {
cleanup();
reject(error);
}
});
// Latch the ack for the whole retry sequence (issue #512): the worker
// acks exactly once, and on a slow boot (>500ms — inspected or heavily
// loaded host) that ack lands between attempt windows. A per-attempt
// listener silently drops it, and for a worker that then exits (dry-run)
// every remaining retry fails against a process that already did its job.
let acked = false;
const onAck = () => {
acked = true;
};
this.on('init-received', onAck);

// Wait up to ms, ending early (true) the moment the ack arrives — or
// immediately when it was already latched by the long-lived listener
const waitForAck = (ms: number): Promise<boolean> =>
new Promise<boolean>((resolve) => {
if (acked) {
resolve(true);
return;
}
let settled = false;
const settle = (value: boolean) => {
if (settled) return;
settled = true;
clearTimeout(timer);
this.removeListener('init-received', onAckNow);
resolve(value);
};
const onAckNow = () => settle(true);
this.on('init-received', onAckNow);
const timer = setTimeout(() => settle(false), ms);
});

if (received) {
this.logger.info(`[ProxyManager] Init command acknowledged on attempt ${attempt + 1}`);
try {
for (let attempt = 0; attempt <= maxRetries; attempt++) {
if (acked) {
this.logger.info(`[ProxyManager] Init command acknowledged before attempt ${attempt + 1}`);
return;
}
const timeoutMs = delays[Math.min(attempt, delays.length - 1)];

let sendFailed = false;
try {
this.sendCommand(initCommand);
} catch (error) {
lastError = error as Error;
sendFailed = true;
this.logger.warn(
`[ProxyManager] Error sending init on attempt ${attempt + 1}: ${lastError.message}`
);
// Once the worker has exited without acking, no ack can arrive —
// fail fast with the detailed exit message instead of burning the
// remaining retries against a process that is gone (issue #512)
if (this.lastExitDetails) {
break;
}
}

this.logger.warn(
`[ProxyManager] Init not acknowledged, attempt ${attempt + 1}/${maxRetries + 1}`
);
} catch (error) {
lastError = error as Error;
this.logger.warn(
`[ProxyManager] Error sending init on attempt ${attempt + 1}: ${lastError.message}`
);
}
// A failed send delivered nothing to wait for; an earlier attempt's
// late ack is still caught by the latch during the backoff below
if (!sendFailed) {
if (await waitForAck(timeoutMs)) {
this.logger.info(`[ProxyManager] Init command acknowledged on attempt ${attempt + 1}`);
return;
}

this.logger.warn(
`[ProxyManager] Init not acknowledged, attempt ${attempt + 1}/${maxRetries + 1}`
);
}

if (attempt < maxRetries) {
const waitMs = delays[Math.min(attempt, delays.length - 1)];
await new Promise((resolve) => setTimeout(resolve, waitMs));
if (attempt < maxRetries) {
const waitMs = delays[Math.min(attempt, delays.length - 1)];
if (await waitForAck(waitMs)) {
this.logger.info(
`[ProxyManager] Init command acknowledged during backoff after attempt ${attempt + 1}`
);
return;
}
}
}
} finally {
this.removeListener('init-received', onAck);
}

let detailMessage = `Failed to initialize proxy after ${maxRetries + 1} attempts. ${
Expand Down
72 changes: 67 additions & 5 deletions tests/unit/proxy/proxy-manager.handshake.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -61,31 +61,93 @@ describe('ProxyManager sendInitWithRetry', () => {
expect(sendCommandMock).toHaveBeenCalledTimes(1);
});

it('retries when acknowledgement arrives after the first timeout', async () => {
it('latches an acknowledgement that lands between attempt windows (issue #512)', async () => {
vi.useFakeTimers();
// The worker acks once, 600ms after the init send — after attempt 1's
// 500ms window expired, during the backoff sleep. Pre-#512 this ack was
// dropped (its listener had been removed) and the whole launch failed if
// the worker then exited; now it resolves the retry loop without a resend.
const sendCommandMock = vi
.spyOn(manager as unknown as { sendCommand: (command: object) => void }, 'sendCommand')
.mockImplementationOnce(() => {
setTimeout(() => (manager as unknown as EventEmitter).emit('init-received'), 600);
});

const initPromise = (manager as unknown as { sendInitWithRetry: (command: object) => Promise<void> }).sendInitWithRetry(
{ cmd: 'init' }
);

vi.advanceTimersByTime(500); // attempt 1 window expires without the ack
await Promise.resolve();
vi.advanceTimersByTime(100); // ack fires during the backoff sleep
await Promise.resolve();
await initPromise;

expect(sendCommandMock).toHaveBeenCalledTimes(1);
});

it('retries and resolves when only a later attempt is acknowledged', async () => {
vi.useFakeTimers();
let attempt = 0;
const sendCommandMock = vi
.spyOn(manager as unknown as { sendCommand: (command: object) => void }, 'sendCommand')
.mockImplementation(() => {
attempt += 1;
const delay = attempt === 1 ? 600 : 100;
setTimeout(() => (manager as unknown as EventEmitter).emit('init-received'), delay);
if (attempt === 2) {
setTimeout(() => (manager as unknown as EventEmitter).emit('init-received'), 100);
}
// attempt 1: message lost entirely — no ack ever fires for it
});

const initPromise = (manager as unknown as { sendInitWithRetry: (command: object) => Promise<void> }).sendInitWithRetry(
{ cmd: 'init' }
);

vi.advanceTimersByTime(600); // first ack (lost) + first timeout (500)
vi.advanceTimersByTime(500); // attempt 1 window expires
await Promise.resolve();
vi.advanceTimersByTime(500); // backoff before retry
await Promise.resolve();
vi.advanceTimersByTime(100); // second attempt acknowledges
vi.advanceTimersByTime(100); // attempt 2 acknowledges
await Promise.resolve();
await initPromise;
expect(sendCommandMock).toHaveBeenCalledTimes(2);
});

it('fails fast once the worker has exited without acking (issue #512)', async () => {
vi.useFakeTimers();
let attempt = 0;
const sendCommandMock = vi
.spyOn(manager as unknown as { sendCommand: (command: object) => void }, 'sendCommand')
.mockImplementation(() => {
attempt += 1;
if (attempt > 1) {
// Worker exited between attempts; ProxyManager recorded the exit
(manager as unknown as { lastExitDetails: unknown }).lastExitDetails = {
code: 1,
signal: null,
timestamp: Date.now(),
capturedStderr: ['boom'],
};
throw new Error('Proxy process not available');
}
});

const initPromise = (manager as unknown as { sendInitWithRetry: (command: object) => Promise<void> }).sendInitWithRetry(
{ cmd: 'init' }
);
const rejection = expect(initPromise).rejects.toThrow('Proxy exit details -> code=1');

vi.advanceTimersByTime(500); // attempt 1 window expires
await Promise.resolve();
vi.advanceTimersByTime(500); // backoff, then attempt 2's send throws
await Promise.resolve();

// No further windows/backoffs are burned: the loop breaks on the dead
// worker instead of retrying four more times over ~15s
await rejection;
expect(sendCommandMock).toHaveBeenCalledTimes(2);
});

it('throws after exhausting retries when acknowledgement never arrives', async () => {
vi.useFakeTimers();
const sendCommandMock = vi
Expand Down
39 changes: 18 additions & 21 deletions tests/unit/proxy/proxy-manager.start.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -491,36 +491,33 @@ describe('ProxyManager.start', () => {
expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Error sending init on attempt 1'));
});

it('surfaces detailed error after exhausting init retries', async () => {
it('surfaces detailed error and fails fast once the worker exited without acking (issue #512)', async () => {
fakeProcess.sendCommand.mockReset();
fakeProcess.sendCommand.mockImplementation(() => {
throw new Error('ipc failure');
});

(proxyManager as unknown as {
lastExitDetails: {
code: number | null;
signal: string | null;
timestamp: number;
capturedStderr: string[];
};
}).lastExitDetails = {
code: 12,
signal: 'SIGTERM',
timestamp: Date.now(),
capturedStderr: ['fatal: adapter crashed']
};
fakeProcess.sendCommand
.mockImplementationOnce(() => {
// First init is delivered but never acked; the worker dies shortly
// after — handleProxyExit records lastExitDetails
setTimeout(() => fakeProcess.emit('exit', 12, 'SIGTERM'), 100);
})
.mockImplementation(() => {
throw new Error('Proxy process not available');
});

const startPromise = proxyManager.start(baseConfig);

// Attach the rejection expectation BEFORE driving the rejection: the
// async fake-timer loop yields through real ticks, where an unhandled
// rejection would otherwise be flagged (issue #420).
const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy after 6 attempts\. Last error: ipc failure/);
await vi.advanceTimersByTimeAsync(16500);
// With exit details recorded, retrying is pointless (no ack can arrive
// from an exited worker) — the failure surfaces on attempt 2's failed
// send instead of burning ~15s of retries (issue #512), and carries
// the exit details.
const rejection = expect(startPromise).rejects.toThrow(/Failed to initialize proxy after 6 attempts\. Last error: Proxy process not available[\s\S]*code=12 signal=SIGTERM/);
await vi.advanceTimersByTimeAsync(8000);

await rejection;
expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Error sending init on attempt 6'));
expect(logger.warn).toHaveBeenCalledWith(expect.stringContaining('Error sending init on attempt 2'));
expect(logger.warn).not.toHaveBeenCalledWith(expect.stringContaining('Error sending init on attempt 3'));
});
});

Expand Down
Loading