diff --git a/contributingGuides/SEQUENTIAL_QUEUE.md b/contributingGuides/SEQUENTIAL_QUEUE.md index d007244f2a67..4c322aa969e6 100644 --- a/contributingGuides/SEQUENTIAL_QUEUE.md +++ b/contributingGuides/SEQUENTIAL_QUEUE.md @@ -391,6 +391,8 @@ Three concerns cut across every block. **How it works today.** `SaveResponseInOnyx` is the **sole producer** of `shouldPauseQueue`: it sets the flag when the command is not in `requestsToIgnoreLastUpdateID` and `OnyxUpdates.doesClientNeedToBeUpdated` reports a `previousUpdateID` gap, after stashing the update info. `process()` then `pause()`s. The flag flips first, but the just-processed request is still removed and its `queueFlushedData` saved before the recursion early-returns on the pause. The actual gap fetch runs in a **decoupled** `OnyxUpdateManager` flow that fetches the missing range, applies the deferred updates in order, and then calls `unpause()`. Within this concern `pause()` has two inbound callers: `applyOnyxUpdatesReliably` (on detecting a missing-updates fetch) and `DeferredOnyxUpdates`, with `unpause()` called once the gap is filled. +The fetch also carries a **stall guard**. A successful `GetMissingOnyxMessages` must move `lastUpdateIDAppliedToClient` past the ID it was fired from. When a 200 doesn't, the server can't serve that range right now, and refetching won't help (production traces showed this loop firing about once per incoming Pusher update). On the first such response `OnyxUpdateManager` escalates to a single *incremental* `ReconnectApp` and backs off further fetches from the same client state. Every skipped cycle still resumes the queue, so a stalled fetch can't freeze the app. The `ReconnectApp` goes through the queue normally, and a duplicate is dropped when a reconnect with the same or wider range is already waiting or in flight. Its response applies even with the gap open, so it normally moves the client to the server head. The back-off expires after a minute. Then the normal flow fetches again, and a repeat stall escalates and alerts again. Even a lost reconnect can't silence the client for good: the worst case is one fetch and one reconnect per minute. Failed or unanswered fetches prove nothing about the range and keep their existing retry behavior. Both fetch sites (the pending-updates branch and the gap branch) share the guard. + **Sharp edges.** - The in-code source comment at the `resolveIsReadyPromise` decision claims `isQueuePaused` is set for offline pauses as well as `shouldPauseQueue` data-gap syncs. That is **inaccurate**: no offline path ever calls `pause()` (its only callers are the `shouldPauseQueue` response, `DeferredOnyxUpdates`, and `applyOnyxUpdatesReliably`); offline is handled entirely by the separate `isOfflineNetwork()` gate. The decision logic itself is correct (it keys on `isOfflineNetwork()`); only the explanatory comment is wrong (see [the state machine](#why-isreadypromise-resolves-on-offline-not-on-paused)). - `shouldPauseQueue` rides on the response object, so any middleware registered after `SaveResponseInOnyx` that returned a *new* response object would strip the flag. Today the only later middleware is `FraudMonitoring`, which returns the response unchanged, so the flag survives. But the in-code comment claiming `SaveResponseInOnyx` "must be last" is stale (see [Middleware](#the-middleware-chain-boundary)). diff --git a/src/CONST/index.ts b/src/CONST/index.ts index ecce42fcc859..99b776478351 100644 --- a/src/CONST/index.ts +++ b/src/CONST/index.ts @@ -2440,6 +2440,7 @@ const CONST = { SUSTAINED_FAILURE_THRESHOLD_COUNT: 3, SUSTAINED_FAILURE_WINDOW_MS: 10 * 1000, RECONNECT_STAMPEDE_JITTER_MS: 5000, + STALLED_UPDATES_FETCH_BACKOFF_TIME_MS: 60 * 1000, }, // The number of milliseconds for an idle session to expire SESSION_EXPIRATION_TIME_MS: 2 * 3600 * 1000, // 2 hours diff --git a/src/libs/actions/OnyxUpdateManager/index.ts b/src/libs/actions/OnyxUpdateManager/index.ts index a38f83bca587..2a7081009ea3 100644 --- a/src/libs/actions/OnyxUpdateManager/index.ts +++ b/src/libs/actions/OnyxUpdateManager/index.ts @@ -3,7 +3,7 @@ import Log from '@libs/Log'; import {setAuthToken} from '@libs/Network/NetworkStore'; import {unpause as unpauseSequentialQueue} from '@libs/Network/SequentialQueue'; -import {finalReconnectAppAfterActivatingReliableUpdates, getMissingOnyxUpdates} from '@userActions/App'; +import {finalReconnectAppAfterActivatingReliableUpdates, getMissingOnyxUpdates, reconnectApp} from '@userActions/App'; import updateSessionAuthTokens from '@userActions/Session/updateSessionAuthTokens'; import CONST from '@src/CONST'; @@ -66,10 +66,70 @@ const createQueryPromiseWrapper = () => let queryPromiseWrapper = createQueryPromiseWrapper(); let isFetchingForPendingUpdates = false; +// A successful fetch of missing updates must move the client past the update ID it was fired from. +// When a 200 doesn't, the server can't serve that range right now and refetching won't help +// (production traces showed this loop firing about once per incoming Pusher update). So the first +// such response escalates to a single incremental ReconnectApp, whose response applies even with +// the gap open and normally catches the client up. Further fetches from the same client state back +// off, until the client advances or a minute passes; then the normal flow fetches and escalates again. +let stalledFetch: {clientUpdateID: number; time: number} | undefined; + const resetDeferralLogicVariables = () => { clearDeferredOnyxUpdates({shouldUnpauseSequentialQueue: false}); + stalledFetch = undefined; }; +function escalateIfFetchStalled(response: Awaited>, lastUpdateIDFromClient: number): boolean { + // A failed or unanswered fetch proves nothing about the server's ability to serve the range, + // so leave it to the existing retry paths. + if (!response || response.jsonCode !== 200) { + return false; + } + + // The client advanced, either through this response or through another path in the meantime + // (e.g. a parallel Pusher update applied mid-fetch). The fetches are making progress. + if (Number(response.lastUpdateID ?? CONST.DEFAULT_NUMBER_ID) > lastUpdateIDFromClient || lastUpdateIDAppliedToClient > lastUpdateIDFromClient) { + return false; + } + + stalledFetch = {clientUpdateID: lastUpdateIDFromClient, time: Date.now()}; + Log.alert('[OnyxUpdateManager] GetMissingOnyxMessages did not advance the client, escalating to an incremental ReconnectApp', { + lastUpdateIDFromClient, + responseLastUpdateID: response.lastUpdateID, + responsePreviousUpdateID: response.previousUpdateID, + }); + reconnectApp(lastUpdateIDFromClient); + return true; +} + +// A fetch from this client state recently stalled and escalated to a ReconnectApp. Give that reconnect +// its back-off window instead of repeating a fetch the server has shown it cannot serve. +function isFetchAlreadyStalled(lastUpdateIDFromClient: number): boolean { + if (!stalledFetch || stalledFetch.clientUpdateID !== lastUpdateIDFromClient) { + return false; + } + if (Date.now() - stalledFetch.time >= CONST.NETWORK.STALLED_UPDATES_FETCH_BACKOFF_TIME_MS) { + stalledFetch = undefined; + return false; + } + setMissingOnyxUpdatesQueryPromise(Promise.resolve()); + return true; +} + +// Fetches the missing updates and afterwards validates and applies the deferred updates, which recurses +// while the deferred updates still have gaps. When the fetch settles without progress, escalateIfFetchStalled +// takes over and the deferred updates are skipped: they sit behind the unclosed gap and could never apply. +function fetchMissingUpdates(lastUpdateIDFromClient: number, updateIDTo: number | string | undefined, clientLastUpdateID?: number) { + setMissingOnyxUpdatesQueryPromise( + getMissingOnyxUpdates(lastUpdateIDFromClient, updateIDTo).then((response) => { + if (escalateIfFetchStalled(response, lastUpdateIDFromClient)) { + return; + } + return validateAndApplyDeferredUpdates(clientLastUpdateID); + }), + ); +} + // This function will reset the query variables, unpause the SequentialQueue and log an info to the user. function finalizeUpdatesAndResumeQueue() { console.debug('[OnyxUpdateManager] Done applying all updates'); @@ -141,15 +201,17 @@ function handleMissingOnyxUpdates(onyxUpdatesFromServer: O return true; } + if (isFetchAlreadyStalled(lastUpdateIDFromClient)) { + return true; + } + console.debug(`[OnyxUpdateManager] Client is fetching pending updates from the server, from updates ${lastUpdateIDFromClient} to ${Number(pendingUpdateID)}`); Log.info('There are pending updates from the server, so fetching incremental updates', true, { pendingUpdateID, lastUpdateIDFromClient, }); - // Get the missing Onyx updates from the server and afterward validate and apply the deferred updates. - // This will trigger recursive calls to "validateAndApplyDeferredUpdates" if there are gaps in the deferred updates. - setMissingOnyxUpdatesQueryPromise(getMissingOnyxUpdates(lastUpdateIDFromClient, lastUpdateIDFromServer).then(() => validateAndApplyDeferredUpdates(clientLastUpdateID))); + fetchMissingUpdates(lastUpdateIDFromClient, lastUpdateIDFromServer, clientLastUpdateID); return true; } @@ -176,6 +238,11 @@ function handleMissingOnyxUpdates(onyxUpdatesFromServer: O // This client already has the reliable updates mode enabled, but it's missing some updates and it needs to fetch those. // Therefore, we are calling the GetMissingOnyxUpdates query, to fetch the missing updates. + // Checked before enqueueing: a skipped cycle finalizes right away, which would wipe the just-deferred update anyway. + if (isFetchAlreadyStalled(lastUpdateIDFromClient)) { + return true; + } + const areDeferredUpdatesQueued = !isEmptyDeferredOnyxUpdates(); // Add the new update to the deferred updates @@ -193,9 +260,7 @@ function handleMissingOnyxUpdates(onyxUpdatesFromServer: O previousUpdateIDFromServer, }); - // Get the missing Onyx updates from the server and afterwards validate and apply the deferred updates. - // This will trigger recursive calls to "validateAndApplyDeferredUpdates" if there are gaps in the deferred updates. - setMissingOnyxUpdatesQueryPromise(getMissingOnyxUpdates(lastUpdateIDFromClient, previousUpdateIDFromServer).then(() => validateAndApplyDeferredUpdates(clientLastUpdateID))); + fetchMissingUpdates(lastUpdateIDFromClient, previousUpdateIDFromServer, clientLastUpdateID); return true; }; diff --git a/src/libs/actions/__mocks__/App.ts b/src/libs/actions/__mocks__/App.ts index aedb73d276e2..36e59830c8da 100644 --- a/src/libs/actions/__mocks__/App.ts +++ b/src/libs/actions/__mocks__/App.ts @@ -2,7 +2,7 @@ import type * as AppImport from '@libs/actions/App'; import * as OnyxUpdates from '@userActions/OnyxUpdates'; -import type {OnyxUpdatesFromServer} from '@src/types/onyx'; +import type {OnyxUpdatesFromServer, Response as OnyxResponse} from '@src/types/onyx'; import createProxyForObject from '@src/utils/createProxyForObject'; import type {OnyxKey} from 'react-native-onyx'; @@ -16,7 +16,6 @@ const { setSidebarLoaded, setUpPoliciesAndNavigate, openApp, - reconnectApp, handleRestrictedEvent, finalReconnectAppAfterActivatingReliableUpdates, createWorkspaceWithPolicyDraftAndNavigateToIt, @@ -26,19 +25,29 @@ const { type AppMockValues = { missingOnyxUpdatesToBeApplied: Array> | undefined; + missingOnyxUpdatesResponse: OnyxResponse | undefined; }; type AppActionsMock = typeof AppImport & { - getMissingOnyxUpdates: jest.Mock>; + getMissingOnyxUpdates: jest.Mock | undefined | void>, [updateIDFrom?: number, updateIDTo?: number | string]>; + reconnectApp: jest.Mock; mockValues: AppMockValues; }; const mockValues: AppMockValues = { missingOnyxUpdatesToBeApplied: undefined, + missingOnyxUpdatesResponse: undefined, }; const mockValuesProxy = createProxyForObject(mockValues); +const reconnectApp = jest.fn(); + const getMissingOnyxUpdates = jest.fn((updateIDFrom: number, updateIDTo: number) => { + // When a response is set, the server answers without serving the requested range: nothing is applied. + if (mockValuesProxy.missingOnyxUpdatesResponse !== undefined) { + return Promise.resolve(mockValuesProxy.missingOnyxUpdatesResponse); + } + const updates = mockValuesProxy.missingOnyxUpdatesToBeApplied ?? []; if (updates.length === 0) { for (let i = updateIDFrom + 1; i <= updateIDTo; i++) { @@ -67,6 +76,7 @@ const getMissingOnyxUpdates = jest.fn((updateIDFrom: number, updateIDTo: number) export { // Mocks getMissingOnyxUpdates, + reconnectApp, mockValuesProxy as mockValues, // Actual App implementation @@ -74,7 +84,6 @@ export { setSidebarLoaded, setUpPoliciesAndNavigate, openApp, - reconnectApp, handleRestrictedEvent, finalReconnectAppAfterActivatingReliableUpdates, createWorkspaceWithPolicyDraftAndNavigateToIt, diff --git a/tests/unit/OnyxUpdateManagerTest.ts b/tests/unit/OnyxUpdateManagerTest.ts index 9cccae128f80..833f6a542b2f 100644 --- a/tests/unit/OnyxUpdateManagerTest.ts +++ b/tests/unit/OnyxUpdateManagerTest.ts @@ -1,3 +1,4 @@ +import Log from '@libs/Log'; import * as SequentialQueue from '@libs/Network/SequentialQueue'; import type {AppActionsMock} from '@userActions/__mocks__/App'; @@ -71,6 +72,7 @@ describe('OnyxUpdateManager', () => { OnyxUpdateManagerUtils.mockValues.beforeValidateAndApplyDeferredUpdates = undefined; ApplyUpdates.mockValues.beforeApplyUpdates = undefined; App.mockValues.missingOnyxUpdatesToBeApplied = undefined; + App.mockValues.missingOnyxUpdatesResponse = undefined; OnyxUpdateManager.resetDeferralLogicVariables(); }); @@ -492,6 +494,153 @@ describe('OnyxUpdateManager', () => { }); }); + it('should escalate to a single incremental ReconnectApp when the gap fetch returns no progress', async () => { + // Simulate the production stall: the server answers the gap fetch with a 200 that carries no updates + // and no lastUpdateID, so the client cannot advance no matter how often the fetch is repeated. + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 200, onyxData: []}; + const alertSpy = jest.spyOn(Log, 'alert'); + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + + // One useless answer is proof the server cannot close this gap: escalate right away to an + // incremental ReconnectApp, fired from the stalled client update ID, and raise the alert that + // makes stalled clients visible in production monitoring. + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledWith(1); + expect(alertSpy).toHaveBeenCalledTimes(1); + + // A further gap push against the same client state must back off: no new fetch, no second reconnect. + OnyxUpdateManager.handleMissingOnyxUpdates(update5); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + + // When the ReconnectApp response advances the client (simulated directly here), the guard releases + // and a fresh gap is fetched again. + App.mockValues.missingOnyxUpdatesResponse = undefined; + await Onyx.set(ONYXKEYS.ONYX_UPDATES_LAST_UPDATE_ID_APPLIED_TO_CLIENT, 5); + + OnyxUpdateManager.handleMissingOnyxUpdates(update7); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(2); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + }); + + it('should retry the gap fetch and escalate again after the back-off expires when the client still has not advanced', async () => { + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 200, onyxData: []}; + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + + // Within the back-off window a gap push from the same client state is skipped entirely. + OnyxUpdateManager.handleMissingOnyxUpdates(update5); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + + // One useless answer only proves the server could not serve the range at that moment, and the + // escalated reconnect is not guaranteed to survive its retries. Once the back-off expires the + // normal flow must fetch again, and a repeat stall must escalate again. + const dateNowSpy = jest.spyOn(Date, 'now').mockImplementation(() => new Date().getTime() + 61000); + OnyxUpdateManager.handleMissingOnyxUpdates(update7); + await OnyxUpdateManager.queryPromise; + dateNowSpy.mockRestore(); + + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(2); + expect(App.reconnectApp).toHaveBeenCalledTimes(2); + expect(App.reconnectApp).toHaveBeenLastCalledWith(1); + }); + + it('should not escalate to ReconnectApp when the gap fetch advances the client', async () => { + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + + expect(lastUpdateIDAppliedToClient).toBe(3); + expect(App.reconnectApp).not.toHaveBeenCalled(); + }); + + it('should not escalate or back off when the fetch response reports progress', async () => { + // Progress is read from the response itself: its lastUpdateID is past the ID the fetch was fired + // from, so this is not a stall even though nothing was applied yet. + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 200, lastUpdateID: 2, onyxData: []}; + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + expect(App.reconnectApp).not.toHaveBeenCalled(); + const fetchCalls = App.getMissingOnyxUpdates.mock.calls.length; + + OnyxUpdateManager.handleMissingOnyxUpdates(update5); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates.mock.calls.length).toBeGreaterThan(fetchCalls); + expect(App.reconnectApp).not.toHaveBeenCalled(); + }); + + it('should not escalate when the client advances through another path while the fetch is in flight', async () => { + // The response itself reports no progress, but a contiguous update advanced the client mid-fetch, + // so the next fetch fires from a new ID and the client can still catch up. + App.getMissingOnyxUpdates.mockImplementationOnce(async () => { + await Onyx.set(ONYXKEYS.ONYX_UPDATES_LAST_UPDATE_ID_APPLIED_TO_CLIENT, 2); + return {jsonCode: 200, onyxData: []}; + }); + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + + expect(App.reconnectApp).not.toHaveBeenCalled(); + }); + + it('should not escalate to ReconnectApp when the gap fetch fails', async () => { + // A failed fetch proves nothing about the server's ability to serve the range, so it must neither + // escalate nor latch the back-off: the next gap push retries the fetch as before. + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 407}; + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + expect(App.reconnectApp).not.toHaveBeenCalled(); + const fetchCallsAfterFailure = App.getMissingOnyxUpdates.mock.calls.length; + + OnyxUpdateManager.handleMissingOnyxUpdates(update5); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates.mock.calls.length).toBeGreaterThan(fetchCallsAfterFailure); + expect(App.reconnectApp).not.toHaveBeenCalled(); + }); + + it('should back off a pending-updates fetch that returns no progress', async () => { + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 200, onyxData: []}; + + OnyxUpdateManager.handleMissingOnyxUpdates(pendingUpdateUpTo2); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + + // The pending-updates branch fires the same fetch as the gap branch, so it must back off the same way. + OnyxUpdateManager.handleMissingOnyxUpdates(pendingUpdateUpTo3); + await OnyxUpdateManager.queryPromise; + expect(App.getMissingOnyxUpdates).toHaveBeenCalledTimes(1); + expect(App.reconnectApp).toHaveBeenCalledTimes(1); + }); + + it('should resume the SequentialQueue exactly once per backed-off gap push after escalating', async () => { + // Escalation itself is asserted in the escalate test; here it is only the setup for the unpause check. + App.mockValues.missingOnyxUpdatesResponse = {jsonCode: 200, onyxData: []}; + + OnyxUpdateManager.handleMissingOnyxUpdates(update3); + await OnyxUpdateManager.queryPromise; + + // The backed-off cycle must still finalize and resume the queue, or the app would freeze. + const unpauseSpy = jest.spyOn(SequentialQueue, 'unpause'); + OnyxUpdateManager.handleMissingOnyxUpdates(update5); + // queryPromise resolves on the first finalize, so drain microtasks first: a leaked second finalize + // would resume the queue a second time and must get the chance to surface before the assertion. + await OnyxUpdateManager.queryPromise; + await waitForBatchedUpdates(); + expect(unpauseSpy).toHaveBeenCalledTimes(1); + }); + it('should apply deferred updates after fetching pending updates', () => { App.mockValues.missingOnyxUpdatesToBeApplied = [update2, update3];