Bug 1410270 - Run Places maintenance for certain Sync bookmark errors. r=tcsc draft
authorKit Cambridge <kit@yakshaving.ninja>
Wed, 11 Apr 2018 18:25:33 -0700
changeset 785151 afbe3a02d23c3f910110634e67281cddd00ac305
parent 785138 64c1ee39634e840db0b48c7f1503478c8e8f49e3
child 785175 6901037bd7aa31d7d696daf4b119922217c9d1ea
push id107156
push userbmo:kit@mozilla.com
push dateThu, 19 Apr 2018 18:41:55 +0000
reviewerstcsc
bugs1410270
milestone61.0a1
Bug 1410270 - Run Places maintenance for certain Sync bookmark errors. r=tcsc MozReview-Commit-ID: 54lYPfPods2
services/sync/modules/engines/bookmarks.js
services/sync/tests/unit/test_bookmark_engine.js
services/sync/tests/unit/test_bookmark_repair_responder.js
--- a/services/sync/modules/engines/bookmarks.js
+++ b/services/sync/modules/engines/bookmarks.js
@@ -15,31 +15,34 @@ ChromeUtils.import("resource://services-
 ChromeUtils.import("resource://services-sync/record.js");
 ChromeUtils.import("resource://services-sync/util.js");
 
 XPCOMUtils.defineLazyModuleGetters(this, {
   SyncedBookmarksMirror: "resource://gre/modules/SyncedBookmarksMirror.jsm",
   BookmarkValidator: "resource://services-sync/bookmark_validator.js",
   OS: "resource://gre/modules/osfile.jsm",
   PlacesBackups: "resource://gre/modules/PlacesBackups.jsm",
+  PlacesDBUtils: "resource://gre/modules/PlacesDBUtils.jsm",
   PlacesSyncUtils: "resource://gre/modules/PlacesSyncUtils.jsm",
   PlacesUtils: "resource://gre/modules/PlacesUtils.jsm",
   Resource: "resource://services-sync/resource.js",
 });
 
 XPCOMUtils.defineLazyGetter(this, "PlacesBundle", () => {
   return Services.strings.createBundle("chrome://places/locale/places.properties");
 });
 
 XPCOMUtils.defineLazyGetter(this, "ANNOS_TO_TRACK", () => [
   PlacesSyncUtils.bookmarks.DESCRIPTION_ANNO,
   PlacesSyncUtils.bookmarks.SIDEBAR_ANNO, PlacesUtils.LMANNO_FEEDURI,
   PlacesUtils.LMANNO_SITEURI,
 ]);
 
+const PLACES_MAINTENANCE_INTERVAL_SECONDS = 4 * 60 * 60; // 4 hours.
+
 const FOLDER_SORTINDEX = 1000000;
 
 // Roots that should be deleted from the server, instead of applied locally.
 // This matches `AndroidBrowserBookmarksRepositorySession::forbiddenGUID`,
 // but allows tags because we don't want to reparent tag folders or tag items
 // to "unfiled".
 const FORBIDDEN_INCOMING_IDS = ["pinned", "places", "readinglist"];
 
@@ -385,16 +388,52 @@ BaseBookmarksEngine.prototype = {
 
   async resetLocalSyncID() {
     let newSyncID = await PlacesSyncUtils.bookmarks.resetSyncId();
     this._log.debug("Assigned new sync ID ${newSyncID}", { newSyncID });
     await super.ensureCurrentSyncID(newSyncID); // Remove in bug 1443021.
     return newSyncID;
   },
 
+  async _sync() {
+    try {
+      await super._sync();
+      if (this._ranMaintenanceOnLastSync) {
+        // If the last sync failed, we ran maintenance, and this sync succeeded,
+        // maintenance likely fixed the issue.
+        this._ranMaintenanceOnLastSync = false;
+        this.service.recordTelemetryEvent("maintenance", "fix",
+          "bookmarks");
+      }
+    } catch (ex) {
+      if (Async.isShutdownException(ex) || ex.status > 0) {
+        // Don't run maintenance on shutdown or HTTP errors.
+        throw ex;
+      }
+      // Run Places maintenance periodically to try to recover from corruption
+      // that might have caused the sync to fail. We cap the interval because
+      // persistent failures likely indicate a problem that won't be fixed by
+      // running maintenance after every failed sync.
+      let elapsedSinceMaintenance = Date.now() / 1000 -
+        Services.prefs.getIntPref(
+        "places.database.lastMaintenance", 0);
+      if (elapsedSinceMaintenance >= PLACES_MAINTENANCE_INTERVAL_SECONDS) {
+        this._log.error("Bookmark sync failed, ${elapsedSinceMaintenance}s " +
+                        "elapsed since last run; running Places maintenance",
+                        { elapsedSinceMaintenance });
+        await PlacesDBUtils.maintenanceOnIdle();
+        this._ranMaintenanceOnLastSync = true;
+        this.service.recordTelemetryEvent("maintenance", "run", "bookmarks");
+      } else {
+        this._ranMaintenanceOnLastSync = false;
+      }
+      throw ex;
+    }
+  },
+
   async _syncFinish() {
     await SyncEngine.prototype._syncFinish.call(this);
     await PlacesSyncUtils.bookmarks.ensureMobileQuery();
   },
 
   async _createRecord(id) {
     if (this._modified.isTombstone(id)) {
       // If we already know a changed item is a tombstone, just create the
--- a/services/sync/tests/unit/test_bookmark_engine.js
+++ b/services/sync/tests/unit/test_bookmark_engine.js
@@ -8,16 +8,26 @@ ChromeUtils.import("resource://gre/modul
 ChromeUtils.import("resource://gre/modules/osfile.jsm");
 ChromeUtils.import("resource://services-common/utils.js");
 ChromeUtils.import("resource://services-sync/constants.js");
 ChromeUtils.import("resource://services-sync/engines.js");
 ChromeUtils.import("resource://services-sync/engines/bookmarks.js");
 ChromeUtils.import("resource://services-sync/service.js");
 ChromeUtils.import("resource://services-sync/util.js");
 
+var recordedEvents = [];
+
+function checkRecordedEvents(object, expected, message) {
+  // Ignore event telemetry from the merger.
+  let repairEvents = recordedEvents.filter(event => event.object == object);
+  deepEqual(repairEvents, expected, message);
+  // and clear the list so future checks are easier to write.
+  recordedEvents = [];
+}
+
 async function fetchAllRecordIds() {
   let db = await PlacesUtils.promiseDBConnection();
   let rows = await db.executeCached(`
     WITH RECURSIVE
     syncedItems(id, guid) AS (
       SELECT b.id, b.guid FROM moz_bookmarks b
       WHERE b.guid IN ('menu________', 'toolbar_____', 'unfiled_____',
                        'mobile______')
@@ -42,16 +52,20 @@ async function cleanup(engine, server) {
   Service.recordManager.clearCache();
   await promiseStopServer(server);
   await engine._tracker.stop();
 }
 
 add_task(async function setup() {
   await generateNewKeys(Service.collectionKeys);
   await Service.engineManager.unregister("bookmarks");
+
+  Service.recordTelemetryEvent = (object, method, value, extra = undefined) => {
+    recordedEvents.push({ object, method, value, extra });
+  };
 });
 
 function add_bookmark_test(task) {
   add_task(async function() {
     _(`Running test ${task.name} with legacy bookmarks engine`);
     let legacyEngine = new BookmarksEngine(Service);
     await legacyEngine.initialize();
     try {
@@ -66,16 +80,83 @@ function add_bookmark_test(task) {
     try {
       await task(bufferedEngine);
     } finally {
       await bufferedEngine.finalize();
     }
   });
 }
 
+add_bookmark_test(async function test_maintenance_after_failure(engine) {
+  _("Ensure we try to run maintenance if the engine fails to sync");
+
+  let server = await serverForFoo(engine);
+  await SyncTestingInfrastructure(server);
+
+  try {
+    let syncStartup = engine._syncStartup;
+    let syncError = new Error("Something is rotten in the state of Places");
+    engine._syncStartup = function() {
+      throw syncError;
+    };
+
+    Services.prefs.clearUserPref("places.database.lastMaintenance");
+
+    _("Ensure the sync fails and we run maintenance");
+    await Assert.rejects(
+      sync_engine_and_validate_telem(engine, true),
+      ex => ex == syncError
+    );
+    checkRecordedEvents("maintenance", [{
+      object: "maintenance",
+      method: "run",
+      value: "bookmarks",
+      extra: undefined,
+    }], "Should record event for first maintenance run");
+
+    _("Sync again, but ensure maintenance doesn't run");
+    await Assert.rejects(
+      sync_engine_and_validate_telem(engine, true),
+      ex => ex == syncError
+    );
+    checkRecordedEvents("maintenance", [],
+      "Should not record event if maintenance didn't run");
+
+    _("Fast-forward last maintenance pref; ensure maintenance runs");
+    Services.prefs.setIntPref("places.database.lastMaintenance",
+      Date.now() / 1000 - 14400);
+    await Assert.rejects(
+      sync_engine_and_validate_telem(engine, true),
+      ex => ex == syncError
+    );
+    checkRecordedEvents("maintenance", [{
+      object: "maintenance",
+      method: "run",
+      value: "bookmarks",
+      extra: undefined,
+    }], "Should record event for second maintenance run");
+
+    _("Fix sync failure; ensure we report success after maintenance");
+    engine._syncStartup = syncStartup;
+    await sync_engine_and_validate_telem(engine, false);
+    checkRecordedEvents("maintenance", [{
+      object: "maintenance",
+      method: "fix",
+      value: "bookmarks",
+      extra: undefined,
+    }], "Should record event for successful sync after second maintenance");
+
+    await sync_engine_and_validate_telem(engine, false);
+    checkRecordedEvents("maintenance", [],
+      "Should not record maintenance events after successful sync");
+  } finally {
+    await cleanup(engine, server);
+  }
+});
+
 add_bookmark_test(async function test_delete_invalid_roots_from_server(engine) {
   _("Ensure that we delete the Places and Reading List roots from the server.");
 
   let store   = engine._store;
   let server = await serverForFoo(engine);
   await SyncTestingInfrastructure(server);
 
   let collection = server.user("foo").collection("bookmarks");
--- a/services/sync/tests/unit/test_bookmark_repair_responder.js
+++ b/services/sync/tests/unit/test_bookmark_repair_responder.js
@@ -10,18 +10,20 @@ ChromeUtils.import("resource://services-
 // 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 = [];
 
 function checkRecordedEvents(expected) {
-  // Ignore event telemetry from the merger.
-  let repairEvents = recordedEvents.filter(event => event.object != "mirror");
+  // Ignore event telemetry from the merger and Places maintenance.
+  let repairEvents = recordedEvents.filter(event =>
+    !["mirror", "maintenance"].includes(event.object)
+  );
   deepEqual(repairEvents, expected);
   // and clear the list so future checks are easier to write.
   recordedEvents = [];
 }
 
 function getServerBookmarks(server) {
   return server.user("foo").collection("bookmarks");
 }