Closed Bug 1396544 Opened 2 years ago Closed 2 years ago

Attempting and failing to sync without Firefox Sync configured

Categories

(Firefox :: Sync, defect)

defect
Not set

Tracking

()

RESOLVED FIXED
Firefox 57
Tracking Status
firefox57 --- fixed

People

(Reporter: florian, Assigned: markh)

Details

Attachments

(1 file)

I have left a local build running over the week-end, and this morning I found plenty of lines like this in my terminal:

1504518898173	Sync.BrowserIDManager	ERROR	Could not authenticate: no user is logged in
1504518898177	Sync.ErrorHandler	ERROR	Sync encountered a login error

This is an almost new profile (generated by ./mach run after the last clobber)

The browser console shows this error 62 times:
Sync encountered an error - see about:sync-log for the log file. policies.js:773

There are several dozen log files in about:sync-log, all showing:
1504513590301	Sync.LogManager	DEBUG	Flushing file log
1504513590345	Sync.LogManager	DEBUG	Log cleanup threshold time: 1503649590345
1504513590485	Sync.LogManager	DEBUG	Done deleting files.
1504518898168	Sync.Service	DEBUG	User-Agent: Firefox/57.0a1 (Intel Mac OS X 10.12) FxSync/1.59.0.20170831233318.desktop
1504518898169	Sync.Service	INFO	Starting sync at 2017-09-04 11:54:58 in browser session VgIlivSa9-Dw
1504518898169	Sync.Service	DEBUG	In sync: should login.
1504518898170	Sync.Service	INFO	Logging in the user.
1504518898173	Sync.BrowserIDManager	INFO	initializeWithCurrentIdentity has no user logged in
1504518898173	Sync.BrowserIDManager	ERROR	Could not authenticate: no user is logged in
1504518898174	Sync.Status	DEBUG	Status.login: error.login.reason.no_username => error.login.reason.no_username
1504518898174	Sync.Status	DEBUG	Status.service: service.client_not_configured => service.client_not_configured
1504518898175	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1504518898176	Sync.SyncScheduler	DEBUG	Next sync in 3600000 ms.
1504518898177	Sync.ErrorHandler	ERROR	Sync encountered a login error
1504518898194	Sync.Service	DEBUG	Exception calling WrappedLock: no user is logged in
1504518898195	Sync.Service	DEBUG	Not syncing: login returned false.
1504518898201	Sync.ErrorHandler	DEBUG	Addons installed: 0


Here are all the sync-related preferences from the profile's prefs.js file:
user_pref("services.sync.clients.lastSync", "0");
user_pref("services.sync.clients.lastSyncLocal", "0");
user_pref("services.sync.declinedEngines", "");
user_pref("services.sync.engine.addresses.available", true);
user_pref("services.sync.globalScore", 0);
user_pref("services.sync.nextSync", 1504522498);
user_pref("services.sync.tabs.lastSync", "0");
user_pref("services.sync.tabs.lastSyncLocal", "0");


The only maybe slightly unusual thing I've done is that about:preferences#general was the selected tab during the whole week-end.
Here's my best guess for what happens here:

* about:preferences initializes sync, but that doesn't do much - it notices no one is logged in.
* We lost the network connection for some reason, then it came back - this can also be simulated by explicitly toggling Firefox offline and back online.
* The network state caused us to hit http://searchfox.org/mozilla-central/rev/f2a1911ad310bf8651f342d719e4f4ca0a7b9bfb/services/sync/modules/policies.js#154.
* checkSyncStatus()/_checkSync doesn't consider sync not being configured as a valid reason to not sync!
* syncs are scheduled and each sync fails with the errors we see above.

Patch forthcoming - I'll ask rnewman for review as he might be aware of some subtleties.
Assignee: nobody → markh
Status: NEW → ASSIGNED
(In reply to Mark Hammond [:markh] from comment #1)

> * We lost the network connection for some reason, then it came back - this
> can also be simulated by explicitly toggling Firefox offline and back online.

It's on my macbook, and I put the laptop to sleep at least twice between opening about:preferences and seeing the bug, as I commuted home for the week-end. So yeah, the network connection definitely changed at least twice.

> Patch forthcoming

Thanks for the quick reaction! :-)
Comment on attachment 8904396 [details]
Bug 1396544 - don't schedule syncs when Sync isn't configured.

https://reviewboard.mozilla.org/r/176200/#review181378

::: services/sync/modules/service.js:1053
(Diff revision 1)
>     * @return Reason for not syncing; not-truthy if sync should run
>     */
>    _checkSync: function _checkSync(ignore) {
>      let reason = "";
> -    if (!this.enabled)
> +    // Ideally we'd call _checkSetup() here but that has too many side-effects.
> +    if (Status.service == CLIENT_NOT_CONFIGURED)

You might want to add this check to `shouldLogin`, too — if we know the client isn't configured, we shouldn't even try.
Attachment #8904396 - Flags: review?(rnewman) → review+
(In reply to Richard Newman [:rnewman] from comment #4)
> You might want to add this check to `shouldLogin`, too — if we know the
> client isn't configured, we shouldn't even try.

That got tricky, so I opened bug 1397087 instead.
Pushed by mhammond@skippinet.com.au:
https://hg.mozilla.org/integration/autoland/rev/1576df4c449c
don't schedule syncs when Sync isn't configured. r=rnewman
https://hg.mozilla.org/mozilla-central/rev/1576df4c449c
Status: ASSIGNED → RESOLVED
Closed: 2 years ago
Resolution: --- → FIXED
Target Milestone: --- → Firefox 57
You need to log in before you can comment on or make changes to this bug.