Bug 1805702 - Log engagement event regardless of recording being enabled. r=daisuke

Logs engagement telemetry for debug purposes, regardless of it being reported
upstream.
Also changes a couple other logs to make browser.urlbar.logLevel = "Info"
more readable and usable.

Differential Revision: https://phabricator.services.mozilla.com/D164701

browser/components/urlbar/UrlbarController.sys.mjs

@@ -2,6 +2,9 @@
  * License, v. 2.0. If a copy of the MPL was not distributed with this
  * file, You can obtain one at http://mozilla.org/MPL/2.0/. */
 
+const { XPCOMUtils } = ChromeUtils.import(
+  "resource://gre/modules/XPCOMUtils.jsm"
+);
 import { AppConstants } from "resource://gre/modules/AppConstants.sys.mjs";
 
 const lazy = {};
@@ -91,6 +94,10 @@ export class UrlbarController {
       this,
       options.eventTelemetryCategory
     );
+
+    XPCOMUtils.defineLazyGetter(this, "logger", () =>
+      lazy.UrlbarUtils.getLogger({ prefix: "Controller" })
+    );
   }
 
   get NOTIFICATIONS() {
@@ -1038,10 +1045,6 @@ class TelemetryEvent {
       selType,
     }
   ) {
-    if (!lazy.UrlbarPrefs.get("searchEngagementTelemetryEnabled")) {
-      return;
-    }
-
     const browserWindow = this._controller.browserWindow;
     let sap = "urlbar";
     if (searchSource === "urlbar-handoff") {
@@ -1070,9 +1073,10 @@ class TelemetryEvent {
       .map(r => lazy.UrlbarUtils.searchEngagementTelemetryType(r))
       .join(",");
 
+    let eventInfo;
     if (method === "engagement") {
       const selectedResult = currentResults[selIndex];
-      Glean.urlbar.engagement.record({
+      eventInfo = {
         sap,
         interaction,
         n_chars: numChars,
@@ -1090,9 +1094,9 @@ class TelemetryEvent {
           selType === "help" || selType === "dismiss" ? selType : action,
         groups,
         results,
-      });
+      };
     } else if (method === "abandonment") {
-      Glean.urlbar.abandonment.record({
+      eventInfo = {
         sap,
         interaction,
         n_chars: numChars,
@@ -1100,9 +1104,9 @@ class TelemetryEvent {
         n_results: numResults,
         groups,
         results,
-      });
+      };
     } else if (method === "impression") {
-      Glean.urlbar.impression.record({
+      eventInfo = {
         reason,
         sap,
         interaction,
@@ -1111,9 +1115,18 @@ class TelemetryEvent {
         n_results: numResults,
         groups,
         results,
-      });
+      };
     } else {
       Cu.reportError(`Unknown telemetry event method: ${method}`);
+      return;
+    }
+
+    this._controller.logger.info(
+      `${method} event: ${JSON.stringify(eventInfo)}`
+    );
+
+    if (lazy.UrlbarPrefs.get("searchEngagementTelemetryEnabled")) {
+      Glean.urlbar[method].record(eventInfo);
     }
   }
 

browser/components/urlbar/UrlbarProvidersManager.sys.mjs

@@ -211,11 +211,11 @@ class ProvidersManager {
    *   a UrlbarController instance
    */
   async startQuery(queryContext, controller = null) {
-    lazy.logger.info(`Query start ${queryContext.searchString}`);
+    lazy.logger.info(`Query start "${queryContext.searchString}"`);
 
     // Define the muxer to use.
     let muxerName = queryContext.muxer || DEFAULT_MUXER;
-    lazy.logger.info(`Using muxer ${muxerName}`);
+    lazy.logger.debug(`Using muxer ${muxerName}`);
     let muxer = this.muxers.get(muxerName);
     if (!muxer) {
       throw new Error(`Muxer with name ${muxerName} not found`);
@@ -450,7 +450,9 @@ class Query {
 
     // Start querying active providers.
     let startQuery = async provider => {
-      provider.logger.info(`Starting query for "${this.context.searchString}"`);
+      provider.logger.debug(
+        `Starting query for "${this.context.searchString}"`
+      );
       let addedResult = false;
       await provider.tryMethod("startQuery", this.context, (...args) => {
         addedResult = true;
@@ -485,7 +487,11 @@ class Query {
       );
     }
 
-    lazy.logger.info(`Queried ${queryPromises.length} providers`);
+    lazy.logger.info(
+      `Queried ${queryPromises.length} providers: ${activeProviders.map(
+        p => p.name
+      )}`
+    );
     await Promise.all(queryPromises);
 
     // All the providers are done returning results, so we can stop chunking.
@@ -512,7 +518,7 @@ class Query {
     this.canceled = true;
     this.context.deferUserSelectionProviders.clear();
     for (let provider of this.providers) {
-      provider.logger.info(
+      provider.logger.debug(
         `Canceling query for "${this.context.searchString}"`
       );
       // Mark the instance as no more valid, see start() for details.

browser/components/urlbar/UrlbarTokenizer.sys.mjs

@@ -238,7 +238,7 @@ export var UrlbarTokenizer = {
    *          tokens property.
    */
   tokenize(queryContext) {
-    lazy.logger.info(
+    lazy.logger.debug(
       "Tokenizing search string",
       JSON.stringify(queryContext.searchString)
     );
@@ -410,6 +410,6 @@ function filterTokens(tokens) {
     }
   }
 
-  lazy.logger.info("Filtered Tokens", tokens);
+  lazy.logger.info("Filtered Tokens", filtered);
   return filtered;
 }