Closed Bug 1395332 Opened 7 years ago Closed 7 years ago

Firefox Refresh causes Sync to forget it's signed in, even though FxA credentials exist

Categories

(Firefox :: Sync, enhancement, P1)

enhancement

Tracking

()

VERIFIED FIXED
Firefox 57
Tracking Status
firefox57 --- verified

People

(Reporter: lina, Assigned: markh)

References

Details

Attachments

(1 file, 1 obsolete file)

Verdi brought up an interesting issue in https://github.com/mozilla/fxa/issues/258#issuecomment-326050303.

Here's what I think is happening: Sync checks the `services.sync.username` pref to see if it should initialize at startup. Firefox Refresh keeps the FxA credentials in `signedInUser.json` (https://searchfox.org/mozilla-central/rev/51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/browser/components/migration/FirefoxProfileMigrator.js#135), but wipes all preferences, so Sync doesn't think it's configured (https://searchfox.org/mozilla-central/rev/51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/services/sync/Weave.js#103-112,132-133).

However, opening about:preferences#sync calls `ensureLoaded` (https://searchfox.org/mozilla-central/rev/51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/browser/components/preferences/in-content-new/sync.js#71), which forces Sync to start up. At that point, Sync queries FxA, which realizes it's signed in, signs an assertion for the token server, and lets sync proceed as normal.

However, I think there's another problem. Sync stores the last sync times for each engine in prefs, to avoid redownloading everything from the server on every sync. Wiping these preferences will trigger full syncs. Most of the data should be unchanged locally, so I think our reconciliation logic will pick up on that and skip upload...but I suspect we'll increase load on the server downloading every record, or introduce corruption if the server data are inconsistent.

