From a6cafa066a60702ab3c2c43006e5fc60fb8639e0 Mon Sep 17 00:00:00 2001 From: Marc Glasser Date: Thu, 6 Jun 2024 11:34:26 -1000 Subject: [PATCH 1/8] Add logs for backend reachability and SequentialQueue --- src/libs/Network/SequentialQueue.ts | 24 ++++++++++++++++++++++-- src/libs/NetworkConnection.ts | 8 ++++---- src/libs/actions/Network.ts | 8 +++++++- 3 files changed, 33 insertions(+), 7 deletions(-) diff --git a/src/libs/Network/SequentialQueue.ts b/src/libs/Network/SequentialQueue.ts index b94166c0249d..91949b7933df 100644 --- a/src/libs/Network/SequentialQueue.ts +++ b/src/libs/Network/SequentialQueue.ts @@ -26,6 +26,7 @@ let isQueuePaused = false; */ function pause() { if (isQueuePaused) { + console.debug('[SequentialQueue] Queue already paused'); return; } @@ -40,6 +41,7 @@ function flushOnyxUpdatesQueue() { // The only situation where the queue is paused is if we found a gap between the app current data state and our server's. If that happens, // we'll trigger async calls to make the client updated again. While we do that, we don't want to insert anything in Onyx. if (isQueuePaused) { + console.debug('[SequentialQueue] Queue already paused'); return; } QueuedOnyxUpdates.flushQueue(); @@ -56,11 +58,18 @@ function flushOnyxUpdatesQueue() { function process(): Promise { // When the queue is paused, return early. This prevents any new requests from happening. The queue will be flushed again when the queue is unpaused. if (isQueuePaused) { + console.debug('[SequentialQueue] Unable to process. Queue is paused.'); + return Promise.resolve(); + } + + if (NetworkStore.isOffline()) { + console.debug('[SequentialQueue] Unable to process. We are offline.'); return Promise.resolve(); } const persistedRequests = PersistedRequests.getAll(); - if (persistedRequests.length === 0 || NetworkStore.isOffline()) { + if (persistedRequests.length === 0) { + console.debug('[SequentialQueue] Unable to process. No requests to process.'); return Promise.resolve(); } @@ -72,6 +81,7 @@ function process(): Promise { // A response might indicate that the queue should be paused. This happens when a gap in onyx updates is detected between the client and the server and // that gap needs resolved before the queue can continue. if (response?.shouldPauseQueue) { + console.debug('[SequentialQueue] Handled \'shouldPauseQueue\' in response. Pausing the queue.'); pause(); } PersistedRequests.remove(requestToProcess); @@ -102,16 +112,24 @@ function process(): Promise { function flush() { // When the queue is paused, return early. This will keep an requests in the queue and they will get flushed again when the queue is unpaused if (isQueuePaused) { + console.debug('[SequentialQueue] Unable to flush. Queue is paused.'); + return; + } + + if (isSequentialQueueRunning) { + console.debug('[SequentialQueue] Unable to flush. Queue is already running.'); return; } - if (isSequentialQueueRunning || PersistedRequests.getAll().length === 0) { + if (PersistedRequests.getAll().length === 0) { + console.debug('[SequentialQueue] Unable to flush. No requests to process.'); return; } // ONYXKEYS.PERSISTED_REQUESTS is shared across clients, thus every client/tab will have a copy // It is very important to only process the queue from leader client otherwise requests will be duplicated. if (!ActiveClientManager.isClientTheLeader()) { + console.debug('[SequentialQueue] Unable to flush. Client is not the leader.'); return; } @@ -128,6 +146,7 @@ function flush() { callback: () => { Onyx.disconnect(connectionID); process().finally(() => { + console.debug('[SequentialQueue] Finished processing queue.'); isSequentialQueueRunning = false; resolveIsReadyPromise?.(); currentRequest = null; @@ -142,6 +161,7 @@ function flush() { */ function unpause() { if (!isQueuePaused) { + console.debug('[SequentialQueue] Unable to unpause queue. We are already processing.'); return; } diff --git a/src/libs/NetworkConnection.ts b/src/libs/NetworkConnection.ts index b3dd24fcd4ae..b6a1481224de 100644 --- a/src/libs/NetworkConnection.ts +++ b/src/libs/NetworkConnection.ts @@ -43,7 +43,7 @@ function setOfflineStatus(isCurrentlyOffline: boolean): void { // When reconnecting, ie, going from offline to online, all the reconnection callbacks // are triggered (this is usually Actions that need to re-download data from the server) if (isOffline && !isCurrentlyOffline) { - NetworkActions.setIsBackendReachable(true); + NetworkActions.setIsBackendReachable(true, 'moved from offline to online'); triggerReconnectionCallbacks('offline status changed'); } @@ -118,20 +118,20 @@ function subscribeToBackendAndInternetReachability(): () => void { }) .then((isBackendReachable: boolean) => { if (isBackendReachable) { - NetworkActions.setIsBackendReachable(true); + NetworkActions.setIsBackendReachable(true, 'successfully completed API request'); return; } checkInternetReachability().then((isInternetReachable: boolean) => { setOfflineStatus(!isInternetReachable); setNetWorkStatus(isInternetReachable); - NetworkActions.setIsBackendReachable(false); + NetworkActions.setIsBackendReachable(false, 'request succeeded, but internet reachability test failed'); }); }) .catch(() => { checkInternetReachability().then((isInternetReachable: boolean) => { setOfflineStatus(!isInternetReachable); setNetWorkStatus(isInternetReachable); - NetworkActions.setIsBackendReachable(false); + NetworkActions.setIsBackendReachable(false, 'request failed and internet reachability test failed'); }); }); }, CONST.NETWORK.BACKEND_CHECK_INTERVAL_MS); diff --git a/src/libs/actions/Network.ts b/src/libs/actions/Network.ts index 9c88403b0e98..2e5ef5b605f7 100644 --- a/src/libs/actions/Network.ts +++ b/src/libs/actions/Network.ts @@ -1,8 +1,14 @@ import Onyx from 'react-native-onyx'; import type {NetworkStatus} from '@libs/NetworkConnection'; import ONYXKEYS from '@src/ONYXKEYS'; +import Log from '@libs/Log'; -function setIsBackendReachable(isBackendReachable: boolean) { +function setIsBackendReachable(isBackendReachable: boolean, reason: string) { + if (isBackendReachable) { + Log.info(`[Network] Backend is reachable because: ${reason}`); + } else { + Log.info(`[Network] Backend is not reachable because: ${reason}`); + } Onyx.merge(ONYXKEYS.NETWORK, {isBackendReachable}); } From 69a4c79dfc9eefafd152e48cf9c0fafea69b1b70 Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 12:44:39 -0600 Subject: [PATCH 2/8] Prettier --- src/libs/Network/SequentialQueue.ts | 2 +- src/libs/actions/Network.ts | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/src/libs/Network/SequentialQueue.ts b/src/libs/Network/SequentialQueue.ts index f27c89a47f72..43d9bc26e347 100644 --- a/src/libs/Network/SequentialQueue.ts +++ b/src/libs/Network/SequentialQueue.ts @@ -81,7 +81,7 @@ function process(): Promise { // A response might indicate that the queue should be paused. This happens when a gap in onyx updates is detected between the client and the server and // that gap needs resolved before the queue can continue. if (response?.shouldPauseQueue) { - console.debug('[SequentialQueue] Handled \'shouldPauseQueue\' in response. Pausing the queue.'); + console.debug("[SequentialQueue] Handled 'shouldPauseQueue' in response. Pausing the queue."); pause(); } PersistedRequests.remove(requestToProcess); diff --git a/src/libs/actions/Network.ts b/src/libs/actions/Network.ts index 2e5ef5b605f7..90d4649311d9 100644 --- a/src/libs/actions/Network.ts +++ b/src/libs/actions/Network.ts @@ -1,7 +1,7 @@ import Onyx from 'react-native-onyx'; +import Log from '@libs/Log'; import type {NetworkStatus} from '@libs/NetworkConnection'; import ONYXKEYS from '@src/ONYXKEYS'; -import Log from '@libs/Log'; function setIsBackendReachable(isBackendReachable: boolean, reason: string) { if (isBackendReachable) { From 4f8ec01a36a821009c2c2b473669393aa1c7a2d8 Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 12:53:08 -0600 Subject: [PATCH 3/8] Change debug to logs --- src/libs/Network/SequentialQueue.ts | 27 ++++++++++++++------------- 1 file changed, 14 insertions(+), 13 deletions(-) diff --git a/src/libs/Network/SequentialQueue.ts b/src/libs/Network/SequentialQueue.ts index 43d9bc26e347..10df3c703c92 100644 --- a/src/libs/Network/SequentialQueue.ts +++ b/src/libs/Network/SequentialQueue.ts @@ -1,5 +1,6 @@ import Onyx from 'react-native-onyx'; import * as ActiveClientManager from '@libs/ActiveClientManager'; +import Log from '@libs/Log'; import * as Request from '@libs/Request'; import * as RequestThrottle from '@libs/RequestThrottle'; import * as PersistedRequests from '@userActions/PersistedRequests'; @@ -26,11 +27,11 @@ let isQueuePaused = false; */ function pause() { if (isQueuePaused) { - console.debug('[SequentialQueue] Queue already paused'); + Log.info('[SequentialQueue] Queue already paused'); return; } - console.debug('[SequentialQueue] Pausing the queue'); + Log.info('[SequentialQueue] Pausing the queue'); isQueuePaused = true; } @@ -41,7 +42,7 @@ function flushOnyxUpdatesQueue() { // The only situation where the queue is paused is if we found a gap between the app current data state and our server's. If that happens, // we'll trigger async calls to make the client updated again. While we do that, we don't want to insert anything in Onyx. if (isQueuePaused) { - console.debug('[SequentialQueue] Queue already paused'); + Log.info('[SequentialQueue] Queue already paused'); return; } QueuedOnyxUpdates.flushQueue(); @@ -58,18 +59,18 @@ function flushOnyxUpdatesQueue() { function process(): Promise { // When the queue is paused, return early. This prevents any new requests from happening. The queue will be flushed again when the queue is unpaused. if (isQueuePaused) { - console.debug('[SequentialQueue] Unable to process. Queue is paused.'); + Log.info('[SequentialQueue] Unable to process. Queue is paused.'); return Promise.resolve(); } if (NetworkStore.isOffline()) { - console.debug('[SequentialQueue] Unable to process. We are offline.'); + Log.info('[SequentialQueue] Unable to process. We are offline.'); return Promise.resolve(); } const persistedRequests = PersistedRequests.getAll(); if (persistedRequests.length === 0) { - console.debug('[SequentialQueue] Unable to process. No requests to process.'); + Log.info('[SequentialQueue] Unable to process. No requests to process.'); return Promise.resolve(); } @@ -81,7 +82,7 @@ function process(): Promise { // A response might indicate that the queue should be paused. This happens when a gap in onyx updates is detected between the client and the server and // that gap needs resolved before the queue can continue. if (response?.shouldPauseQueue) { - console.debug("[SequentialQueue] Handled 'shouldPauseQueue' in response. Pausing the queue."); + Log.info("[SequentialQueue] Handled 'shouldPauseQueue' in response. Pausing the queue."); pause(); } PersistedRequests.remove(requestToProcess); @@ -112,24 +113,24 @@ function process(): Promise { function flush() { // When the queue is paused, return early. This will keep an requests in the queue and they will get flushed again when the queue is unpaused if (isQueuePaused) { - console.debug('[SequentialQueue] Unable to flush. Queue is paused.'); + Log.info('[SequentialQueue] Unable to flush. Queue is paused.'); return; } if (isSequentialQueueRunning) { - console.debug('[SequentialQueue] Unable to flush. Queue is already running.'); + Log.info('[SequentialQueue] Unable to flush. Queue is already running.'); return; } if (PersistedRequests.getAll().length === 0) { - console.debug('[SequentialQueue] Unable to flush. No requests to process.'); + Log.info('[SequentialQueue] Unable to flush. No requests to process.'); return; } // ONYXKEYS.PERSISTED_REQUESTS is shared across clients, thus every client/tab will have a copy // It is very important to only process the queue from leader client otherwise requests will be duplicated. if (!ActiveClientManager.isClientTheLeader()) { - console.debug('[SequentialQueue] Unable to flush. Client is not the leader.'); + Log.info('[SequentialQueue] Unable to flush. Client is not the leader.'); return; } @@ -146,7 +147,7 @@ function flush() { callback: () => { Onyx.disconnect(connectionID); process().finally(() => { - console.debug('[SequentialQueue] Finished processing queue.'); + Log.info('[SequentialQueue] Finished processing queue.'); isSequentialQueueRunning = false; if (NetworkStore.isOffline() || PersistedRequests.getAll().length === 0) { resolveIsReadyPromise?.(); @@ -163,7 +164,7 @@ function flush() { */ function unpause() { if (!isQueuePaused) { - console.debug('[SequentialQueue] Unable to unpause queue. We are already processing.'); + Log.info('[SequentialQueue] Unable to unpause queue. We are already processing.'); return; } From ed85fecf451ea05ba647bfae8134a6d7e273f111 Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 12:53:19 -0600 Subject: [PATCH 4/8] Move check outside of promise --- src/libs/NetworkConnection.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/libs/NetworkConnection.ts b/src/libs/NetworkConnection.ts index 0aa3f224858d..897b947e6815 100644 --- a/src/libs/NetworkConnection.ts +++ b/src/libs/NetworkConnection.ts @@ -125,17 +125,17 @@ function subscribeToBackendAndInternetReachability(): () => void { NetworkActions.setIsBackendReachable(true, 'successfully completed API request'); return; } + NetworkActions.setIsBackendReachable(false, 'request succeeded, but internet reachability test failed'); checkInternetReachability().then((isInternetReachable: boolean) => { setOfflineStatus(!isInternetReachable); setNetWorkStatus(isInternetReachable); - NetworkActions.setIsBackendReachable(false, 'request succeeded, but internet reachability test failed'); }); }) .catch(() => { + NetworkActions.setIsBackendReachable(false, 'request failed and internet reachability test failed'); checkInternetReachability().then((isInternetReachable: boolean) => { setOfflineStatus(!isInternetReachable); setNetWorkStatus(isInternetReachable); - NetworkActions.setIsBackendReachable(false, 'request failed and internet reachability test failed'); }); }); }, CONST.NETWORK.BACKEND_CHECK_INTERVAL_MS); From 98e2e5bf8f931ea82e2f2b2e2c3bf7397dc5cddc Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 13:00:34 -0600 Subject: [PATCH 5/8] Add more logs for when going offline --- src/libs/NetworkConnection.ts | 14 +++++++------- src/libs/actions/Network.ts | 7 ++++++- 2 files changed, 13 insertions(+), 8 deletions(-) diff --git a/src/libs/NetworkConnection.ts b/src/libs/NetworkConnection.ts index 897b947e6815..60f838759ef9 100644 --- a/src/libs/NetworkConnection.ts +++ b/src/libs/NetworkConnection.ts @@ -37,8 +37,8 @@ const triggerReconnectionCallbacks = throttle( * Called when the offline status of the app changes and if the network is "reconnecting" (going from offline to online) * then all of the reconnection callbacks are triggered */ -function setOfflineStatus(isCurrentlyOffline: boolean): void { - NetworkActions.setIsOffline(isCurrentlyOffline); +function setOfflineStatus(isCurrentlyOffline: boolean, reason: string): void { + NetworkActions.setIsOffline(isCurrentlyOffline, reason); // When reconnecting, ie, going from offline to online, all the reconnection callbacks // are triggered (this is usually Actions that need to re-download data from the server) @@ -74,13 +74,13 @@ Onyx.connect({ } shouldForceOffline = currentShouldForceOffline; if (shouldForceOffline) { - setOfflineStatus(true); + setOfflineStatus(true, 'shouldForceOffline was detected in the Onyx data'); Log.info(`[NetworkStatus] Setting "offlineStatus" to "true" because user is under force offline`); } else { // If we are no longer forcing offline fetch the NetInfo to set isOffline appropriately NetInfo.fetch().then((state) => { const isInternetReachable = !!state.isInternetReachable; - setOfflineStatus(isInternetReachable); + setOfflineStatus(isInternetReachable, 'NetInfo checked if the internet is reachable'); Log.info( `[NetworkStatus] The force-offline mode was turned off. Getting the device network status from NetInfo. Network state: ${JSON.stringify( state, @@ -127,14 +127,14 @@ function subscribeToBackendAndInternetReachability(): () => void { } NetworkActions.setIsBackendReachable(false, 'request succeeded, but internet reachability test failed'); checkInternetReachability().then((isInternetReachable: boolean) => { - setOfflineStatus(!isInternetReachable); + setOfflineStatus(!isInternetReachable, 'checkInternetReachability was called after api/ping returned a non-200 jsonCode'); setNetWorkStatus(isInternetReachable); }); }) .catch(() => { NetworkActions.setIsBackendReachable(false, 'request failed and internet reachability test failed'); checkInternetReachability().then((isInternetReachable: boolean) => { - setOfflineStatus(!isInternetReachable); + setOfflineStatus(!isInternetReachable, 'checkInternetReachability was called after api/ping request failed'); setNetWorkStatus(isInternetReachable); }); }); @@ -163,7 +163,7 @@ function subscribeToNetworkStatus(): () => void { Log.info('[NetworkConnection] Not setting offline status because shouldForceOffline = true'); return; } - setOfflineStatus(state.isInternetReachable === false); + setOfflineStatus(state.isInternetReachable === false, 'NetInfo received a state change event'); Log.info(`[NetworkStatus] NetInfo.addEventListener event coming, setting "offlineStatus" to ${!!state.isInternetReachable} with network state: ${JSON.stringify(state)}`); setNetWorkStatus(state.isInternetReachable); }); diff --git a/src/libs/actions/Network.ts b/src/libs/actions/Network.ts index 90d4649311d9..6bb0b9454012 100644 --- a/src/libs/actions/Network.ts +++ b/src/libs/actions/Network.ts @@ -12,7 +12,12 @@ function setIsBackendReachable(isBackendReachable: boolean, reason: string) { Onyx.merge(ONYXKEYS.NETWORK, {isBackendReachable}); } -function setIsOffline(isOffline: boolean) { +function setIsOffline(isOffline: boolean, reason: string) { + if (isOffline) { + Log.info(`[Network] Client is entering offline mode because: ${reason}`); + } else { + Log.info(`[Network] Client is back online because: ${reason}`); + } Onyx.merge(ONYXKEYS.NETWORK, {isOffline}); } From e404d1c9803a7d73fe748a981e81da5055a6b07f Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 13:12:09 -0600 Subject: [PATCH 6/8] Default reason to a blank screen --- src/libs/actions/Network.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libs/actions/Network.ts b/src/libs/actions/Network.ts index 6bb0b9454012..5f9600818b2d 100644 --- a/src/libs/actions/Network.ts +++ b/src/libs/actions/Network.ts @@ -12,7 +12,7 @@ function setIsBackendReachable(isBackendReachable: boolean, reason: string) { Onyx.merge(ONYXKEYS.NETWORK, {isBackendReachable}); } -function setIsOffline(isOffline: boolean, reason: string) { +function setIsOffline(isOffline: boolean, reason = '') { if (isOffline) { Log.info(`[Network] Client is entering offline mode because: ${reason}`); } else { From cfb586c61b16b5c81a2d6aeeaf3e1ea5b0c94e8e Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 13:13:48 -0600 Subject: [PATCH 7/8] Restructure logic for optional reason --- src/libs/actions/Network.ts | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/libs/actions/Network.ts b/src/libs/actions/Network.ts index 5f9600818b2d..883e336d6c90 100644 --- a/src/libs/actions/Network.ts +++ b/src/libs/actions/Network.ts @@ -13,10 +13,11 @@ function setIsBackendReachable(isBackendReachable: boolean, reason: string) { } function setIsOffline(isOffline: boolean, reason = '') { - if (isOffline) { - Log.info(`[Network] Client is entering offline mode because: ${reason}`); - } else { - Log.info(`[Network] Client is back online because: ${reason}`); + if (reason) { + let textToLog = '[Network] Client is'; + textToLog += isOffline ? ' entering offline mode' : ' back online'; + textToLog += ` because: ${reason}`; + Log.info(textToLog); } Onyx.merge(ONYXKEYS.NETWORK, {isOffline}); } From 41ff6a2f873ef7b7648d01cdd4d2ae9221622aa1 Mon Sep 17 00:00:00 2001 From: Tim Golen Date: Fri, 7 Jun 2024 13:30:58 -0600 Subject: [PATCH 8/8] Fix another default variable --- src/libs/NetworkConnection.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/libs/NetworkConnection.ts b/src/libs/NetworkConnection.ts index 60f838759ef9..de064441047a 100644 --- a/src/libs/NetworkConnection.ts +++ b/src/libs/NetworkConnection.ts @@ -37,7 +37,7 @@ const triggerReconnectionCallbacks = throttle( * Called when the offline status of the app changes and if the network is "reconnecting" (going from offline to online) * then all of the reconnection callbacks are triggered */ -function setOfflineStatus(isCurrentlyOffline: boolean, reason: string): void { +function setOfflineStatus(isCurrentlyOffline: boolean, reason = ''): void { NetworkActions.setIsOffline(isCurrentlyOffline, reason); // When reconnecting, ie, going from offline to online, all the reconnection callbacks