Expensify / App

Welcome to New Expensify: a complete re-imagination of financial collaboration, centered around chat. Help us build the next generation of Expensify by sharing feedback and contributing to the code.
https://new.expensify.com
MIT License
3.56k stars 2.9k forks source link

[HOLD for payment 2021-12-15] Add logs to Expensify.js to help determine source of persistent iOS splash screen bug #6358

Closed NikkiWines closed 2 years ago

NikkiWines commented 2 years ago

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


cc: @kadiealexander cc: @kidroca as you suggested this here

Add logs to Expensify.js in componentDidMount() and componentDidUpdate() to help identify the root cause of the persistent splash screen bug.

Note: Because the above modification won't resolve the root cause of the persistent splash screen bug, the base pay for this issue is $250. Should these logs lead to more insight into the cause, you will have first dibs at proposing a solution for https://github.com/Expensify/App/issues/5620 and getting the full compensation for that issue. (This is also contingent on whether or not this proposal) ends up fixing this bug)

Action Performed:

Related to https://github.com/Expensify/App/issues/5620

  1. Force close the app or update the app
  2. Open the app

Expected Result:

User should not be stuck on Splash screen

Actual Result:

User is stuck in splash screen

Workaround:

Closing and reopening app fixes the issue.

Platform:

Where is this issue occurring?

Version Number: Reproducible in staging?: Yes Reproducible in production?: Unknown Logs: https://stackoverflow.com/c/expensify/questions/4856 Notes/Photos/Videos: Any additional supporting documentation

Expensify/Expensify Issue URL: Issue reported by: N/A Slack conversation: N/A Related GH Issue: https://github.com/Expensify/App/issues/5620

View all open jobs on GitHub

kidroca commented 2 years ago

I agree with the terms

Just to be clear the intent is to add one log about a minute after app launch that checks the splash screen status using the library api

Half a minute can be fine as well, we just need to make sure we're waiting enough time and post the log - if we wait less it could have just been a slow startup/request etc...

If we add the logging in component did update/mount we might miss the problem

MelvinBot commented 2 years ago

Current assignee @kadiealexander is eligible for the External assigner, not assigning anyone new.

kadiealexander commented 2 years ago

https://www.upwork.com/ab/applicants/1461438341487489024/suggested

MelvinBot commented 2 years ago

Triggered auto assignment to @puneetlath (Exported), see https://stackoverflow.com/c/expensify/questions/7972 for more details.

kadiealexander commented 2 years ago

@puneet for context, @kidroca made this proposal here, which we created a new issue for as discussed here.

Proposal:

Hi, I have been tracking this issue for some time and would like to help move it forward

I've investigated everything written so far and I think the most likely cause is a JS error halting code execution from ever reaching BootSplash.hide()

Here are some facts that will help us dismiss some other possibilities

  1. We were logged in and had a functioning app (The bug happens only after a restart / update)
  2. When there's no app update the bug usually happens after 2 hrs of inactivity (expired token)
  3. The splash screen is initially visible and would only hide when we call BootSplash.hide from our code

It's not a problem of Expensify.js componentDidUpdate or fetchAllReports

From fact 1) we know we have enough information in storage to load without network at all. It's only if our storage was somehow corrupted that we can be stuck here. Expand to see more details... https://github.com/Expensify/App/blob/c3ba59bac53b65d00616dc779eea077825026b4d/src/Expensify.js#L113-L115 From fact 1) we know that `this.getAuthToken()` is `ture` and that `props.initialReportDataLoaded` is `true` as well - `initialReportDataLoaded` is set to `true` after login and remains true ever since - nothing would ever set it to `false` `isSidebarLoaded` would be set to `true` very soon, the outcome of `fetchAllReports` doesn't matter - again from fact 1) we have data in on disk so even if `fetchAllReports` fails completely we have something to load in the LHN - LHN uses reports - they are not safe for eviction, nothing would remove them from storage automatically. Only report actions can be auto evicted, but that doesn't concern the LHN and the `isSidebarLoaded` flag Regarding _"the outcome of `fetchAllReports` doesn't matter"_, I've tried - skip calling it - make it do nothing but return a rejected promise - make it receive an empty list reponse - make it receive a `jsonCode` other than 200 The splash screen would still hide Regarding `SidebarLinks` and `App.setSidebarLoaded` not getting called - yes this could happen but only if something wiped out the data in storage - it's unlikely - if full data is wiped we'd be on the Login screen. Could data be partially wiped? I've traced that as well and will post findings separately, overall it doesn't seem likely

