972129 - Requesting "sync now" while identity manager is still initializing doesn't sync when it becomes ready

Status: RESOLVED FIXED

(Firefox :: Sync, defect)

Description

[Mark Hammond [:markh] [:mhammond]]

STR:
* Configure Fx for sync, then restart.
* Immediately after restart, select "sync now"

Expected:
* Sync starts as soon as possible.

Actual:
* Sync is scheduled for 10 minutes in the future.

Eg, the logs show (with many lines removed):

1392254930735	Sync.Service	INFO	Loading Weave 1.32.0
1392254930765	Sync.ErrorHandler	DEBUG	Beginning user-triggered sync.
1392254930796	Sync.Status	DEBUG	Status.login: success.login => error.login.reason.initializing
1392254930796	Sync.Status	DEBUG	Status.service: success.status_ok => error.login.failed
1392255236850	Sync.SyncScheduler	DEBUG	Clearing sync triggers and the global score.
1392255236850	Sync.SyncScheduler	DEBUG	Next sync in 600000 ms.

The issue is that sync doesn't recognize the "error.login.reason.initializing" state is one that should be resolved very soon.

Comment 1

[Mark Hammond [:markh] [:mhammond]]

Attachment: Reschedule sync after 5 seconds if login failure is due to identity manager not being ready

5 seconds is obviously arbitrary, but seem reasonable given that we don't expect it to take long.

This shouldn't trigger on an unverified user as such users should cause a CLIENT_NOT_CONFIGURED status given we don't yet know their username (although there is some weirdness around that currently which still needs to be resolved).

Comment 2

[Richard Newman [:rnewman]]

Comment on attachment 8375255 [details] [diff] [review]
Reschedule sync after 5 seconds if login failure is due to identity manager not being ready

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

This'll only happen early on, so let's call this 10 seconds. And please add an in-memory counter in the policy object; if we try six times in a minute, and nothing changes, we really ought to back off.

Might as well do something like:

		} else if (Status.login == LOGIN_FAILED_NOT_READY) {
                this._loginNotReadyCounter++;
		this._log.debug("Couldn't log in: identity not ready.");
		this._log.trace("Scheduling a sync at IDENTITY_NOT_READY_RETRY_INTERVAL * " + this._loginNotReadyCounter);
		this.scheduleAtInterval(IDENTITY_NOT_READY_RETRY_INTERVAL * this._loginNotReadyCounter);

Comment 3

[Mark Hammond [:markh] [:mhammond]]

Attachment: 0001-Bug-972129-introduce-a-custom-backoff-schedule-if-fa.patch

(In reply to Richard Newman [:rnewman] from comment #2)

> This'll only happen early on, so let's call this 10 seconds.

I used the backoff strategy you suggested below, so kept this at 5 seconds - if it becomes ready after the initial 5 seconds, the user will probably not be aware we waited at all.  If it's not ready, the next interval will be 10 seconds, etc - so 4 retries in the first minute (which seems reasonable and not too aggressive).

It's obviously easy to still change it to 10 seconds if desired, but IMO, 5 seconds seems perfectly reasonable.

> Might as well do something like:
> 
> 		} else if (Status.login == LOGIN_FAILED_NOT_READY) {
>                 this._loginNotReadyCounter++;
> 		this._log.debug("Couldn't log in: identity not ready.");
> 		this._log.trace("Scheduling a sync at IDENTITY_NOT_READY_RETRY_INTERVAL *
> " + this._loginNotReadyCounter);
> 		this.scheduleAtInterval(IDENTITY_NOT_READY_RETRY_INTERVAL *
> this._loginNotReadyCounter);

It seems slightly risky that this is unbounded, but I defer to your experience here - so done.

Comment 4

[Richard Newman [:rnewman]]

(In reply to Mark Hammond [:markh] from comment #3)

> I used the backoff strategy you suggested below, so kept this at 5 seconds -

Sure.

> It seems slightly risky that this is unbounded, but I defer to your
> experience here - so done.

I figure if it ain't ready in, say, 9 tries in four minutes, then there's no harm in checking that flag every minute or so thereafter.

At the opposite end, once you've been using the browser for an hour or so, the backoff period is going to be longer than the usual sync interval… but if it hasn't become ready by then, then it's unlikely to succeed at all, so again we don't care much.

And worst-case the user will trigger a score-based sync in the mean time.

Comment 5

[Richard Newman [:rnewman]]

Comment on attachment 8375288 [details] [diff] [review]
0001-Bug-972129-introduce-a-custom-backoff-schedule-if-fa.patch

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

::: services/sync/modules/policies.js
@@ +29,5 @@
>                        LOGIN_FAILED_NO_PASSPHRASE,
>                        LOGIN_FAILED_INVALID_PASSPHRASE,
>                        LOGIN_FAILED_LOGIN_REJECTED],
>  
> +  _loginNotReadyCounter: 0,

Newline after.

Comment 6

[Mark Hammond [:markh] [:mhammond]]

https://hg.mozilla.org/integration/fx-team/rev/fa91097a7721

Comment 7

[Ryan VanderMeulen [:RyanVM]]

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

Comment 8

[Mark Hammond [:markh] [:mhammond]]

Attachment: As landed

[Approval Request Comment]
Bug caused by (feature/regressing bug #): N/A
User impact if declined: Sync may not work immediately when requested by the user
Testing completed (on m-c, etc.): Landed on m-c
Risk to taking this patch (and alternatives if risky): Low
String or IDL/UUID changes made by this patch: None

Comment 9

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/releases/mozilla-aurora/rev/19478a56bed8