Bug 1368951 - add x-if-unmodified-since support to the sync test server. r?tcsc draft
authorMark Hammond <mhammond@skippinet.com.au>
Wed, 31 May 2017 18:42:45 +1000
changeset 649682 1c868acb96b35b72f76fab5c6930e9431745a682
parent 649622 7dddbd85047c6dc73ddbe1e423cd643a217845b3
child 649683 b83a47b7789877e52d1358502884f9a3a869a35b
push id75096
push userbmo:markh@mozilla.com
push dateMon, 21 Aug 2017 05:40:36 +0000
reviewerstcsc
bugs1368951
milestone57.0a1
Bug 1368951 - add x-if-unmodified-since support to the sync test server. r?tcsc MozReview-Commit-ID: FF7smwdeQ0k
services/common/modules-testing/logging.js
services/sync/modules/engines.js
services/sync/tests/unit/head_http_server.js
services/sync/tests/unit/test_addons_engine.js
services/sync/tests/unit/test_bookmark_duping.js
services/sync/tests/unit/test_bookmark_engine.js
services/sync/tests/unit/test_bookmark_order.js
services/sync/tests/unit/test_bookmark_repair.js
services/sync/tests/unit/test_bookmark_repair_responder.js
services/sync/tests/unit/test_clients_engine.js
services/sync/tests/unit/test_engine_changes_during_sync.js
services/sync/tests/unit/test_syncengine_sync.js
--- a/services/common/modules-testing/logging.js
+++ b/services/common/modules-testing/logging.js
@@ -40,15 +40,19 @@ this.initTestLogging = function initTest
   Log.repository.getLogger("Services").level = Log.Level[level];
 
   log.level = Log.Level.Trace;
   appender.level = Log.Level.Trace;
   // Overwrite any other appenders (e.g. from previous incarnations)
   log.ownAppenders = [appender];
   log.updateAppenders();
 
+  // SQLite logging is noisy in these tests - we make it quiet by default
+  // (although individual tests are free to bump it later)
+  Log.repository.getLogger("Sqlite").level = Log.Level.Info;
+
   return logStats;
 }
 
 this.getTestLogger = function getTestLogger(component) {
   return Log.repository.getLogger("Testing");
 }
 
--- a/services/sync/modules/engines.js
+++ b/services/sync/modules/engines.js
@@ -1256,21 +1256,26 @@ SyncEngine.prototype = {
       }
       await doApplyBatchAndPersistFailed.call(this);
 
       if (aborting) {
         throw aborting;
       }
     }
 
