[HOLD for payment 2023-02-07] [$1000] Web - Log out - Console error is displayed when log out

[kbecciv]

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:

1. Go to staging.new.expensify.com
2. Log in with expensifail account
3. Go to Setting - Sign out

Expected Result:

Console error is not displayed when log out

Actual Result:

Console error is displayed when log out

Workaround:

Unknown

Platforms:

Which of our officially supported platforms is this issue occurring on?

• Web / Chrome / Safari

Version Number: 1.2.55.0

Reproducible in staging?: Yes

Reproducible in production?: No

If this was caught during regression testing, add the test name, ID and link from TestRail:

Email or phone of affected tester (no customers): applausetester+0901abb@applause.expensifail.com/Feya87Katya

Logs: https://stackoverflow.com/c/expensify/questions/4856

Notes/Photos/Videos: Any additional supporting documentation

Recording.2010.mp4

Expensify/Expensify Issue URL:

Issue reported by: Applause - Internal Team

Slack conversation:

View all open jobs on GitHub

Upwork Automation - Do Not Edit

• Upwork Job URL: https://www.upwork.com/jobs/~015d869c70481d179b
• Upwork Job ID: 1617488772668575744
• Last Price Increase: 2023-01-23

[OSBotify]

👋 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:

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

[marcaaron]

On first glance this error looks kind of harmless - but also like it is coming from the Pusher JS lib?

Are there any observable bad effects here? Or just a console error?

[marcaaron]

I can reproduce this. Suspect it happens because we have already disconnected from Pusher when we try to unsubscribe from the report channel here:

App/src/pages/home/report/ReportActionsView.js

Line 248 in 3661b57

Report.unsubscribeFromReportChannel(this.props.report.reportID);

The only PR I found related to logging out is here: https://github.com/Expensify/App/pull/13886/files

But not really connecting that change with the Pusher error. Probably will require some debugging.

Not sure if this is a "blocker" though. The error does look a bit harmless - but obviously would be ideal to not see it at all.

I want to say one solution would be to prevent unsubscribing if there is no websocket connection, but not really sure if that's correct to assume. And also doesn't quite explain the root cause of why this error has begun showing up.

[marcaaron]

Update: Only managed to reproduce 1/5 sign outs on staging - so I think most likely this is harmless and should be downgraded to "not blocker" while we continue to investigate - removing the label.

[tgolen]

Yeah, I agree this is not a deploy blocker. Sure strange that this would all of a sudden start happening. I did change how the signout stuff works a little bit but it should mean that the redirect to sign-in page doesn't happen until the Onyx change is committed.

I just reproduced this, and the console logs around the error are sure interesting:

I'm not sure what's up with that second error, maybe it's reported in another issue. Seems totally unrelated.

The biggest oddity to me is the log [info] Navigating to route - {"path":"/"} happening twice.

The pusher error is happening from ReportActionsView calling Report.unsubscribeFromReportChannel(this.props.report.reportID); when the component unmounts. So, it's almost like the component is unmounted twice, and therefore we are disconnecting from the report channel twice (one succeeds, the second one fails with that error).

[marcaaron]

Nice debugging.

I don't have much to add but wanted to say that I am not sure if I would 100% trust that log. That can happen anytime the navigation state changes:

App/src/libs/Navigation/NavigationRoot.js

