1400742 - Crash in java.io.FileNotFoundException: /data/user/0/org.mozilla.fennec_aurora/files/fxa.account.json (No such file or directory) at java.io.FileInputStream.open(Native Method)

Status: RESOLVED FIXED

(Firefox for Android Graveyard :: Firefox Accounts, defect)

Description

[Nicholas Nethercote [inactive]]

This bug was filed from the Socorro interface and is 
report bp-932e0872-74a5-433d-b14a-5cc030170916.
=============================================================

A number of crashes with this signature have been happening.

Java Stack Trace:

>java.io.FileNotFoundException: /data/user/0/org.mozilla.fennec_aurora/files/fxa.account.json (No such file or directory)
>	at java.io.FileInputStream.open(Native Method)
>	at java.io.FileInputStream.<init>(FileInputStream.java:146)
>	at android.app.ContextImpl.openFileInput(ContextImpl.java:488)
>	at android.content.ContextWrapper.openFileInput(ContextWrapper.java:186)
>	at org.mozilla.gecko.sync.Utils.readFile(Utils.java:487)
>	at org.mozilla.gecko.fxa.authenticator.AccountPickler.unpickleParams(AccountPickler.java:166)
>	at org.mozilla.gecko.fxa.authenticator.AndroidFxAccount.getAccountUID(AndroidFxAccount.java:232)
>	at org.mozilla.gecko.fxa.authenticator.AndroidFxAccount.unbundle(AndroidFxAccount.java:272)
>	at org.mozilla.gecko.fxa.authenticator.AndroidFxAccount.unbundle(AndroidFxAccount.java:264)
>	at org.mozilla.gecko.fxa.authenticator.AndroidFxAccount.getBundleData(AndroidFxAccount.java:305)
>	at org.mozilla.gecko.fxa.authenticator.AndroidFxAccount.getProfileJSON(AndroidFxAccount.java:886)
>	at org.mozilla.gecko.fxa.activities.FxAccountStatusFragment.updateProfileInformation(FxAccountStatusFragment.java:595)
>	at org.mozilla.gecko.fxa.activities.FxAccountStatusFragment.refresh(FxAccountStatusFragment.java:521)
>	at org.mozilla.gecko.fxa.activities.FxAccountStatusFragment$InnerSyncStatusDelegate$1.run(FxAccountStatusFragment.java:396)
>	at android.app.Activity.runOnUiThread(Activity.java:5851)
>	at org.mozilla.gecko.fxa.activities.FxAccountStatusFragment$InnerSyncStatusDelegate.onSyncStarted(FxAccountStatusFragment.java:416)
>	at org.mozilla.gecko.fxa.sync.FxAccountSyncStatusHelper$1.run(FxAccountSyncStatusHelper.java:59)
>	at android.os.Handler.handleCallback(Handler.java:836)
>	at android.os.Handler.dispatchMessage(Handler.java:103)
>	at android.os.Looper.loop(Looper.java:203)
>	at android.app.ActivityThread.main(ActivityThread.java:6233)
>	at java.lang.reflect.Method.invoke(Native Method)
>	at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:1063)
>	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:924)

One user comment about this said "I was changing my sync account on many devices at the same time."

jchen, any ideas?

Comment 2

[(inactive) Jim Chen [:jchen] [:darchons]]

Possibly related to bug 1399904?

Comment 3

[:Grisha Kruglov]

It is indeed!

Comment 4

[:Grisha Kruglov]

We pickle Firefox account asynchronously in onPerformSync; at the same time Android fires off onStatusChanged events for any SyncStatusObservers. This is inherently racy. As a result, sometimes we try to read profile file before it has been pickled.

That is what happens in the stack trace in Comment 0. Our prior behavior was to fall back to only displaying account's email (which is the name of the Android account, as so could be obtained without unpickling) instead of displaying (email, displayName, and avatar).

Other stack traces are somewhat different. My guess from quickly perusing them is that they're different parts of the UI/application racing with the background process.

Comment 5

