Bug 691663 - SyncScheduler should obey backoffInterval at all times. r=rnewman

services/sync/modules/policies.js

@@ -122,7 +122,6 @@ let SyncScheduler = {
       case "weave:service:sync:start":
         // Clear out any potentially pending syncs now that we're syncing
         this.clearSyncTriggers();
-        this.nextSync = 0;
 
         // reset backoff info, if the server tells us to continue backing off,
         // we'll handle that later
@@ -131,16 +130,16 @@ let SyncScheduler = {
         this.globalScore = 0;
         break;
       case "weave:service:sync:finish":
+        this.nextSync = 0;
         this.adjustSyncInterval();
 
-        let sync_interval;
-
         if (Status.service == SYNC_FAILED_PARTIAL && this.requiresBackoff) {
           this.requiresBackoff = false;
           this.handleSyncError();
           return;
         }
 
+        let sync_interval;
         this._syncErrors = 0;
         if (Status.sync == NO_SYNC_NODE_FOUND) {
           this._log.trace("Scheduling a sync at interval NO_SYNC_NODE_FOUND.");
@@ -182,6 +181,7 @@ let SyncScheduler = {
         // should still be updated so that the next sync has a correct interval.
         this.updateClientMode();
         this.adjustSyncInterval();
+        this.nextSync = 0;
         this.handleSyncError();
         break;
       case "weave:service:backoff:interval":
@@ -238,7 +238,7 @@ let SyncScheduler = {
           this._log.trace("Genuine return from idle. Syncing.");
           // Trigger a sync if we have multiple clients.
           if (this.numClients > 1) {
-            Utils.nextTick(Weave.Service.sync, Weave.Service);
+            this.scheduleNextSync(0);
           }
         }, IDLE_OBSERVER_BACK_DELAY, this, "idleDebouncerTimer");
         break;
@@ -350,14 +350,23 @@ let SyncScheduler = {
    * Set a timer for the next sync
    */
   scheduleNextSync: function scheduleNextSync(interval) {
-    // Figure out when to sync next if not given a interval to wait
+    // If no interval was specified, use the current sync interval.
-    if (interval == null || interval == undefined) {
+    if (interval == null) {
-      // Check if we had a pending sync from last time
+      interval = this.syncInterval;
-      if (this.nextSync != 0)
+    }
-        interval = Math.min(this.syncInterval, (this.nextSync - Date.now()));
+
-      // Use the bigger of default sync interval and backoff
+    // Ensure the interval is set to no less than the backoff.
-      else
+    if (Status.backoffInterval && interval < Status.backoffInterval) {
-        interval = Math.max(this.syncInterval, Status.backoffInterval);
+      interval = Status.backoffInterval;
+    }
+
+    if (this.nextSync != 0) {
+      // There's already a sync scheduled. Don't reschedule if that's already
+      // going to happen sooner than requested.
+      let currentInterval = this.nextSync - Date.now();
+      if (currentInterval < interval) {
+        return;
+      }
     }
 
     // Start the sync right away if we're already late

services/sync/modules/service.js

@@ -944,6 +944,8 @@ WeaveSvc.prototype = {
     // Reset all engines and clear keys.
     this.resetClient();
     CollectionKeys.clear();
+    Status.resetBackoff();
+    Status.resetSync();
 
     // Reset Weave prefs.
     this._ignorePrefObserver = true;

services/sync/tests/unit/test_interval_triggers.js

@@ -369,7 +369,6 @@ add_test(function test_bug671378_scenario() {
     Utils.nextTick(function() {
       Svc.Obs.remove("weave:service:sync:start", onSyncStart);
 
-      do_check_eq(SyncScheduler.nextSync, 0);
       SyncScheduler.scheduleNextSync();
       do_check_neq(SyncScheduler.nextSync, 0);
       do_check_eq(SyncScheduler.syncInterval, SyncScheduler.singleDeviceInterval);

services/sync/tests/unit/test_sendcredentials_controller.js

@@ -12,6 +12,9 @@ function run_test() {
   Service.passphrase = Utils.generatePassphrase();
   Service.serverURL  = "http://weave.server/";
 
+  initTestLogging("Trace");
+  Log4Moz.repository.getLogger("Sync.SendCredentialsController").level = Log4Moz.Level.Trace;
+  Log4Moz.repository.getLogger("Sync.SyncScheduler").level = Log4Moz.Level.Trace;
   run_next_test();
 }
 
@@ -26,8 +29,6 @@ function make_sendCredentials_test(topic) {
         // when the exchange is complete by faking another notification.
         do_check_false(sendAndCompleteCalled);
         sendAndCompleteCalled = true;
-        this.controller.onComplete();
-        Svc.Obs.notify(topic);
 
         // Verify it sends the correct data.
         do_check_eq(data.account,   Service.account);
@@ -35,11 +36,16 @@ function make_sendCredentials_test(topic) {
         do_check_eq(data.synckey,   Service.passphrase);
         do_check_eq(data.serverURL, Service.serverURL);
 
+        this.controller.onComplete();
         // Verify it schedules a sync for the expected interval.
         let expectedInterval = SyncScheduler.activeInterval;
         do_check_true(SyncScheduler.nextSync - Date.now() <= expectedInterval);
-        SyncScheduler.setDefaults();
 
+        // Signal the end of another sync. We shouldn't be registered anymore,
+        // so we shouldn't re-enter this method (cf sendAndCompleteCalled above)
+        Svc.Obs.notify(topic);
+
+        SyncScheduler.setDefaults();
         Utils.nextTick(run_next_test);
       }
     };

services/sync/tests/unit/test_syncscheduler.js

@@ -204,27 +204,8 @@ add_test(function test_calculateBackoff() {
   run_next_test();
 });
 
-add_test(function test_scheduleNextSync() {
+add_test(function test_scheduleNextSync_noBackoff() {
-  let server = sync_httpd_setup();
+  _("scheduleNextSync() uses the current syncInterval if no interval is provided.");
-  setUp();
-
-  Svc.Obs.add("weave:service:sync:finish", function onSyncFinish() {
-    // Ensure this gets called after SyncScheduler's observer so we
-    // can cancel the timer set by SyncScheduler.scheduleNextSync().
-    Utils.nextTick(function () {
-      SyncScheduler.setDefaults();
-      Svc.Prefs.resetBranch("");
-      SyncScheduler.syncTimer.clear();
-      Svc.Obs.remove("weave:service:sync:finish", onSyncFinish);
-      Service.startOver();
-      server.stop(run_next_test);
-    }, this);
-  });
-  
-  // Make sync happen faster
-  SyncScheduler.singleDeviceInterval = 100;
-  SyncScheduler.syncInterval = SyncScheduler.singleDeviceInterval;
-
   // Test backoffInterval is 0 as expected.
   do_check_eq(Status.backoffInterval, 0);
 
@@ -232,24 +213,97 @@ add_test(function test_scheduleNextSync() {
   SyncScheduler.nextSync = 0;
   SyncScheduler.scheduleNextSync();
 
-  // Test nextSync value was changed.
-  do_check_true(SyncScheduler.nextSync > 0);
-
   // nextSync - Date.now() might be smaller than expectedInterval
   // since some time has passed since we called scheduleNextSync().
-  let expectedInterval = SyncScheduler.singleDeviceInterval;
+  do_check_true(SyncScheduler.nextSync - Date.now()
-  do_check_true(SyncScheduler.nextSync - Date.now() <= expectedInterval);
+                <= SyncScheduler.syncInterval);
-  do_check_eq(SyncScheduler.syncTimer.delay, expectedInterval);
+  do_check_eq(SyncScheduler.syncTimer.delay, SyncScheduler.syncInterval);
 
   _("Test setting sync interval when nextSync != 0");
-  // Schedule next sync for 100ms in the future.
   SyncScheduler.nextSync = Date.now() + SyncScheduler.singleDeviceInterval;
   SyncScheduler.scheduleNextSync();
 
   // nextSync - Date.now() might be smaller than expectedInterval
   // since some time has passed since we called scheduleNextSync().
-  do_check_true(SyncScheduler.nextSync - Date.now() <= expectedInterval);
+  do_check_true(SyncScheduler.nextSync - Date.now()
-  do_check_true(SyncScheduler.syncTimer.delay <= expectedInterval);
+                <= SyncScheduler.syncInterval);
+  do_check_true(SyncScheduler.syncTimer.delay <= SyncScheduler.syncInterval);
+
+  _("Scheduling requests for intervals larger than the current one will be ignored.");
+  // Request a sync at a longer interval. The sync that's already scheduled
+  // for sooner takes precedence.
+  let nextSync = SyncScheduler.nextSync;
+  let timerDelay = SyncScheduler.syncTimer.delay;
+  let requestedInterval = SyncScheduler.syncInterval * 10;
+  SyncScheduler.scheduleNextSync(requestedInterval);
+  do_check_eq(SyncScheduler.nextSync, nextSync);
+  do_check_eq(SyncScheduler.syncTimer.delay, timerDelay);
+
+  // We can schedule anything we want if there isn't a sync scheduled.
+  SyncScheduler.nextSync = 0;
+  SyncScheduler.scheduleNextSync(requestedInterval);
+  do_check_true(SyncScheduler.nextSync <= Date.now() + requestedInterval);
+  do_check_eq(SyncScheduler.syncTimer.delay, requestedInterval);
+
+  // Request a sync at the smallest possible interval (0 triggers now).
+  SyncScheduler.scheduleNextSync(1);
+  do_check_true(SyncScheduler.nextSync <= Date.now() + 1);
+  do_check_eq(SyncScheduler.syncTimer.delay, 1);
+
+  SyncScheduler.syncTimer.clear();
+  Service.startOver();
+  run_next_test();
+});
+
+add_test(function test_scheduleNextSync_backoff() {
+ _("scheduleNextSync() will honour backoff in all scheduling requests.");
+  Status.backoffInterval = 7337000;
+  do_check_true(Status.backoffInterval > SyncScheduler.syncInterval);
+
+  _("Test setting sync interval when nextSync == 0");
+  SyncScheduler.nextSync = 0;
+  SyncScheduler.scheduleNextSync();
+
+  // nextSync - Date.now() might be smaller than expectedInterval
+  // since some time has passed since we called scheduleNextSync().
+  do_check_true(SyncScheduler.nextSync - Date.now()
+                <= Status.backoffInterval);
+  do_check_eq(SyncScheduler.syncTimer.delay, Status.backoffInterval);
+
+  _("Test setting sync interval when nextSync != 0");
+  SyncScheduler.nextSync = Date.now() + SyncScheduler.singleDeviceInterval;
+  SyncScheduler.scheduleNextSync();
+
+  // nextSync - Date.now() might be smaller than expectedInterval
+  // since some time has passed since we called scheduleNextSync().
+  do_check_true(SyncScheduler.nextSync - Date.now()
+                <= Status.backoffInterval);
+  do_check_true(SyncScheduler.syncTimer.delay <= Status.backoffInterval);
+
+  // Request a sync at a longer interval. The sync that's already scheduled
+  // for sooner takes precedence.
+  let nextSync = SyncScheduler.nextSync;
+  let timerDelay = SyncScheduler.syncTimer.delay;
+  let requestedInterval = SyncScheduler.syncInterval * 10;
+  do_check_true(requestedInterval > Status.backoffInterval);
+  SyncScheduler.scheduleNextSync(requestedInterval);
+  do_check_eq(SyncScheduler.nextSync, nextSync);
+  do_check_eq(SyncScheduler.syncTimer.delay, timerDelay);
+
+  // We can schedule anything we want if there isn't a sync scheduled.
+  SyncScheduler.nextSync = 0;
+  SyncScheduler.scheduleNextSync(requestedInterval);
+  do_check_true(SyncScheduler.nextSync <= Date.now() + requestedInterval);
+  do_check_eq(SyncScheduler.syncTimer.delay, requestedInterval);
+
+  // Request a sync at the smallest possible number.
+  SyncScheduler.scheduleNextSync(1);
+  do_check_true(SyncScheduler.nextSync <= Date.now() + Status.backoffInterval);
+  do_check_eq(SyncScheduler.syncTimer.delay, Status.backoffInterval);
+
+  SyncScheduler.syncTimer.clear();
+  Service.startOver();
+  run_next_test();
 });
 
 add_test(function test_handleSyncError() {
@@ -502,17 +556,19 @@ add_test(function test_idle_adjustSyncInterval() {
 
 add_test(function test_back_triggersSync() {
   // Confirm defaults.
-  do_check_eq(SyncScheduler.idle, false);
+  do_check_false(SyncScheduler.idle);
+  do_check_eq(Status.backoffInterval, 0);
 
   // Set up: Define 2 clients and put the system in idle.
   SyncScheduler.numClients = 2;
   SyncScheduler.observe(null, "idle", Svc.Prefs.get("scheduler.idleTime"));
-  do_check_eq(SyncScheduler.idle, true);
+  do_check_true(SyncScheduler.idle);
 
   // We don't actually expect the sync (or the login, for that matter) to
   // succeed. We just want to ensure that it was attempted.
   Svc.Obs.add("weave:service:login:error", function onLoginError() {
     Svc.Obs.remove("weave:service:login:error", onLoginError);
+    SyncScheduler.syncTimer.clear();
     SyncScheduler.setDefaults();    
     run_next_test();
   });
@@ -521,6 +577,36 @@ add_test(function test_back_triggersSync() {
   SyncScheduler.observe(null, "back", Svc.Prefs.get("scheduler.idleTime"));
 });
 
+add_test(function test_back_triggersSync_observesBackoff() {
+  // Confirm defaults.
+  do_check_false(SyncScheduler.idle);
+
+  // Set up: Set backoff, define 2 clients and put the system in idle.
+  Status.backoffInterval = 7337000;
+  SyncScheduler.numClients = 2;
+  SyncScheduler.observe(null, "idle", Svc.Prefs.get("scheduler.idleTime"));
+  do_check_eq(SyncScheduler.idle, true);
+
+  function onLoginStart() {
+    do_throw("Shouldn't have kicked off a sync!");
+  }
+  Svc.Obs.add("weave:service:login:start", onLoginStart);
+
+  timer = Utils.namedTimer(function () {
+    Svc.Obs.remove("weave:service:login:start", onLoginStart);
+
+    do_check_true(SyncScheduler.nextSync <= Date.now() + Status.backoffInterval);
+    do_check_eq(SyncScheduler.syncTimer.delay, Status.backoffInterval);
+
+    SyncScheduler.syncTimer.clear();
+    SyncScheduler.setDefaults();
+    run_next_test();
+  }, IDLE_OBSERVER_BACK_DELAY * 1.5, {}, "timer");
+
+  // Send a 'back' event to try to trigger sync soonish.
+  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.");