From f914ffe2728f07954dfd9c47fc28e4ae782f93f7 Mon Sep 17 00:00:00 2001 From: Renato Alcara Date: Mon, 27 Apr 2026 00:30:37 -0300 Subject: [PATCH] fix(bounded-retry): address PR #393 second-round review MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit All 5 issues verified as REAL (not false positives) and fixed: 1. **CRITICAL: query() swallows timeouts → bounded-retry treats as success** (CodeRabbit Critical, line 319 socket.ts) waitForMessage() returns undefined on timeout instead of throwing. queryInternal() returns that undefined unchanged. uploadToServer was `await query(...)` then logging success regardless — a timed-out upload would update lastUploadTime with no retry triggered. Fix: validate response shape inside uploadToServer: if (!result) throw new Boom('Pre-key upload query timed out (no response)', { statusCode: 408 }) Bounded-retry now sees the throw and properly retries. 2. **MAJOR: Outer Promise.race + bounded-retry can run in parallel** (CodeRabbit Major + Copilot, line 674 socket.ts) With safety margin (ttlMs=28s vs UPLOAD_TIMEOUT=30s) bounded-retry should always reach give-up first, but if anything bypasses that bound the outer race rejects while bounded-retry keeps running. Fix: wire AbortController. Pass its signal to bounded-retry. On outer race timeout, abort the controller → bounded-retry stops cleanly with BoundedRetryAbortedError. uploadToServer also honours the signal before logging success. 3. **MINOR: sleep-leak test does not observe the leak** (CodeRabbit Minor) Test only triggered 4 sleeps — below Node's 11-listener warning — and never captured warning events. Fix: spy on signal.addEventListener / removeEventListener and assert add count == remove count. 4. **MINOR: structured-logger thenable .catch can throw** (Copilot) Code called (hookResult as Promise).catch(...) directly. Fails on thenables that only implement .then. Fix: use Promise.resolve(hookResult).catch(...) which adapts any thenable safely. 5. **Internal: bounded-retry catch was double-removing outer-abort listener** Found by the new spy-based test. Both catch and finally called removeEventListener. Removed redundant catch-block remove; finally is single source of truth. Build clean, 35/35 suites, 809/809 tests pass. --- src/Socket/socket.ts | 53 ++++++++++++++++++----- src/Utils/bounded-retry.ts | 7 +-- src/Utils/structured-logger.ts | 8 +++- src/__tests__/Utils/bounded-retry.test.ts | 30 +++++++++---- 4 files changed, 71 insertions(+), 27 deletions(-) diff --git a/src/Socket/socket.ts b/src/Socket/socket.ts index 229a3ed9..992a3f1c 100644 --- a/src/Socket/socket.ts +++ b/src/Socket/socket.ts @@ -630,6 +630,13 @@ export const makeSocket = (config: SocketConfig) => { return } + // Shared abort controller so the outer Promise.race can cancel the + // in-flight bounded-retry loop if its own timeout fires first. + // Without this, the outer race rejects but the bounded-retry loop + // keeps running in the background, mutating lastUploadTime / logs + // after the caller has given up (CodeRabbit + Copilot reviews). + const uploadAbort = new AbortController() + const uploadLogic = async () => { logger.info({ count }, 'uploading pre-keys') @@ -646,18 +653,33 @@ export const makeSocket = (config: SocketConfig) => { // the previous circuit breaker AND the manual exponential backoff // retry loop with maxRetries=3). // - // IMPORTANT: bounded-retry's ttlMs MUST be < UPLOAD_TIMEOUT (the - // outer Promise.race below). Otherwise the outer race fires first - // and bounded-retry never reaches its natural give-up — losing - // structured logs / metrics. Use UPLOAD_TIMEOUT - 2s as a safety - // margin so bounded-retry always wins. + // CRITICAL: query() returns `undefined` on timeout (it does NOT + // throw — see waitForMessage). If we just `await query(node)`, + // a timed-out upload would resolve with undefined and bounded-retry + // would treat it as success. Validate the response shape so a + // timeout actually triggers a retry (CodeRabbit review on PR #393). + // + // bounded-retry's ttlMs MUST be < UPLOAD_TIMEOUT (the outer + // Promise.race below). With margin (28s vs 30s) bounded-retry + // always reaches its natural give-up first. We additionally pass + // an AbortController signal so that if the outer race ever fires + // first, the bounded-retry loop is aborted and does not keep + // running in the background (CodeRabbit + Copilot reviews). const PER_ATTEMPT_TIMEOUT_MS = 8_000 const RETRY_TTL_MS = UPLOAD_TIMEOUT - 2_000 - // Pass the matching timeoutMs to query() so a stale attempt does - // not keep an iq listener registered after bounded-retry has moved - // on to the next attempt (Copilot review on PR #393). - const uploadToServer = async () => { - await query(node, PER_ATTEMPT_TIMEOUT_MS) + + const uploadToServer = async (signal?: AbortSignal) => { + const result = await query(node, PER_ATTEMPT_TIMEOUT_MS) + if (signal?.aborted) { + throw new Error('aborted') + } + + if (!result) { + // query() returned undefined → underlying iq response + // timed out. Throw so bounded-retry retries. + throw new Boom('Pre-key upload query timed out (no response)', { statusCode: 408 }) + } + logger.info({ count }, 'uploaded pre-keys successfully') lastUploadTime = Date.now() } @@ -670,6 +692,7 @@ export const makeSocket = (config: SocketConfig) => { delays: [1000, 2000, 4000, 8000], ttlMs: RETRY_TTL_MS, perAttemptTimeoutMs: PER_ATTEMPT_TIMEOUT_MS, + signal: uploadAbort.signal, logger }) } catch (uploadError) { @@ -678,11 +701,17 @@ export const makeSocket = (config: SocketConfig) => { } } - // Add timeout protection + // Outer timeout protection. With ttlMs=28s vs UPLOAD_TIMEOUT=30s, + // bounded-retry should always win — but if anything ever blocks + // uploadLogic outside bounded-retry's reach, this race aborts the + // whole thing cleanly via uploadAbort. uploadPreKeysPromise = Promise.race([ uploadLogic(), new Promise((_, reject) => - setTimeout(() => reject(new Boom('Pre-key upload timeout', { statusCode: 408 })), UPLOAD_TIMEOUT) + setTimeout(() => { + uploadAbort.abort() + reject(new Boom('Pre-key upload timeout', { statusCode: 408 })) + }, UPLOAD_TIMEOUT) ) ]) diff --git a/src/Utils/bounded-retry.ts b/src/Utils/bounded-retry.ts index aa2563ed..0cd67779 100644 --- a/src/Utils/bounded-retry.ts +++ b/src/Utils/bounded-retry.ts @@ -325,11 +325,8 @@ export async function withBoundedRetry( lastError = err as Error attempt++ - // Detach outer-abort listener as soon as the attempt settles so - // it cannot fire after the controller is no longer in scope. - if (options.signal && onOuterAbort) { - options.signal.removeEventListener('abort', onOuterAbort) - } + // (outer-abort listener detachment happens in the finally below — + // avoiding a double-remove that breaks listener-count assertions.) // If the outer signal aborted us mid-attempt, surface that explicitly // rather than as a generic operation failure. diff --git a/src/Utils/structured-logger.ts b/src/Utils/structured-logger.ts index ffe64ab3..c69a2596 100644 --- a/src/Utils/structured-logger.ts +++ b/src/Utils/structured-logger.ts @@ -497,8 +497,12 @@ export class StructuredLogger implements ILogger { if (externalHook) { try { const hookResult = externalHook(entry) as unknown - if (hookResult && typeof (hookResult as Promise).then === 'function') { - ;(hookResult as Promise).catch(() => { + // Use Promise.resolve().catch() so any thenable (including + // Promise-likes that only implement .then) is handled + // safely — calling .catch directly would throw on such + // objects (Copilot review on PR #393). + if (hookResult && typeof (hookResult as PromiseLike).then === 'function') { + void Promise.resolve(hookResult as PromiseLike).catch(() => { this.metrics.hookFailures++ }) } diff --git a/src/__tests__/Utils/bounded-retry.test.ts b/src/__tests__/Utils/bounded-retry.test.ts index fcb07af4..c5d0f661 100644 --- a/src/__tests__/Utils/bounded-retry.test.ts +++ b/src/__tests__/Utils/bounded-retry.test.ts @@ -285,7 +285,23 @@ describe('bounded-retry — WhatsApp-aligned per-operation retry', () => { // Regression: sleep used signal.addEventListener with { once: true } but // never removed the listener on timer-resolve. With many retries on a // shared signal, listeners would accumulate. + // + // Make the failure mode observable by spying on add/removeEventListener + // directly so the assertion fails if cleanup is removed. const ctrl = new AbortController() + const realAdd = ctrl.signal.addEventListener.bind(ctrl.signal) + const realRemove = ctrl.signal.removeEventListener.bind(ctrl.signal) + let addCount = 0 + let removeCount = 0 + ctrl.signal.addEventListener = ((type: string, listener: never, opts?: never) => { + if (type === 'abort') addCount++ + return realAdd(type, listener, opts) + }) as typeof ctrl.signal.addEventListener + ctrl.signal.removeEventListener = ((type: string, listener: never, opts?: never) => { + if (type === 'abort') removeCount++ + return realRemove(type, listener, opts) + }) as typeof ctrl.signal.removeEventListener + const op = jest .fn<() => Promise>() .mockRejectedValueOnce(new Error('1')) @@ -293,23 +309,21 @@ describe('bounded-retry — WhatsApp-aligned per-operation retry', () => { .mockRejectedValueOnce(new Error('3')) .mockResolvedValueOnce('ok') - // Track listener count via getMaxListeners-style check is not portable - // across runtimes, so we instead verify completion proceeds without - // MaxListenersExceededWarning being raised. The implementation must - // remove the listener on each successful sleep. const result = await withBoundedRetry(op, { name: 'no-leak', delays: [5], jitter: 0, - ttlMs: 200, + ttlMs: 500, signal: ctrl.signal }) expect(result).toBe('ok') expect(op).toHaveBeenCalledTimes(4) - // If listeners leaked, we would see them by counting. AbortSignal does - // not expose listenerCount publicly; the regression manifests as a - // runtime warning. Test passes if no warning + result is correct. + // If sleep() leaks listeners, addCount > removeCount. Each retry adds + // listeners (1 sleep + 1 outer-abort forwarding) and must remove the + // same number on settlement. + expect(addCount).toBeGreaterThan(0) + expect(addCount).toBe(removeCount) }) test('logger receives structured logs for retry, give-up, and recovery', async () => {