Mark, does this theory sound correct to you?
Flags: needinfo?(markh)
(In reply to Kit Cambridge (he/him) [:kitcambridge] (UTC-7) from comment #0)
> (https://searchfox.org/mozilla-central/rev/
> 51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/browser/components/migration/
> FirefoxProfileMigrator.js#135), but wipes all preferences, so Sync doesn't
> think it's configured
> (https://searchfox.org/mozilla-central/rev/
> 51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/services/sync/Weave.js#103-112,132-
> 133).

Yeah, that sounds correct. I think we should consider deprecating that enabled getter and replace it with an async .isEnabled, and use that new function internally (ie, so Weave.js no longer checks that pref)

(I'm a little surprised we've never noticed that before though)

> However, opening about:preferences#sync calls `ensureLoaded`
> (https://searchfox.org/mozilla-central/rev/
> 51b3d67a5ec1758bd2fe7d7b6e75ad6b6b5da223/browser/components/preferences/in-
> content-new/sync.js#71), which forces Sync to start up. At that point, Sync
> queries FxA, which realizes it's signed in, signs an assertion for the token
> server, and lets sync proceed as normal.

Sadly, I'm guessing that's probably what we tested - we checked about:preferences to ensure the account was carried over, and a side-effect of that was that sync initialized (although I would have expected to notice the hamburger menu being wrong)

(see also bug 1395485 for another wrinkle here)

> However, I think there's another problem. Sync stores the last sync times
> for each engine in prefs, to avoid redownloading everything from the server
> on every sync. Wiping these preferences will trigger full syncs. Most of the
> data should be unchanged locally, so I think our reconciliation logic will
> pick up on that and skip upload...but I suspect we'll increase load on the
> server downloading every record,

Yeah, that's correct, but I'd almost argue that's a feature :)

> or introduce corruption if the server data
> are inconsistent.

hrm - I'd actually expect this to possibly *fix* corruption and bring the client and server into a consistent state - what scenarios do you see increasing corruption?
Blocks: 972196
Flags: needinfo?(markh)
hrmph - but fixing this in the obvious way means pulling in FxA very early in browser startup, which really isn't going to fly for 57 given all the work we've done to reduce this.

I'm not sure what to do about this.  cc Ed incase he has any ideas...
Attached patch t.patch (obsolete) — Splinter Review
FWIW, this is roughly what I had in mind, but as mentioned, it will pull way too much in at browser startup.
Let's say we have a a pref P which is false by default.
On startup, if services.sync.username is empty AND P is false, we go for the more expensive check (pull FxA credentials), eventually login if there is login data, then set P to true.

Since all preferences are reset when the profile is refreshed, that would mean we only do that expensive check once.
(In reply to Edouard Oger [:eoger] from comment #5)
> Let's say we have a a pref P which is false by default.
> On startup, if services.sync.username is empty AND P is false, we go for the
> more expensive check (pull FxA credentials), eventually login if there is
> login data, then set P to true.
> 
> Since all preferences are reset when the profile is refreshed, that would
> mean we only do that expensive check once.

IIUC though, it will mean we do that expensive check once for every user who doesn't have sync configured?
Yes, keep it mind that it would only happen once in a lifetime of a Firefox installation (well, more if there's refreshes).
Yeah, but it just seems a shame to do that on the very first time 57 runs, but I agree it might be our only option. I wonder if there's any way we can otherwise detect the profile reset case so we can take that pain only in that case.
I wonder if we could set a pref in the migrator (https://searchfox.org/mozilla-central/source/browser/components/migration/FirefoxProfileMigrator.js) to do the expensive check. Looks like it already has some `Services.prefs.set*Pref` calls.
astevenson came to me this morning with a similar issue:
The UI showed that he he was connected, but about:sync-log was empty.
I asked if the profile was refreshed recently and he confirmed it to me, so I suspect the same problem is happening here.
(In reply to Mark Hammond [:markh] from comment #8)
> Yeah, but it just seems a shame to do that on the very first time 57 runs,
> but I agree it might be our only option. I wonder if there's any way we can
> otherwise detect the profile reset case so we can take that pain only in
> that case.

You all probably know this but just in case - the refresh date is noted somewhere in the user's profile. Maybe that's something you can use?
(In reply to Verdi [:verdi] from comment #12)
> You all probably know this but just in case - the refresh date is noted
> somewhere in the user's profile. Maybe that's something you can use?

I didn't know that, and I can't find anywhere it is recorded. I can see where the creation date of the profile is stored, but not the fact it was a refresh. Do you have any more details, or know who we should ask?

(In reply to Kit Cambridge (he/him) [:kitcambridge] (UTC-7) from comment #9)
> I wonder if we could set a pref in the migrator
> (https://searchfox.org/mozilla-central/source/browser/components/migration/
> FirefoxProfileMigrator.js) to do the expensive check. Looks like it already
> has some `Services.prefs.set*Pref` calls.

That would seem ideal. The existing prefs are only set when there's a session store (or something :) but I guess we certainly could consider doing the same basic thing - just set one pref to indicate that sync was migrated (and we'd reset it after looking up FxA). Later we might even use this pref to do smarter things if we deem them necessary.

As Ed mentions, that "expensive" check probably isn't *that* expensive, however, I suspect that because it would probably need to happen on the very first run of a profile, we'd end up triggering talos regressions and/or the "whitelist" of modules that should be imported at browser startup, which will probably end up being a bigger can of worms than arranging for a new custom pref in the migrator.
> > You all probably know this but just in case - the refresh date is noted
> > somewhere in the user's profile. Maybe that's something you can use?
> 
> I didn't know that, and I can't find anywhere it is recorded. I can see
> where the creation date of the profile is stored, but not the fact it was a
> refresh. Do you have any more details, or know who we should ask?

I designed times.json to support exactly this kind of usage -- to record the original creation time of the profile, and then each significant event like a reset. I don't know if anyone implemented the refresh part.
I just opened times.json for a test profile that I created and I see {"created":1503688431428,"reset":1504246888760}
MattN just confirmed with me over slack that times.json is the place.
(In reply to Verdi [:verdi] from comment #16)
> MattN just confirmed with me over slack that times.json is the place.

http://gph.is/2dUteLx
That's interesting, thanks - I went looking in the profiles after testing reset and didn't see the reset time there - that's probably just something I did wrong though.

Thinking more, I'm not sure this helps us too much in this scenario - IIUC, ProfileAge.jsm will not have read times.json when we need it (ie, immediately after startup) and loading that additional module is undesirable.

So I'm inclined to think we should change FirefoxProfileMigrator.js to also set a new pref, and then "do something" as the browser starts - which need not be loading FxAccounts in Weave.js's .enabled getter - eg, it might be OK for the state to be incorrect for a second or 2 after a profile reset so long as it updates relatively quickly.

It's a bit hand-wavey, but it doesn't look too difficult to experiment with.
Priority: -- → P1
I'm going to have a stab at this.
Assignee: nobody → markh
Status: NEW → ASSIGNED
Comment on attachment 8905802 [details]
Bug 1395332 - perform some post-profile-migration steps to ensure Sync works correctly in the new profile.

This patch is largely complete, but I'm only requesting feedback at this stage to check the approach is sane.

Gijs, it seems that you and MattN are the obvious reviewers for the profile reset code, and I know you both have a large review queue, but I chose you :) Feel free to delegate the request to someone else. Ed, there's no such escape hatch for you ;)

The approach I've taken is to write a preference to the new profile that indicates some post-refresh migration action needs to be taken. Currently, that action is only to stash the FxA email address in the services.sync.username preference.

An alternative approach would be for the migration code to parse the JSON in signedInUser.json and write the new services.sync.username preference directly - this would avoid the changes needed in UIState.jsm and nsBrowserGlue.js, making the patch smaller and also avoid checking the new preference name on every startup - but seems slightly uglier to me as then the profile migration code needs to know what's stored inside that file, and in the future we might even end up doing additional migration checks. However, I'm in 2 minds about this, so it wouldn't be too difficult to convince me that we should parse the JSON in the migrator and drop the new preference.

Either way, this patch has reasonably good tests and works well.

WDYT?
Attachment #8905802 - Flags: feedback?(gijskruitbosch+bugs)
Attachment #8905802 - Flags: feedback?(eoger)
Attachment #8903081 - Attachment is obsolete: true
Comment on attachment 8905802 [details]
Bug 1395332 - perform some post-profile-migration steps to ensure Sync works correctly in the new profile.

https://reviewboard.mozilla.org/r/177608/#review182664

::: browser/components/migration/tests/marionette/test_refresh_firefox.py:384
(Diff revision 1)
> +        self.assertEqual(result["accountData"]["uid"], "uid");
> +        self.assertEqual(result["accountData"]["keyFetchToken"], "top-secret");
> +        self.assertEqual(result["prefBeforeWeaveMigration"], hasMigrated);
> +        if hasMigrated:
> +          # pref should never exist after migration.
> +          self.assertEqual(result["prefAfterWeaveMigration"], False);

*sob* - I'm actually going to need to rethink this test with the nsBrowserGlue.js change - it races and does the migration - but I'll leave this patch up for now waiting for the general feedback.
(In reply to Mark Hammond [:markh] from comment #21)
> An alternative approach would be for the migration code to parse the JSON in
> signedInUser.json and write the new services.sync.username preference
> directly

On reflection, if I was reviewing this patch I'd probably suggest that was a more pragmatic option.
(In reply to Mark Hammond [:markh] from comment #23)

> On reflection, if I was reviewing this patch I'd probably suggest that was a
> more pragmatic option.

Your comment convinced me of the same, if that's of any interest :D
Comment on attachment 8905802 [details]
Bug 1395332 - perform some post-profile-migration steps to ensure Sync works correctly in the new profile.

Clearing review per the earlier comments. :-)

If we are going to go the migration route, the code looks reasonable, but we should probably make the pref write thing a flag that migrators set (ie "please write the prefs file when done") where the actual save gets executed by the thing calling the resources' migrate() functions. It might also need to wait for the save to happen, I forget how all the "make pref saving omt and async" stuff landed on that front.
Attachment #8905802 - Flags: feedback?(gijskruitbosch+bugs)
Comment on attachment 8905802 [details]
Bug 1395332 - perform some post-profile-migration steps to ensure Sync works correctly in the new profile.

https://reviewboard.mozilla.org/r/177608/#review183716

::: browser/components/migration/FirefoxProfileMigrator.js:133
(Diff revision 2)
>          aCallback(true);
>        }
>      };
>    };
>  
> +  let savePrefs = function() {

Nit: `function savePrefs()`

::: browser/components/migration/FirefoxProfileMigrator.js:136
(Diff revision 2)
>    };
>  
> +  let savePrefs = function() {
> +    // If we've used the pref service to write prefs for the new profile, it's too
> +    // early in startup for the service to have a profile directory, so we have to
> +    // manually tell it where to save the prefs file.

TBH, I would prefer this to be invoked "centrally", based on a flag, once migration of all resources has finished, so probably from MigrationUtils.jsm . But it likely doesn't really matter, so let's leave that as followup fodder...

::: browser/components/migration/FirefoxProfileMigrator.js:204
(Diff revision 2)
> +          let fstream = Cc[FILE_INPUT_STREAM_CID].createInstance(Ci.nsIFileInputStream);
> +          fstream.init(file, -1, 0, 0);
> +          let raw = NetUtil.readInputStreamToString(fstream, fstream.available(),
> +                                                    { charset: "UTF-8" });
> +          let data = JSON.parse(raw);

Please use `fetch()` instead, to avoid this main-thread-blocking IO.
Attachment #8905802 - Flags: review?(gijskruitbosch+bugs) → review-
Comment on attachment 8905802 [details]
Bug 1395332 - perform some post-profile-migration steps to ensure Sync works correctly in the new profile.

https://reviewboard.mozilla.org/r/177608/#review184096

::: browser/components/migration/FirefoxProfileMigrator.js:193
(Diff revision 3)
> +    migrate: aCallback => {
> +      let doMigrate = async () => {

Alternatively, you could consider:

```js
async migrate() {
  try {
    // all the await code
  } catch (ex) {
    aCallback(false);
    return;
  }
  aCallback(true);
}
```

which avoids the nested function. I'm not sure which you think is preferable here, I could be convinced either way. Really, we need to refactor this stuff so it just uses async functions, but who has the time to do all that work...

::: browser/components/migration/FirefoxProfileMigrator.js:198
(Diff revision 3)
> +        let file = this._getFileObject(sourceProfileDir, "signedInUser.json");
> +        if (file) {
> +          let raw = await OS.File.read(file.path, {encoding: "utf-8"});

`_getFileObject` still does sync main-thread IO (`file.exists()`). This is a drop-in replacement in this code that doesn't:

```js
let oldPath = OS.Path.join(sourceProfileDir.path, "signedInUser.json");
await OS.File.read(oldPath, ...);
...
```

::: browser/components/migration/FirefoxProfileMigrator.js:208
(Diff revision 3)
> +            let username = data.accountData.email;
> +            // Write it to prefs.js and flush the file.
> +            Services.prefs.setStringPref("services.sync.username", username);
> +            savePrefs();
> +            // and copy the file itself.
> +            file.copyTo(currentProfileDir, "");

Same for `.copyTo`. We can use:
```js

await OS.File.copy(oldPath, OS.Path.join(currentProfileDir.path, "signedInUser.json"));

```
Attachment #8905802 - Flags: review?(gijskruitbosch+bugs) → review+
(In reply to :Gijs from comment #29)
> Alternatively, you could consider:

Doh - yeah, I think that's better.

> `_getFileObject` still does sync main-thread IO (`file.exists()`). This is a
> drop-in replacement in this code that doesn't:

Yeah, but I thought it better to be consistent with the rest of the code that already exists there, especially given the tiny file being copied in this case compared with places.sqlite etc - but OK, I changed it to use async IO everywhere :)

Thanks!
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/080b044b13e3
perform some post-profile-migration steps to ensure Sync works correctly in the new profile. r=Gijs
(In reply to Mark Hammond [:markh] from comment #30)
> > `_getFileObject` still does sync main-thread IO (`file.exists()`). This is a
> > drop-in replacement in this code that doesn't:
> 
> Yeah, but I thought it better to be consistent with the rest of the code
> that already exists there, especially given the tiny file being copied in
> this case compared with places.sqlite etc - but OK, I changed it to use
> async IO everywhere :)
> 
> Thanks!

Yeah, really we should be changing all of these (and the other migrators) to use async IO... but time is not a thing most of us have a lot of. At least now we have a pattern of how to do this stuff. :-)
https://hg.mozilla.org/mozilla-central/rev/080b044b13e3
Status: ASSIGNED → RESOLVED
Closed: 7 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 57
I think QA verification of this bug is worthwhile
Flags: qe-verify?
I can reproduce this issue in nightly 57.0a1 (2017-08-30) (64-bit) in 64-bit Linux following the STR found here(https://github.com/mozilla/fxa/issues/258#issuecomment-326050303).

I can verify that this is fixed in latest firefox beta 57.0b7

Build ID 	20171009192146
User Agent 	Mozilla/5.0 (X11; Linux x86_64; rv:57.0) Gecko/20100101 Firefox/57.0
QA Whiteboard: [bugday-20171011]
I can reproduce this bug with Nightly 57.0a1 (2017-08-30) (64-bit) in Windows 7, 64 Bit as per the STR found here(https://github.com/mozilla/fxa/issues/258#issuecomment-326050303).

This bug's fix is verified with latest Beta 57.0b8!

Build ID 	20171013042429
User Agent 	Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:57.0) Gecko/20100101 Firefox/57.0

[testday-20171013]
As the fix is verified in both Linux(comment 37) and windows(comment 38), I am marking this bug as verified fixed.
Status: RESOLVED → VERIFIED
You need to log in before you can comment on or make changes to this bug.