It's likely an error halting code execution

Sync Errors that are thrown inside component code like render, componentDidMount would prevent any further code being executed

As of React 16, errors that were not caught by any error boundary will result in unmounting of the whole React component tree. https://reactjs.org/docs/error-boundaries.html#new-behavior-for-uncaught-errors

If such an error happens at launch before we hide the splash screen, our ErrorBoundary component will stop render the app (it's children) and no code will be able to call BootSplash.hide()

https://github.com/Expensify/App/blob/c3ba59bac53b65d00616dc779eea077825026b4d/src/App.js#L35-L37

https://github.com/Expensify/App/blob/c3ba59bac53b65d00616dc779eea077825026b4d/src/components/ErrorBoundary/BaseErrorBoundary.js#L39-L47

If this ever happened the ErrorBoundary component would be sending very distinct logs containing more information. It would be very helpful to post them here so that we can zoom in on something specific Such logs would be prefixed with [alrt] NewExpensify crash caught by error boundary and will contain error - a message, and errorInfo - a component stack trace

In case the Error Boundary theory is wrong

We need to take some measures to pinpoint the problem without having to analyze the whole app

1 Add some code to the <Expensify /> component

    componentDidMount() {
        this.debugBootsplashIssues();
    }

    debugSplashIssues() {
        setTimeout(() => {
            BootSplash.getVisibilityStatus()
                .then((status) => {
                    if (status === 'visible') {
                        Log.alert('[BootSplash] splash screen is still visible a minute after launch', this.props, false);
                    }
                });
        }, 60 * 1000);
    }

Hopefully the logs around this alert here would be able to tell us what's going on

It might be better to have this outside of Component code in case there's an error that's preventing React to initialize - perhaps put it in src/libs/BootSplash/index.native.js

2 Let the <ErrorBoundary /> render something

Make the Error boundary hide the splash and render some fallback content in case it catches an error This would let people know where they've encountered a startup error, or they're stuck due to something else It can be configured to be ENV specific - render more debug information in test flight and dev, and something more user friendly for production.

sidferreira commented 2 years ago

@NikkiWines when discussing this issue in Slack with @tgolen I suggested make a build with Bugsnag ( www.bugsnag.com ) that is a great tool for React Native. It has a leaveBreadcrumb functionality that allows one to add "logs" that will show up only when an error is reported.

We can basically add 2 errors:

( https://expensify.slack.com/archives/C01GTK53T8Q/p1635878140359900?thread_ts=1635255533.107600&cid=C01GTK53T8Q )

Bugsnag includes SourceMap support so it allows to track even other JS/Native issues.

NikkiWines commented 2 years ago

@sidferreira, that looks like a good discussion.

Bugsnag certainly looks like a helpful option but to implement it we'll likely need to have a larger discussion with the rest of the team, especially given that we already have our own existing logging solution with Log.

sidferreira commented 2 years ago

@NikkiWines I see it as a temporary use... being removed once we find out what's wrong. Also, as a freelancer I have no access to the logs, so it is impossible to me have access to logs to try to propose a solution.

And of course we could use a TestFlight build focusing some users ( aka @tgolen ) that have this issue more frequently, not having this specific build "in the wild".

Also I'm not sure how much extra information simple "logs" would offer compared to a way to properly understand step by step how the app behave and when things go sideways...

kidroca commented 2 years ago

Bump, I've submitted a proposal on Upwork

kadiealexander commented 2 years ago

Sorry for the delay @kidroca, I've hired you in Upwork! Please go ahead with the proposal.

MelvinBot commented 2 years ago

📣 @kidroca You have been assigned to this job by @kadiealexander! Please apply to this job in Upwork and let us know when we can expect a PR to be ready for review 🧑‍💻 Keep in mind: Code of Conduct | Contributing 📖

botify commented 2 years ago

The solution for this issue has been :rocket: deployed to production :rocket: in version 1.1.18-3 and is now subject to a 7-day regression period :calendar:. Here is the list of pull requests that resolve this issue:

If no regressions arise, payment will be issued on 2021-12-15. :confetti_ball:

kadiealexander commented 2 years ago

Paid! Thanks so much for your help on this @kidroca!