Note: There are a few cases of duplicates in user autocompletion which are being worked on.

OS X: Spurious 'back' events from idle observer cause too many instant syncs

VERIFIED FIXED in Firefox 8

Status

Cloud Services
Firefox Sync: Backend
VERIFIED FIXED
6 years ago
6 years ago

People

(Reporter: philikon, Assigned: philikon)

Tracking

(Depends on: 1 bug, {verified-aurora, verified-beta})

unspecified
mozilla10
x86
Mac OS X
verified-aurora, verified-beta
Points:
---
Dependency tree / graph

Firefox Tracking Flags

(firefox7 affected, firefox8 verified, firefox9 verified, firefox10 verified)

Details

(Whiteboard: [verified in services][qa!])

Attachments

(4 attachments, 3 obsolete attachments)

While my Windows machine syncs nicely every hour ('idleInterval') at night, my Mac "wakes up" every few minutes in the middle of the night just like that and decides to sync:

1317730539006	Sync.SyncScheduler	TRACE	We're no longer idle.
1317730539010	Sync.SyncScheduler	TRACE	We're idle.

1317733002010	Sync.SyncScheduler	TRACE	We're no longer idle.
1317733002012	Sync.SyncScheduler	TRACE	We're idle.

etc.

Note how close those notifications are. I suspect that within the same event loop tick, the idle observer is called for 'back' and for 'idle' again. I suggest we implement a "debouncer switch" for the 'back' observer.
Created attachment 564726 [details] [diff] [review]
v1
Assignee: nobody → philipp
Status: NEW → ASSIGNED
Attachment #564726 - Flags: review?(rnewman)
Comment on attachment 564726 [details] [diff] [review]
v1

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

Not reviewing tests yet (until the positive case is tested).

::: services/sync/modules/constants.js
@@ +122,5 @@
>  
>  // Delay before incrementing global score
>  SCORE_UPDATE_DELAY:                    100,
>  
> +// Delay for the back observer debouncer

Explain value, as discussed IRL.

::: services/sync/modules/policies.js
@@ +225,5 @@
>          // were just active.)
>          this.adjustSyncInterval();
>          break;
>        case "back":
>          this._log.trace("We're no longer idle.");

Perhaps change this to "Received notification that we're back from idle.", because it's not always accurate.

