Bug 804479 - Intermittent test_password_tracker.js, test_history_tracker.js, test_bookmark_store.js, test_forms_tracker.js | test failed (with xpcshell return code: -2147483645), "ASSERTION: thread pool wasn't shutdown… " r=gps
authorRichard Newman <rnewman@mozilla.com>
Wed, 05 Dec 2012 16:46:25 -0800
changeset 115141 569db4506cb15e1af73490e43fe58ccbbb80811e
parent 115140 3c88682ae393ccb6ad2d7d66a04eab5ff1be167e
child 115142 eed8b79a4803cbd745df0088f599f2a24f62a24e
push id23973
push useremorley@mozilla.com
push dateThu, 06 Dec 2012 10:04:18 +0000
treeherdermozilla-central@ddda5400c826 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersgps
bugs804479
milestone20.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 804479 - Intermittent test_password_tracker.js, test_history_tracker.js, test_bookmark_store.js, test_forms_tracker.js | test failed (with xpcshell return code: -2147483645), "ASSERTION: thread pool wasn't shutdown… " r=gps
services/sync/modules/engines.js
services/sync/tests/unit/test_addons_tracker.js
services/sync/tests/unit/test_bookmark_store.js
services/sync/tests/unit/test_bookmark_tracker.js
services/sync/tests/unit/test_forms_tracker.js
services/sync/tests/unit/test_history_tracker.js
services/sync/tests/unit/test_password_tracker.js
services/sync/tests/unit/test_prefs_tracker.js
services/sync/tests/unit/test_tab_tracker.js
services/sync/tests/unit/test_tracker_addChanged.js
--- a/services/sync/modules/engines.js
+++ b/services/sync/modules/engines.js
@@ -72,19 +72,29 @@ Tracker.prototype = {
     Observers.notify("weave:engine:score:updated", this.name);
   },
 
   // Should be called by service everytime a sync has been done for an engine
   resetScore: function T_resetScore() {
     this._score = 0;
   },
 
