756366 - Firefox not remembering Sync had been setup across restart

Status: VERIFIED FIXED

(Firefox :: Sync, defect)

Description

[Samat Jain]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:14.0) Gecko/20120517 Firefox/14.0a2
Build ID: 20120517081353

Steps to reproduce:

I’m having trouble setting up Sync on a new desktop install of Firefox. On first run, Sync appears to  work fine. When I restart Firefox, it appears to forget I had setup Sync already, though synced data   and various Sync-related settings remain.

1. Created new Firefox profile (start w/ firefox -ProfileManager, created new profile called “sync-    test”), and started Firefox w/ it
2. Started Sync setup(Tools menu -> Set up Sync)
3. Clicked “I Have an Account”
4. Clicked “Sync Options”
5. Chose “Replace all data on this computer with my Sync data”
6. Entered code on other computer/device, finished setup
7. See “Setup complete” screen. Wait until finished.
8. Checked that Sync synced stuff correctly. Appears to have: saved passwords there, as is browser     history, etc.
9. Checked about:sync-log. No logs present.
10. File menu -> Quit.
11. Started Firefox again, into same “sync-test” profile.
12. Check tools menu. Says “Setup Sync” again, and launches Sync setup wizard (same as in step 2). 
13. Checked about:sync-logs. There are no logs.
14. Checked about:config, filted on “sync”. Some sync preferences exist, e.g. “services.sync.account”  is “tamasrepus”.
15. Checked whether data synced previously has been kept; it has. Passwords, history, etc appear to be there.

My Sync username is “tamasrepus”.

Problematic machine’s (using packages from Ubuntu’s firefox-aurora PPA, on Ubuntu 12.04 (precise))     user-agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:14.0) Gecko/20120517 Firefox/14.0a2

Machine that so far appears to be working (also packages from Ubuntu’s firefox-aurora PPA, but using   Ubuntu 11.10 (oneiric)): Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:14.0) Gecko/20120517 Firefox/14.0a2
This has been happening for the past week or so (over various Aurora builds), and I’ve done various other things trying to fix it,  including doing a “Reset Sync” with “Replace all other devices with this computer’s data”, all to no avail.

I also actively use Sync on Firefox 15/Nightly on an Android phone, if that's relevant.

How else can I diagnose this?


Actual results:

Firefox forgot that I had already setup Sync.


Expected results:

Firefox should remember that I had setup Sync.

Comment 1

[Gregory Szorc [:gps]]

I almost wonder if Firefox is crashing on shutdown and all your preference changes aren't being flushed to disk as a result.

Do you see any indication that Firefox is crashing on shutdown?

Can you try reproducing with the official Firefox packages from https://www.mozilla.org/firefox/aurora/. It is possible this is a bug in Ubuntu's packaging. (I personally noticed the other day that Firefox crashed on shutdown the first time I used the Ubuntu package.)

Also, Sync won't retain logs if a sync was successful. To change that behavior, flip services.sync.log.appender.file.logOnSuccess to true in about:config.

Comment 2

[Samat Jain]

I noticed Ubuntu's Aurora builds crashing on shutdown sometime last week, but they haven't been doing it lately and AFAIK there's no indication of crashing now.

I tried with Firefox's official 64-bit Linux Aurora package (I couldn't get the 32-bit version to work) from http://ftp.mozilla.org/pub/mozilla.org/firefox/nightly/latest-mozilla-aurora/, and repeated the steps above (i.e. new profile). Same result, no indication of crashing either…

I flipped services.sync.log.appender.file.logOnSuccess, attaching log…

Comment 3

[Samat Jain]

Attachment: Log from first sync

Comment 4

[Gregory Szorc [:gps]]

Comment on attachment 625032 [details]
Log from first sync

Yeah, Sync is definitely working in this log.

Could you start Firefox from the command-line and attach the terminal output from right before you close Firefox to when the process terminates? That should expose a silent shutdown crash.