@@ +229,5 @@
>          this._log.trace("We're no longer idle.");
>          this.idle = false;
> +        Utils.namedTimer(function onBack() {
> +          if (this.idle) {
> +            this._log.trace("... and we're idle again. Not going to do anything.");

s/Not going to do anything/Ignoring spurious back notification/
Created attachment 564729 [details] [diff] [review]
v2

Addressed nits and added another test (for positive behaviour), too.
Attachment #564726 - Attachment is obsolete: true
Attachment #564726 - Flags: review?(rnewman)
Attachment #564729 - Flags: review?(rnewman)
Comment on attachment 564729 [details] [diff] [review]
v2

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

::: services/sync/tests/unit/test_syncscheduler.js
@@ +509,5 @@
> +  SyncScheduler.observe(null, "idle", Svc.Prefs.get("scheduler.idleTime"));
> +  do_check_eq(SyncScheduler.idle, true);
> +
> +  // We don't actually expect the sync (or the login, for that matter) to
> +  // succeed. We just want to ensure that it happened.

s/happened/was attempted

@@ +521,5 @@
> +  SyncScheduler.observe(null, "back", Svc.Prefs.get("scheduler.idleTime"));
> +});
> +
> +add_test(function test_back_debouncing() {
> +  _("Ensure spurious back-then-idle events as observed on OS X don't trigger a sync.");

, as observed on OS X,
Attachment #564729 - Flags: review?(rnewman) → review+
Blocks: 692006
https://hg.mozilla.org/services/services-central/rev/7b01879fc0a3
Whiteboard: [fixed in services]
STRs for QA:

* Get a Mac (I have an MBP)
* Set 'services.sync.log.appender.file.logOnSuccess' to true, 'services.sync.log.logger.service.main' to Trace, and then restart.
* Leave the machine sitting & syncing for a few hours.

Expected behaviour:

* The machine syncs with 'services.sync.scheduler.idleInterval' (default is 1 hour) once it's been sitting idle for 'services.sync.scheduler.idleTime' (default is 5 minutes).

Observed behaviour without this fix:

* The machine "wakes up" from idle every 10 to 20 minutes for just a few milliseconds (see log snippets in comment 0) and kicks off a sync.
Note that the idle stuff only has any effect if there are at least 2 devices connected to the account.
(Assignee)

Updated

6 years ago
Depends on: 692225
On XP and Mac with the latest s-c builds, testing this passes.  Once active sync timers settled to idle timer, I got syncs only once per hour as expected. No unexpected syncs in between. Then a sync on return from idle.
Whiteboard: [fixed in services] → [verified in services]
Created attachment 565041 [details]
logs during verification pass

shows "smoking gun" per philikon. successfully ignoring spurious back notification
Created attachment 565044 [details]
logs during verification pass
Attachment #565041 - Attachment is obsolete: true
Comment on attachment 564729 [details] [diff] [review]
v2

Requesting approval for Aurora as this patch will help reduce server load due to unnecessary syncing (caused by spurious back-from-idle notifications on Macs). The patch has been verified by Services QA.
Attachment #564729 - Flags: approval-mozilla-aurora?
Created attachment 565055 [details] [diff] [review]
patch for beta and release

Requesting approval for Beta and Release. Please see comment 11 for justification.
Attachment #565055 - Flags: approval-mozilla-release?
Attachment #565055 - Flags: approval-mozilla-beta?
Comment on attachment 565055 [details] [diff] [review]
patch for beta and release

Bah, wrong bug for this patch.
Attachment #565055 - Attachment is obsolete: true
Attachment #565055 - Flags: approval-mozilla-release?
Attachment #565055 - Flags: approval-mozilla-beta?
Created attachment 565077 [details] [diff] [review]
patch for beta

Requesting approval for Beta. Please see comment 11 for justification.
Attachment #565077 - Flags: approval-mozilla-beta?
Created attachment 565078 [details] [diff] [review]
patch for release

Request approval for Release. Please see comment 11 for justification.
Attachment #565078 - Flags: approval-mozilla-release?
https://hg.mozilla.org/mozilla-central/rev/7b01879fc0a3
Status: ASSIGNED → RESOLVED
Last Resolved: 6 years ago
status-firefox10: --- → fixed
status-firefox7: --- → affected
status-firefox8: --- → affected
status-firefox9: --- → affected
Resolution: --- → FIXED
Target Milestone: --- → mozilla10

Updated

6 years ago
Attachment #565077 - Flags: approval-mozilla-beta? → approval-mozilla-beta+

Updated

6 years ago
Attachment #564729 - Flags: approval-mozilla-aurora? → approval-mozilla-aurora+
https://hg.mozilla.org/releases/mozilla-aurora/rev/dc260d4908e8
status-firefox9: affected → fixed
https://hg.mozilla.org/releases/mozilla-beta/rev/74718deb120f
status-firefox8: affected → fixed
qa+ for verification in Firefox 8, 9, and 10 using the testcase in comment 6.
Whiteboard: [verified in services] → [verified in services][qa+]
(Assignee)

Updated

6 years ago
Attachment #565078 - Flags: approval-mozilla-release?
verified cross channel
Status: RESOLVED → VERIFIED
Keywords: verified-aurora, verified-beta

Comment 21

6 years ago
Hi Tracy

based on you comment, can I change the tracking status to verified on 8, 9, 10?

Thanks

(In reply to Tracy Walker [:tracy] from comment #20)
> verified cross channel
done. I'm not sure it's necessary to go back and update all the bugs that were affected by the change in status field.  Let's just use it instead of the ambiguous keywords going forward.  Thanks Vlad.
status-firefox10: fixed → verified
status-firefox8: fixed → verified
status-firefox9: fixed → verified
Whiteboard: [verified in services][qa+] → [verified in services][qa!]
You need to log in before you can comment on or make changes to this bug.