Bug 1003204: Removed CommonUtils.exceptionStr() in services/sync r=markh r=gfritzsche
authorAnup Kumar <allamsetty.anup@gmail.com>
Thu, 07 Jan 2016 07:09:00 +0100
changeset 278960 d818de93b48f531eb13789bed8ca9917771e1c9a
parent 278959 9433893449d376f76d22faed6cdffe20ee3ab4ac
child 278961 bf1d46d3edfc7cff8469d46393835b915634420e
push id29862
push userkwierso@gmail.com
push dateFri, 08 Jan 2016 00:35:36 +0000
treeherdermozilla-central@2c8701e3ee11 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersmarkh, gfritzsche
bugs1003204
milestone46.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 1003204: Removed CommonUtils.exceptionStr() in services/sync r=markh r=gfritzsche
services/sync/modules/addonsreconciler.js
services/sync/modules/addonutils.js
services/sync/modules/engines.js
services/sync/modules/engines/bookmarks.js
services/sync/modules/engines/passwords.js
services/sync/modules/identity.js
services/sync/modules/policies.js
services/sync/modules/record.js
services/sync/modules/resource.js
services/sync/modules/service.js
services/sync/modules/stages/enginesync.js
services/sync/modules/util.js
services/sync/tests/unit/head_http_server.js
services/sync/tests/unit/test_addon_utils.js
services/sync/tests/unit/test_addons_store.js
services/sync/tests/unit/test_bookmark_engine.js
services/sync/tests/unit/test_fxa_node_reassignment.js
services/sync/tests/unit/test_node_reassignment.js
services/sync/tests/unit/test_service_sync_locked.js
services/sync/tests/unit/test_utils_catch.js
services/sync/tps/extensions/tps/resource/tps.jsm
--- a/services/sync/modules/addonsreconciler.js
+++ b/services/sync/modules/addonsreconciler.js
@@ -483,18 +483,17 @@ AddonsReconciler.prototype = {
   _addChange: function _addChange(date, change, state) {
     this._log.info("Change recorded for " + state.id);
     this._changes.push([date, change, state.id]);
 
     for (let listener of this._listeners) {
       try {
         listener.changeListener.call(listener, date, change, state);
       } catch (ex) {
-        this._log.warn("Exception calling change listener: " +
-                       Utils.exceptionStr(ex));
+        this._log.warn("Exception calling change listener", ex);
       }
     }
   },
 
   /**
    * Obtain the set of changes to add-ons since the date passed.
    *
    * This will return an array of arrays. Each entry in the array has the
@@ -630,17 +629,17 @@ AddonsReconciler.prototype = {
       // See note for _shouldPersist.
       if (this._shouldPersist) {
         let cb = Async.makeSpinningCallback();
         this.saveState(null, cb);
         cb.wait();
       }
     }
     catch (ex) {
-      this._log.warn("Exception: " + Utils.exceptionStr(ex));
+      this._log.warn("Exception", ex);
     }
   },
 
   // AddonListeners
   onEnabling: function onEnabling(addon, requiresRestart) {
     this._handleListener("onEnabling", addon, requiresRestart);
   },
   onEnabled: function onEnabled(addon) {
--- a/services/sync/modules/addonutils.js
+++ b/services/sync/modules/addonutils.js
@@ -142,17 +142,17 @@ AddonUtilsInternal.prototype = {
 
             cb(new Error("Download failed: " + install.error), null);
           }
         };
         install.addListener(listener);
         install.install();
       }
       catch (ex) {
-        this._log.error("Error installing add-on: " + Utils.exceptionstr(ex));
+        this._log.error("Error installing add-on", ex);
         cb(ex, null);
       }
     }.bind(this));
   },
 
   /**
    * Uninstalls the Addon instance and invoke a callback when it is done.
    *
--- a/services/sync/modules/engines.js
+++ b/services/sync/modules/engines.js
@@ -10,17 +10,16 @@ this.EXPORTED_SYMBOLS = [
   "Store"
 ];
 
 var {classes: Cc, interfaces: Ci, results: Cr, utils: Cu} = Components;
 
 Cu.import("resource://services-common/async.js");
 Cu.import("resource://gre/modules/Log.jsm");
 Cu.import("resource://services-common/observers.js");
-Cu.import("resource://services-common/utils.js");
 Cu.import("resource://services-sync/constants.js");
 Cu.import("resource://services-sync/identity.js");
 Cu.import("resource://services-sync/record.js");
 Cu.import("resource://services-sync/resource.js");
 Cu.import("resource://services-sync/util.js");
 
 /*
  * Trackers are associated with a single engine and deal with
@@ -303,18 +302,17 @@ Store.prototype = {
       try {
         this.applyIncoming(record);
       } catch (ex if (ex.code == Engine.prototype.eEngineAbortApplyIncoming)) {
         // This kind of exception should have a 'cause' attribute, which is an
         // originating exception.
         // ex.cause will carry its stack with it when rethrown.
         throw ex.cause;
       } catch (ex if !Async.isShutdownException(ex)) {
-        this._log.warn("Failed to apply incoming record " + record.id);
-        this._log.warn("Encountered exception: " + Utils.exceptionStr(ex));
+        this._log.warn("Failed to apply incoming record " + record.id, ex);
         this.engine._noteApplyFailure();
         failed.push(record.id);
       }
     };
     return failed;
   },
 
   /**
@@ -573,26 +571,21 @@ EngineManager.prototype = {
       let engine = new engineObject(this.service);
       let name = engine.name;
       if (name in this._engines) {
         this._log.error("Engine '" + name + "' is already registered!");
       } else {
         this._engines[name] = engine;
       }
     } catch (ex) {
-      this._log.error(CommonUtils.exceptionStr(ex));
-
-      let mesg = ex.message ? ex.message : ex;
       let name = engineObject || "";
       name = name.prototype || "";
       name = name.name || "";
 
-      let out = "Could not initialize engine '" + name + "': " + mesg;
-      this._log.error(out);
-
+      this._log.error(`Could not initialize engine ${name}`, ex);
       return engineObject;
     }
   },
 
   unregister: function (val) {
     let name = val;
     if (val instanceof Engine) {
       name = val.name;
@@ -812,17 +805,17 @@ SyncEngine.prototype = {
       }
     });
   },
 
   get previousFailed() {
     return this._previousFailed;
   },
   set previousFailed(val) {
-    let cb = (error) => this._log.error(Utils.exceptionStr(error));
+    let cb = (error) => this._log.error("Failed to set previousFailed", error);
     // Coerce the array to a string for more efficient comparison.
     if (val + "" == this._previousFailed) {
       return;
     }
     this._previousFailed = val;
     Utils.namedTimer(function () {
       Utils.jsonSave("failed/" + this.name, this, val, cb);
     }, 0, this, "_previousFailedDelay");
@@ -995,18 +988,17 @@ SyncEngine.prototype = {
 
     function doApplyBatch() {
       this._tracker.ignoreAll = true;
       try {
         failed = failed.concat(this._store.applyIncomingBatch(applyBatch));
       } catch (ex if !Async.isShutdownException(ex)) {
         // Catch any error that escapes from applyIncomingBatch. At present
         // those will all be abort events.
-        this._log.warn("Got exception " + Utils.exceptionStr(ex) +
-                       ", aborting processIncoming.");
+        this._log.warn("Got exception, aborting processIncoming", ex);
         aborting = ex;
       }
       this._tracker.ignoreAll = false;
       applyBatch = [];
     }
 
     function doApplyBatchAndPersistFailed() {
       // Apply remaining batch.
@@ -1064,44 +1056,43 @@ SyncEngine.prototype = {
           switch (strategy) {
             case null:
               // Retry succeeded! No further handling.
               break;
             case SyncEngine.kRecoveryStrategy.retry:
               self._log.debug("Ignoring second retry suggestion.");
               // Fall through to error case.
             case SyncEngine.kRecoveryStrategy.error:
-              self._log.warn("Error decrypting record: " + Utils.exceptionStr(ex));
+              self._log.warn("Error decrypting record", ex);
               self._noteApplyFailure();
               failed.push(item.id);
               return;
             case SyncEngine.kRecoveryStrategy.ignore:
               self._log.debug("Ignoring record " + item.id +
                               " with bad HMAC: already handled.");
               return;
           }
         }
       } catch (ex) {
-        self._log.warn("Error decrypting record: " + Utils.exceptionStr(ex));
+        self._log.warn("Error decrypting record", ex);
         self._noteApplyFailure();
         failed.push(item.id);
         return;
       }
 
       let shouldApply;
       try {
         shouldApply = self._reconcile(item);
       } catch (ex if (ex.code == Engine.prototype.eEngineAbortApplyIncoming)) {
         self._log.warn("Reconciliation failed: aborting incoming processing.");
         self._noteApplyFailure();
         failed.push(item.id);
         aborting = ex.cause;
       } catch (ex if !Async.isShutdownException(ex)) {
-        self._log.warn("Failed to reconcile incoming record " + item.id);
-        self._log.warn("Encountered exception: " + Utils.exceptionStr(ex));
+        self._log.warn("Failed to reconcile incoming record " + item.id, ex);
         self._noteApplyFailure();
         failed.push(item.id);
         return;
       }
 
       if (shouldApply) {
         count.applied++;
         applyBatch.push(item);
@@ -1480,17 +1471,17 @@ SyncEngine.prototype = {
         try {
           let out = this._createRecord(id);
           if (this._log.level <= Log.Level.Trace)
             this._log.trace("Outgoing: " + out);
 
           out.encrypt(this.service.collectionKeys.keyForCollection(this.name));
           up.pushData(out);
         } catch (ex if !Async.isShutdownException(ex)) {
-          this._log.warn("Error creating record: " + Utils.exceptionStr(ex));
+          this._log.warn("Error creating record", ex);
         }
 
         // Partial upload
         if ((++count % MAX_UPLOAD_RECORDS) == 0)
           doUpload((count - MAX_UPLOAD_RECORDS) + " - " + count + " out");
 
         this._store._sleep(0);
       }
@@ -1571,17 +1562,17 @@ SyncEngine.prototype = {
       canDecrypt = true;
     }.bind(this);
 
     // Any failure fetching/decrypting will just result in false
     try {
       this._log.trace("Trying to decrypt a record from the server..");
       test.get();
     } catch (ex if !Async.isShutdownException(ex)) {
-      this._log.debug("Failed test decrypt: " + Utils.exceptionStr(ex));
+      this._log.debug("Failed test decrypt", ex);
     }
 
     return canDecrypt;
   },
 
   _resetClient: function () {
     this.resetLastSync();
     this.previousFailed = [];
--- a/services/sync/modules/engines/bookmarks.js
+++ b/services/sync/modules/engines/bookmarks.js
@@ -421,35 +421,32 @@ BookmarksEngine.prototype = {
         yield PlacesBackups.create(null, true);
         this._log.debug("Bookmarks backup done.");
       }
     }.bind(this)).then(
       cb, ex => {
         // Failure to create a backup is somewhat bad, but probably not bad
         // enough to prevent syncing of bookmarks - so just log the error and
         // continue.
-        this._log.warn("Got exception \"" + Utils.exceptionStr(ex) +
-                       "\" backing up bookmarks, but continuing with sync.");
+        this._log.warn("Error while backing up bookmarks, but continuing with sync", ex);
         cb();
       }
     );
 
     cb.wait();
 
     this.__defineGetter__("_guidMap", function() {
       // Create a mapping of folder titles and separator positions to GUID.
       // We do this lazily so that we don't do any work unless we reconcile
       // incoming items.
       let guidMap;
       try {
         guidMap = this._buildGUIDMap();
       } catch (ex if !Async.isShutdownException(ex)) {
-        this._log.warn("Got exception \"" + Utils.exceptionStr(ex) +
-                       "\" building GUID map." +
-                       " Skipping all other incoming items.");
+        this._log.warn("Error while building GUID map, skipping all other incoming items", ex);
         throw {code: Engine.prototype.eEngineAbortApplyIncoming,
                cause: ex};
       }
       delete this._guidMap;
       return this._guidMap = guidMap;
     });
 
     this._store._childrenToOrder = {};
@@ -686,17 +683,17 @@ BookmarksStore.prototype = {
                     parentId);
     try {
       if (parentId > 0) {
         PlacesUtils.bookmarks.moveItem(itemId, parentId,
                                        PlacesUtils.bookmarks.DEFAULT_INDEX);
         return true;
       }
     } catch(ex) {
-      this._log.debug("Failed to reparent item. " + Utils.exceptionStr(ex));
+      this._log.debug("Failed to reparent item", ex);
     }
     return false;
   },
 
   // Turn a record's nsINavBookmarksService constant and other attributes into
   // a granular type for comparison.
   _recordType: function _recordType(itemId) {
     let bms  = PlacesUtils.bookmarks;
@@ -1318,18 +1315,17 @@ BookmarksStore.prototype = {
     if (!itemID || !tags) {
       return;
     }
 
     try {
       let u = PlacesUtils.bookmarks.getBookmarkURI(itemID);
       this._tagURI(u, tags);
     } catch (e) {
-      this._log.warn("Got exception fetching URI for " + itemID + ": not tagging. " +
-                     Utils.exceptionStr(e));
+      this._log.warn(`Got exception fetching URI for ${itemID} not tagging`, e);
 
       // I guess it doesn't have a URI. Don't try to tag it.
       return;
     }
   },
 
   /**
    * Associate the provided URI with the provided array of tags.
--- a/services/sync/modules/engines/passwords.js
+++ b/services/sync/modules/engines/passwords.js
@@ -64,17 +64,17 @@ PasswordEngine.prototype = {
         } else {
           this._log.debug("Didn't find any passwords to delete");
         }
         // If there were no ids to delete, or we succeeded, or got a 400,
         // record success.
         Svc.Prefs.set("deletePwdFxA", true);
         Svc.Prefs.reset("deletePwd"); // The old prefname we previously used.
       } catch (ex if !Async.isShutdownException(ex)) {
-        this._log.debug("Password deletes failed: " + Utils.exceptionStr(ex));
+        this._log.debug("Password deletes failed", ex);
       }
     }
   },
 
   _findDupe: function (item) {
     let login = this._store._nsLoginInfoFromRecord(item);
     if (!login) {
       return;
@@ -228,18 +228,17 @@ PasswordStore.prototype = {
     }
 
     this._log.debug("Adding login for " + record.hostname);
     this._log.trace("httpRealm: " + JSON.stringify(login.httpRealm) + "; " +
                     "formSubmitURL: " + JSON.stringify(login.formSubmitURL));
     try {
       Services.logins.addLogin(login);
     } catch(ex) {
-      this._log.debug("Adding record " + record.id +
-                      " resulted in exception " + Utils.exceptionStr(ex));
+      this._log.debug(`Adding record ${record.id} resulted in exception`, ex);
     }
   },
 
   remove: function (record) {
     this._log.trace("Removing login " + record.id);
 
     let loginItem = this._getLoginFromGUID(record.id);
     if (!loginItem) {
@@ -261,19 +260,17 @@ PasswordStore.prototype = {
     let newinfo = this._nsLoginInfoFromRecord(record);
     if (!newinfo) {
       return;
     }
 
     try {
       Services.logins.modifyLogin(loginItem, newinfo);
     } catch(ex) {
-      this._log.debug("Modifying record " + record.id +
-                      " resulted in exception " + Utils.exceptionStr(ex) +
-                      ". Not modifying.");
+      this._log.debug(`Modifying record ${record.id} resulted in exception; not modifying`, ex);
     }
   },
 
   wipe: function () {
     Services.logins.removeAllLogins();
   },
 };
 
--- a/services/sync/modules/identity.js
+++ b/services/sync/modules/identity.js
@@ -321,17 +321,17 @@ IdentityManager.prototype = {
                      "set!");
       return null;
     }
 
     if (!this._syncKeyBundle) {
       try {
         this._syncKeyBundle = new SyncKeyBundle(this.username, this.syncKey);
       } catch (ex) {
-        this._log.warn(Utils.exceptionStr(ex));
+        this._log.warn("Failed to create sync bundle", ex);
         return null;
       }
     }
 
     return this._syncKeyBundle;
   },
 
   /**
--- a/services/sync/modules/policies.js
+++ b/services/sync/modules/policies.js
@@ -576,17 +576,17 @@ ErrorHandler.prototype = {
         break;
       case "weave:engine:sync:error":
         let exception = subject;  // exception thrown by engine's sync() method
         let engine_name = data;   // engine name that threw the exception
 
         this.checkServerError(exception, "engines/" + engine_name);
 
         Status.engines = [engine_name, exception.failureCode || ENGINE_UNKNOWN_FAIL];
-        this._log.debug(engine_name + " failed: " + Utils.exceptionStr(exception));
+        this._log.debug(engine_name + " failed", exception);
 
         Services.telemetry.getKeyedHistogramById("WEAVE_ENGINE_SYNC_ERRORS")
                           .add(engine_name);
         break;
       case "weave:service:login:error":
         this._log.error("Sync encountered a login error");
         this.resetFileLog();
 
--- a/services/sync/modules/record.js
+++ b/services/sync/modules/record.js
@@ -234,17 +234,17 @@ RecordManager.prototype = {
       if (!this.response.success)
         return null;
 
       let record = new this._recordType(url);
       record.deserialize(this.response);
 
       return this.set(url, record);
     } catch (ex if !Async.isShutdownException(ex)) {
-      this._log.debug("Failed to import record: " + Utils.exceptionStr(ex));
+      this._log.debug("Failed to import record", ex);
       return null;
     }
   },
 
   get: function RecordMgr_get(url) {
     // Use a url string as the key to the hash
     let spec = url.spec ? url.spec : url;
     if (spec in this._records)
--- a/services/sync/modules/resource.js
+++ b/services/sync/modules/resource.js
@@ -228,17 +228,17 @@ AsyncResource.prototype = {
     // is performed asynchronously.
     let listener = new ChannelListener(this._onComplete, this._onProgress,
                                        this._log, this.ABORT_TIMEOUT);
     channel.requestMethod = action;
     try {
       channel.asyncOpen(listener, null);
     } catch (ex) {
       // asyncOpen can throw in a bunch of cases -- e.g., a forbidden port.
-      this._log.warn("Caught an error in asyncOpen: " + CommonUtils.exceptionStr(ex));
+      this._log.warn("Caught an error in asyncOpen", ex);
       CommonUtils.nextTick(callback.bind(this, ex));
     }
   },
 
   _onComplete: function _onComplete(error, data, channel) {
     this._log.trace("In _onComplete. Error is " + error + ".");
 
     if (error) {
@@ -275,19 +275,17 @@ AsyncResource.prototype = {
 
       // Additionally give the full response body when Trace logging.
       if (this._log.level <= Log.Level.Trace)
         this._log.trace(action + " body: " + data);
 
     } catch(ex) {
       // Got a response, but an exception occurred during processing.
       // This shouldn't occur.
-      this._log.warn("Caught unexpected exception " + CommonUtils.exceptionStr(ex) +
-                     " in _onComplete.");
-      this._log.debug(CommonUtils.stackTrace(ex));
+      this._log.warn("Caught unexpected exception in _oncomplete", ex);
     }
 
     // Process headers. They can be empty, or the call can otherwise fail, so
     // put this in its own try block.
     let headers = {};
     try {
       this._log.trace("Processing response headers.");
 
@@ -315,35 +313,33 @@ AsyncResource.prototype = {
       let contentLength = headers["content-length"];
       if (success && contentLength && data &&
           contentLength != data.length) {
         this._log.warn("The response body's length of: " + data.length +
                        " doesn't match the header's content-length of: " +
                        contentLength + ".");
       }
     } catch (ex) {
-      this._log.debug("Caught exception " + CommonUtils.exceptionStr(ex) +
-                      " visiting headers in _onComplete.");
-      this._log.debug(CommonUtils.stackTrace(ex));
+      this._log.debug("Caught exception visiting headers in _onComplete", ex);
     }
 
     let ret     = new String(data);
     ret.url     = channel.URI.spec;
     ret.status  = status;
     ret.success = success;
     ret.headers = headers;
 
     // Make a lazy getter to convert the json response into an object.
     // Note that this can cause a parse error to be thrown far away from the
     // actual fetch, so be warned!
     XPCOMUtils.defineLazyGetter(ret, "obj", function() {
       try {
         return JSON.parse(ret);
       } catch (ex) {
-        this._log.warn("Got exception parsing response body: \"" + CommonUtils.exceptionStr(ex));
+        this._log.warn("Got exception parsing response body", ex);
         // Stringify to avoid possibly printing non-printable characters.
         this._log.debug("Parse fail: Response body starts: \"" +
                         JSON.stringify((ret + "").slice(0, 100)) +
                         "\".");
         throw ex;
       }
     }.bind(this));
 
@@ -539,50 +535,49 @@ ChannelListener.prototype = {
   },
 
   onDataAvailable: function Channel_onDataAvail(req, cb, stream, off, count) {
     let siStream;
     try {
       siStream = Cc["@mozilla.org/scriptableinputstream;1"].createInstance(Ci.nsIScriptableInputStream);
       siStream.init(stream);
     } catch (ex) {
-      this._log.warn("Exception creating nsIScriptableInputStream." + CommonUtils.exceptionStr(ex));
+      this._log.warn("Exception creating nsIScriptableInputStream", ex);
       this._log.debug("Parameters: " + req.URI.spec + ", " + stream + ", " + off + ", " + count);
       // Cannot proceed, so rethrow and allow the channel to cancel itself.
       throw ex;
     }
 
     try {
       this._data += siStream.read(count);
     } catch (ex) {
       this._log.warn("Exception thrown reading " + count + " bytes from " + siStream + ".");
       throw ex;
     }
 
     try {
       this._onProgress();
     } catch (ex if !Async.isShutdownException(ex)) {
       this._log.warn("Got exception calling onProgress handler during fetch of "
-                     + req.URI.spec);
-      this._log.debug(CommonUtils.exceptionStr(ex));
+                     + req.URI.spec, ex);
       this._log.trace("Rethrowing; expect a failure code from the HTTP channel.");
       throw ex;
     }
 
     this.delayAbort();
   },
 
   /**
    * Create or push back the abort timer that kills this request.
    */
   delayAbort: function delayAbort() {
     try {
       CommonUtils.namedTimer(this.abortRequest, this._timeout, this, "abortTimer");
     } catch (ex) {
-      this._log.warn("Got exception extending abort timer: " + CommonUtils.exceptionStr(ex));
+      this._log.warn("Got exception extending abort timer", ex);
     }
   },
 
   abortRequest: function abortRequest() {
     // Ignore any callbacks if we happen to get any now
     this.onStopRequest = function() {};
     let error = Components.Exception("Aborting due to channel inactivity.",
                                      Cr.NS_ERROR_NET_TIMEOUT);
@@ -666,19 +661,19 @@ ChannelNotificationListener.prototype = 
             this._log.debug("Header: " + header + " = " + printed);
             newChannel.setRequestHeader(header, value, false);
           } else {
             this._log.warn("No value for header " + header);
           }
         }
       }
     } catch (ex) {
-      this._log.error("Error copying headers: " + CommonUtils.exceptionStr(ex));
+      this._log.error("Error copying headers", ex);
     }
 
     // We let all redirects proceed.
     try {
       callback.onRedirectVerifyCallback(Cr.NS_OK);
     } catch (ex) {
-      this._log.error("onRedirectVerifyCallback threw!" + CommonUtils.exceptionStr(ex));
+      this._log.error("onRedirectVerifyCallback threw!", ex);
     }
   }
 };
