Merge pull request #43227 from Expensify/marcaaron-addLogsForSequenti…

…alQueueBackendReachability

Add logs for backend reachability and SequentialQueue

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,10 +27,11 @@ let isQueuePaused = false;
  */
 function pause() {
     if (isQueuePaused) {
+        Log.info('[SequentialQueue] Queue already paused');
         return;
     }
 
-    console.debug('[SequentialQueue] Pausing the queue');
+    Log.info('[SequentialQueue] Pausing the queue');
     isQueuePaused = true;
 }
 
@@ -40,6 +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) {
+        Log.info('[SequentialQueue] Queue already paused');
         return;
     }
     QueuedOnyxUpdates.flushQueue();
@@ -56,11 +59,18 @@ function flushOnyxUpdatesQueue() {
 function process(): Promise<void> {
     // 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) {
+        Log.info('[SequentialQueue] Unable to process. Queue is paused.');
+        return Promise.resolve();
+    }
+
+    if (NetworkStore.isOffline()) {
+        Log.info('[SequentialQueue] Unable to process. We are offline.');
         return Promise.resolve();
     }
 
     const persistedRequests = PersistedRequests.getAll();
-    if (persistedRequests.length === 0 || NetworkStore.isOffline()) {
+    if (persistedRequests.length === 0) {
+        Log.info('[SequentialQueue] Unable to process. No requests to process.');
         return Promise.resolve();
     }
 
@@ -72,6 +82,7 @@ function process(): Promise<void> {
             // 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) {
+                Log.info("[SequentialQueue] Handled 'shouldPauseQueue' in response. Pausing the queue.");
                 pause();
             }
             PersistedRequests.remove(requestToProcess);
@@ -102,16 +113,24 @@ function process(): Promise<void> {
 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) {
+        Log.info('[SequentialQueue] Unable to flush. Queue is paused.');
+        return;
+    }
+
+    if (isSequentialQueueRunning) {
+        Log.info('[SequentialQueue] Unable to flush. Queue is already running.');
         return;
     }
 
-    if (isSequentialQueueRunning || PersistedRequests.getAll().length === 0) {
+    if (PersistedRequests.getAll().length === 0) {
+        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()) {
+        Log.info('[SequentialQueue] Unable to flush. Client is not the leader.');
         return;
     }
 
@@ -128,6 +147,7 @@ function flush() {
         callback: () => {
             Onyx.disconnect(connectionID);
             process().finally(() => {
+                Log.info('[SequentialQueue] Finished processing queue.');
                 isSequentialQueueRunning = false;
                 if (NetworkStore.isOffline() || PersistedRequests.getAll().length === 0) {
                     resolveIsReadyPromise?.();
@@ -144,6 +164,7 @@ function flush() {
  */
 function unpause() {
     if (!isQueuePaused) {
+        Log.info('[SequentialQueue] Unable to unpause queue. We are already processing.');
         return;
     }
 

src/libs/NetworkConnection.ts

@@ -37,13 +37,13 @@ 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 = ''): 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)
     if (isOffline && !isCurrentlyOffline) {
-        NetworkActions.setIsBackendReachable(true);
+        NetworkActions.setIsBackendReachable(true, 'moved from offline to online');
         triggerReconnectionCallbacks('offline status changed');
     }
 
@@ -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,
@@ -122,20 +122,20 @@ function subscribeToBackendAndInternetReachability(): () => void {
             })
             .then((isBackendReachable: boolean) => {
                 if (isBackendReachable) {
-                    NetworkActions.setIsBackendReachable(true);
+                    NetworkActions.setIsBackendReachable(true, 'successfully completed API request');
                     return;
                 }
+                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);
-                    NetworkActions.setIsBackendReachable(false);
                 });
             })
             .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);
-                    NetworkActions.setIsBackendReachable(false);
                 });
             });
     }, CONST.NETWORK.BACKEND_CHECK_INTERVAL_MS);
@@ -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);
     });

src/libs/actions/Network.ts

@@ -1,12 +1,24 @@
 import Onyx from 'react-native-onyx';
+import Log from '@libs/Log';
 import type {NetworkStatus} from '@libs/NetworkConnection';
 import ONYXKEYS from '@src/ONYXKEYS';
 
-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});
 }
 
-function setIsOffline(isOffline: boolean) {
+function setIsOffline(isOffline: boolean, 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});
 }