Lines 60 to 68 in 6902b94

	return (
	<NavigationContainer
	fallback={(
	<FullScreenLoadingIndicator
	logDetail={{name: 'Navigation Fallback Loader', authenticated: props.authenticated}}
	style={styles.navigatorFullScreenLoading}
	/>
	)}
	onStateChange={parseAndLogRoute}

Doesn't answer the question of why the NavigationContainer state changes twice - but it might not be because we explicitly navigated to /.

[marcaaron]

Oh I wonder if the Onyx.clear() has something to do with it. Perhaps something about the order in which the subscribers are notified? Maybe we didn't notice this before because of this change:

6def1b3

I'm assuming the Onyx.clear() call unhooks subscribers in a particular order - but in the previous code we would always first log the user out and then clear the rest of the keys. So maybe some of those keys clearing causes a re-render somewhere. Just kinda riffing on that train of thought though - not sure how or why that would cause either of these errors.

[dylanexpensify]

Sorry I missed this -reviewing

[dylanexpensify]

Could reproduce the error in staging. @marcaaron @tgolen are we good making this external? Or do we think internal?

[tgolen]

I think it should go external first 👍

[melvin-bot]

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

• [SignOutFlow] proper pusher event type for user typing event #14526

If no regressions arise, payment will be issued on 2023-02-07. 🎊

After the hold period, please check if any of the following need payment for this issue, and if so check them off after paying:

• External issue reporter
• Contributor that fixed the issue
• Contributor+ that helped on the issue and/or PR

As a reminder, here are the bonuses/penalties that should be applied for any External issue:

• Merged PR within 3 business days of assignment - 50% bonus
• Merged PR more than 9 business days after assignment - 50% penalty

[melvin-bot]

BugZero Checklist: The PR fixing this issue has been merged! The following checklist (instructions) will need to be completed before the issue can be closed:

• [@Santhosh-Sellavel / @chiragsalian] The PR that introduced the bug has been identified. Link to the PR: Unsure which PR caused the issue. It could be from pusher side, hard to say.
• [@Santhosh-Sellavel / @chiragsalian] The offending PR has been commented on, pointing out the bug it caused and why, so the author and reviewers can learn from the mistake. Link to comment: N/A
• [@Santhosh-Sellavel / @chiragsalian] A discussion in #expensify-bugs has been started about whether any other steps should be taken (e.g. updating the PR review checklist) in order to catch this type of bug sooner. Link to discussion: https://expensify.slack.com/archives/C049HHMV9SM/p1674474393716959
• [@dylanexpensify] A regression test has been added or updated so that the same bug will not reach production again. Link to the GH issue for creating the test here:

[Prince-Mendiratta]

I think this issue is past the regression period now?
Also, there hasn't been any updates in the upstream issue, should we ping them about it?
cc @Santhosh-Sellavel @chiragsalian

[Santhosh-Sellavel]

@chiragsalian I'm not sure what caused this regression, apart from the PR which removed the event name #752 did we break something else?

cc: @Prince-Mendiratta

[Prince-Mendiratta]

@Santhosh-Sellavel I'll need to view the https://github.com/Expensify/Expensify/issues/144728 issue once.

I think this fix might have broken what was the intentional fix behind #752. I just tried out the mentioned steps in #752 and looks like sending the event name to the unsubscribe function just unbinds that specific event from the channel but does not unsubscribe from the channel itself, the channel connection remains open when we navigate to another channel. Although this won't cause any regression since we do not have any other events subsribed to the report, I'll need to see why the fix was implemented first in https://github.com/Expensify/Expensify/issues/144728.

As for this specific issue, the root cause and solution mentioned in the proposal is correct, we will need to see why this might break and re create https://github.com/Expensify/Expensify/issues/144728 issue.

It's pretty weird though, has this issue been in the repo since 3 years or did it just start popping up?!

If this indeed has repercussions, we might want to revert the current changes and instead add a delay after channel.unbind() to make sure that the channel is unbound before unsubscribing from the socket.

[chiragsalian]

Hmm okay, so I think your solution was fine @Prince-Mendiratta.

You mention your fix might have brought back this issue - #752. But i was not able to reproduce it. The issue is more than 2 years old.

With your solution prince I would think that unbinding from the event won't unsubscribe from the channel itself and maybe that's fine. We can create a follow-up issue to figure out how to unsubscribe from the channel itself so that it doesn't take up pusher space perhaps.

has this issue been in the repo since 3 years or did it just start popping up?!

Not sure, maybe no one noticed it before. Hard to say 🤷‍♂️ Not sure if it's worth the time and effort tracing through the past code IMO.

As a first step let's confirm if there are problems,

1. Tagging @marcaaron if you can reproduce this issue on the latest App code since you created the issue to begin with. I could not reproduce the issue.
2. To confirm if there is a problem only unsubscribing from the event but keeping the socket active. If there is no problem here I'm not sure if anything needs to be done.

[Santhosh-Sellavel]

Cool, @chiragsalian We can this off this checklist!

[chiragsalian]

Yup, updated

[marcaaron]

Tagging @marcaaron if you can reproduce this #752 on the latest App code since you created the issue to begin with. I could not reproduce the issue.

Sorry, I won't have time to test this. If we can't reproduce it then let's consider it fixed.

[Santhosh-Sellavel]

@dylanexpensify bump for payment thanks!

[dylanexpensify]

on it!

[dylanexpensify]

@Santhosh-Sellavel did you apply? Can't see you on the job proposals in Upwork

[dylanexpensify]

@Prince-Mendiratta sent offer!

[Prince-Mendiratta]

@dylanexpensify accepted. Would this be eligible for a timeline bonus?

[dylanexpensify]

@Prince-Mendiratta can you confirm your PR didn't lead to a regression? If so, then yes it's eligible!

[Prince-Mendiratta]

@dylanexpensify Yes, can confirm, no regressions here. The issue we were talking about in the comment above was super old and we were unable to reproduce.

[Santhosh-Sellavel]

@dylanexpensify Applied now, yeah no regressions!

[dylanexpensify]

Wooot!

[dylanexpensify]

payment sent @Prince-Mendiratta with bonus!
offer sent @Santhosh-Sellavel !

[Prince-Mendiratta]

thanks a lot everyone, cheers!

[dylanexpensify]

payment sent @Santhosh-Sellavel !

[dylanexpensify]

posted about RT steps

[dylanexpensify]

alrighty, we're gonna do nothing for RT, so all good here!