[:Grisha Kruglov]

Hmm. While the raciness described in Comment 4 is there and might still cause issues, I think the lower-level problem here is different.

This specifically involves a broader use of account UID that was implemented in Bug 1368147.

What happens is that we're trying to get some account data, which is normally stored in account's user data, and cached in memory. In the cache, it's keyed by UID. So, we need to know account UID first. It's stored account user data as well IF the account has been created on the devices after Bug 1368147. However, for the other cases, account user data won't have UID in it, and so we need to fetch it from the pickled fxa.account.json file first, then persist it in the user data for easy access, and then finally use it to access the in-memory cache.

Nick alluded to some history of the in-memory cache (https://bugzilla.mozilla.org/show_bug.cgi?id=1368147#c46), and how it was there to work around caching/invalidation bugs in get/setUserData. If these problems have been solved for API levels 16+, we can remove the cache entirely, and access account bundle JSON string directly from account's user data. This will eliminate getAccountUID() entirely from the unbundle() code path.

One upside of the current caching mechanism is that it saves us from parsing JSON bundle string again and again, but that seems like a small perf penalty to pay to untangle this mess.

Comment 6

[:Grisha Kruglov]

Attachment: Bug 1400742 - Remove per-account in-memory cache

Review commit: https://reviewboard.mozilla.org/r/181536/diff/#index_header
See other reviews: https://reviewboard.mozilla.org/r/181536/

Comment 7

[:Grisha Kruglov]

Just triggered this by disconnecting an account in Sync Prefs.

Comment 8

[Nick Alexander :nalexander [he/him]]

Comment on attachment 8910061 [details]
Bug 1400742 - Remove per-account in-memory cache

https://reviewboard.mozilla.org/r/181536/#review187266

One substantive issue.  No need for re-review if you just leave it in, but run it by me if you do remove it: I'd like to understand why it can go.

::: commit-message-a0eb2:1
(Diff revision 1)
> +Bug 1400742 - Remove per-account in-memory cache r=nalexander

Include a summary of what's happening and why we feel it's safe to remove this now.

::: mobile/android/services/src/main/java/org/mozilla/gecko/fxa/authenticator/AndroidFxAccount.java
(Diff revision 1)
> -        Logger.debug(LOG_TAG, "Returning cached account bundle.");
> -        return cachedBundle;
> -      }
> -    }
> -
> -    final int version = getAccountVersion();

Why are you removing the version checking code?  It's non-trivial, so if it should really go, you should remove the function entirely (since this is the only consumer, AFAICT).

If you keep it, add logging for these error cases -- or hard fail, so we find out -- since returning null probably is terible.

Comment 9

[:Grisha Kruglov]

Comment on attachment 8910061 [details]
Bug 1400742 - Remove per-account in-memory cache

https://reviewboard.mozilla.org/r/181536/#review187266

> Why are you removing the version checking code?  It's non-trivial, so if it should really go, you should remove the function entirely (since this is the only consumer, AFAICT).
> 
> If you keep it, add logging for these error cases -- or hard fail, so we find out -- since returning null probably is terible.

Got a little trigger happy there. I'll hard fail here the obviously wrong case, and hopefully we won't hear about it in a few days... :)

Comment 10

[:Grisha Kruglov]

Comment on attachment 8910061 [details]
Bug 1400742 - Remove per-account in-memory cache

Review request updated; see interdiff: https://reviewboard.mozilla.org/r/181536/diff/1-2/

Comment 11

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/cadfde4972ab
Remove per-account in-memory cache r=nalexander

Comment 12

[Sebastian Hengst [:aryx] (needinfo me if it's about an intermittent or backout)]

https://hg.mozilla.org/mozilla-central/rev/cadfde4972ab

Comment 13

[:Grisha Kruglov]

NI myself to check if we still see these/similar crashes a few days after this patch makes into into nightly/beta.

Comment 14

[:Grisha Kruglov]

Follow-ups Bug 1403787, Bug 1404124 should have covered the rest of similar problems.