Bug 1470333: Part 1 - Optimize debug logging statements in FormAutoFillContent. r=MattN

These cause us to load Console.jsm and create a ConsoleAPI instance in every
content process, which is expensive both in terms of memory and startup
performance.

Checking the log level before we touch the console object is much cheaper,
in terms of both memory and performance.

MozReview-Commit-ID: 19f0ggAda2J

--HG--
extra : rebase_source : 38077a14122d201d11079330565d82f6f963b428

browser/extensions/formautofill/FormAutofillContent.jsm

@@ -98,7 +98,7 @@ AutofillProfileAutoCompleteSearch.prototype = {
     let {activeInput, activeSection, activeFieldDetail, savedFieldNames} = FormAutofillContent;
     this.forceStop = false;
 
-    this.log.debug("startSearch: for", searchString, "with input", activeInput);
+    this.debug("startSearch: for", searchString, "with input", activeInput);
 
     let isAddressField = FormAutofillUtils.isAddressField(activeFieldDetail.fieldName);
     let isInputAutofilled = activeFieldDetail.state == FIELD_STATES.AUTO_FILLED;
@@ -196,7 +196,7 @@ AutofillProfileAutoCompleteSearch.prototype = {
    *          Promise that resolves when addresses returned from parent process.
    */
   _getRecords(data) {
-    this.log.debug("_getRecords with data:", data);
+    this.debug("_getRecords with data:", data);
     return new Promise((resolve) => {
       Services.cpmm.addMessageListener("FormAutofill:Records", function getResult(result) {
         Services.cpmm.removeMessageListener("FormAutofill:Records", getResult);
@@ -222,7 +222,7 @@ let ProfileAutocomplete = {
     }
 
     FormAutofillUtils.defineLazyLogGetter(this, "ProfileAutocomplete");
-    this.log.debug("ensureRegistered");
+    this.debug("ensureRegistered");
     this._factory = new AutocompleteFactory();
     this._factory.register(AutofillProfileAutoCompleteSearch);
     this._registered = true;
@@ -235,7 +235,7 @@ let ProfileAutocomplete = {
       return;
     }
 
-    this.log.debug("ensureUnregistered");
+    this.debug("ensureUnregistered");
     this._factory.unregister();
     this._factory = null;
     this._registered = false;
@@ -275,7 +275,7 @@ let ProfileAutocomplete = {
   },
 
   _fillFromAutocompleteRow(focusedInput) {
-    this.log.debug("_fillFromAutocompleteRow:", focusedInput);
+    this.debug("_fillFromAutocompleteRow:", focusedInput);
     let formDetails = FormAutofillContent.activeFormDetails;
     if (!formDetails) {
       // The observer notification is for a different frame.
@@ -388,21 +388,21 @@ var FormAutofillContent = {
    */
   notify(formElement, domWin) {
     try {
-      this.log.debug("Notifying form early submission");
+      this.debug("Notifying form early submission");
 
       if (!FormAutofillUtils.isAutofillEnabled) {
-        this.log.debug("Form Autofill is disabled");
+        this.debug("Form Autofill is disabled");
         return true;
       }
 
       if (domWin && PrivateBrowsingUtils.isContentWindowPrivate(domWin)) {
-        this.log.debug("Ignoring submission in a private window");
+        this.debug("Ignoring submission in a private window");
         return true;
       }
 
       let handler = this._formsDetails.get(formElement);
       if (!handler) {
-        this.log.debug("Form element could not map to an existing handler");
+        this.debug("Form element could not map to an existing handler");
         return true;
       }
 
@@ -530,10 +530,10 @@ var FormAutofillContent = {
   },
 
   identifyAutofillFields(element) {
-    this.log.debug("identifyAutofillFields:", "" + element.ownerDocument.location);
+    this.debug("identifyAutofillFields:", element.ownerDocument.location.href);
 
     if (!this.savedFieldNames) {
-      this.log.debug("identifyAutofillFields: savedFieldNames are not known yet");
+      this.debug("identifyAutofillFields: savedFieldNames are not known yet");
       Services.cpmm.sendAsyncMessage("FormAutofill:InitStorage");
     }
 
@@ -542,14 +542,14 @@ var FormAutofillContent = {
       let formLike = FormLikeFactory.createFromField(element);
       formHandler = new FormAutofillHandler(formLike);
     } else if (!formHandler.updateFormIfNeeded(element)) {
-      this.log.debug("No control is removed or inserted since last collection.");
+      this.debug("No control is removed or inserted since last collection.");
       return;
     }
 
     let validDetails = formHandler.collectFormFields();
 
     this._formsDetails.set(formHandler.form.rootElement, formHandler);
-    this.log.debug("Adding form handler to _formsDetails:", formHandler);
+    this.debug("Adding form handler to _formsDetails:", formHandler);
 
     validDetails.forEach(detail =>
       this._markAsAutofillField(detail.elementWeakRef.get())

browser/extensions/formautofill/FormAutofillUtils.jsm

@@ -45,6 +45,26 @@ ChromeUtils.import("resource://gre/modules/Services.jsm");
 ChromeUtils.defineModuleGetter(this, "CreditCard",
   "resource://gre/modules/CreditCard.jsm");
 
+XPCOMUtils.defineLazyPreferenceGetter(this, "logLevel", "extensions.formautofill.loglevel",
+                                      "Warn");
+
+// A logging helper for debug logging to avoid creating Console objects
+// or triggering expensive JS -> C++ calls when debug logging is not
+// enabled.
+//
+// Console objects, even natively-implemented ones, can consume a lot of
+// memory, and since this code may run in every content process, that
+// memory can add up quickly. And, even when debug-level messages are
+// being ignored, console.debug() calls can be expensive.
+//
+// This helper avoids both of those problems by never touching the
+// console object unless debug logging is enabled.
+function debug() {
+  if (logLevel == "debug") {
+    this.log.debug(...arguments);
+  }
+}
+
 let AddressDataLoader = {
   // Status of address data loading. We'll load all the countries with basic level 1
   // information while requesting conutry information, and set country to true.
@@ -338,6 +358,8 @@ this.FormAutofillUtils = {
   },
 
   defineLazyLogGetter(scope, logPrefix) {
+    scope.debug = debug;
+
     XPCOMUtils.defineLazyGetter(scope, "log", () => {
       let ConsoleAPI = ChromeUtils.import("resource://gre/modules/Console.jsm", {}).ConsoleAPI;
       return new ConsoleAPI({