While you are at it, please also include the terminal output from when you launch Firefox from the terminal. That may also print information about unclean shutdowns.

Comment 5

[Samat Jain]

Attachment: Console output from running Firefox on the command line

Comment 6

[Samat Jain]

Attached terminal output from running the official Firefox binary.

Is there a verbose flag to pass so it prints more? Other than that, no, doesn't appear to be crashing.

Comment 7

[Gregory Szorc [:gps]]

Doh. I think it may be a compile-time thing. I'm so used to building Firefox from source that I forget what the official binaries do.

Launch firefox with -jsconsole. Do you see anything strange in the Error Console on startup?

Comment 8

[Samat Jain]

Attachment: Copied & pasted error log

Copied & pasted entries from the Error Log.

I didn't see a way to copy everything, so I selectively picked errors/warnings that may have been interesting (the majority of warnings were CSS-related).

Comment 9

[Gregory Szorc [:gps]]

I don't see anything too alarming. And, there are some Sync logs in there, so it seems this profile is working!

Comment 10

[Samat Jain]

So… I'm out of ideas how to diagnose this. Any idea what preferences Firefox looks at to determine whether Sync has been setup already? Prefs like "services.sync.account" remain set across restarts. I'm not sure what else is important.

I'm working on getting a fresh computer to test with to see whether it's something with the builds or something with my profile data stored on Sync.

Comment 11

[Richard Newman [:rnewman]]

Do you have Firefox set to cleared saved passwords on exit?

Comment 12

[Samat Jain]

> Do you have Firefox set to cleared saved passwords on exit?

Nope, it's off. I'm doing this against a fresh profile so all other settings should be at their defaults.

Comment 13

[Samat Jain]

Debugged this a bit more, and noticed the difference between a functional/non-functional profile…

I believe there's a bug with “Replace all data on this computer with my Sync data” (i.e. step 5 above). That, or something with the data stored in my account, which means a bug in something that put the data there.

When setting up Sync, if I use the default (merge data), all works fine.

But for replace: immediately after setting up Sync, if I take a peak at Firefox's password manager, I see 2 entries (fresh profile):

chrome://weave (Mozilla Services Password)
chrome://weave (Mozilla Services Encryption Passphrase)

Once Sync is complete a few minutes later, these two entries are gone—Sync appears to wipe them out. On restart, both entries are still missing. I don't know whether a "replace" is supposed to not erase these, or bring these two entries back from the server-stored Sync data.

When doing setup with merge, and checking a working profile, Firefox's Password Manager still has these two entries.

I see this behavior in both Aurora (see original bug) and today's Nightly; I haven't checked a release or beta yet.


Comment 14

[Samat Jain]

Mmm, and I think I found another bug in Bugzilla that caused that to get mangled… reposting:

Debugged this a bit more, and noticed the difference between a functional/non-functional profile…

I believe there's a bug with “Replace all data on this computer with my Sync data” (i.e. step 5 above). That, or something with the data stored in my account, which means a bug in something that put the data there.

When setting up Sync, if I use the default (merge data), all works fine.

But for replace: immediately after setting up Sync, if I take a peak at Firefox's password manager, I see 2 entries (fresh profile):

chrome://weave (Mozilla Services Password)
chrome://weave (Mozilla Services Encryption Passphrase)

Once Sync is complete a few minutes later, these two entries are gone—Sync appears to wipe them out. On restart, both entries are still missing. I don't know whether a "replace" is supposed to not erase these, or bring these two entries back from the server-stored Sync data.

When doing setup with merge, and checking a working profile, Firefox's Password Manager still has these two entries.

I see this behavior in both Aurora (see original bug) and today's Nightly; I haven't checked a release or beta yet.

Comment 15

[Gregory Szorc [:gps]]

I was able to reproduce this.

Comment 16

[Gregory Szorc [:gps]]