--- a/services/sync/modules/service.js
+++ b/services/sync/modules/service.js
@@ -16,17 +16,16 @@ const CLUSTER_BACKOFF = 5 * 60 * 1000; /
 const PBKDF2_KEY_BYTES = 16;
 
 const CRYPTO_COLLECTION = "crypto";
 const KEYS_WBO = "keys";
 
 Cu.import("resource://gre/modules/Preferences.jsm");
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 Cu.import("resource://gre/modules/Log.jsm");
-Cu.import("resource://services-common/utils.js");
 Cu.import("resource://services-sync/constants.js");
 Cu.import("resource://services-sync/engines.js");
 Cu.import("resource://services-sync/engines/clients.js");
 Cu.import("resource://services-sync/identity.js");
 Cu.import("resource://services-sync/policies.js");
 Cu.import("resource://services-sync/record.js");
 Cu.import("resource://services-sync/resource.js");
 Cu.import("resource://services-sync/rest.js");
@@ -485,18 +484,17 @@ Sync11Service.prototype = {
         let engineName = name + "Engine";
         if (!(engineName in ns)) {
           this._log.warn("Could not find exported engine instance: " + engineName);
           continue;
         }
 
         this.engineManager.register(ns[engineName]);
       } catch (ex) {
-        this._log.warn("Could not register engine " + name + ": " +
-                       CommonUtils.exceptionStr(ex));
+        this._log.warn("Could not register engine " + name, ex);
       }
     }
 
     this.engineManager.setDeclined(declined);
   },
 
   QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver,
                                          Ci.nsISupportsWeakReference]),
