Bug 1303945 - Avoid having TPS write directly to the form history database and remove private-browsing tests. r=tcsc draft
authorMark Hammond <mhammond@skippinet.com.au>
Tue, 20 Sep 2016 17:04:50 +1000
changeset 416444 ffec877dd81fe0a23aad945517e8f771b0fe355a
parent 416363 69a451ac94605fe68efa3780fd20a66ccdcb0b35
child 416445 82a1975d7c62e10926b5a73908401c0bcf813b42
push id30151
push userbmo:markh@mozilla.com
push dateThu, 22 Sep 2016 07:20:21 +0000
reviewerstcsc
bugs1303945
milestone52.0a1
Bug 1303945 - Avoid having TPS write directly to the form history database and remove private-browsing tests. r=tcsc MozReview-Commit-ID: JsPGSJpQ7b1
services/sync/modules/engines.js
services/sync/modules/util.js
services/sync/tests/tps/all_tests.json
services/sync/tests/tps/test_formdata.js
services/sync/tests/tps/test_privbrw_formdata.js
services/sync/tests/unit/test_service_sync_locked.js
services/sync/tps/extensions/tps/resource/modules/forms.jsm
services/sync/tps/extensions/tps/resource/tps.jsm
--- a/services/sync/modules/engines.js
+++ b/services/sync/modules/engines.js
@@ -102,17 +102,17 @@ Tracker.prototype = {
       Utils.jsonSave("changes/" + this.file, this, this.changedIDs, cb);
     }, 1000, this, "_lazySave");
   },
 
   loadChangedIDs: function (cb) {
     Utils.jsonLoad("changes/" + this.file, this, function(json) {
       if (json && (typeof(json) == "object")) {
         this.changedIDs = json;
-      } else {
+      } else if (json !== null) {
         this._log.warn("Changed IDs file " + this.file + " contains non-object value.");
         json = null;
       }
       if (cb) {
         cb.call(this, json);
       }
     });
   },
--- a/services/sync/modules/util.js
+++ b/services/sync/modules/util.js
@@ -90,17 +90,17 @@ this.Utils = {
    */
   catch: function Utils_catch(func, exceptionCallback) {
     let thisArg = this;
     return function WrappedCatch() {
       try {
         return func.call(thisArg);
       }
       catch(ex) {
-        thisArg._log.debug("Exception", ex);
+        thisArg._log.debug("Exception calling " + (func.name || "anonymous function"), ex);
         if (exceptionCallback) {
           return exceptionCallback.call(thisArg, ex);
         }
         return null;
       }
     };
   },
 
@@ -353,17 +353,18 @@ this.Utils = {
     }
 
     let json;
 
     try {
       json = yield CommonUtils.readJSON(path);
     } catch (e) {
       if (e instanceof OS.File.Error && e.becauseNoSuchFile) {
-        // Ignore non-existent files.
+        // Ignore non-existent files, but explicitly return null.
+        json = null;
       } else {
         if (that._log) {
           that._log.debug("Failed to load json", e);
         }
       }
     }
 
     callback.call(that, json);
--- a/services/sync/tests/tps/all_tests.json
+++ b/services/sync/tests/tps/all_tests.json
@@ -11,17 +11,16 @@
     "test_bug556509.js",
     "test_bug562515.js",
     "test_bug563989.js",
     "test_bug535326.js",
     "test_bug501528.js",
     "test_bug575423.js",
     "test_bug546807.js",
     "test_history_collision.js",
-    "test_privbrw_formdata.js",
     "test_privbrw_passwords.js",
     "test_privbrw_tabs.js",
     "test_bookmarks_in_same_named_folder.js",
     "test_client_wipe.js",
     "test_special_tabs.js",
     "test_addon_sanity.js",
     "test_addon_restartless_xpi.js",
     "test_addon_nonrestartless_xpi.js",
--- a/services/sync/tests/tps/test_formdata.js
+++ b/services/sync/tests/tps/test_formdata.js
@@ -26,32 +26,42 @@ var formdata1 = [
     value: "failure",
     date: -2
   },
   { fieldname: "username",
     value: "joe"
   }
 ];
 
