2054812 - [IPProtection] VPN Authorization breaks if fxa token expired

Status: VERIFIED FIXED

(Firefox for Android :: Privacy, defect)

Description

[Mike a [:mavduevskiy]]

Steps to reproduce

1. Clean the app, sign in a user (with sync, not vpn)
2. Move system time by a week forward
3. Kill and restart the app
4. Quickly start vpn authorization (either through onboarding or through settings; the time window is ~4 seconds)
5. Authorize VPN

Expected behavior

VPN turns on

Actual behavior

VPN locks in "connecting" state until restart

Device information

• Firefox version: Nightly/Beta
• Android device model: Pixel 7
• Android OS version: 16

Any additional information?

Bug 2052599 has a video from QA that shows the race condition with onboarding, but I was able to replicate it through regular settings. Here is a log of me going through the STR, navigating to vpn settings screen and pressing "Get Started". You can see that CheckAccount and Toggle happen before the account is initialized.

Cleaner race - without onboarding
---------------------------- PROCESS ENDED (22304) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (22223) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (21913) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (22102) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS ENDED (21879) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (22871) for package org.mozilla.fenix.debug ----------------------------
---------------------------- PROCESS STARTED (22903) for package org.mozilla.fenix.debug ----------------------------
19:42:36.905 I StandaloneCoroutine{Active}@4e3de0e, account state = mozilla.components.service.fxa.manager.AccountState$Unknown@f82002f
19:42:36.906 I ___________________________________________________
19:42:36.906 I iPProtectionReducer, action = AccountManagerStateChanged(status=WarmingUp)
19:42:36.906 I iPProtectionReducer, before state = eligibilityStatus = Unknown, serviceStatus = Uninitialized, accountStatus = Uninitialized
19:42:36.906 I iPProtectionReducer, after state = eligibilityStatus = Unknown, serviceStatus = Uninitialized, accountStatus = WarmingUp
19:42:36.906 I ___________________________________________________
19:42:36.913 I iPProtectionReducer, action = EligibilityChanged(eligibility=Eligible)
19:42:36.913 I iPProtectionReducer, before state = eligibilityStatus = Unknown, serviceStatus = Uninitialized, accountStatus = WarmingUp
19:42:36.913 I iPProtectionReducer, after state = eligibilityStatus = Eligible, serviceStatus = Uninitialized, accountStatus = WarmingUp
19:42:36.913 I ___________________________________________________
19:42:37.839 I iPProtectionReducer, action = EngineStateChanged(info=StateInfo(serviceState=Unauthenticated, proxyState=NOT_READY, remaining=-1, max=-1, resetTime=null, lastError=null))
19:42:37.839 I iPProtectionReducer, before state = eligibilityStatus = Eligible, serviceStatus = Uninitialized, accountStatus = WarmingUp
19:42:37.839 I iPProtectionReducer, after state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = WarmingUp
19:42:37.839 I ___________________________________________________
---------------------------- PROCESS STARTED (23121) for package org.mozilla.fenix.debug ----------------------------
19:42:39.584 I iPProtectionReducer, action = mozilla.components.feature.ipprotection.store.IPProtectionAction$CheckAccount@dbd9842
19:42:39.584 I iPProtectionReducer, before state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = WarmingUp
19:42:39.584 I iPProtectionReducer, after state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = WarmingUp
19:42:39.584 I ___________________________________________________
19:42:40.240 I iPProtectionReducer, action = mozilla.components.feature.ipprotection.store.IPProtectionAction$Toggle@d39930a
19:42:40.240 I iPProtectionReducer, before state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = WarmingUp
19:42:41.449 I iPProtectionReducer, action = AwaitingAuth(status=AwaitingAuthentication)
19:42:41.449 I iPProtectionReducer, before state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = RequestingAuthentication
19:42:41.449 I iPProtectionReducer, after state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = AwaitingAuthentication
19:42:41.449 I ___________________________________________________
19:42:41.449 I Sync Store, action = UpdateAccount(account=Account(uid=f41caf8809c541aeb70f158d702d891c, email=[e-mail], avatar=Avatar(url=https://profile.accounts.firefox.com/v1/avatar/m, isDefault=false), displayName=null))
19:42:41.449 I Sync Store, before: status = NotInitialized, accountState = mozilla.components.service.fxa.manager.AccountState$Unknown@f82002f
19:42:41.449 I Sync Store, after: status = NotInitialized, accountState = mozilla.components.service.fxa.manager.AccountState$Unknown@f82002f
19:42:41.449 I Sync Store___________________________________________________
19:42:41.454 I Sync Store, action = UpdateAccountState(accountState=mozilla.components.service.fxa.manager.AccountState$Authenticated@70c530c)
19:42:41.454 I Sync Store, before: status = NotInitialized, accountState = mozilla.components.service.fxa.manager.AccountState$Unknown@f82002f
19:42:41.454 I Sync Store, after: status = NotInitialized, accountState = mozilla.components.service.fxa.manager.AccountState$Authenticated@70c530c
19:42:41.454 I Sync Store___________________________________________________
19:42:41.455 I StandaloneCoroutine{Active}@4e3de0e, account state = mozilla.components.service.fxa.manager.AccountState$Authenticated@70c530c
19:42:41.455 I ___________________________________________________
19:42:41.472 I iPProtectionReducer, action = AccountManagerStateChanged(status=NeedsAuthorization)
19:42:41.472 I iPProtectionReducer, before state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = AwaitingAuthentication
19:42:41.472 I iPProtectionReducer, after state = eligibilityStatus = Eligible, serviceStatus = Unauthenticated, accountStatus = NeedsAuthorization

Comment 1

[BugBot [:suhaib / :marco]]

Set release status flags based on info from the regressing bug 2050967

Comment 2

[Mike a [:mavduevskiy]]

From a conversation with :jonalmeida, manipulating phone clock causes account manager to act funny, but in normal usage the combination of token expiration and jumping into vpn should be rather unlikely. So I am giving it S3.

Comment 3

[Mike a [:mavduevskiy]]

Attachment: Bug 2054812 - Check account when vpn toggle fails for an entitled user

Comment 4

[BugBot [:suhaib / :marco]]

Set release status flags based on info from the regressing bug 2050967

Comment 5

[Mike a [:mavduevskiy]]

Attachment: WIP: Bug 2054812 - Delay vpn onboarding until acc manager is ready

Comment 6

[Phabricator Automation]

Comment on attachment 9614648 [details]
WIP: Bug 2054812 - Delay vpn onboarding until acc manager is ready

Revision D313597 was moved to bug 2057032. Setting attachment 9614648 [details] to obsolete.

Comment 7

[Pulsebot]

Pushed by [e-mail]:
https://github.com/mozilla-firefox/firefox/commit/2a068caa3ce3
https://hg.mozilla.org/integration/autoland/rev/1e90f0c31957
Check account when vpn toggle fails for an entitled user r=android-reviewers,jonalmeida

Comment 8

[Mike a [:mavduevskiy]]

Attachment: Bug 2054812 - Check account when vpn toggle fails for an entitled user

This is a release uplift

Comment 9

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/1e90f0c31957

Comment 10

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/1e90f0c31957

Comment 11

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/1e90f0c31957

Comment 12

[Norisz Fay [:noriszfay]]

https://hg.mozilla.org/mozilla-central/rev/1e90f0c31957

Comment 13

[BugBot [:suhaib / :marco]]

The patch landed in nightly and beta is affected.
:mavduevskiy, is this bug important enough to require an uplift?

• If yes, please nominate the patch for beta approval.
  • See https://wiki.mozilla.org/Release_Management/Requesting_an_Uplift for documentation on how to request an uplift.
• If no, please set status-firefox154 to wontfix.

For more information, please visit BugBot documentation.

Comment 15

[Mike a [:mavduevskiy]]

Attachment: Bug 2054812 - Check account when vpn toggle fails for an entitled user

This patch aims to unblock authenticated users that initiated VPN auth flow while
their account was still being warming up. That would result in user
having "entitled" account status, but ip protection service would be
still "unauthenticated", which locks the UI in connecting state. Why?

Normally, that state means that the user has finished auth flow, and
ip protection machinery is processing new data and eventually moving
into "ready" state. The source of truth for the UI is the service state.
The auth flow is finished (we closed the custom tab with account),
but the ip protection state hasn't updated yet - so the UI goes into
connecting state, to show that it's working and prevent user from
repeated calls.

Happy state flow is, account manager notifies it's ready, vpn ui
elements initiate account check - that warms up the ip protection
machinery, and then user goes through the auth flow, so ip protection
responds to the auth flow properly, and eventually goes into ready
state.

But vpn auth flow doesn't wait for fxa to finish warming up, and the vpn
auth flow might be started before that.

I tried several approaches here:

1. Make CheckAccount work for WarmingUp account state. Didn't work:
   WarmingUp means both not account and an account in process
2. Lock "get started" until WarmingUp finishes. Didn't work: the
   CheckAccount is fired when the screen is opened, it doesn't listen to
   the account state.
3. Making IPProtectionStorageSynchronizer to also check account if
   NeedsAuthorization happens during Auth flow. Didn't work: it still
   leaves the race condition, fxa might take longer than auth flow.

I also noticed that when FXA is not ready, the state transitions as if
it were Authentication (AwaitingAuthentication, etc), which then updates
with "NeedsAuthorization" - and the FXA page shows Authorization. What's
happening in code doesn't represent what's going on.

But in the end, I want to avoid locking user in the "connecting" state.
Our auth proccess always ends with a toggle action, so if that errors
while we are entitled but the service state is still unauthenticated, we
it means fxa and vpn auth went out of sync, and we should check account
state (warm up the ip protection machinery).

In theory, we could warn a check after seeing a toggle failure while the
service is unauthenticated - without considering account state, but I
wanted to be eplicit about this case to minimize side-effects when we
introduce gpi as a way to enroll.

For that racing condition, the user will see a snackbar error "try
again", but they actually will be able to try again. Added telemetry to
see how often that happens, for prioritizing feature improvments here.

Original Revision: https://phabricator.services.mozilla.com/D312137

Comment 16

[Phabricator Automation]

firefox-beta Uplift Approval Request

• User impact if declined/Reason for urgency: Without this patch, some users will be locked in "connecting" state after trying out VPN feature for the first time; the only way to unblock for them is to restart the app.

It's a blocker for vpn rollout in 153

• Code covered by automated testing?: yes
• Fix verified in Nightly?: no
• Needs manual QE testing?: yes
• Steps to reproduce for manual QE testing: SRT is in the bug description Bug 2054812 comment 0

and another bug has alternative STR Bug 2055471

• Risk associated with taking this patch: low
• Explanation of risk level: The change redirects the handling of an action in the state machine with a different, already existing and tested logic path. Should be as safe as it gets.
• String changes made/needed?: no
• Is Android affected?: yes

Comment 17

[Phabricator Automation]

firefox-release Uplift Approval Request

• User impact if declined/Reason for urgency: Without this patch, some users will be locked in "connecting" state after trying out VPN feature for the first time; the only way to unblock for them is to restart the app.

It's a blocker for vpn rollout in 153

• Code covered by automated testing?: yes
• Fix verified in Nightly?: no
• Needs manual QE testing?: yes
• Steps to reproduce for manual QE testing: SRT is in the bug description Bug 2054812 comment 0

and another bug has alternative STR Bug 2055471

• Risk associated with taking this patch: low
• Explanation of risk level: The change redirects the handling of an action in the state machine with a different, already existing and tested logic path. Should be as safe as it gets.
• String changes made/needed?: no
• Is Android affected?: yes

Comment 18

[Alexandra Martin [:alemartin], FxA/SubPlat/VPN QA]

Attachment: verification_new1.mp4

Fix looked at in Fx Nightly 155.0a1 (Build #2016174455) with a Google Pixel 7a (Android 16).

Mike, I've tried 3 times (testing both a fresh install from the Play Store and clearing cache/storage). I wanted to test with the latest build directly from ftp.mozilla.org too, but I can't create another Fx Account until tomorrow. That said, since it's the same build number as the Play Store one, it probably wouldn't make a difference anyway.

I still get the "Couldn't connect to VPN" error, and the VPN doesn't turn on automatically. However, the screen is no longer frozen in the "Connecting" state, and I don't need to restart the app to turn the VPN on manually.

Let me know if I can try something else. Thanks!

Comment 19

[Mike a [:mavduevskiy]]

hi, Alexandra, that's good news, thank you!

this is a multilayered bug:

1. auth flow locks user in "connecting" state after they restart
2. onboarding card is shown before account manager has initialized
3. a user can get into auth flow through the menu before the account manager has been initialized

The fix was focused on the part 1 - there was no work around that broken state except for restart, and it would be an S2 blocking a rollout. The others look less severe.

The follow up to this is https://bugzilla.mozilla.org/show_bug.cgi?id=2057032.

Comment 20

[Alexandra Martin [:alemartin], FxA/SubPlat/VPN QA]

Thank you! I will mark this as verified for Nightly 155, and once the fix reaches Beta, I’ll verify it there as well. I’ll also keep an eye on bug 2057032.

Comment 21

[Pulsebot]

https://github.com/mozilla-firefox/firefox/commit/6a4fa1ee26ac
https://hg.mozilla.org/releases/mozilla-beta/rev/807b53978927

Comment 22

[Pulsebot]

https://github.com/mozilla-firefox/firefox/commit/a921dca50a12
https://hg.mozilla.org/releases/mozilla-release/rev/b2259e81d514

Comment 23

[Alexandra Martin [:alemartin], FxA/SubPlat/VPN QA]

Attachment: verification_new9.mp4

Fix verified in Fx Beta 154.0b3 (Build #2016175146). User is not blocked in the "Connecting" state and can turn the VPN on and off without needing to restart the app.

Comment 24

[Alexandra Martin [:alemartin], FxA/SubPlat/VPN QA]

Attachment: verification_new15.mp4

Verified fix in Fx 153.0.1 (Build #2016175154) using a Google Pixel 7a (Android 16). Overall, the fix looks fine.