fix(bounded-retry): address PR #393 second-round review

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.
This commit is contained in:
Renato Alcara
2026-04-27 00:30:37 -03:00
parent 73d63b6304
commit f914ffe272
4 changed files with 71 additions and 27 deletions
+41 -12
View File
@@ -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<void>((_, 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)
)
])
+2 -5
View File
@@ -325,11 +325,8 @@ export async function withBoundedRetry<T>(
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.
+6 -2
View File
@@ -497,8 +497,12 @@ export class StructuredLogger implements ILogger {
if (externalHook) {
try {
const hookResult = externalHook(entry) as unknown
if (hookResult && typeof (hookResult as Promise<unknown>).then === 'function') {
;(hookResult as Promise<unknown>).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<unknown>).then === 'function') {
void Promise.resolve(hookResult as PromiseLike<unknown>).catch(() => {
this.metrics.hookFailures++
})
}
+22 -8
View File
@@ -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<string>>()
.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 () => {