-    // Mobile: check if we got the maximum that we requested; get the rest if so.
+    // History: check if we got the maximum that we requested; get the rest if so.
     if (handled.length == newitems.limit) {
+      // XXX - this block appears to have no test coverage (eg, throwing here,
+      // or commenting the entire block causes no tests to fail.)
+      // See bug 1368951 comment 3 for some insightful analysis of why this
+      // might not be doing what we expect anyway, so it may be the case that
+      // this needs both fixing *and* tests.
       let guidColl = new Collection(this.engineURL, null, this.service);
 
-      // Sort and limit so that on mobile we only get the last X records.
+      // Sort and limit so that we only get the last X records.
       guidColl.limit = this.downloadLimit;
       guidColl.newer = this.lastSync;
 
       // index: Orders by the sortindex descending (highest weight first).
       guidColl.sort  = "index";
 
       let guids = await guidColl.get();
       if (!guids.success)
@@ -1730,16 +1735,17 @@ SyncEngine.prototype = {
       coll[key] = val;
       await coll.delete();
     };
 
     for (let [key, val] of Object.entries(this._delete)) {
       // Remove the key for future uses
       delete this._delete[key];
 
+      this._log.trace("doing post-sync deletions", {key, val});
       // Send a simple delete for the property
       if (key != "ids" || val.length <= 100)
         await doDelete(key, val);
       else {
         // For many ids, split into chunks of at most 100
         while (val.length > 0) {
           await doDelete(key, val.slice(0, 100));
           val = val.slice(100);
--- a/services/sync/tests/unit/head_http_server.js
+++ b/services/sync/tests/unit/head_http_server.js
@@ -244,16 +244,17 @@ ServerCollection.prototype = {
   },
 
   /**
    * Insert the provided WBO under its ID.
    *
    * @return the provided WBO.
    */
   insertWBO: function insertWBO(wbo) {
+    this.timestamp = Math.max(this.timestamp, wbo.modified);
     return this._wbos[wbo.id] = wbo;
   },
 
   /**
    * Insert the provided payload as part of a new ServerWBO with the provided
    * ID.
    *
    * @param id
@@ -440,17 +441,17 @@ ServerCollection.prototype = {
 
           self._log.info("Records: " + records + ", nextOffset: " + nextOffset);
           if (records != null) {
             response.setHeader("X-Weave-Records", "" + records);
           }
           if (nextOffset) {
             response.setHeader("X-Weave-Next-Offset", "" + nextOffset);
           }
-          response.setHeader("X-Last-Modified", "" + this.timestamp);
+          response.setHeader("X-Last-Modified", "" + self.timestamp);
           break;
 
         case "POST":
           let res = self.post(readBytesFromInputStream(request.bodyInputStream), request);
           body = JSON.stringify(res);
           response.newModified = res.modified;
           break;
 
@@ -461,42 +462,50 @@ ServerCollection.prototype = {
           body = JSON.stringify(ts);
           response.newModified = ts;
           response.deleted = deleted;
           break;
       }
       response.setHeader("X-Weave-Timestamp",
                          "" + new_timestamp(),
                          false);
-      response.setStatusLine(request.httpVersion, statusCode, status);
-      response.bodyOutputStream.write(body, body.length);
 
       // Update the collection timestamp to the appropriate modified time.
       // This is either a value set by the handler, or the current time.
       if (request.method != "GET") {
-        this.timestamp = (response.newModified >= 0) ?
+        self.timestamp = (response.newModified >= 0) ?
                          response.newModified :
                          new_timestamp();
       }
+      response.setHeader("X-Last-Modified", "" + self.timestamp, false);
+
+      response.setStatusLine(request.httpVersion, statusCode, status);
+      response.bodyOutputStream.write(body, body.length);
     };
   }
 
 };
 
 /*
  * Test setup helpers.
  */
 function sync_httpd_setup(handlers) {
   handlers["/1.1/foo/storage/meta/global"]
       = (new ServerWBO("global", {})).handler();
   return httpd_setup(handlers);
 }
 
 /*
  * Track collection modified times. Return closures.
+ *
+ * XXX - DO NOT USE IN NEW TESTS
+ *
+ * This code has very limited and very hacky timestamp support - the test
+ * server now has more complete and correct support - using this helper
+ * may cause strangeness wrt timestamp headers and 412 responses.
  */
 function track_collections_helper() {
 
   /*
    * Our tracking object.
    */
   let collections = {};
 
@@ -937,45 +946,66 @@ SyncServer.prototype = {
 
       let match = this.storageRE.exec(rest);
       if (!match) {
         this._log.warn("SyncServer: Unknown storage operation " + rest);
         throw HTTP_404;
       }
       let [, collection, wboID] = match;
       let coll = this.getCollection(username, collection);
+
+      let checkXIUSFailure = () => {
+        if (req.hasHeader("x-if-unmodified-since")) {
+          let xius = parseFloat(req.getHeader("x-if-unmodified-since"));
+          // Sadly the way our tests are setup, we often end up with xius of
+          // zero (typically when syncing just one engine, so the date from
+          // info/collections isn't used) - so we allow that to work.
+          // Further, the Python server treats non-existing collections as
+          // having a timestamp of 0.
+          let collTimestamp = coll ? coll.timestamp : 0;
+          if (xius && xius < collTimestamp) {
+            this._log.info(`x-if-unmodified-since mismatch - request wants ${xius} but our collection has ${collTimestamp}`);
+            respond(412, "precondition failed", "precondition failed");
+            return true;
+          }
+        }
+        return false;
+      }
+
       switch (req.method) {
         case "GET": {
           if (!coll) {
             if (wboID) {
               respond(404, "Not found", "Not found");
               return undefined;
             }
-            // *cries inside*: Bug 687299 - now fixed, so apparently the real
-            // sync server *will* 404 in this case - bug 1347807 is to change
-            // this to a 404 and fix a handful of test failures it causes.
+            // *cries inside*: - apparently the real sync server returned 200
+            // here for some time, then returned 404 for some time (bug 687299),
+            // and now is back to 200 (bug 963332).
             respond(200, "OK", "[]");
             return undefined;
           }
           if (!wboID) {
             return coll.collectionHandler(req, resp);
           }
           let wbo = coll.wbo(wboID);
           if (!wbo) {
             respond(404, "Not found", "Not found");
             return undefined;
           }
           return wbo.handler()(req, resp);
         }
-        // TODO: implement handling of X-If-Unmodified-Since for write verbs.
         case "DELETE": {
           if (!coll) {
             respond(200, "OK", "{}");
             return undefined;
           }
+          if (checkXIUSFailure()) {
+            return undefined;
+          }
           if (wboID) {
             let wbo = coll.wbo(wboID);
             if (wbo) {
               wbo.delete();
               this.callback.onItemDeleted(username, collection, wboID);
             }
             respond(200, "OK", "{}");
             return undefined;
@@ -1006,21 +1036,45 @@ SyncServer.prototype = {
 
           // Notify of item deletion.
           let deleted = resp.deleted || [];
           for (let i = 0; i < deleted.length; ++i) {
             this.callback.onItemDeleted(username, collection, deleted[i]);
           }
           return undefined;
         }
+        case "PUT":
+          // PUT and POST have slightly different XIUS semantics - for PUT,
+          // the check is against the item, whereas for POST it is against
+          // the collection. So first, a special-case for PUT.
+          if (req.hasHeader("x-if-unmodified-since")) {
+            let xius = parseFloat(req.getHeader("x-if-unmodified-since"));
+            // treat and xius of zero as if it wasn't specified - this happens
+            // in some of our tests for a new collection.
+            if (xius > 0) {
+              let wbo = coll.wbo(wboID);
+              if (xius < wbo.modified) {
+                this._log.info(`x-if-unmodified-since mismatch - request wants ${xius} but wbo has ${wbo.modified}`);
+                respond(412, "precondition failed", "precondition failed");
+                return undefined;
+              }
+              wbo.handler()(req, resp);
+              coll.timestamp = resp.newModified;
+              return resp;
+            }
+          }
+          // fall through to post.
         case "POST":
-        case "PUT":
+          if (checkXIUSFailure()) {
+            return undefined;
+          }
           if (!coll) {
             coll = this.createCollection(username, collection);
           }
+
           if (wboID) {
             let wbo = coll.wbo(wboID);
             if (!wbo) {
               this._log.trace("SyncServer: creating WBO " + collection + "/" + wboID);
               wbo = coll.insert(wboID);
             }
             // Rather than instantiate each WBO's handler function, do it once
             // per request. They get hit far less often than do collections.
--- a/services/sync/tests/unit/test_addons_engine.js
+++ b/services/sync/tests/unit/test_addons_engine.js
@@ -223,21 +223,22 @@ add_task(async function test_disabled_in
   let addon = reconciler.getAddonStateFromSyncGUID(id);
   do_check_neq(null, addon);
   do_check_eq(false, addon.enabled);
 
   // We fake an app restart and perform another sync, just to make sure things
   // are sane.
   restartManager();
 
+  let collection = server.getCollection(USER, "addons");
+  engine.lastModified = collection.timestamp;
   await engine._sync();
 
   // The client should not upload a new record. The old record should be
   // retained and unmodified.
-  let collection = server.getCollection(USER, "addons");
   do_check_eq(1, collection.count());
 
   let payload = collection.payloads()[0];
   do_check_neq(null, collection.wbo(id));
   do_check_eq(ADDON_ID, payload.addonID);
   do_check_false(payload.enabled);
 
   await promiseStopServer(server);
--- a/services/sync/tests/unit/test_bookmark_duping.js
+++ b/services/sync/tests/unit/test_bookmark_duping.js
@@ -285,38 +285,42 @@ add_task(async function test_dupe_repare
       bmkUri: "http://getfirefox.com/",
       type: "bookmark",
       title: "Get Firefox!",
       parentName: "Folder 1",
       parentid: folder2_guid,
     };
 
     let deltaSeconds = 500;
-    collection.insert(newGUID, encryptPayload(to_apply), Date.now() / 1000 + deltaSeconds);
+    let newWBO = collection.insert(newGUID, encryptPayload(to_apply), Date.now() / 1000 + deltaSeconds);
+    do_print(`new duplicate of ${bmk1_guid} is ${newGUID}`);
 
     // Make a change to the bookmark that's a dupe, and set the modification
     // time further in the future than the incoming record. This will cause
     // us to issue the infamous "DATA LOSS" warning in the logs but cause us
     // to *not* apply the incoming record.
     await PlacesTestUtils.setBookmarkSyncFields({
       guid: bmk1_guid,
       syncChangeCounter: 1,
       lastModified: Date.now() + (deltaSeconds + 10) * 1000,
     });
 
     _("Syncing so new dupe record is processed");
-    engine.lastSync = engine.lastSync - 5;
+    // We need to take care to only sync the one new record - if we also see
+    // our local item as incoming the test fails - bug 1368608.
+    engine.lastSync = newWBO.modified - 0.000001;
+    engine.lastModified = null;
     await engine.sync();
 
     // We should have logically deleted the dupe record.
     equal(collection.count(), 8);
     ok(getServerRecord(collection, bmk1_guid).deleted);
     // and physically removed from the local store.
     await promiseNoLocalItem(bmk1_guid);
-    // The original folder still longer has the item
+    // The original folder still has the item
     equal((await getFolderChildrenIDs(folder1_id)).length, 1);
     // The second folder does not.
     equal((await getFolderChildrenIDs(folder2_id)).length, 0);
 
     // The record for folder1 on the server should reference only the GUID.
     let serverRecord1 = getServerRecord(collection, folder1_guid);
     ok(!serverRecord1.children.includes(bmk1_guid));
     ok(serverRecord1.children.includes(newGUID));
--- a/services/sync/tests/unit/test_bookmark_engine.js
+++ b/services/sync/tests/unit/test_bookmark_engine.js
@@ -745,32 +745,35 @@ add_task(async function test_sync_dateAd
 
     // Also, add a local bookmark and make sure it's date added makes it up to the server
     let bzid = PlacesUtils.bookmarks.insertBookmark(
       PlacesUtils.bookmarksMenuFolderId, Utils.makeURI("https://bugzilla.mozilla.org/"),
       PlacesUtils.bookmarks.DEFAULT_INDEX, "Bugzilla");
 
     let bzguid = await PlacesUtils.promiseItemGuid(bzid);
 
-
+    // last sync did a POST, which doesn't advance its lastModified value.
+    // Next sync of the engine doesn't hit info/collections, so lastModified
+    // remains stale. Setting it to null side-steps that.
+    engine.lastModified = null;
     await sync_engine_and_validate_telem(engine, false);
 
     let newRecord2 = await store.createRecord(item2GUID);
     equal(newRecord2.dateAdded, item2.dateAdded, "dateAdded update should work for earlier date");
 
     let bzWBO = JSON.parse(JSON.parse(collection._wbos[bzguid].payload).ciphertext);
     ok(bzWBO.dateAdded, "Locally added dateAdded lost");
 
     let localRecord = await store.createRecord(bzguid);
     equal(bzWBO.dateAdded, localRecord.dateAdded, "dateAdded should not change during upload");
 
     item2.dateAdded += 10000;
     collection.insert(item2GUID, encryptPayload(item2.cleartext), now / 1000 - 10);
-    engine.lastSync = now / 1000 - 20;
 
+    engine.lastModified = null;
     await sync_engine_and_validate_telem(engine, false);
 
     let newerRecord2 = await store.createRecord(item2GUID);
     equal(newerRecord2.dateAdded, newRecord2.dateAdded,
       "dateAdded update should be ignored for later date if we know an earlier one ");
 
 
 
--- a/services/sync/tests/unit/test_bookmark_order.js
+++ b/services/sync/tests/unit/test_bookmark_order.js
@@ -135,16 +135,17 @@ async function resolveConflict(engine, c
     parentid: guids.res,
     bmkUri: "ircs://irc.mozilla.org/nightly",
     title: "IRC",
   }];
   for (let record of serverRecords) {
     collection.insert(record.id, encryptPayload(record), timestamp);
   }
 
+  engine.lastModified = collection.timestamp;
   await sync_engine_and_validate_telem(engine, false);
 
   let expectedTree = buildTree(guids);
   await assertBookmarksTreeMatches(PlacesUtils.bookmarks.menuGuid,
     expectedTree, message);
 }
 
 add_task(async function test_local_order_newer() {
--- a/services/sync/tests/unit/test_bookmark_repair.js
+++ b/services/sync/tests/unit/test_bookmark_repair.js
@@ -477,20 +477,22 @@ add_task(async function test_repair_serv
     let validationPromise = promiseValidationDone([]);
     _("Syncing.");
     await Service.sync();
     // should have 2 clients
     equal(clientsEngine.stats.numClients, 2)
     await validationPromise;
 
     // Now we will reach into the server and create a tombstone for that bookmark
+    // but with a last-modified in the past - this way our sync isn't going to
+    // pick up the record.
     server.insertWBO("foo", "bookmarks", new ServerWBO(bookmarkInfo.guid, encryptPayload({
       id: bookmarkInfo.guid,
       deleted: true,
-    }), Date.now() / 1000));
+    }), (Date.now() - 60000) / 1000));
 
     // sync again - we should have a few problems...
     _("Syncing again.");
     validationPromise = promiseValidationDone([
       {"name": "serverDeleted", "count": 1},
       {"name": "deletedChildren", "count": 1},
       {"name": "orphans", "count": 1}
     ]);
--- a/services/sync/tests/unit/test_bookmark_repair_responder.js
+++ b/services/sync/tests/unit/test_bookmark_repair_responder.js
@@ -8,18 +8,16 @@ Cu.import("resource://gre/modules/Log.js
 
 Cu.import("resource://services-sync/engines/bookmarks.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/bookmark_repair.js");
 Cu.import("resource://testing-common/services/sync/utils.js");
 
 initTestLogging("Trace");
 Log.repository.getLogger("Sync.Engine.Bookmarks").level = Log.Level.Trace;
-// sqlite logging generates lots of noise and typically isn't helpful here.
-Log.repository.getLogger("Sqlite").level = Log.Level.Error;
 
 // Disable validation so that we don't try to automatically repair the server
 // when we sync.
 Svc.Prefs.set("engine.bookmarks.validation.enabled", false);
 
 // stub telemetry so we can easily check the right things are recorded.
 var recordedEvents = [];
 
--- a/services/sync/tests/unit/test_clients_engine.js
+++ b/services/sync/tests/unit/test_clients_engine.js
@@ -137,16 +137,17 @@ add_task(async function test_bad_hmac() 
       "That means we get an HMAC error but redownload keys.");
     Service.lastHMACEvent = 0;
     engine.localID = Utils.makeGUID();
     await engine.resetClient();
     generateNewKeys(Service.collectionKeys);
     deletedCollections = [];
     deletedItems       = [];
     check_clients_count(1);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     _("Old record was not deleted, new one uploaded.");
     equal(deletedCollections.length, 0);
     equal(deletedItems.length, 0);
     check_clients_count(2);
 
     _("Now try the scenario where our keys are wrong *and* there's a bad record.");
@@ -157,16 +158,17 @@ add_task(async function test_bad_hmac() 
     await engine.resetClient();
     deletedCollections = [];
     deletedItems       = [];
     check_clients_count(0);
 
     await uploadNewKeys();
 
     // Sync once to upload a record.
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     check_clients_count(1);
 
     // Generate and upload new keys, so the old client record is wrong.
     await uploadNewKeys();
 
     // Create a new client record and new keys. Now our keys are wrong, as well
     // as the object on the server. We'll download the new keys and also delete
@@ -236,16 +238,17 @@ add_task(async function test_full_sync()
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     let store = engine._store;
 
     _("First sync. 2 records downloaded; our record uploaded.");
     strictEqual(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     ok(engine.lastRecordUpload > 0);
     deepEqual(user.collection("clients").keys().sort(),
               [activeID, deletedID, engine.localID].sort(),
               "Our record should be uploaded on first sync");
     let ids = await store.getAllIDs();
     deepEqual(Object.keys(ids).sort(),
               [activeID, deletedID, engine.localID].sort(),
@@ -287,24 +290,26 @@ add_task(async function test_sync() {
     return user.collection("clients").wbo(engine.localID);
   }
 
   try {
 
     _("First sync. Client record is uploaded.");
     equal(clientWBO(), undefined);
     equal(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     ok(!!clientWBO().payload);
     ok(engine.lastRecordUpload > 0);
 
     _("Let's time travel more than a week back, new record should've been uploaded.");
     engine.lastRecordUpload -= MORE_THAN_CLIENTS_TTL_REFRESH;
     let lastweek = engine.lastRecordUpload;
     clientWBO().payload = undefined;
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     ok(!!clientWBO().payload);
     ok(engine.lastRecordUpload > lastweek);
 
     _("Remove client record.");
     await engine.removeClientData();
     equal(clientWBO().payload, undefined);
 
@@ -372,25 +377,28 @@ add_task(async function test_last_modifi
     version: "48",
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     let collection = user.collection("clients");
 
     _("Sync to download the record");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     equal(engine._store._remoteClients[activeID].serverLastModified, now - 10,
           "last modified in the local record is correctly the server last-modified");
 
     _("Modify the record and re-upload it");
     // set a new name to make sure we really did upload.
     engine._store._remoteClients[activeID].name = "New name";
     engine._modified.set(activeID, 0);
+    // The sync above also did a POST, so adjust our lastModified.
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._uploadOutgoing();
 
     _("Local record should have updated timestamp");
     ok(engine._store._remoteClients[activeID].serverLastModified >= now);
 
     _("Record on the server should have new name but not serverLastModified");
     let payload = JSON.parse(JSON.parse(collection.payload(activeID)).ciphertext);
     equal(payload.name, "New name");
@@ -626,16 +634,17 @@ add_task(async function test_filter_dupl
     protocols: ["1.5"],
   }), now - 604820));
 
   try {
     let store = engine._store;
 
     _("First sync");
     strictEqual(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     ok(engine.lastRecordUpload > 0);
     deepEqual(user.collection("clients").keys().sort(),
               [recentID, dupeID, oldID, engine.localID].sort(),
               "Our record should be uploaded on first sync");
 
     let ids = await store.getAllIDs();
     deepEqual(Object.keys(ids).sort(),
@@ -1018,16 +1027,17 @@ add_task(async function test_merge_comma
     }],
     version: "48",
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     _("First sync. 2 records downloaded.");
     strictEqual(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     _("Broadcast logout to all clients");
     await engine.sendCommand("logout", []);
     await engine._sync();
 
     let collection = server.getCollection("foo", "clients");
     let desktopPayload = JSON.parse(JSON.parse(collection.payload(desktopID)).ciphertext);
@@ -1070,16 +1080,17 @@ add_task(async function test_duplicate_r
     commands: [],
     version: "48",
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     _("First sync. 1 record downloaded.");
     strictEqual(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     _("Send tab to client");
     await engine.sendCommand("displayURI", ["https://example.com", engine.localID, "Yak Herders Anonymous"]);
     await engine._sync();
 
     _("Simulate the desktop client consuming the command and syncing to the server");
     server.insertWBO("foo", "clients", new ServerWBO(desktopID, encryptPayload({
@@ -1088,16 +1099,17 @@ add_task(async function test_duplicate_r
       type: "desktop",
       commands: [],
       version: "48",
       protocols: ["1.5"],
     }), now - 10));
 
     _("Send another tab to the desktop client");
     await engine.sendCommand("displayURI", ["https://foobar.com", engine.localID, "Foo bar!"], desktopID);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     let collection = server.getCollection("foo", "clients");
     let desktopPayload = JSON.parse(JSON.parse(collection.payload(desktopID)).ciphertext);
     compareCommands(desktopPayload.commands, [{
       command: "displayURI",
       args: ["https://foobar.com", engine.localID, "Foo bar!"],
     }], "Should only send the second command to the desktop client");
@@ -1142,16 +1154,17 @@ add_task(async function test_upload_afte
     commands: [],
     version: "48",
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     _("First sync. 2 records downloaded.");
     strictEqual(engine.lastRecordUpload, 0);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     _("Send tab to client");
     await engine.sendCommand("displayURI", ["https://example.com", engine.localID, "Yak Herders Anonymous"], deviceBID);
 
     const oldUploadOutgoing = SyncEngine.prototype._uploadOutgoing;
     SyncEngine.prototype._uploadOutgoing = async () => engine._onRecordsWritten([], [deviceBID]);
     await engine._sync();
@@ -1288,16 +1301,17 @@ add_task(async function test_keep_cleare
 
     // Simulate reboot
     SyncEngine.prototype._uploadOutgoing = oldUploadOutgoing;
     engine = Service.clientsEngine = new ClientEngine(Service);
     await engine.initialize();
 
     commandsProcessed = 0;
     engine._handleDisplayURIs = (uris) => { commandsProcessed = uris.length };
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     await engine.processIncomingCommands();
     equal(commandsProcessed, 1, "We processed one command (the other were cleared)");
 
     localRemoteRecord = JSON.parse(JSON.parse(collection.payload(deviceBID)).ciphertext);
     deepEqual(localRemoteRecord.commands, [], "Should be empty");
   } finally {
     await cleanup();
@@ -1341,24 +1355,26 @@ add_task(async function test_deleted_com
     type: "desktop",
     commands: [],
     version: "48",
     protocols: ["1.5"],
   }), now - 10));
 
   try {
     _("First sync. 2 records downloaded.");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     _("Delete a record on the server.");
     let collection = server.getCollection("foo", "clients");
     collection.remove(deletedID);
 
     _("Broadcast a command to all clients");
     await engine.sendCommand("logout", []);
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
 
     deepEqual(collection.keys().sort(), [activeID, engine.localID].sort(),
       "Should not reupload deleted clients");
 
     let activePayload = JSON.parse(JSON.parse(collection.payload(activeID)).ciphertext);
     compareCommands(activePayload.commands, [{ command: "logout", args: [] }],
       "Should send the command to the active client");
@@ -1381,30 +1397,32 @@ add_task(async function test_send_uri_ac
 
   await SyncTestingInfrastructure(server);
   generateNewKeys(Service.collectionKeys);
 
   try {
     let fakeSenderID = Utils.makeGUID();
 
     _("Initial sync for empty clients collection");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     let collection = server.getCollection("foo", "clients");
     let ourPayload = JSON.parse(JSON.parse(collection.payload(engine.localID)).ciphertext);
     ok(ourPayload, "Should upload our client record");
 
     _("Send a URL to the device on the server");
     ourPayload.commands = [{
       command: "displayURI",
       args: ["https://example.com", fakeSenderID, "Yak Herders Anonymous"],
       flowID: Utils.makeGUID(),
     }];
     server.insertWBO("foo", "clients", new ServerWBO(engine.localID, encryptPayload(ourPayload), now));
 
     _("Sync again");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     compareCommands(engine.localCommands, [{
       command: "displayURI",
       args: ["https://example.com", fakeSenderID, "Yak Herders Anonymous"],
     }], "Should receive incoming URI");
     ok((await engine.processIncomingCommands()), "Should process incoming commands");
     const clearedCommands = (await engine._readCommands())[engine.localID];
     compareCommands(clearedCommands, [{
@@ -1458,16 +1476,17 @@ add_task(async function test_command_syn
     type: "mobile",
     commands: [],
     version: "48",
     protocols: ["1.5"]
   }), Date.now() / 1000));
 
   try {
     equal(collection.count(), 2, "2 remote records written");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     equal(collection.count(), 3, "3 remote records written (+1 for the synced local record)");
 
     await engine.sendCommand("wipeAll", []);
     engine._tracker.addChangedID(engine.localID);
     const getClientFxaDeviceId = sinon.stub(engine, "getClientFxaDeviceId", (id) => "fxa-" + id);
     const engineMock = sinon.mock(engine);
     let _notifyCollectionChanged = engineMock.expects("_notifyCollectionChanged")
@@ -1521,16 +1540,17 @@ add_task(async function ensureSameFlowID
       id: remoteId2,
       name: "Remote client 2",
       type: "mobile",
       commands: [],
       version: "48",
       protocols: ["1.5"]
     }), Date.now() / 1000));
 
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     await engine.sendCommand("wipeAll", []);
     await engine._sync();
     equal(events.length, 2);
     // we don't know what the flowID is, but do know it should be the same.
     equal(events[0].extra.flowID, events[1].extra.flowID);
     // Wipe remote clients to ensure deduping doesn't prevent us from adding the command.
     for (let client of Object.values(engine._store._remoteClients)) {
@@ -1655,16 +1675,17 @@ add_task(async function test_other_clien
       calls++;
       return Promise.resolve(true);
     }
   };
 
   try {
     engine.lastRecordUpload = 0;
     _("First sync, should notify other clients");
+    engine.lastModified = server.getCollection("foo", "clients").timestamp;
     await engine._sync();
     equal(calls, 1);
 
     _("Second sync, should not notify other clients");
     await engine._sync();
     equal(calls, 1);
   } finally {
     engine.fxAccounts = fxAccounts;
--- a/services/sync/tests/unit/test_engine_changes_during_sync.js
+++ b/services/sync/tests/unit/test_engine_changes_during_sync.js
@@ -14,18 +14,16 @@ const LoginInfo = Components.Constructor
 /**
  * We don't test the clients or tabs engines because neither has conflict
  * resolution logic. The clients engine syncs twice per global sync, and
  * custom conflict resolution logic for commands that doesn't use
  * timestamps. Tabs doesn't have conflict resolution at all, since it's
  * read-only.
  */
 
-Log.repository.getLogger("Sqlite").level = Log.Level.Error;
-
 async function assertChildGuids(folderGuid, expectedChildGuids, message) {
   let tree = await PlacesUtils.promiseBookmarksTree(folderGuid);
   let childGuids = tree.children.map(child => child.guid);
   deepEqual(childGuids, expectedChildGuids, message);
 }
 
 async function cleanup(engine, server) {
   Svc.Obs.notify("weave:engine:stop-tracking");
--- a/services/sync/tests/unit/test_syncengine_sync.js
+++ b/services/sync/tests/unit/test_syncengine_sync.js
@@ -461,16 +461,17 @@ add_task(async function test_processInco
 
   // Simulate a locally-deleted item.
   engine._store.items = {};
   engine._tracker.addChangedID("DUPE_LOCAL", now + 3);
   do_check_false((await engine._store.itemExists("DUPE_LOCAL")));
   do_check_false((await engine._store.itemExists("DUPE_INCOMING")));
   do_check_eq("DUPE_LOCAL", (await engine._findDupe({id: "DUPE_INCOMING"})));
 
+  engine.lastModified = server.getCollection(user, engine.name).timestamp;
   await engine._sync();
 
   // After the sync, the server's payload for the original ID should be marked
   // as deleted.
   do_check_empty(engine._store.items);
   let collection = server.getCollection(user, "rotary");
   do_check_eq(1, collection.count());
   wbo = collection.wbo("DUPE_INCOMING");
@@ -534,16 +535,17 @@ add_task(async function test_processInco
   let wbo = new ServerWBO("DUPE_INCOMING", record, now + 2);
   server.insertWBO(user, "rotary", wbo);
 
   await engine._store.create({id: "DUPE_LOCAL", denomination: "local"});
   engine._tracker.addChangedID("DUPE_LOCAL", now + 3);
   do_check_true((await engine._store.itemExists("DUPE_LOCAL")));
   do_check_eq("DUPE_LOCAL", (await engine._findDupe({id: "DUPE_INCOMING"})));
 
+  engine.lastModified = server.getCollection(user, engine.name).timestamp;
   await engine._sync();
 
   // The ID should have been changed to incoming.
   do_check_attribute_count(engine._store.items, 1);
   do_check_true("DUPE_INCOMING" in engine._store.items);
 
   // On the server, the local ID should be deleted and the incoming ID should
   // have its payload set to what was in the local record.
@@ -572,16 +574,17 @@ add_task(async function test_processInco
   let wbo = new ServerWBO("DUPE_INCOMING", record, now + 2);
   server.insertWBO(user, "rotary", wbo);
 
   await engine._store.create({id: "DUPE_LOCAL", denomination: "local"});
   engine._tracker.addChangedID("DUPE_LOCAL", now + 1);
   do_check_true((await engine._store.itemExists("DUPE_LOCAL")));
   do_check_eq("DUPE_LOCAL", (await engine._findDupe({id: "DUPE_INCOMING"})));
 
+  engine.lastModified = server.getCollection(user, engine.name).timestamp;
   await engine._sync();
 
   // The ID should have been changed to incoming.
   do_check_attribute_count(engine._store.items, 1);
   do_check_true("DUPE_INCOMING" in engine._store.items);
 
   // On the server, the local ID should be deleted and the incoming ID should
   // have its payload retained.