@@ -683,18 +681,17 @@ Sync11Service.prototype = {
       }
       else {
         // No update needed: we're good!
         return true;
       }
 
     } catch (ex) {
       // This means no keys are present, or there's a network error.
-      this._log.debug("Failed to fetch and verify keys: "
-                      + Utils.exceptionStr(ex));
+      this._log.debug("Failed to fetch and verify keys", ex);
       this.errorHandler.checkServerError(ex, "crypto/keys");
       return false;
     }
   },
 
   verifyLogin: function verifyLogin(allow40XRecovery = true) {
     if (!this.identity.username) {
       this._log.warn("No username in verifyLogin.");
@@ -780,17 +777,17 @@ Sync11Service.prototype = {
         default:
           // Server didn't respond with something that we expected
           this.status.login = LOGIN_FAILED_SERVER_ERROR;
           this.errorHandler.checkServerError(test, "info/collections");
           return false;
       }
     } catch (ex) {
       // Must have failed on some network issue
-      this._log.debug("verifyLogin failed: " + Utils.exceptionStr(ex));
+      this._log.debug("verifyLogin failed", ex);
       this.status.login = LOGIN_FAILED_NETWORK_ERROR;
       this.errorHandler.checkServerError(ex, "info/collections");
       return false;
     }
   },
 
   generateNewSymmetricKeys: function generateNewSymmetricKeys() {
     this._log.info("Generating new keys WBO...");
@@ -853,18 +850,17 @@ Sync11Service.prototype = {
     let client = new UserAPI10Client(this.userAPIURI);
     let cb = Async.makeSpinningCallback();
     client.changePassword(this.identity.username,
                           this.identity.basicPassword, newPassword, cb);
 
     try {
       cb.wait();
     } catch (ex) {
-      this._log.debug("Password change failed: " +
-                      CommonUtils.exceptionStr(ex));
+      this._log.debug("Password change failed", ex);
       return false;
     }
 
     // Save the new password for requests and login manager.
     this.identity.basicPassword = newPassword;
     this.persistLogin();
     return true;
   },
@@ -900,18 +896,17 @@ Sync11Service.prototype = {
 
     // Deletion doesn't make sense if we aren't set up yet!
     if (this.clusterURL != "") {
       // Clear client-specific data from the server, including disabled engines.
       for (let engine of [this.clientsEngine].concat(this.engineManager.getAll())) {
         try {
           engine.removeClientData();
         } catch(ex) {
-          this._log.warn("Deleting client data for " + engine.name + " failed:"
-                         + Utils.exceptionStr(ex));
+          this._log.warn(`Deleting client data for ${engine.name} failed`, ex);
         }
       }
       this._log.debug("Finished deleting client data.");
     } else {
       this._log.debug("Skipping client data removal: no cluster URL.");
     }
 
     // We want let UI consumers of the following notification know as soon as
@@ -1532,35 +1527,34 @@ Sync11Service.prototype = {
     let response;
     if (!collections) {
       // Strip the trailing slash.
       let res = this.resource(this.storageURL.slice(0, -1));
       res.setHeader("X-Confirm-Delete", "1");
       try {
         response = res.delete();
       } catch (ex) {
-        this._log.debug("Failed to wipe server: " + CommonUtils.exceptionStr(ex));
+        this._log.debug("Failed to wipe server", ex);
         throw ex;
       }
       if (response.status != 200 && response.status != 404) {
         this._log.debug("Aborting wipeServer. Server responded with " +
                         response.status + " response for " + this.storageURL);
         throw response;
       }
       return response.headers["x-weave-timestamp"];
     }
 
     let timestamp;
     for (let name of collections) {
       let url = this.storageURL + name;
       try {
         response = this.resource(url).delete();
       } catch (ex) {
-        this._log.debug("Failed to wipe '" + name + "' collection: " +
-                        Utils.exceptionStr(ex));
+        this._log.debug("Failed to wipe '" + name + "' collection", ex);
         throw ex;
       }
 
       if (response.status != 200 && response.status != 404) {
         this._log.debug("Aborting wipeServer. Server responded with " +
                         response.status + " response for " + url);
         throw response;
       }
@@ -1696,18 +1690,17 @@ Sync11Service.prototype = {
     }
 
     let info_type = "info/" + type;
     this._log.trace("Retrieving '" + info_type + "'...");
     let url = this.userBaseURL + info_type;
     return this.getStorageRequest(url).get(function onComplete(error) {
       // Note: 'this' is the request.
       if (error) {
-        this._log.debug("Failed to retrieve '" + info_type + "': " +
-                        Utils.exceptionStr(error));
+        this._log.debug("Failed to retrieve '" + info_type + "'", error);
         return callback(error);
       }
       if (this.response.status != 200) {
         this._log.debug("Failed to retrieve '" + info_type +
                         "': server responded with HTTP" +
                         this.response.status);
         return callback(this.response);
       }
--- a/services/sync/modules/stages/enginesync.js
+++ b/services/sync/modules/stages/enginesync.js
@@ -137,18 +137,17 @@ EngineSynchronizer.prototype = {
         this._syncEngine(this.service.clientsEngine);
       }
     }
 
     // Update engines because it might change what we sync.
     try {
       this._updateEnabledEngines();
     } catch (ex) {
-      this._log.debug("Updating enabled engines failed: " +
-                      Utils.exceptionStr(ex));
+      this._log.debug("Updating enabled engines failed", ex);
       this.service.errorHandler.checkServerError(ex, "meta/global");
       this.onComplete(ex);
       return;
     }
 
     // If the engines to sync has been specified, we sync in the order specified.
     let enginesToSync;
     if (allowEnginesHint && engineNamesToSync) {
--- a/services/sync/modules/util.js
+++ b/services/sync/modules/util.js
@@ -30,17 +30,16 @@ XPCOMUtils.defineLazyGetter(this, "FxAcc
  * Utility functions
  */
 
 this.Utils = {
   // Alias in functions from CommonUtils. These previously were defined here.
   // In the ideal world, references to these would be removed.
   nextTick: CommonUtils.nextTick,
   namedTimer: CommonUtils.namedTimer,
-  exceptionStr: CommonUtils.exceptionStr,
   stackTrace: CommonUtils.stackTrace,
   makeURI: CommonUtils.makeURI,
   encodeUTF8: CommonUtils.encodeUTF8,
   decodeUTF8: CommonUtils.decodeUTF8,
   safeAtoB: CommonUtils.safeAtoB,
   byteArrayToString: CommonUtils.byteArrayToString,
   bytesAsHex: CommonUtils.bytesAsHex,
   hexToBytes: CommonUtils.hexToBytes,
@@ -72,17 +71,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: " + Utils.exceptionStr(ex));
+        thisArg._log.debug("Exception", ex);
         if (exceptionCallback) {
           return exceptionCallback.call(thisArg, ex);
         }
         return null;
       }
     };
   },
 
@@ -337,18 +336,17 @@ this.Utils = {
     let json;
 
     try {
       json = yield CommonUtils.readJSON(path);
     } catch (e if e instanceof OS.File.Error && e.becauseNoSuchFile) {
       // Ignore non-existent files.
     } catch (e) {
       if (that._log) {
-        that._log.debug("Failed to load json: " +
-                        CommonUtils.exceptionStr(e));
+        that._log.debug("Failed to load json", e);
       }
     }
 
     callback.call(that, json);
   }),
 
   /**
    * Save a json-able object to disk in the profile directory.
--- a/services/sync/tests/unit/head_http_server.js
+++ b/services/sync/tests/unit/head_http_server.js
@@ -581,17 +581,17 @@ SyncServer.prototype = {
                      i.primaryPort + "/";
       this.started = true;
       if (cb) {
         cb();
       }
     } catch (ex) {
       _("==========================================");
       _("Got exception starting Sync HTTP server.");
-      _("Error: " + Utils.exceptionStr(ex));
+      _("Error: " + Log.exceptionStr(ex));
       _("Is there a process already listening on port " + port + "?");
       _("==========================================");
       do_throw(ex);
     }
 
   },
 
   /**
--- a/services/sync/tests/unit/test_addon_utils.js
+++ b/services/sync/tests/unit/test_addon_utils.js
@@ -1,13 +1,14 @@
 /* Any copyright is dedicated to the Public Domain.
    http://creativecommons.org/publicdomain/zero/1.0/ */
 
 "use strict";
 
+Cu.import("resource://gre/modules/Log.jsm");
 Cu.import("resource://gre/modules/Preferences.jsm");
 Cu.import("resource://services-sync/addonutils.js");
 Cu.import("resource://services-sync/util.js");
 
 const HTTP_PORT = 8888;
 const SERVER_ADDRESS = "http://127.0.0.1:8888";
 
 var prefs = new Preferences();
@@ -30,17 +31,17 @@ function createAndStartHTTPServer(port=H
     server.registerFile("/search/guid:rewrite%40tests.mozilla.org",
                         do_get_file("rewrite-search.xml"));
 
     server.start(port);
 
     return server;
   } catch (ex) {
     _("Got exception starting HTTP server on port " + port);
-    _("Error: " + Utils.exceptionStr(ex));
+    _("Error: " + Log.exceptionStr(ex));
     do_throw(ex);
   }
 }
 
 function run_test() {
   initTestLogging("Trace");
 
   run_next_test();
--- a/services/sync/tests/unit/test_addons_store.js
+++ b/services/sync/tests/unit/test_addons_store.js
@@ -1,13 +1,14 @@
 /* Any copyright is dedicated to the Public Domain.
    http://creativecommons.org/publicdomain/zero/1.0/ */
 
 "use strict";
 
+Cu.import("resource://gre/modules/Log.jsm");
 Cu.import("resource://gre/modules/Preferences.jsm");
 Cu.import("resource://services-sync/addonutils.js");
 Cu.import("resource://services-sync/engines/addons.js");
 Cu.import("resource://services-sync/service.js");
 Cu.import("resource://services-sync/util.js");
 Cu.import("resource://testing-common/services/sync/utils.js");
 
 const HTTP_PORT = 8888;
@@ -56,17 +57,17 @@ function createAndStartHTTPServer(port) 
     server.registerFile("/search/guid:missing-xpi%40tests.mozilla.org",
                         do_get_file("missing-xpi-search.xml"));
 
     server.start(port);
 
     return server;
   } catch (ex) {
     _("Got exception starting HTTP server on port " + port);
-    _("Error: " + Utils.exceptionStr(ex));
+    _("Error: " + Log.exceptionStr(ex));
     do_throw(ex);
   }
 }
 
 function run_test() {
   initTestLogging("Trace");
   Log.repository.getLogger("Sync.Engine.Addons").level = Log.Level.Trace;
   Log.repository.getLogger("Sync.AddonsRepository").level =
--- a/services/sync/tests/unit/test_bookmark_engine.js
+++ b/services/sync/tests/unit/test_bookmark_engine.js
@@ -66,17 +66,17 @@ add_test(function test_ID_caching() {
   let newMobileID;
 
   // With noCreate, we don't find an entry.
   try {
     newMobileID = store.idForGUID("mobile", true);
     _("New mobile ID: " + newMobileID);
   } catch (ex) {
     err = ex;
-    _("Error: " + Utils.exceptionStr(err));
+    _("Error: " + Log.exceptionStr(err));
   }
 
   do_check_true(!err);
 
   // With !noCreate, lookup works, and it's different.
   newMobileID = store.idForGUID("mobile", false);
   _("New mobile ID: " + newMobileID);
   do_check_true(!!newMobileID);
@@ -215,17 +215,17 @@ add_task(function test_restorePromptsReu
 
     PlacesUtils.bookmarks.removeItem(bmk1_id);
 
     let error;
     try {
       engine.sync();
     } catch(ex) {
       error = ex;
-      _("Got error: " + Utils.exceptionStr(ex));
+      _("Got error: " + Log.exceptionStr(ex));
     }
     do_check_true(!error);
 
     _("Verify that there's only one bookmark on the server, and it's Thunderbird.");
     // Of course, there's also the Bookmarks Toolbar and Bookmarks Menu...
     let wbos = collection.keys(function (id) {
       return ["menu", "toolbar", "mobile", "unfiled", folder1_guid].indexOf(id) == -1;
     });
@@ -259,17 +259,17 @@ add_task(function test_restorePromptsReu
     _("Have the correct number of IDs locally, too.");
     do_check_eq(count, ["menu", "toolbar", "mobile", "unfiled", folder1_id, bmk1_id].length);
 
     _("Sync again. This'll wipe bookmarks from the server.");
     try {
       engine.sync();
     } catch(ex) {
       error = ex;
-      _("Got error: " + Utils.exceptionStr(ex));
+      _("Got error: " + Log.exceptionStr(ex));
     }
     do_check_true(!error);
 
     _("Verify that there's only one bookmark on the server, and it's Firefox.");
     // Of course, there's also the Bookmarks Toolbar and Bookmarks Menu...
     let payloads     = server.user("foo").collection("bookmarks").payloads();
     let bookmarkWBOs = payloads.filter(function (wbo) {
                          return wbo.type == "bookmark";
--- a/services/sync/tests/unit/test_fxa_node_reassignment.js
+++ b/services/sync/tests/unit/test_fxa_node_reassignment.js
@@ -92,17 +92,17 @@ function prepareServer(cbAfterTokenFetch
 
 function getReassigned() {
   try {
     return Services.prefs.getBoolPref("services.sync.lastSyncReassigned");
   } catch (ex if (ex.result == Cr.NS_ERROR_UNEXPECTED)) {
     return false;
   } catch (ex) {
     do_throw("Got exception retrieving lastSyncReassigned: " +
-             Utils.exceptionStr(ex));
+             Log.exceptionStr(ex));
   }
 }
 
 /**
  * Make a test request to `url`, then watch the result of two syncs
  * to ensure that a node request was made.
  * Runs `between` between the two. This can be used to undo deliberate failure
  * setup, detach observers, etc.
--- a/services/sync/tests/unit/test_node_reassignment.js
+++ b/services/sync/tests/unit/test_node_reassignment.js
@@ -91,17 +91,17 @@ function prepareServer() {
 
 function getReassigned() {
   try {
     return Services.prefs.getBoolPref("services.sync.lastSyncReassigned");
   } catch (ex if (ex.result == Cr.NS_ERROR_UNEXPECTED)) {
     return false;
   } catch (ex) {
     do_throw("Got exception retrieving lastSyncReassigned: " +
-             Utils.exceptionStr(ex));
+             Log.exceptionStr(ex));
   }
 }
 
 /**
  * Make a test request to `url`, then watch the result of two syncs
  * to ensure that a node request was made.
  * Runs `between` between the two. This can be used to undo deliberate failure
  * setup, detach observers, etc.
--- a/services/sync/tests/unit/test_service_sync_locked.js
+++ b/services/sync/tests/unit/test_service_sync_locked.js
@@ -6,31 +6,31 @@ Cu.import("resource://services-sync/util
 
 function run_test() {
   let debug = [];
   let info  = [];
 
   function augmentLogger(old) {
     let d = old.debug;
     let i = old.info;
-    old.debug = function(m) { debug.push(m); d.call(old, m); }
-    old.info  = function(m) { info.push(m);  i.call(old, m); }
+    // For the purposes of this test we don't need to do full formatting
+    // of the 2nd param, as the ones we care about are always strings.
+    old.debug = function(m, p) { debug.push(p ? m + ": " + p : m); d.call(old, m, p); }
+    old.info  = function(m, p) { info.push(p ? m + ": " + p : m);  i.call(old, m, p); }
     return old;
   }
 
   Log.repository.rootLogger.addAppender(new Log.DumpAppender());
 
   augmentLogger(Service._log);
 
   // 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_eq(debug[debug.length - 2],
-              "Exception: Could not acquire lock. Label: \"service.js: login\". No traceback available");
-  do_check_eq(info[info.length - 1],
-              "Cannot start sync: already syncing?");
+  do_check_true(debug[debug.length - 2].startsWith("Exception: Could not acquire lock. Label: \"service.js: login\"."));
+  do_check_eq(info[info.length - 1], "Cannot start sync: already syncing?");
 }
 
--- a/services/sync/tests/unit/test_utils_catch.js
+++ b/services/sync/tests/unit/test_utils_catch.js
@@ -3,17 +3,17 @@ Cu.import("resource://services-sync/serv
 
 function run_test() {
   _("Make sure catch when copied to an object will correctly catch stuff");
   let ret, rightThis, didCall, didThrow, wasTen, wasLocked;
   let obj = {
     catch: Utils.catch,
     _log: {
       debug: function(str) {
-        didThrow = str.search(/^Exception: /) == 0;
+        didThrow = str.search(/^Exception/) == 0;
       },
       info: function(str) {
         wasLocked = str.indexOf("Cannot start sync: already syncing?") == 0;
       }
     },
 
     func: function() {
       return this.catch(function() {
--- a/services/sync/tps/extensions/tps/resource/tps.jsm
+++ b/services/sync/tps/extensions/tps/resource/tps.jsm
@@ -9,16 +9,17 @@
 
 var EXPORTED_SYMBOLS = ["ACTIONS", "TPS"];
 
 const {classes: Cc, interfaces: Ci, utils: Cu} = Components;
 
 var module = this;
 
 // Global modules
+Cu.import("resource://gre/modules/Log.jsm");
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 Cu.import("resource://services-common/async.js");
 Cu.import("resource://services-sync/constants.js");
 Cu.import("resource://services-sync/main.js");
 Cu.import("resource://services-sync/util.js");
 
 // TPS modules
@@ -133,17 +134,17 @@ var TPS = {
       Cu.import("resource://tps/auth/sync.jsm", module);
     }
   },
 
   DumpError(msg, exc = null) {
     this._errors++;
     let errInfo;
     if (exc) {
-      errInfo = Utils.exceptionStr(exc); // includes details and stack-trace.
+      errInfo = Log.exceptionStr(exc); // includes details and stack-trace.
     } else {
       // always write a stack even if no error passed.
       errInfo = Utils.stackTrace(new Error());
     }
     Logger.logError(`[phase ${this._currentPhase}] ${msg} - ${errInfo}`);
     this.quit();
   },
 
@@ -1046,9 +1047,9 @@ var Tabs = {
 var Windows = {
   add: function Window__add(aWindow) {
     TPS.StartAsyncOperation();
     TPS.HandleWindows(aWindow, ACTION_ADD);
   },
 };
 
 // Initialize TPS
-TPS._init();
\ No newline at end of file
+TPS._init();