[$4000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out #7424

kavimuru · 2022-01-26T18:08:21Z

If you haven’t already, check out our contributing guidelines for onboarding and email contributors@expensify.com to request to join our Slack channel!

Action Performed:

Launch the app
Log in with applausetester+0901abb@applause.expensifail.com
In LHN find the user applausetester+1226abb@applause.expensifail.com
Send Message to applausetester+1226abb@applause.expensifail.com
Go to Setting and log out
Leave the New Expensify app for about 10-15 minutes
Back again to New Expensify app and log in with applausetester+0901abb@applause.expensifail.com

Expected Result:

Log in with account

Actual Result:

Infinite loading when left app idle for 10 min after logout

Workaround:

Unknown

Platform:

Where is this issue occurring?

Android

Version Number: 1.1.33.2
Reproducible in staging?: Yes
Reproducible in production?: No
Logs: https://stackoverflow.com/c/expensify/questions/4856
Notes/Photos/Videos:
Expensify/Expensify Issue URL:

Bug5424233_Screen_Recording_20220126-124622_New_Expensify.mp4

Issue reported by: Applause
Slack conversation:

View all open jobs on GitHub

OSBotify · 2022-01-26T18:09:10Z

👋 Friendly reminder that deploy blockers are time-sensitive ⏱ issues! Check out the open StagingDeployCash deploy checklist to see the list of PRs included in this release, then work quickly to do one of the following:

Identify the pull request that introduced this issue and revert it.
Find someone who can quickly fix the issue.
Fix the issue yourself.

MelvinBot · 2022-01-26T18:09:12Z

Triggered auto assignment to @thienlnam (Engineering), see https://stackoverflow.com/c/expensify/questions/4319 for more details.

thienlnam · 2022-01-26T18:54:56Z

Looking into logs and recent issues that might have caused this, seeing a couple things in logs

https://staging.expensify.com/_devportal/tools/logSearch/#query=request_id:(%226d357ba62909ebe8-BOS%22)+AND+timestamp:[2022-01-25T23:04:17.301Z+TO+2022-01-26T01:04:17.301Z]&index=logs_expensify-015005

 User tried to get a policy they have no access to ~~ policyID: '_FAKE_'

Also considering it's loading spinner it seems like it is related to Onyx stuff
https://staging.expensify.com/_devportal/tools/logSearch/#query=request_id:(%226d357707afedebe8-DEN%22)+AND+timestamp:[2022-01-25T23:01:07.894Z+TO+2022-01-26T01:01:07.894Z]&index=logs_expensify-015005

thienlnam · 2022-01-26T18:57:18Z

Looks like this is most likely related - cc @luacmartins
#7397

luacmartins · 2022-01-26T19:13:18Z

It could be, but seems kind of odd. Have you been able to reproduce this on dev?

thienlnam · 2022-01-26T19:37:10Z

Agreed, I'm not able to get my android simulator working right now so unfortunately not. There have also been a couple Onyx updates that could be the problem but this one seemed most related to the sign in / sign out flow

thienlnam · 2022-01-26T20:27:41Z

@kavimuru Could you please try to reproduce this? I'm having issues with my dev and wanted to make sure it is happening consistently and is not a one-off

thienlnam · 2022-01-27T01:39:49Z

~~Looks like the only tester with Android 12 was able to reproduce this~~
https://expensify.slack.com/archives/C01GTK53T8Q/p1643242758028500?thread_ts=1643238659.022300&cid=C01GTK53T8Q

EDIT: Looks like it was also reproducible on A11 so it is not OS specific

thienlnam · 2022-01-27T22:45:49Z

Looking into logs on the account applausetester+0901abb@applause.expensifail.com -

From the video it looks like we aren't even getting to the splash screen so I've narrowed it down to a couple of areas
Slash screen status:

App/src/Expensify.js

Lines 163 to 176 in 45f5e38

    
           reportBootSplashStatus() { 
        
               BootSplash 
        
                   .getVisibilityStatus() 
        
                   .then((status) => { 
        
                       const appState = AppState.currentState; 
        
                       Log.info('[BootSplash] splash screen status', false, {appState, status}); 
        
                       if (status === 'visible') { 
        
                           const props = _.omit(this.props, ['children', 'session']); 
        
                           props.isAuthenticated = this.isAuthenticated(); 
        
                           Log.alert('[BootSplash] splash screen is still visible', {props}, false); 
        
                       } 
        
                   }); 
        
           }

or some kind of error in the app init that causes us to hide the splash screen

App/src/components/ErrorBoundary/BaseErrorBoundary.js

Lines 38 to 43 in 45f5e38

    
           componentDidCatch(error, errorInfo) { 
        
               this.props.logError(this.props.errorMessage, error, errorInfo); 
        
               // We hide the splash screen since the error might happened during app init 
        
               BootSplash.hide(); 
        
           }

thienlnam · 2022-01-27T22:46:47Z

The only issues on the checklist that we've merged that seems to possibly be related would be
Onyx updates cc @kidroca, any idea on this?
And this #7397 but that doesn't seem to make much sense

kidroca · 2022-01-28T17:41:40Z

@thienlnam I'll take a look when I can

mvtglobally · 2022-01-28T19:24:19Z

Issue is not consistently repro for everyone. but we were able to repro with 2 different tester/devices

sketchydroide · 2022-01-31T12:12:47Z

This is currently a blocker for the deployment, any updates?

kidroca · 2022-01-31T13:15:23Z

I couldn't recreate on emulator with my dev test accounts (Android 10)
I've noticed posting a comment has some kind of lag and I'm following that

thienlnam · 2022-01-31T18:56:57Z

It's not a consistently produceable issue, so I'm not sure if it is a blocker. Can't tell if this is also re-produceable in production

sketchydroide · 2022-01-31T19:04:13Z

I just tried on my device, and was unable to replicate, my version was 1.1.33-3 though. Not sure if that is important.
I tend to agree with @thienlnam, this might not be a blocker
@mvtglobally can we test for 1.1.33-3 as well just to make sure 🙏🏼 thanks

mvtglobally · 2022-01-31T20:23:03Z

@sketchydroide we are checking new build

mvtglobally · 2022-01-31T21:20:34Z

@sketchydroide @thienlnam out of 6 testers 3 were able to repro on the latest build.

Additional accounts used to validate
applausetester+0524@applause.expensifail.com
applausetester+2501mn@applause.expensifail.com

Screen_Recording_20220131-154042_New.Expensify.mp4

screen-20220131-160138.1.mp4

mvtglobally · 2022-02-01T14:49:14Z

@kidroca any discoveries?

@AndrewGable @thienlnam, @sketchydroide it has been 7 days since last deploy. Anything can be done to expedite or downgrade this issue?

roryabraham · 2022-02-01T17:34:51Z

Talked with @thienlnam about this and we're going to demote it from deploy blocker to regular bug. Since we can't reproduce it, we won't be able to quickly fix it, and we don't want to continue holding up the deploy. @mvtglobally Please add this to weekly KI retests.

Also, let's make this external and get more eyes on it? It seems likely that it's related to Onyx or network code, so seems like something in @kidroca's wheelhouse.

kidroca · 2022-02-01T18:46:00Z

Just saw this getting deployed to production: #7370 (comment)

it was related to infinite loading when null was set on Onyx affecting iOS and Android

It could be related, though I see that the issue is reported to be seen in staging and not prod

marcaaron · 2022-04-21T17:43:44Z

Not much other context, but based on where it's located - the reports either never loaded for these users or there was an issue processing the response. Will try to see if there are any stalled network requests.

mallenexpensify · 2022-04-21T21:59:36Z

@parasharrajat hired you for C+ compensation for reviewing @kidroca 's PR that he got compensated for. Can you please accept the offer I sent? https://www.upwork.com/jobs/~01bea655d1a3ea7f17

kadiealexander · 2022-04-22T05:21:34Z

@thienlnam do you think we have enough context from the logs to put this back into the Help Wanted pool as Rajat suggested?

thienlnam · 2022-04-22T18:49:56Z

@kadiealexander Yeah let's put this back in the Help Wanted pool. We have some logs as Marc posted that may help provide some information that can be used as a starting point for an investigation. I'll continue posting new logs weekly.

jliexpensify · 2022-04-24T23:26:47Z

Added the label!

thienlnam · 2022-05-02T18:50:09Z

Logs look the same as the last ones Marc posted.
Main Drawer Loader with no reportID

jliexpensify · 2022-05-03T06:47:51Z

@thienlnam - should we double the $?

luacmartins · 2022-05-03T14:21:19Z

@thienlnam I think I managed to reproduce this today on iOS dev while testing an unrelated PR. Sorry if this is already known, I just quickly skimmed through this conversation. Steps:

Log into the app
Kill wifi connection
Reconnect to wifi
Logout
Log back in
Infinite loading spinner shows up and we hit the log line above on time out with no reportID.

video.mov

Logs:

 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [info] Finished API request - {"command":"Get","shouldUseSecure":false,"returnValueList":"personalDetailsList","jsonCode":200,"requestID":"ux5H2T"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [info] Finished API request - {"command":"GetRequestCountryCode","shouldUseSecure":false,"jsonCode":200,"requestID":"m23j1v"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"GetRequestCountryCode","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [info] Finished API request - {"command":"Get","shouldUseSecure":false,"returnValueList":"chatList","jsonCode":200,"requestID":"W8Flia"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [Network] There was an error in the Log API command, unable to log to server! [Error: Unable to reauthenticate because we are offline]
 DEBUG  [info] Finished API request - {"command":"Get","shouldUseSecure":false,"returnValueList":"nameValuePairs","jsonCode":200,"requestID":"bn8gYg"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [info] Finished API request - {"command":"Get","shouldUseSecure":false,"returnValueList":"nameValuePairs","jsonCode":200,"requestID":"gB3vKx"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 DEBUG  [info] Finished API request - {"command":"Get","shouldUseSecure":false,"returnValueList":"nameValuePairs","jsonCode":200,"requestID":"7gNyql"}
 DEBUG  [info] [Network] A retryable request failed - {"retryCount":1,"command":"Get","error":"Unable to reauthenticate because we are offline"}
 WARN  Possible Unhandled Promise Rejection (id: 0):
Error: session.offlineMessageRetry
Error: session.offlineMessageRetry
    at anonymous (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:196503:31)
    at tryCallOne (/Users/distiller/hermes/build_iphonesimulator/lib/InternalBytecode/InternalBytecode.js:53:16)
    at anonymous (/Users/distiller/hermes/build_iphonesimulator/lib/InternalBytecode/InternalBytecode.js:139:27)
    at apply (native)
    at anonymous (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:29830:26)
    at _callTimer (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:29726:17)
    at _callReactNativeMicrotasksPass (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:29765:17)
    at callReactNativeMicrotasks (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:29975:44)
    at __callReactNativeMicrotasks (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:5837:46)
    at anonymous (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:5615:45)
    at __guard (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:5820:15)
    at flushedQueue (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:5614:21)
    at invokeCallbackAndReturnFlushedQueue (http://localhost:8081/index.bundle?platform=ios&dev=true&minify=false&modulesOnly=false&runModule=true&app=com.chat.expensify.chat:5607:33)
 DEBUG  [alrt] ENSURE_BUGBOT [LoadingIndicator] Visible after timeout - {"timeout":15000,"name":"Main Drawer Loader","initialParams":{"reportID":""}}

parasharrajat · 2022-05-03T14:33:04Z

Nice catch.

thienlnam · 2022-05-03T17:40:16Z

@jliexpensify Let's double this bounty

@luacmartins Awesome, that's super helpful - added it to the OP to help others reproduce

marcaaron · 2022-05-03T17:57:04Z

Just want to add that if we think this is related to the retry logic (looks like @luacmartins comments suggests it could be) then we should not accept any proposals to change it as we're in the midst of overhauling the entire system.

kidroca · 2022-05-03T19:12:00Z

Following the shared steps #7424 (comment)

For some reason [NetworkConnection] event is falsely triggered after login even though we're online

[info] [NetworkConnection] NetInfo state change - {"type":"none","isConnected":false,"details":{},"isInternetReachable":false}

This prevent further network calls and we never fully fetch report data
There's no other [NetworkConnection] event to tell us we're online

This seems to be a simulator only thing as it's not recreatable on physical device
Note how the dot stays gray after you disconnect and reconnect the wifi (e.g. reconnecting is not detected)
On a physical device the dot becomes green again as soon as you reconnect

kidroca · 2022-05-03T19:35:16Z

From logs it looks like the most likely cause of the infinite spinner is not having reports loaded:

App/src/libs/Navigation/AppNavigator/MainDrawerNavigator.js

Lines 51 to 53 in db7c93f

    
           if (!initialParams.reportID) { 
        
               return <FullScreenLoadingIndicator logDetail={{name: 'Main Drawer Loader', initialParams}} />; 
        
           }

Is there a way to cross reference the logs for some chatList requests that fail or result in a non 200 code here:

App/src/libs/actions/Report.js

Lines 1000 to 1007 in 3fc95c6

    
           Onyx.set(ONYXKEYS.IS_LOADING_REPORT_DATA, true); 
        
           return API.Get({ 
        
               returnValueList: 'chatList', 
        
           }) 
        
               .then((response) => { 
        
                   if (response.jsonCode !== 200) { 
        
                       return; 
        
                   }

And/or some errors along the way that prevented to merge (or have) reports here:

App/src/libs/actions/Report.js

Line 422 in 3fc95c6

Onyx.mergeCollection(ONYXKEYS.COLLECTION.REPORT, simplifiedReports);

If that line of code is never reached we'll be stuck on the spinner.

kidroca · 2022-05-03T19:46:05Z

Since after login we're starting with a clean Onyx state, this network call is essential to init and we need to do something to handle it better, because without it there are no reports and no sidebar

we need to handle the non 200 case
we need to handle the spotty or no connection case during login (e.g. we didn't fetch any reports even after 10 retries)
something else?

Maybe we could use the MainDrawer loading indicator here

App/src/libs/Navigation/AppNavigator/MainDrawerNavigator.js

Lines 51 to 53 in db7c93f

    
           if (!initialParams.reportID) { 
        
               return <FullScreenLoadingIndicator logDetail={{name: 'Main Drawer Loader', initialParams}} />; 
        
           }

and enhance it with a onTimeout prop
The onTimeout callback will be triggered when the loader has been visible for unreasonable amount of time (15 sec.)
We can use it to:

prompt the user: "You appear to be stuck loading, do you want to try again?"
- automatically dismiss the prompt if the loader disappears in the meantime
or don't prompt but take automatic action - if you're stuck on that loader re-init App

Pros:

easy to implement
better experience than being stuck

Cons:

sounds like it doesn't solve the root problem
it might false-positively re-init app on slower connections (though this is only for logins)

Maybe we can come up with something better, if the logs review more leads

kadiealexander · 2022-05-03T21:56:32Z

Doubled the job listed here, get those proposals in!

marcaaron · 2022-05-03T22:03:50Z

NetInfo has a known bug on iOS simulator so I'm not sure if I trust that what @luacmartins found is related at all.

Is there a way to cross reference the logs for some chatList requests that fail or result in a non 200 code here:

Yes we can do this. When I looked last time nothing jumped out at me and the requests were returning 200

kadiealexander · 2022-05-11T01:53:25Z

Job doubled here, please get your proposals in!

https://www.upwork.com/ab/applicants/1515835444097523712/job-details
https://www.upwork.com/jobs/~01bea655d1a3ea7f17

mvtglobally · 2022-05-17T03:17:10Z

Issue not reproducible during KI retests. (First week)

parasharrajat · 2022-05-17T10:58:25Z

Interesting ⬆️

marcaaron · 2022-05-17T18:05:07Z

Maybe we should close this issue and reopen it if it's still a problem? Don't really see why we would keep doubling the price of an issue that has no reproduction and isn't happening consistently... but that's just me... 🙃

parasharrajat · 2022-05-20T19:31:06Z

@mallenexpensify This is still pending. Thank you. I applied to the job.

mallenexpensify · 2022-05-23T18:52:23Z

I'm a lil confused, want to confirm

@parasharrajat you're due $250 for help on this issue or PR, correct?
@kidroca are you do payment?!??! Or did work hourly? If payment is due, how much?

parasharrajat · 2022-05-23T18:52:48Z

yes

mallenexpensify · 2022-05-23T18:56:35Z

Paid @parasharrajat $250, thanks for the help!

kidroca · 2022-05-24T05:38:22Z

@mallenexpensify
No payment is due for me

mallenexpensify · 2022-05-24T17:31:03Z

Thanks @kidroca . Issue is already closed so... 👋

kavimuru added the DeployBlockerCash This issue or pull request should block deployment label Jan 26, 2022

OSBotify mentioned this issue Jan 26, 2022

Deploy Checklist: New Expensify 2022-01-25 #7395

Closed

46 tasks

github-actions bot added Engineering Hourly KSv2 labels Jan 26, 2022

MelvinBot assigned thienlnam Jan 26, 2022

thienlnam added the Needs Reproduction Reproducible steps needed label Jan 31, 2022

roryabraham added Daily KSv2 and removed DeployBlockerCash This issue or pull request should block deployment Hourly KSv2 labels Feb 1, 2022

jliexpensify added the Help Wanted Apply this label when an issue is open to proposals by contributors label Apr 24, 2022

kadiealexander changed the title ~~[$1000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out~~ [$2000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out May 3, 2022

kadiealexander changed the title ~~[$2000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out~~ [$4000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out May 11, 2022

thienlnam closed this as completed May 17, 2022

[$4000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out #7424

[$4000] Android - Infinite loading spinner appears when sign in to the app leaving idle for 10 min after sign out #7424

Comments

kavimuru commented Jan 26, 2022 • edited by marcaaron Loading

Action Performed:

Expected Result:

Actual Result:

Workaround:

Platform:

OSBotify commented Jan 26, 2022

MelvinBot commented Jan 26, 2022

thienlnam commented Jan 26, 2022

thienlnam commented Jan 26, 2022

luacmartins commented Jan 26, 2022

thienlnam commented Jan 26, 2022

thienlnam commented Jan 26, 2022

thienlnam commented Jan 27, 2022 • edited Loading

thienlnam commented Jan 27, 2022

thienlnam commented Jan 27, 2022

kidroca commented Jan 28, 2022

mvtglobally commented Jan 28, 2022

sketchydroide commented Jan 31, 2022

kidroca commented Jan 31, 2022

thienlnam commented Jan 31, 2022

sketchydroide commented Jan 31, 2022

mvtglobally commented Jan 31, 2022

mvtglobally commented Jan 31, 2022

mvtglobally commented Feb 1, 2022 • edited Loading

roryabraham commented Feb 1, 2022 • edited Loading

kidroca commented Feb 1, 2022

marcaaron commented Apr 21, 2022

mallenexpensify commented Apr 21, 2022

kadiealexander commented Apr 22, 2022 • edited Loading

thienlnam commented Apr 22, 2022

jliexpensify commented Apr 24, 2022

thienlnam commented May 2, 2022

jliexpensify commented May 3, 2022

luacmartins commented May 3, 2022 • edited Loading

parasharrajat commented May 3, 2022

thienlnam commented May 3, 2022

marcaaron commented May 3, 2022

kidroca commented May 3, 2022 • edited Loading

kidroca commented May 3, 2022

kidroca commented May 3, 2022

kadiealexander commented May 3, 2022

marcaaron commented May 3, 2022

kadiealexander commented May 11, 2022

mvtglobally commented May 17, 2022

parasharrajat commented May 17, 2022

marcaaron commented May 17, 2022

parasharrajat commented May 20, 2022 • edited Loading

mallenexpensify commented May 23, 2022

parasharrajat commented May 23, 2022

mallenexpensify commented May 23, 2022

kidroca commented May 24, 2022

mallenexpensify commented May 24, 2022

kavimuru commented Jan 26, 2022 •

edited by marcaaron

Loading

thienlnam commented Jan 27, 2022 •

edited

Loading

mvtglobally commented Feb 1, 2022 •

edited

Loading

roryabraham commented Feb 1, 2022 •

edited

Loading

kadiealexander commented Apr 22, 2022 •

edited

Loading

luacmartins commented May 3, 2022 •

edited

Loading

kidroca commented May 3, 2022 •

edited

Loading

parasharrajat commented May 20, 2022 •

edited

Loading