diff --git a/.changeset/quiet-stream-reconnect-logs.md b/.changeset/quiet-stream-reconnect-logs.md new file mode 100644 index 00000000..a06d8efe --- /dev/null +++ b/.changeset/quiet-stream-reconnect-logs.md @@ -0,0 +1,11 @@ +--- +'@vercel/flags-core': patch +--- + +Reduce log noise from stream reconnects. + +Retryable stream errors are no longer logged on every failed attempt; the +underlying error is now surfaced only once retries are exhausted (via the +existing "Max retry count exceeded" log). The stream/polling initialization +timeout warnings were also reworded to make clear the client keeps connecting +in the background while serving fallback values. diff --git a/packages/vercel-flags-core/CLAUDE.md b/packages/vercel-flags-core/CLAUDE.md index 69fb0314..1e3c67ba 100644 --- a/packages/vercel-flags-core/CLAUDE.md +++ b/packages/vercel-flags-core/CLAUDE.md @@ -209,8 +209,8 @@ Only call `initialize()` explicitly when the test specifically needs to verify i ### Assert console output from the implementation The implementation logs warnings/errors for specific conditions. Tests must assert these: -- Stream timeout: `console.warn('@vercel/flags-core: Stream initialization timeout, falling back')` -- Stream error (e.g., 502): `console.error('@vercel/flags-core: Stream error', expect.any(Error))` +- Stream timeout: `console.warn('@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background')` +- Stream error: retryable failures are silent; the error is only logged once retries are exhausted via `console.error('@vercel/flags-core: Max retry count exceeded', lastError)` - 401 fast-fail: `console.error` with auth error (no retry, no timeout wait) ### Do not weaken assertions when adapting tests diff --git a/packages/vercel-flags-core/src/black-box.test.ts b/packages/vercel-flags-core/src/black-box.test.ts index 6ed5a187..0ecae9ed 100644 --- a/packages/vercel-flags-core/src/black-box.test.ts +++ b/packages/vercel-flags-core/src/black-box.test.ts @@ -638,7 +638,7 @@ describe('Controller (black-box)', () => { expect(result.metrics?.connectionState).toBe('disconnected'); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); warnSpy.mockRestore(); }); @@ -675,12 +675,13 @@ describe('Controller (black-box)', () => { expect(result.value).toBe(true); expect(result.metrics?.source).toBe('embedded'); - expect(errorSpy).toHaveBeenCalledWith( + // Retryable stream errors are silent until retries are exhausted. + expect(errorSpy).not.toHaveBeenCalledWith( '@vercel/flags-core: Stream error', - expect.any(Error), + expect.anything(), ); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); errorSpy.mockRestore(); warnSpy.mockRestore(); @@ -781,7 +782,7 @@ describe('Controller (black-box)', () => { expect(result.metrics?.source).toBe('embedded'); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); warnSpy.mockRestore(); }); @@ -962,7 +963,7 @@ describe('Controller (black-box)', () => { expect(result.metrics?.source).toBe('in-memory'); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); warnSpy.mockRestore(); @@ -998,7 +999,7 @@ describe('Controller (black-box)', () => { expect(result.metrics?.source).toBe('in-memory'); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); warnSpy.mockRestore(); @@ -1897,11 +1898,10 @@ describe('Controller (black-box)', () => { expect(result.metrics?.source).toBe('embedded'); expect(result.metrics?.connectionState).toBe('disconnected'); - expect(errorSpy).toHaveBeenCalledWith( + // Retryable stream errors are silent until retries are exhausted. + expect(errorSpy).not.toHaveBeenCalledWith( '@vercel/flags-core: Stream error', - expect.objectContaining({ - message: 'stream body was not present', - }), + expect.anything(), ); await client.shutdown(); @@ -3289,12 +3289,13 @@ describe('Controller (black-box)', () => { expect(h0['X-Retry-Attempt']).toBe('0'); expect(h1['X-Retry-Attempt']).toBe('1'); - expect(errorSpy).toHaveBeenCalledWith( + // Retryable stream errors are silent until retries are exhausted. + expect(errorSpy).not.toHaveBeenCalledWith( '@vercel/flags-core: Stream error', - expect.any(Error), + expect.anything(), ); expect(warnSpy).toHaveBeenCalledWith( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); errorSpy.mockRestore(); warnSpy.mockRestore(); diff --git a/packages/vercel-flags-core/src/controller/index.ts b/packages/vercel-flags-core/src/controller/index.ts index c173e69b..a46a5497 100644 --- a/packages/vercel-flags-core/src/controller/index.ts +++ b/packages/vercel-flags-core/src/controller/index.ts @@ -496,7 +496,7 @@ export class Controller implements ControllerInterface { if (result === 'timeout') { console.warn( - '@vercel/flags-core: Stream initialization timeout, falling back', + '@vercel/flags-core: Stream initialization timeout, falling back while continuing to connect in the background', ); // Don't stop stream - let it continue trying in background. // Swallow the rejection from the background stream promise to @@ -556,7 +556,7 @@ export class Controller implements ControllerInterface { if (result === 'timeout') { console.warn( - '@vercel/flags-core: Polling initialization timeout, falling back', + '@vercel/flags-core: Polling initialization timeout, falling back while continuing to poll in the background', ); return false; } diff --git a/packages/vercel-flags-core/src/controller/stream-connection.test.ts b/packages/vercel-flags-core/src/controller/stream-connection.test.ts index 5093984e..e575a507 100644 --- a/packages/vercel-flags-core/src/controller/stream-connection.test.ts +++ b/packages/vercel-flags-core/src/controller/stream-connection.test.ts @@ -487,11 +487,45 @@ describe('connectStream', () => { vi.useRealTimers(); }); - // Note: Testing MAX_RETRY_COUNT exceeded is skipped because the backoff delays - // make the test too slow. The behavior is: - // - After 10 retries without receiving data, the connection aborts - // - console.error('@vercel/flags-core: Max retry count exceeded') is logged - // This is tested indirectly through Controller integration tests. + it('should log the underlying error once max retries are exceeded', async () => { + vi.useFakeTimers({ shouldAdvanceTime: true }); + const errorSpy = vi.spyOn(console, 'error').mockImplementation(() => {}); + + // Every attempt fails with the same network-style error. + fetchMock.mockImplementation(() => + Promise.reject(new Error('fetch failed')), + ); + + const abortController = new AbortController(); + + const promise = connectStream( + { host: HOST, sdkKey: 'vf_test', abortController, fetch: fetchMock }, + { onDatafile: vi.fn() }, + ); + // Attach the rejection expectation up front so the rejection is never + // briefly unhandled while we drive the timers below. + const rejection = expect(promise).rejects.toThrow( + 'stream: max retry count exceeded before receiving data', + ); + + // Drive the retry loop to exhaustion (MAX_RETRY_COUNT = 15, backoff caps + // at 60s). Advancing past the max backoff repeatedly walks every attempt. + for (let i = 0; i <= 16; i++) { + await vi.advanceTimersByTimeAsync(61_000); + } + + await rejection; + + // Retryable failures stay silent; the underlying error surfaces only here. + expect(errorSpy).toHaveBeenCalledWith( + '@vercel/flags-core: Max retry count exceeded', + expect.objectContaining({ message: 'fetch failed' }), + ); + + abortController.abort(); + errorSpy.mockRestore(); + vi.useRealTimers(); + }); it('should stop when abortController is aborted externally', async () => { fetchMock.mockImplementation((_input, init) => diff --git a/packages/vercel-flags-core/src/controller/stream-connection.ts b/packages/vercel-flags-core/src/controller/stream-connection.ts index fcf4c156..723e6e4f 100644 --- a/packages/vercel-flags-core/src/controller/stream-connection.ts +++ b/packages/vercel-flags-core/src/controller/stream-connection.ts @@ -78,10 +78,14 @@ export async function connectStream( void (async () => { let initialDataReceived = false; + let lastError: unknown; while (!abortController.signal.aborted) { if (retryCount > MAX_RETRY_COUNT) { - console.error('@vercel/flags-core: Max retry count exceeded'); + console.error( + '@vercel/flags-core: Max retry count exceeded', + lastError ?? 'stream closed repeatedly without an error', + ); if (!initialDataReceived) { rejectInit!( new Error('stream: max retry count exceeded before receiving data'), @@ -242,9 +246,10 @@ export async function connectStream( break; } // Ping timeout aborts only the per-connection controller; this is - // an expected reconnect, not a real error — skip the noisy log. + // an expected reconnect, not a real error. Stay silent on retryable + // failures too — the error is only logged once retries are exhausted. if (!connectionAbort.signal.aborted) { - console.error('@vercel/flags-core: Stream error', error); + lastError = error; } onDisconnect?.(); retryCount++;