1865086 - FxaDeviceConstellationException$EnsureCapabilitiesFailed

Status: RESOLVED FIXED

(Firefox for Android :: Accounts and Sync, defect, P3)

Description

[Ben Dean-Kawamura [:bdk]]

We've had an increase in these over the last few weeks (sentry). I think that increase corresponds to us merging this app-services PR.

We should figure out the cause of this and fix it.

Comment 1

[Ben Dean-Kawamura [:bdk]]

Interestingly, the same PR merge seems to correspond to a decrease in AccountManagerException$MissingKeyFromSyncScopedAccessToken errors (sentry). Looking at the ac.as.build_version field, it seems like the last build with a missing key error was on 2023/11/1 and most of the ensure_capabilities errors are happening with builds after that date.

One theory on this is that the client thinks it's authenticated but it's not. Before, the main way this would express itself is through access token issues when the first sync happened. After the merge, it's causing failures in ensure_capabilities. This makes some sense because part of the app-services PR change updated what we stored in the state and made it so the very first ensure_capabilities call after the migration would access the network.

Comment 2

[Ben Dean-Kawamura [:bdk]]

Is the auth recovery system working correctly is this case? If finalizeDevice fails, we return AuthenticationError which should lead to an auth recovery attempt, if that recovery attempt succeeds then the I believe the state machine transitions directly to Authenticated. I think there are 2 potential issues here:

• finalizeDevice will report the auth error, even if we successfully recover from it
• If we recover, I don't think we run finalizeDevice again (nor do we run authenticationSideEffects)

Comment 3

[BMO Github Automation]

Attachment: [mozilla-mobile/firefox-android] Bug 1865086 - More FxA error reporting (#4503)

Comment 4

[BMO Github Automation]

Authored by https://github.com/bendk
https://github.com/mozilla-mobile/firefox-android/commit/70e0cc437e1c3624a6bb196ba8097316efb38ba9
[main] Bug 1865086 - More FxA error reporting

Comment 5

[Ben Dean-Kawamura [:bdk]]

Steps to (almost) reproduce:

• Install a fresh version of the 2023-11-11 nightly. I used https://archive.mozilla.org/pub/fenix/nightly/2023/11/2023-11-01-04-01-28-fenix-121.0a1-android-x86_64/
• Startup firefox, click through the welcome screens, log in to FxA, sync your data
• From a different machine, change the FxA password
• Go back to Fenix and try to sync again. This should result in you being in the "authentication problems" state
• Close Fenix
• Install a recent nightly. I used https://archive.mozilla.org/pub/fenix/nightly/2023/11/2023-11-30-16-04-05-fenix-122.0a1-android-x86_64/
• Open FF

When I did this, I saw this in the logs

12-01 00:40:52.356 12578 12724 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Account$Start@c669834' for state Idle(accountState=NotAuthenticated). Next state is Active(progressState=Initializing)
12-01 00:40:52.397 12578 12724 I FirefoxAccountStateMachine: Ran 'mozilla.components.service.fxa.manager.Event$Account$Start@c669834' side-effects for state Active(progressState=Initializing), got successive event mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@c883a9
12-01 00:40:52.397 12578 12724 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@c883a9' for state Active(progressState=Initializing). Next state is Active(progressState=CompletingAuthentication)
12-01 00:40:53.833 12578 12724 I FirefoxAccountStateMachine: Ran 'mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@c883a9' side-effects for state Active(progressState=CompletingAuthentication), got successive event AuthenticationError - finalizeDevice
12-01 00:40:53.925 12578 12724 I FirefoxAccountStateMachine: Ran 'AuthenticationError - finalizeDevice' side-effects for state Active(progressState=RecoveringFromAuthProblem), got successive event mozilla.components.service.fxa.manager.Event$Progress$FailedToRecoverFromAuthenticationProblem@63c16e7
12-01 00:40:53.925 12578 12724 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Progress$FailedToRecoverFromAuthenticationProblem@63c16e7' for state Active(progressState=RecoveringFromAuthProblem). Next state is Idle(accountState=AuthenticationProblem)
12-01 00:51:27.304 13656 13798 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Account$Start@3964c79' for state Idle(accountState=NotAuthenticated). Next state is Active(progressState=Initializing)
12-01 00:51:27.326 13656 13798 I FirefoxAccountStateMachine: Ran 'mozilla.components.service.fxa.manager.Event$Account$Start@3964c79' side-effects for state Active(progressState=Initializing), got successive event mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@646d65d
12-01 00:51:27.326 13656 13798 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@646d65d' for state Active(progressState=Initializing). Next state is Active(progressState=CompletingAuthentication)
12-01 00:51:28.561 13656 13798 I FirefoxAccountStateMachine: Ran 'mozilla.components.service.fxa.manager.Event$Progress$AccountRestored@646d65d' side-effects for state Active(progressState=CompletingAuthentication), got successive event AuthenticationError - finalizeDevice
12-01 00:51:28.659 13656 13798 I FirefoxAccountStateMachine: Ran 'AuthenticationError - finalizeDevice' side-effects for state Active(progressState=RecoveringFromAuthProblem), got successive event mozilla.components.service.fxa.manager.Event$Progress$FailedToRecoverFromAuthenticationProblem@ce188c4
12-01 00:51:28.659 13656 13798 I FirefoxAccountStateMachine: Processing event 'mozilla.components.service.fxa.manager.Event$Progress$FailedToRecoverFromAuthenticationProblem@ce188c4' for state Active(progressState=RecoveringFromAuthProblem). Next state is Idle(accountState=AuthenticationProblem)

I think the line with got successive event AuthenticationError - finalizeDevice indicates that we hit this branch: https://github.com/mozilla-mobile/firefox-android/blob/f9adc5e884078e4d16847e2117ab8c9ebab2793c/android-components/components/service/firefox-accounts/src/main/java/mozilla/components/service/fxa/FxaDeviceConstellation.kt#L104

I don't see the exception report in my logs, but I'm not sure if I'm expected to see that. My guess is that crash reporting is either disabled or it doesn't appear in adb logcat. The alternate explanation is there's another way to get the above authentication error, but I can't see it.

If this is true, then I think this is just another case of https://bugzilla.mozilla.org/show_bug.cgi?id=1794212. It's just slightly different now that the app-services code was refactored. I believe this is the PR that changed things, https://github.com/mozilla/application-services/pull/5887, since removes the cached capabilities and causes the next startup to re-send them.

Comment 6

[Ben Dean-Kawamura [:bdk]]

The above error repeats on every restart, which may explain the volume of sentry reports for an somewhat unlikely edge case.

Comment 7

[Ben Dean-Kawamura [:bdk]]

If the above is true, then I think we can close this bug as a dup of 1794212, which I hope to fix in early next year. Maybe we could remove the crash reporting code to decrease the sentry traffic, but it's not all that much traffic.

Comment 8

[Ben Dean-Kawamura [:bdk]]

These have significantly dropped from a few hundred a day to about 12 a day since we moved to the a-s state machine. I assume the remaining events are from devices that haven't upgraded yet. Let's close this.