Bug 770418 - Improve identity logging output. r=dolske,jparsons

--HG--
extra : rebase_source : 4bfe055e1b783ffa80ad9b8515168a68e02f6a90

toolkit/identity/Identity.jsm

@@ -25,10 +25,10 @@ XPCOMUtils.defineLazyModuleGetter(this,
                                   "resource://gre/modules/identity/jwcrypto.jsm");
 
 function log(...aMessageArgs) {
-  Logger.log([null].concat(aMessageArgs));
+  Logger.log.apply(Logger, ["core"].concat(aMessageArgs));
 }
 function reportError(...aMessageArgs) {
-  Logger.reportError([null].concat(aMessageArgs));
+  Logger.reportError.apply(Logger, ["core"].concat(aMessageArgs));
 }
 
 function IDService() {
@@ -53,7 +53,7 @@ IDService.prototype = {
         if (!aSubject || !aSubject.wrappedJSObject)
           break;
         let subject = aSubject.wrappedJSObject;
-        log("NOW SELECT", aSubject.wrappedJSObject);
+        log("Auth complete:", aSubject.wrappedJSObject);
         // We have authenticated in order to provision an identity.
         // So try again.
         this.selectIdentity(subject.rpId, subject.identity);

toolkit/identity/IdentityProvider.jsm

@@ -24,10 +24,10 @@ XPCOMUtils.defineLazyModuleGetter(this,
                                   "resource://gre/modules/identity/jwcrypto.jsm");
 
 function log(...aMessageArgs) {
-  Logger.log(["IDP"].concat(aMessageArgs));
+  Logger.log.apply(Logger, ["IDP"].concat(aMessageArgs));
 }
 function reportError(...aMessageArgs) {
-  Logger.reportError(["IDP"].concat(aMessageArgs));
+  Logger.reportError.apply(Logger, ["IDP"].concat(aMessageArgs));
 }
 
 
@@ -232,7 +232,7 @@ IdentityProviderService.prototype = {
     jwcrypto.generateKeyPair(jwcrypto.ALGORITHMS.DS160, function gkpCb(err, kp) {
       log("in gkp callback");
       if (err) {
-        log("ERROR: genKeyPair:" + err);
+        log("ERROR: genKeyPair:", err);
         provFlow.callback(err);
         return;
       }

toolkit/identity/LogUtils.jsm

@@ -42,7 +42,7 @@ IdentityLogger.prototype = {
     }
   },
 
-  _generateLogMessage: function _generateLogMessage(aPrefix, ...args) {
+  _generateLogMessage: function _generateLogMessage(aPrefix, args) {
     // create a string representation of a list of arbitrary things
     let strings = [];
 
@@ -63,12 +63,11 @@ IdentityLogger.prototype = {
         }
       }
     });
-    return 'Identity ' + aPrefix + ': ' + strings.join(' : ');
+    return 'Identity ' + aPrefix + ': ' + strings.join(' ');
   },
 
   /**
    * log() - utility function to print a list of arbitrary things
-   * Depends on IdentityStore (bottom of this file) for _debug.
    *
    * Enable with about:config pref toolkit.identity.debug
    */
@@ -76,11 +75,6 @@ IdentityLogger.prototype = {
     if (!this._debug) {
       return;
     }
-    if (typeof this === 'undefined') {
-      for (var frame=Components.stack; frame; frame = frame.caller) {
-        dump (frame + "\n");
-      }
-    }
     let output = this._generateLogMessage(aPrefix, args);
     dump(output + "\n");
 
@@ -97,8 +91,11 @@ IdentityLogger.prototype = {
 
     // Report the error in the browser
     let output = this._generateLogMessage(aPrefix, aArgs);
-    Cu.reportError("Identity: " + output);
-    dump(output + "\n");
+    Cu.reportError(output);
+    dump("ERROR: " + output + "\n");
+    for (let frame = Components.stack.caller; frame; frame = frame.caller) {
+      dump(frame + "\n");
+    }
   }
 
 };

toolkit/identity/RelyingParty.jsm

@@ -23,10 +23,10 @@ XPCOMUtils.defineLazyModuleGetter(this,
                                   "resource://gre/modules/identity/jwcrypto.jsm");
 
 function log(...aMessageArgs) {
-  Logger.log(["RP"].concat(aMessageArgs));
+  Logger.log.apply(Logger, ["RP"].concat(aMessageArgs));
 }
 function reportError(...aMessageArgs) {
-  Logger.reportError(["RP"].concat(aMessageArgs));
+  Logger.reportError.apply(Logger, ["RP"].concat(aMessageArgs));
 }
 
 function IdentityRelyingParty() {

toolkit/identity/Sandbox.jsm

@@ -9,11 +9,14 @@ const EXPORTED_SYMBOLS = ["Sandbox"];
 const {classes: Cc, interfaces: Ci, utils: Cu} = Components;
 
 const XHTML_NS = "http://www.w3.org/1999/xhtml";
-const PREF_DEBUG = "toolkit.identity.debug";
 
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 
+XPCOMUtils.defineLazyModuleGetter(this,
+                                  "Logger",
+                                  "resource://gre/modules/identity/LogUtils.jsm");
+
 /**
  * An object that represents a sandbox in an iframe loaded with aURL. The
  * callback provided to the constructor will be invoked when the sandbox is
@@ -31,8 +34,7 @@ Cu.import("resource://gre/modules/Services.jsm");
 function Sandbox(aURL, aCallback) {
   // Normalize the URL so the comparison in _makeSandboxContentLoaded works
   this._url = Services.io.newURI(aURL, null, null).spec;
-  this._debug = Services.prefs.getBoolPref(PREF_DEBUG);
-  this._log("Creating sandbox for: " + this._url);
+  this._log("Creating sandbox for:", this._url);
   this._createFrame();
   this._createSandbox(aCallback);
 }
@@ -52,9 +54,9 @@ Sandbox.prototype = {
    * id and URL).
    */
   reload: function Sandbox_reload(aCallback) {
-    this._log("reload: " + this.id + " : " + this._url);
+    this._log("reload:", this.id, ":", this._url);
     this._createSandbox(function createdSandbox(aSandbox) {
-      this._log("reloaded sandbox id: ", aSandbox.id);
+      this._log("reloaded sandbox id:", aSandbox.id);
       aCallback(aSandbox);
     }.bind(this));
   },
@@ -63,7 +65,7 @@ Sandbox.prototype = {
    * Frees the sandbox and releases the iframe created to host it.
    */
   free: function Sandbox_free() {
-    this._log("free: " + this.id);
+    this._log("free:", this.id);
     this._container.removeChild(this._frame);
     this._frame = null;
     this._container = null;
@@ -116,8 +118,8 @@ Sandbox.prototype = {
   _createSandbox: function Sandbox__createSandbox(aCallback) {
     let self = this;
     function _makeSandboxContentLoaded(event) {
-      self._log("_makeSandboxContentLoaded : " + self.id + " : "
-                + event.target.location.toString());
+      self._log("_makeSandboxContentLoaded:", self.id,
+                event.target.location.toString());
       if (event.target != self._frame.contentDocument) {
         return;
       }
@@ -148,10 +150,7 @@ Sandbox.prototype = {
   },
 
   _log: function Sandbox__log(...aMessageArgs) {
-    if (!this._debug) {
-      return;
-    }
-    dump("Sandbox: " + aMessageArgs.join(" : ") + "\n");
+    Logger.log.apply(Logger, ["sandbox"].concat(aMessageArgs));
   },
 
 };

toolkit/identity/jwcrypto.jsm

@@ -16,10 +16,6 @@ Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 Cu.import("resource://gre/modules/identity/LogUtils.jsm");
 
-XPCOMUtils.defineLazyModuleGetter(this,
-                                  "IDLog",
-                                  "resource://gre/modules/identity/IdentityStore.jsm");
-
 XPCOMUtils.defineLazyServiceGetter(this,
                                    "IdentityCryptoService",
                                    "@mozilla.org/identity/crypto-service;1",
@@ -30,7 +26,7 @@ const EXPORTED_SYMBOLS = ["jwcrypto"];
 const ALGORITHMS = { RS256: "RS256", DS160: "DS160" };
 
 function log(...aMessageArgs) {
-  Logger.log(["jwcrypto"].concat(aMessageArgs));
+  Logger.log.apply(Logger, ["jwcrypto"].concat(aMessageArgs));
 }
 
 function generateKeyPair(aAlgorithmName, aCallback) {

toolkit/identity/tests/unit/head_identity.js

@@ -74,7 +74,7 @@ registrar.registerFactory(Components.ID("{fbfae60b-64a4-44ef-a911-08ceb70b9f31}"
 // The following are utility functions for Identity testing
 
 function log(...aMessageArgs) {
-  Logger.log(["test"].concat(aMessageArgs));
+  Logger.log.apply(Logger, ["test"].concat(aMessageArgs));
 }
 
 function get_idstore() {

toolkit/identity/tests/unit/test_crypto_service.js

@@ -20,7 +20,7 @@ function do_check_eq_or_slightly_less(x, y) {
 
 function test_dsa() {
   idService.generateKeyPair(ALG_DSA, function (rv, keyPair) {
-    log("DSA generateKeyPair finished " + rv);
+    log("DSA generateKeyPair finished ", rv);
     do_check_true(Components.isSuccessCode(rv));
     do_check_eq(typeof keyPair.sign, "function");
     do_check_eq(keyPair.keyType, ALG_DSA);
@@ -32,7 +32,7 @@ function test_dsa() {
 
     log("about to sign with DSA key");
     keyPair.sign("foo", function (rv, signature) {
-      log("DSA sign finished " + rv + " " + signature);
+      log("DSA sign finished ", rv, signature);
       do_check_true(Components.isSuccessCode(rv));
       do_check_true(signature.length > 1);
       // TODO: verify the signature with the public key
@@ -43,7 +43,7 @@ function test_dsa() {
 
 function test_rsa() {
   idService.generateKeyPair(ALG_RSA, function (rv, keyPair) {
-    log("RSA generateKeyPair finished " + rv);
+    log("RSA generateKeyPair finished ", rv);
     do_check_true(Components.isSuccessCode(rv));
     do_check_eq(typeof keyPair.sign, "function");
     do_check_eq(keyPair.keyType, ALG_RSA);
@@ -53,7 +53,7 @@ function test_rsa() {
 
     log("about to sign with RSA key");
     keyPair.sign("foo", function (rv, signature) {
-      log("RSA sign finished " + rv + " " + signature);
+      log("RSA sign finished ", rv, signature);
       do_check_true(Components.isSuccessCode(rv));
       do_check_true(signature.length > 1);
       run_next_test();

toolkit/identity/tests/unit/test_log_utils.js

@@ -17,7 +17,6 @@ function toggle_debug() {
     observe: function observe(aSubject, aTopic, aData) {
       if (aTopic === "nsPref:changed") {
         // race condition?
-dump("WOOT! it changed");
         do_check_eq(Logger._debug, true);
         do_test_finished();
         run_next_test();
@@ -35,7 +34,7 @@ function logAlias(...args) {
   Logger.log.call(["log alias"].concat(args));
 }
 function reportErrorAlias(...args) {
-  Loggerl.reportError.call(["report error alias"].concat(args));
+  Logger.reportError.call(["report error alias"].concat(args));
 }
 
 function test_log() {