-  saveChangedIDs: function T_saveChangedIDs() {
+  persistChangedIDs: true,
+
+  /**
+   * Persist changedIDs to disk at a later date.
+   * Optionally pass a callback to be invoked when the write has occurred.
+   */
+  saveChangedIDs: function (cb) {
+    if (!this.persistChangedIDs) {
+      this._log.debug("Not saving changedIDs.");
+      return;
+    }
     Utils.namedTimer(function() {
-      Utils.jsonSave("changes/" + this.file, this, this.changedIDs);
+      Utils.jsonSave("changes/" + this.file, this, this.changedIDs, cb);
     }, 1000, this, "_lazySave");
   },
 
   loadChangedIDs: function T_loadChangedIDs() {
     Utils.jsonLoad("changes/" + this.file, this, function(json) {
       if (json) {
         this.changedIDs = json;
       }
@@ -117,17 +127,17 @@ Tracker.prototype = {
     // Default to the current time in seconds if no time is provided
     if (when == null)
       when = Math.floor(Date.now() / 1000);
 
     // Add/update the entry if we have a newer time
     if ((this.changedIDs[id] || -Infinity) < when) {
       this._log.trace("Adding changed ID: " + [id, when]);
       this.changedIDs[id] = when;
-      this.saveChangedIDs();
+      this.saveChangedIDs(this.onSavedChangedIDs);
     }
     return true;
   },
 
   removeChangedID: function T_removeChangedID(id) {
     if (!id) {
       this._log.warn("Attempted to remove undefined ID to tracker");
       return false;
--- a/services/sync/tests/unit/test_addons_tracker.js
+++ b/services/sync/tests/unit/test_addons_tracker.js
@@ -15,25 +15,27 @@ Svc.Prefs.set("addons.ignoreRepositoryCh
 Svc.Prefs.set("engine.addons", true);
 
 Service.engineManager.register(AddonsEngine);
 let engine     = Service.engineManager.get("addons");
 let reconciler = engine._reconciler;
 let store      = engine._store;
 let tracker    = engine._tracker;
 
+// Don't write out by default.
+tracker.persistChangedIDs = false;
+
 const addon1ID = "addon1@tests.mozilla.org";
 
 function cleanup_and_advance() {
   Svc.Obs.notify("weave:engine:stop-tracking");
   tracker.observe(null, "weave:engine:stop-tracking");
 
   tracker.resetScore();
   tracker.clearChangedIDs();
-  tracker._lazySave.clear();
 
   reconciler._addons = {};
   reconciler._changes = [];
   let cb = Async.makeSpinningCallback();
   reconciler.saveState(null, cb);
   cb.wait();
 
   run_next_test();
--- a/services/sync/tests/unit/test_bookmark_store.js
+++ b/services/sync/tests/unit/test_bookmark_store.js
@@ -4,18 +4,24 @@
 Cu.import("resource://services-sync/engines.js");
 Cu.import("resource://services-sync/engines/bookmarks.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 
 const PARENT_ANNO = "sync/parent";
 
 Service.engineManager.register(BookmarksEngine);
+
 let engine = Service.engineManager.get("bookmarks");
 let store = engine._store;
+let tracker = engine._tracker;
+
+// Don't write some persistence files asynchronously.
+tracker.persistChangedIDs = false;
+
 let fxuri = Utils.makeURI("http://getfirefox.com/");
 let tburi = Utils.makeURI("http://getthunderbird.com/");
 
 add_test(function test_ignore_specials() {
   _("Ensure that we can't delete bookmark roots.");
 
   // Belt...
   let record = new BookmarkFolder("bookmarks", "toolbar", "folder");
@@ -319,19 +325,19 @@ add_test(function test_move_order() {
     do_check_eq(toolbar.children[0], bmk1_guid);
     do_check_eq(toolbar.children[1], bmk2_guid);
 
     _("Move bookmarks around.");
     store._childrenToOrder = {};
     toolbar.children = [bmk2_guid, bmk1_guid];
     store.applyIncoming(toolbar);
     // Bookmarks engine does this at the end of _processIncoming
-    engine._tracker.ignoreAll = true;
+    tracker.ignoreAll = true;
     store._orderChildren();
-    engine._tracker.ignoreAll = false;
+    tracker.ignoreAll = false;
     delete store._childrenToOrder;
 
     _("Verify new order.");
     do_check_eq(PlacesUtils.bookmarks.getItemIndex(bmk2_id), 0);
     do_check_eq(PlacesUtils.bookmarks.getItemIndex(bmk1_id), 1);
 
   } finally {
     Svc.Obs.notify("weave:engine:stop-tracking");
@@ -394,21 +400,16 @@ add_test(function test_reparentOrphans()
 
     _("Verify that is has been marked as an orphan even though it couldn't be moved into itself.");
     do_check_eq(PlacesUtils.annotations.getItemAnnotation(folder1_id, PARENT_ANNO),
                 folder1_guid);
 
   } finally {
     _("Clean up.");
     store.wipe();
-
-    if (engine._tracker._lazySave) {
-      engine._tracker._lazySave.clear();
-    }
-
     run_next_test();
   }
 });
 
 // Tests Bug 806460, in which query records arrive with empty folder
 // names and missing bookmark URIs.
 add_test(function test_empty_query_doesnt_die() {
   let record = new BookmarkQuery("bookmarks", "8xoDGqKrXf1P");
--- a/services/sync/tests/unit/test_bookmark_tracker.js
+++ b/services/sync/tests/unit/test_bookmark_tracker.js
@@ -6,17 +6,20 @@ Cu.import("resource://services-sync/cons
 Cu.import("resource://services-sync/engines/bookmarks.js");
 Cu.import("resource://services-sync/engines.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 
 Service.engineManager.register(BookmarksEngine);
 let engine = Service.engineManager.get("bookmarks");
 let store  = engine._store;
+let tracker = engine._tracker;
+
 store.wipe();
+tracker.persistChangedIDs = false;
 
 function test_tracking() {
   _("Verify we've got an empty tracker to work with.");
   let tracker = engine._tracker;
   do_check_empty(tracker.changedIDs);
 
   let folder = PlacesUtils.bookmarks.createFolder(
     PlacesUtils.bookmarks.bookmarksMenuFolder,
@@ -61,17 +64,16 @@ function test_tracking() {
     do_check_empty(tracker.changedIDs);
     do_check_eq(tracker.score, 0);
 
   } finally {
     _("Clean up.");
     store.wipe();
     tracker.clearChangedIDs();
     tracker.resetScore();
-    tracker._lazySave.clear();
     Svc.Obs.notify("weave:engine:stop-tracking");
   }
 }
 
 function test_onItemChanged() {
   // Anno that's in ANNOS_TO_TRACK.
   const DESCRIPTION_ANNO = "bookmarkProperties/description";
 
@@ -100,17 +102,16 @@ function test_onItemChanged() {
     do_check_true(tracker.changedIDs[bGUID] > 0);
     do_check_eq(tracker.score, SCORE_INCREMENT_XLARGE);
 
   } finally {
     _("Clean up.");
     store.wipe();
     tracker.clearChangedIDs();
     tracker.resetScore();
-    tracker._lazySave.clear();
     Svc.Obs.notify("weave:engine:stop-tracking");
   }
 }
 
 function test_onItemMoved() {
   _("Verify we've got an empty tracker to work with.");
   let tracker = engine._tracker;
   do_check_empty(tracker.changedIDs);
@@ -153,17 +154,16 @@ function test_onItemMoved() {
     do_check_true(tracker.changedIDs[tb_guid] > 0);
     do_check_eq(tracker.score, SCORE_INCREMENT_XLARGE * 3);
 
   } finally {
     _("Clean up.");
     store.wipe();
     tracker.clearChangedIDs();
     tracker.resetScore();
-    tracker._lazySave.clear();
     Svc.Obs.notify("weave:engine:stop-tracking");
   }
 
 }
 
 function run_test() {
   initTestLogging("Trace");
 
--- a/services/sync/tests/unit/test_forms_tracker.js
+++ b/services/sync/tests/unit/test_forms_tracker.js
@@ -4,16 +4,19 @@
 Cu.import("resource://services-common/log4moz.js");
 Cu.import("resource://services-sync/engines/forms.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 
 function run_test() {
   _("Verify we've got an empty tracker to work with.");
   let tracker = new FormEngine(Service)._tracker;
+  // Don't do asynchronous writes.
+  tracker.persistChangedIDs = false;
+
   do_check_empty(tracker.changedIDs);
   Log4Moz.repository.rootLogger.addAppender(new Log4Moz.DumpAppender());
 
   try {
     _("Create an entry. Won't show because we haven't started tracking yet");
     Svc.Form.addEntry("name", "John Doe");
     do_check_empty(tracker.changedIDs);
 
@@ -41,13 +44,10 @@ function run_test() {
 
     _("Test error detection.");
     // This throws an exception without the fix for Bug 597400.
     tracker.trackEntry("foo", "bar");
 
   } finally {
     _("Clean up.");
     Svc.Form.removeAllEntries();
-    if (tracker._lazySave) {
-      tracker._lazySave.clear();
-    }
   }
 }
--- a/services/sync/tests/unit/test_history_tracker.js
+++ b/services/sync/tests/unit/test_history_tracker.js
@@ -19,16 +19,19 @@ function onScoreUpdated(callback) {
   });
 }
 
 Service.engineManager.clear();
 Service.engineManager.register(HistoryEngine);
 let engine = Service.engineManager.get("history");
 let tracker = engine._tracker;
 
+// Don't write out by default.
+tracker.persistChangedIDs = false;
+
 let _counter = 0;
 function addVisit() {
   let uri = Utils.makeURI("http://getfirefox.com/" + _counter);
   PlacesUtils.history.addVisit(uri, Date.now() * 1000, null, 1, false, 0);
   _counter++;
   return uri;
 }
 
@@ -50,22 +53,33 @@ add_test(function test_not_tracking(next
   Utils.nextTick(function() {
     do_check_empty(tracker.changedIDs);
     do_check_eq(tracker.score, 0);
     run_next_test();
   });
 });
 
 add_test(function test_start_tracking() {
+  _("Add hook for save completion.");
+  tracker.persistChangedIDs = true;
+  tracker.onSavedChangedIDs = function () {
+    _("changedIDs written to disk. Proceeding.");
+    // Turn this back off.
+    tracker.persistChangedIDs = false;
+    delete tracker.onSavedChangedIDs;
+    run_next_test();
+  };
+
   _("Tell the tracker to start tracking changes.");
   onScoreUpdated(function() {
     do_check_attribute_count(tracker.changedIDs, 1);
     do_check_eq(tracker.score, SCORE_INCREMENT_SMALL);
     run_next_test();
   });
+
   Svc.Obs.notify("weave:engine:start-tracking");
   addVisit();
 });
 
 add_test(function test_start_tracking_twice() {
   _("Notifying twice won't do any harm.");
   onScoreUpdated(function() {
     do_check_attribute_count(tracker.changedIDs, 2);
@@ -143,13 +157,10 @@ add_test(function test_stop_tracking_twi
     do_check_empty(tracker.changedIDs);
     run_next_test();
   });
 });
 
 add_test(function cleanup() {
    _("Clean up.");
   PlacesUtils.history.removeAllPages();
-  if (tracker._lazySave) {
-    tracker._lazySave.clear();
-  }
   run_next_test();
 });
--- a/services/sync/tests/unit/test_password_tracker.js
+++ b/services/sync/tests/unit/test_password_tracker.js
@@ -5,22 +5,30 @@ Cu.import("resource://services-sync/cons
 Cu.import("resource://services-sync/engines/passwords.js");
 Cu.import("resource://services-sync/engines.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 
 Service.engineManager.register(PasswordEngine);
 let engine = Service.engineManager.get("passwords");
 let store  = engine._store;
+let tracker = engine._tracker;
 
-function test_tracking() {
+// Don't do asynchronous writes.
+tracker.persistChangedIDs = false;
+
+function run_test() {
+  initTestLogging("Trace");
+  run_next_test();
+}
+
+add_test(function test_tracking() {
   let recordNum = 0;
 
   _("Verify we've got an empty tracker to work with.");
-  let tracker = engine._tracker;
   do_check_empty(tracker.changedIDs);
 
   function createPassword() {
     _("RECORD NUM: " + recordNum);
     let record = {id: "GUID" + recordNum,
                   hostname: "http://foo.bar.com",
                   formSubmitURL: "http://foo.bar.com/baz",
                   username: "john" + recordNum,
@@ -64,41 +72,30 @@ function test_tracking() {
     do_check_empty(tracker.changedIDs);
     do_check_eq(tracker.score, 0);
 
   } finally {
     _("Clean up.");
     store.wipe();
     tracker.clearChangedIDs();
     tracker.resetScore();
-    tracker._lazySave.clear();
     Svc.Obs.notify("weave:engine:stop-tracking");
+    run_next_test();
   }
-}
+});
 
-function test_onWipe() {
+add_test(function test_onWipe() {
   _("Verify we've got an empty tracker to work with.");
-  let tracker = engine._tracker;
   do_check_empty(tracker.changedIDs);
   do_check_eq(tracker.score, 0);
 
   try {
     _("A store wipe should increment the score");
     Svc.Obs.notify("weave:engine:start-tracking");
     store.wipe();
 
     do_check_eq(tracker.score, SCORE_INCREMENT_XLARGE);
   } finally {
     tracker.resetScore();
     Svc.Obs.notify("weave:engine:stop-tracking");
+    run_next_test();
   }
-}
-
-function run_test() {
-  initTestLogging("Trace");
-
-  Log4Moz.repository.getLogger("Sync.Engine.Passwords").level = Log4Moz.Level.Trace;
-  Log4Moz.repository.getLogger("Sync.Store.Passwords").level = Log4Moz.Level.Trace;
-  Log4Moz.repository.getLogger("Sync.Tracker.Passwords").level = Log4Moz.Level.Trace;
-
-  test_tracking();
-  test_onWipe();
-}
+});
--- a/services/sync/tests/unit/test_prefs_tracker.js
+++ b/services/sync/tests/unit/test_prefs_tracker.js
@@ -6,16 +6,20 @@ Cu.import("resource://services-common/ut
 Cu.import("resource://services-sync/constants.js");
 Cu.import("resource://services-sync/engines/prefs.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 
 function run_test() {
   let engine = Service.engineManager.get("prefs");
   let tracker = engine._tracker;
+
+  // Don't write out by default.
+  tracker.persistChangedIDs = false;
+
   let prefs = new Preferences();
 
   try {
 
     _("tracker.modified corresponds to preference.");
     do_check_eq(Svc.Prefs.get("engine.prefs.modified"), undefined);
     do_check_false(tracker.modified);
 
@@ -75,13 +79,10 @@ function run_test() {
     _("Changing some other random pref won't do anything.");
     prefs.set("testing.other", "blergh");
     do_check_eq(tracker.score, SCORE_INCREMENT_XLARGE * 3);
     do_check_eq(tracker.modified, false);
 
   } finally {
     Svc.Obs.notify("weave:engine:stop-tracking");
     prefs.resetBranch("");
-    if (tracker._lazySave) {
-      tracker._lazySave.clear();
-    }
   }
 }
--- a/services/sync/tests/unit/test_tab_tracker.js
+++ b/services/sync/tests/unit/test_tab_tracker.js
@@ -46,16 +46,18 @@ function fakeSvcSession() {
   return logs;
 }
 
 function run_test() {
   let engine = Service.engineManager.get("tabs");
 
   _("We assume that tabs have changed at startup.");
   let tracker = engine._tracker;
+  tracker.persistChangedIDs = false;
+
   do_check_true(tracker.modified);
   do_check_true(Utils.deepEquals(Object.keys(engine.getChangedIDs()),
                                  [clientsEngine.localID]));
 
   let logs;
 
   _("Test listeners are registered on windows");
   logs = fakeSvcWinMediator();
@@ -108,12 +110,9 @@ function run_test() {
   // Pretend we just synced.
   tracker.clearChangedIDs();
   do_check_false(tracker.modified);
 
   tracker.onTab({type: "pageshow", originalTarget: "pageshow"});
   do_check_true(Utils.deepEquals(Object.keys(engine.getChangedIDs()),
                                  [clientsEngine.localID]));
   do_check_eq(logs.length, idx); // test that setTabValue isn't called
-  if (tracker._lazySave) {
-    tracker._lazySave.clear();
-  }
 }
--- a/services/sync/tests/unit/test_tracker_addChanged.js
+++ b/services/sync/tests/unit/test_tracker_addChanged.js
@@ -1,16 +1,23 @@
 /* Any copyright is dedicated to the Public Domain.
    http://creativecommons.org/publicdomain/zero/1.0/ */
 
 Cu.import("resource://services-sync/engines.js");
 Cu.import("resource://services-sync/service.js");
+Cu.import("resource://services-sync/util.js");
 
 function run_test() {
+  run_next_test();
+}
+
+add_test(function test_tracker_basics() {
   let tracker = new Tracker("Tracker", Service);
+  tracker.persistChangedIDs = false;
+
   let id = "the_id!";
 
   _("Make sure nothing exists yet..");
   do_check_eq(tracker.changedIDs[id], null);
 
   _("Make sure adding of time 0 works");
   tracker.addChangedID(id, 0);
   do_check_eq(tracker.changedIDs[id], 0);
@@ -21,10 +28,32 @@ function run_test() {
 
   _("An older time will not replace the newer 10");
   tracker.addChangedID(id, 5);
   do_check_eq(tracker.changedIDs[id], 10);
 
   _("Adding without time defaults to current time");
   tracker.addChangedID(id);
   do_check_true(tracker.changedIDs[id] > 10);
-  tracker._lazySave.clear()
-}
+
+  run_next_test();
+});
+
+add_test(function test_tracker_persistence() {
+  let tracker = new Tracker("Tracker", Service);
+  let id = "abcdef";
+
+  tracker.persistChangedIDs = true;
+  tracker.onSavedChangedIDs = function () {
+    _("IDs saved.");
+    do_check_eq(5, tracker.changedIDs[id]);
+
+    // Verify the write by reading the file back.
+    Utils.jsonLoad("changes/tracker", this, function (json) {
+      do_check_eq(5, json[id]);
+      tracker.persistChangedIDs = false;
+      delete tracker.onSavedChangedIDs;
+      run_next_test();
+    });
+  };
+
+  tracker.addChangedID(id, 5);
+});