When doing a reset sync from remote data, I don't see any log entries from Identity. I suspect that the credentials aren't being saved after the password engine is wiped.

I suspect this is a regression from bug 730989.

rnewman: do you know how we handled this before? Did we ignore Sync credentials when wiping data? Did we have some hook in the "reset sync" flow to force credentials to be saved again? Did we save credentials after every sync? These answers aren't too important, but they may save an iteration on the patch process.

Comment 17

[Gregory Szorc [:gps]]

Also, the credentials aren't lost until the application restarts. If the application is running after reset from remote, Sync still works.

This is almost surely the passwords wipe removing Sync credentials and Sync not flushing them back.

Comment 18

[Richard Newman [:rnewman]]

(In reply to Gregory Szorc [:gps] from comment #16)

> rnewman: do you know how we handled this before? Did we ignore Sync
> credentials when wiping data? Did we have some hook in the "reset sync" flow
> to force credentials to be saved again? Did we save credentials after every
> sync? These answers aren't too important, but they may save an iteration on
> the patch process.

We didn't ignore credentials on wipe. We just wiped each engine, which in this case includes the password engine, and did a thorough job of it.

Sync credentials were kept around because Service.wipeClient called Service.persistLogin after doing its wiping, which directly persisted the two Identity objects by eventually calling Svc.Login.addLogin on each.

The rewritten code in identity.js should do something very similar, and service.js hasn't changed in this regard since the addon days. I don't see any obvious omission, which implies there's just a bug in the persistence code, or wipeClient is throwing before the credentials are persisted.

I'd be inclined to start by checking that credentials are being persisted during wipeClient.

Comment 19

[Gregory Szorc [:gps]]

Attachment: Flush credentials during wipe

This seems to address the problem. I haven't tested it explicitly. Will understand if r+ is conditional on that being done.

xpcshell tests pass. Verified new test failed with patch not applied.

Will eventually request uplift to Aurora.

Comment 20

[Richard Newman [:rnewman]]

Comment on attachment 625780 [details] [diff] [review]
Flush credentials during wipe

Review of attachment 625780 [details] [diff] [review]:
-----------------------------------------------------------------

That makes sense. Thanks for the minimal test, too.

Comment 21

[Gregory Szorc [:gps]]

https://hg.mozilla.org/integration/mozilla-inbound/rev/efed01e37c1b

Verified with local build before pushing. Landed in inbound because bug is a regression and we want it to land on builds ASAP. Will nominate patch for Aurora.

Comment 22

[Gregory Szorc [:gps]]

Comment on attachment 625780 [details] [diff] [review]
Flush credentials during wipe

[Approval Request Comment]
Bug caused by (feature/regressing bug #): 730989
User impact if declined: Sync credentials will get lost on application restart if device is reset.
Testing completed (on m-c, etc.): None yet. QA will verify on Nightly builds in a day or two.
Risk to taking this patch (and alternatives if risky): Should be low. This patches restores the old behavior.
String or UUID changes made by this patch: None

Comment 23

[Ed Morley [:emorley]]

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

Comment 24

[Alex Keybl [:akeybl]]

Comment on attachment 625780 [details] [diff] [review]
Flush credentials during wipe

[Triage Comment]
Approving this low risk fix for Aurora 14 to prevent a new sync regression.

Comment 25

[Richard Newman [:rnewman]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/769754742698

Comment 26

[Andreea Pod]

Following the steps from description all worked fine. 
Verified fixed this on:
- Mozilla/5.0 (Windows NT 6.1; rv:14.0) Gecko/20120604 Firefox/14.0a2
- Mozilla/5.0 (Windows NT 6.1; rv:13.0) Gecko/20100101 Firefox/13.0 (Beta 7)
- Mozilla/5.0 (Windows NT 6.1; rv:13.0) Gecko/20100101 Firefox/13.0

Please reopen or log a new bug if you can still see the problem.