+// This is currently pointless - it *looks* like it is trying to check that
+// one of the entries in formdata1 has been removed, but (a) the delete code
+// isn't active (see comments below), and (b) the way the verification works
+// means it would never do the right thing - it only checks all the entries
+// here exist, but not that they are the only entries in the DB.
 var formdata2 = [
   { fieldname: "testing",
     value: "success",
     date: -1
   },
   { fieldname: "username",
     value: "joe"
   }
 ];
 
 var formdata_delete = [
   { fieldname: "testing",
     value: "failure"
   }
 ];
 
+var formdata_new = [
+  { fieldname: "new-field",
+    value: "new-value"
+  }
+]
 /*
  * Test phases
  */
 
 Phase('phase1', [
   [Formdata.add, formdata1],
   [Formdata.verify, formdata1],
   [Sync]
@@ -67,18 +77,21 @@ Phase('phase2', [
  * tests are disabled below.  See bug 568363.
  */
 
 Phase('phase3', [
   [Sync],
   [Formdata.delete, formdata_delete],
 //[Formdata.verifyNot, formdata_delete],
   [Formdata.verify, formdata2],
+  // add new data after the first Sync, ensuring the tracker works.
+  [Formdata.add, formdata_new],
   [Sync],
 ]);
 
 Phase('phase4', [
   [Sync],
   [Formdata.verify, formdata2],
+  [Formdata.verify, formdata_new],
 //[Formdata.verifyNot, formdata_delete]
 ]);
 
 
deleted file mode 100644
--- a/services/sync/tests/tps/test_privbrw_formdata.js
+++ /dev/null
@@ -1,73 +0,0 @@
-/* Any copyright is dedicated to the Public Domain.
-   http://creativecommons.org/publicdomain/zero/1.0/ */
-
-/*
- * The list of phases mapped to their corresponding profiles.  The object
- * here must be in strict JSON format, as it will get parsed by the Python
- * testrunner (no single quotes, extra comma's, etc).
- */
-EnableEngines(["forms"]);
-
-var phases = { "phase1": "profile1",
-               "phase2": "profile2",
-               "phase3": "profile1",
-               "phase4": "profile2" };
-
-/*
- * Form data
- */
-
-// the form data to add to the browser
-var formdata1 = [
-   { fieldname: "name",
-     value: "xyz",
-     date: -1
-   },
-   { fieldname: "email",
-     value: "abc@gmail.com",
-     date: -2
-   },
-   { fieldname: "username",
-     value: "joe"
-   }
-];
-
-// the form data to add in private browsing mode
-var formdata2 = [
-   { fieldname: "password",
-     value: "secret",
-     date: -1
-   },
-   { fieldname: "city",
-     value: "mtview"
-   }
-];
-
-/*
- * Test phases
- */
-
-Phase('phase1', [
-  [Formdata.add, formdata1],
-  [Formdata.verify, formdata1],
-  [Sync]
-]);
-
-Phase('phase2', [
-  [Sync],
-  [Formdata.verify, formdata1]
-]);
-
-Phase('phase3', [
-  [Sync],
-  [Windows.add, { private: true }],
-  [Formdata.add, formdata2],
-  [Formdata.verify, formdata2],
-  [Sync],
-]);
-
-Phase('phase4', [
-  [Sync],
-  [Formdata.verify, formdata1],
-  [Formdata.verifyNot, formdata2]
-]);
--- a/services/sync/tests/unit/test_service_sync_locked.js
+++ b/services/sync/tests/unit/test_service_sync_locked.js
@@ -26,12 +26,12 @@ function run_test() {
   // Avoid daily ping
   Svc.Prefs.set("lastPing", Math.floor(Date.now() / 1000));
 
   _("Check that sync will log appropriately if already in 'progress'.");
   Service._locked = true;
   Service.sync();
   Service._locked = false;
 
-  do_check_true(debug[debug.length - 2].startsWith("Exception: Could not acquire lock. Label: \"service.js: login\"."));
+  do_check_true(debug[debug.length - 2].startsWith("Exception calling WrappedLock: Could not acquire lock. Label: \"service.js: login\"."));
   do_check_eq(info[info.length - 1], "Cannot start sync: already syncing?");
 }
 
--- a/services/sync/tps/extensions/tps/resource/modules/forms.jsm
+++ b/services/sync/tps/extensions/tps/resource/modules/forms.jsm
@@ -8,158 +8,116 @@
   */
 
 var EXPORTED_SYMBOLS = ["FormData"];
 
 const {classes: Cc, interfaces: Ci, utils: Cu} = Components;
 
 Cu.import("resource://tps/logger.jsm");
 
-var formService = Cc["@mozilla.org/satchel/form-history;1"]
-                  .getService(Ci.nsIFormHistory2);
+Cu.import("resource://gre/modules/FormHistory.jsm");
+Cu.import("resource://gre/modules/Log.jsm");
 
 /**
  * FormDB
  *
- * Helper object containing methods to interact with the moz_formhistory
- * SQLite table.
+ * Helper object containing methods to interact with the FormHistory module.
  */
 var FormDB = {
-  /**
-   * makeGUID
-   *
-   * Generates a brand-new globally unique identifier (GUID).  Borrowed
-   * from Weave's utils.js.
-   *
-   * @return the new guid
-   */
-  makeGUID: function makeGUID() {
-    // 70 characters that are not-escaped URL-friendly
-    const code =
-      "!()*-.0123456789ABCDEFGHIJKLMNOPQRSTUVWXYZ_abcdefghijklmnopqrstuvwxyz~";
-
-    let guid = "";
-    let num = 0;
-    let val;
-
-    // Generate ten 70-value characters for a 70^10 (~61.29-bit) GUID
-    for (let i = 0; i < 10; i++) {
-      // Refresh the number source after using it a few times
-      if (i == 0 || i == 5)
-        num = Math.random();
-
-      // Figure out which code to use for the next GUID character
-      num *= 70;
-      val = Math.floor(num);
-      guid += code[val];
-      num -= val;
-    }
-
-    return guid;
+  _update(data) {
+    return new Promise((resolve, reject) => {
+      let handlers = {
+        handleError(error) {
+          Logger.logError("Error occurred updating form history: " + Log.exceptionStr(error));
+          reject(error);
+        },
+        handleCompletion(reason) {
+          resolve();
+        }
+      }
+      FormHistory.update(data, handlers);
+    });
   },
 
   /**
    * insertValue
    *
-   * Inserts the specified value for the specified fieldname into the
-   * moz_formhistory table.
+   * Adds the specified value for the specified fieldname into form history.
    *
    * @param fieldname The form fieldname to insert
    * @param value The form value to insert
    * @param us The time, in microseconds, to use for the lastUsed
    *        and firstUsed columns
-   * @return nothing
+   * @return Promise<undefined>
    */
-  insertValue: function (fieldname, value, us) {
-    let query = this.createStatement(
-      "INSERT INTO moz_formhistory " +
-      "(fieldname, value, timesUsed, firstUsed, lastUsed, guid) VALUES " +
-      "(:fieldname, :value, :timesUsed, :firstUsed, :lastUsed, :guid)");
-    query.params.fieldname = fieldname;
-    query.params.value = value;
-    query.params.timesUsed = 1;
-    query.params.firstUsed = us;
-    query.params.lastUsed = us;
-    query.params.guid = this.makeGUID();
-    query.execute();
-    query.reset();
+  insertValue(fieldname, value, us) {
+    let data = { op: "add", fieldname, value, timesUsed: 1,
+                 firstUsed: us, lastUsed: us }
+    return this._update(data);
   },
 
   /**
    * updateValue
    *
    * Updates a row in the moz_formhistory table with a new value.
    *
    * @param id The id of the row to update
    * @param newvalue The new value to set
-   * @return nothing
+   * @return Promise<undefined>
    */
-  updateValue: function (id, newvalue) {
-    let query = this.createStatement(
-      "UPDATE moz_formhistory SET value = :value WHERE id = :id");
-    query.params.id = id;
-    query.params.value = newvalue;
-    query.execute();
-    query.reset();
+  updateValue(id, newvalue) {
+    return this._update({ op: "update", guid: id, value: newvalue });
   },
 
   /**
    * getDataForValue
    *
    * Retrieves a set of values for a row in the database that
    * corresponds to the given fieldname and value.
    *
    * @param fieldname The fieldname of the row to query
    * @param value The value of the row to query
-   * @return null if no row is found with the specified fieldname and value,
-   *         or an object containing the row's id, lastUsed, and firstUsed
-   *         values
+   * @return Promise<null if no row is found with the specified fieldname and value,
+   *         or an object containing the row's guid, lastUsed, and firstUsed
+   *         values>
    */
-  getDataForValue: function (fieldname, value) {
-    let query = this.createStatement(
-      "SELECT id, lastUsed, firstUsed FROM moz_formhistory WHERE " +
-      "fieldname = :fieldname AND value = :value");
-    query.params.fieldname = fieldname;
-    query.params.value = value;
-    if (!query.executeStep())
-      return null;
-
-    return {
-      id: query.row.id,
-      lastUsed: query.row.lastUsed,
-      firstUsed: query.row.firstUsed
-    };
+  getDataForValue(fieldname, value) {
+    return new Promise((resolve, reject) => {
+      let result = null;
+      let handlers = {
+        handleResult(oneResult) {
+          if (result != null) {
+            reject("more than 1 result for this query");
+            return;
+          }
+          result = oneResult;
+        },
+        handleError(error) {
+          Logger.logError("Error occurred updating form history: " + Log.exceptionStr(error));
+          reject(error);
+        },
+        handleCompletion(reason) {
+          resolve(result);
+        }
+      }
+      FormHistory.search(["guid", "lastUsed", "firstUsed"], { fieldname }, handlers);
+    });
   },
 
   /**
-   * createStatement
+   * remove
    *
-   * Creates a statement from a SQL string.  This function is borrowed
-   * from Weave's forms.js.
+   * Removes the specified GUID from the database.
    *
-   * @param query The SQL query string
-   * @return the mozIStorageStatement created from the specified SQL
+   * @param guid The guid of the item to delete
+   * @return Promise<>
    */
-  createStatement: function createStatement(query) {
-    try {
-      // Just return the statement right away if it's okay
-      return formService.DBConnection.createStatement(query);
-    }
-    catch(ex) {
-      // Assume guid column must not exist yet, so add it with an index
-      formService.DBConnection.executeSimpleSQL(
-        "ALTER TABLE moz_formhistory ADD COLUMN guid TEXT");
-      formService.DBConnection.executeSimpleSQL(
-        "CREATE INDEX IF NOT EXISTS moz_formhistory_guid_index " +
-        "ON moz_formhistory (guid)");
-    }
-
-    // Try creating the query now that the column exists
-    return formService.DBConnection.createStatement(query);
-  }
+   remove(guid) {
+    return this._update({ op: "remove", guid });
+  },
 };
 
 /**
  * FormData class constructor
  *
  * Initializes instance properties.
  */
 function FormData(props, usSinceEpoch) {
@@ -199,63 +157,63 @@ FormData.prototype = {
    * add it.  Throws on error.
    *
    * @return nothing
    */
   Create: function() {
     Logger.AssertTrue(this.fieldname != null && this.value != null,
       "Must specify both fieldname and value");
 
-    let formdata = FormDB.getDataForValue(this.fieldname, this.value);
-    if (!formdata) {
-      // this item doesn't exist yet in the db, so we need to insert it
-      FormDB.insertValue(this.fieldname, this.value,
-                         this.hours_to_us(this.date));
-    }
-    else {
-      /* Right now, we ignore this case.  If bug 552531 is ever fixed,
-         we might need to add code here to update the firstUsed or
-         lastUsed fields, as appropriate.
-       */
-    }
+    return FormDB.getDataForValue(this.fieldname, this.value).then(formdata => {
+      if (!formdata) {
+        // this item doesn't exist yet in the db, so we need to insert it
+        return FormDB.insertValue(this.fieldname, this.value,
+                                  this.hours_to_us(this.date));
+      } else {
+        /* Right now, we ignore this case.  If bug 552531 is ever fixed,
+           we might need to add code here to update the firstUsed or
+           lastUsed fields, as appropriate.
+         */
+      }
+    });
   },
 
   /**
    * Find
    *
    * Attempts to locate an entry in the moz_formhistory database that
    * matches the fieldname and value for this FormData object.
    *
    * @return true if this entry exists in the database, otherwise false
    */
   Find: function() {
-    let formdata = FormDB.getDataForValue(this.fieldname, this.value);
-    let status = formdata != null;
-    if (status) {
-      /*
-      //form history dates currently not synced!  bug 552531
-      let us = this.hours_to_us(this.date);
-      status = Logger.AssertTrue(
-        us >= formdata.firstUsed && us <= formdata.lastUsed,
-        "No match for with that date value");
+    return FormDB.getDataForValue(this.fieldname, this.value).then(formdata => {
+      let status = formdata != null;
+      if (status) {
+        /*
+        //form history dates currently not synced!  bug 552531
+        let us = this.hours_to_us(this.date);
+        status = Logger.AssertTrue(
+          us >= formdata.firstUsed && us <= formdata.lastUsed,
+          "No match for with that date value");
 
-      if (status)
-      */
-        this.id = formdata.id;
-    }
-    return status;
+        if (status)
+        */
+          this.id = formdata.guid;
+      }
+      return status;
+    });
   },
 
   /**
    * Remove
    *
    * Removes the row represented by this FormData instance from the
    * moz_formhistory database.
    *
    * @return nothing
    */
   Remove: function() {
     /* Right now Weave doesn't handle this correctly, see bug 568363.
      */
-    formService.removeEntry(this.fieldname, this.value);
-    return true;
+    return FormDB.remove(this.id);
   },
 };
--- a/services/sync/tps/extensions/tps/resource/tps.jsm
+++ b/services/sync/tps/extensions/tps/resource/tps.jsm
@@ -77,17 +77,17 @@ const ACTIONS = [
   ACTION_SYNC_WIPE_REMOTE,
   ACTION_VERIFY,
   ACTION_VERIFY_NOT,
 ];
 
 const OBSERVER_TOPICS = ["fxaccounts:onlogin",
                          "fxaccounts:onlogout",
                          "private-browsing",
-                         "quit-application-requested",
+                         "profile-before-change",
                          "sessionstore-windows-restored",
                          "weave:engine:start-tracking",
                          "weave:engine:stop-tracking",
                          "weave:service:login:error",
                          "weave:service:setup-complete",
                          "weave:service:sync:finish",
                          "weave:service:sync:delayed",
                          "weave:service:sync:error",
@@ -161,17 +161,17 @@ var TPS = {
     try {
       Logger.logInfo("----------event observed: " + topic);
 
       switch(topic) {
         case "private-browsing":
           Logger.logInfo("private browsing " + data);
           break;
 
-        case "quit-application-requested":
+        case "profile-before-change":
           OBSERVER_TOPICS.forEach(function(topic) {
             Services.obs.removeObserver(this, topic);
           }, this);
 
           Logger.close();
 
           break;
 
@@ -362,27 +362,28 @@ var TPS = {
   HandleForms: function (data, action) {
     this.shouldValidateForms = true;
     for (let datum of data) {
       Logger.logInfo("executing action " + action.toUpperCase() +
                      " on form entry " + JSON.stringify(datum));
       let formdata = new FormData(datum, this._usSinceEpoch);
       switch(action) {
         case ACTION_ADD:
-          formdata.Create();
+          Async.promiseSpinningly(formdata.Create());
           break;
         case ACTION_DELETE:
-          formdata.Remove();
+          Async.promiseSpinningly(formdata.Remove());
           break;
         case ACTION_VERIFY:
-          Logger.AssertTrue(formdata.Find(), "form data not found");
+          Logger.AssertTrue(Async.promiseSpinningly(formdata.Find()),
+                            "form data not found");
           break;
         case ACTION_VERIFY_NOT:
-          Logger.AssertTrue(!formdata.Find(),
-            "form data found, but it shouldn't be present");
+          Logger.AssertTrue(!Async.promiseSpinningly(formdata.Find()),
+                            "form data found, but it shouldn't be present");
           break;
         default:
           Logger.AssertTrue(false, "invalid action: " + action);
       }
     }
     Logger.logPass("executing action " + action.toUpperCase() +
                    " on formdata");
   },
@@ -586,17 +587,24 @@ var TPS = {
 
   Cleanup() {
     try {
       this.WipeServer();
     } catch (ex) {
       Logger.logError("Failed to wipe server: " + Log.exceptionStr(ex));
     }
     try {
-      Authentication.signOut();
+      if (Authentication.isLoggedIn) {
+        // signout and wait for Sync to completely reset itself.
+        Logger.logInfo("signing out");
+        let waiter = this.createEventWaiter("weave:service:start-over:finish");
+        Authentication.signOut();
+        waiter();
+        Logger.logInfo("signout complete");
+      }
     } catch (e) {
       Logger.logError("Failed to sign out: " + Log.exceptionStr(e));
     }
   },
 
   /**
    * Use Sync's bookmark validation code to see if we've corrupted the tree.
    */
@@ -696,18 +704,18 @@ var TPS = {
     let serverRecordDumpStr;
     let clientRecordDumpStr;
     try {
       Logger.logInfo("About to perform form validation");
       let engine = Weave.Service.engineManager.get("forms");
       let validator = new FormValidator();
       let serverRecords = validator.getServerItems(engine);
       let clientRecords = Async.promiseSpinningly(validator.getClientItems());
-      clientRecordDumpStr = JSON.stringify(clientRecords);
-      serverRecordDumpStr = JSON.stringify(serverRecords);
+      clientRecordDumpStr = JSON.stringify(clientRecords, undefined, 2);
+      serverRecordDumpStr = JSON.stringify(serverRecords, undefined, 2);
       let { problemData } = validator.compareClientWithServer(clientRecords, serverRecords);
       for (let { name, count } of problemData.getSummary()) {
         if (count) {
           Logger.logInfo(`Validation problem: "${name}": ${JSON.stringify(problemData[name])}`);
         }
         Logger.AssertEqual(count, 0, `Form validation error of type ${name}`);
       }
     } catch (e) {
@@ -971,34 +979,66 @@ var TPS = {
     Cu.import('resource://mozmill/modules/frame.js', frame);
     frame.events.addListener('setTest', this.MozmillSetTestListener.bind(this));
     frame.events.addListener('endTest', this.MozmillEndTestListener.bind(this));
     this.StartAsyncOperation();
     frame.runTestFile(mozmillfile.path, null);
   },
 
   /**
+   * Return an object that when called, will block until the named event
+   * is observed. This is similar to waitForEvent, although is typically safer
+   * if you need to do some other work that may make the event fire.
+   *
+   * eg:
+   *    doSomething(); // causes the event to be fired.
+   *    waitForEvent("something");
+   * is risky as the call to doSomething may trigger the event before the
+   * waitForEvent call is made. Contrast with:
+   *
+   *   let waiter = createEventWaiter("something"); // does *not* block.
+   *   doSomething(); // causes the event to be fired.
+   *   waiter(); // will return as soon as the event fires, even if it fires
+   *             // before this function is called.
+   *
+   * @param aEventName
+   *        String event to wait for.
+   */
+  createEventWaiter(aEventName) {
+    Logger.logInfo("Setting up wait for " + aEventName + "...");
+    let cb = Async.makeSpinningCallback();
+    Svc.Obs.add(aEventName, cb);
+    return function() {
+      try {
+        cb.wait();
+      } finally {
+        Svc.Obs.remove(aEventName, cb);
+        Logger.logInfo(aEventName + " observed!");
+      }
+    }
+  },
+
+
+  /**
    * Synchronously wait for the named event to be observed.
    *
    * When the event is observed, the function will wait an extra tick before
    * returning.
    *
+   * Note that in general, you should probably use createEventWaiter unless you
+   * are 100% sure that the event being waited on can only be sent after this
+   * call adds the listener.
+   *
    * @param aEventName
    *        String event to wait for.
    */
   waitForEvent: function waitForEvent(aEventName) {
-    Logger.logInfo("Waiting for " + aEventName + "...");
-    let cb = Async.makeSpinningCallback();
-    Svc.Obs.add(aEventName, cb);
-    cb.wait();
-    Svc.Obs.remove(aEventName, cb);
-    Logger.logInfo(aEventName + " observed!");
+    this.createEventWaiter(aEventName)();
   },
 
-
   /**
    * Waits for Sync to logged in before returning
    */
   waitForSetupComplete: function waitForSetup() {
     if (!this._setupComplete) {
       this.waitForEvent("weave:service:setup-complete");
     }
   },