Bug 1445009: Refactor BrowserErrorReporter.jsm and tests. r=Gijs

The transforms for turning an nsIScriptError into a payload that Sentry
understands were getting a bit complex for a single function, so they're
refactored into a list of transform functions that are applied in sequence to
produce the payload. This will make it easier to manage adding new transforms to
the list.

Refactoring this revaled a problem with the test code: it assumed that listeners
for console messages were notified in order of registration (since it used a
temporary listener to determine when the rest of the listeners had been notified
of a message). Changing the async evaluation of the code broke the tests, so
they had to be refactored as well.

Without a way to know when all console listeners have been notified, we can't
assert that a message will not be received by BrowserErrorReporter. We do two
things to get around this:

- Where possible, call `observe` directly on the reporter instance.
- Add constructor params for registering and unregistering listeners so we can
  test that logic without relying on messages being received or not.

MozReview-Commit-ID: EEH6IROOuHD

--HG--
extra : rebase_source : a5af344c86e9756d4dbef761e4a6060515c87a61
extra : histedit_source : 5491c7359d2989a2735ec6d39de372154706c475

browser/modules/BrowserErrorReporter.jsm

@@ -62,10 +62,16 @@ const PLATFORM_NAMES = {
  * traces; see bug 1426482 for privacy review and server-side mitigation.
  */
 class BrowserErrorReporter {
-  constructor(fetchMethod = this._defaultFetch, chromeOnly = true) {
+  constructor(options = {}) {
     // Test arguments for mocks and changing behavior
-    this.fetch = fetchMethod;
+    this.fetch = options.fetch || defaultFetch;
-    this.chromeOnly = chromeOnly;
+    this.chromeOnly = options.chromeOnly !== undefined ? options.chromeOnly : true;
+    this.registerListener = (
+      options.registerListener || (() => Services.console.registerListener(this))
+    );
+    this.unregisterListener = (
+      options.unregisterListener || (() => Services.console.unregisterListener(this))
+    );
 
     // Values that don't change between error reports.
     this.requestBodyTemplate = {
@@ -120,7 +126,7 @@ class BrowserErrorReporter {
 
   init() {
     if (this.collectionEnabled) {
-      Services.console.registerListener(this);
+      this.registerListener();
 
       // Processing already-logged messages in case any errors occurred before
       // startup.
@@ -132,16 +138,16 @@ class BrowserErrorReporter {
 
   uninit() {
     try {
-      Services.console.unregisterListener(this);
+      this.unregisterListener();
     } catch (err) {} // It probably wasn't registered.
   }
 
   handleEnabledPrefChanged(prefName, previousValue, newValue) {
     if (newValue) {
-      Services.console.registerListener(this);
+      this.registerListener();
     } else {
       try {
-        Services.console.unregisterListener(this);
+        this.unregisterListener();
       } catch (err) {} // It probably wasn't registered.
     }
   }
@@ -165,60 +171,25 @@ class BrowserErrorReporter {
       return;
     }
 
-    const extensions = new Map();
+    const exceptionValue = {};
-    for (let extension of WebExtensionPolicy.getActiveExtensions()) {
+    const transforms = [
-      extensions.set(extension.mozExtensionHostname, extension);
+      addErrorMessage,
+      addStacktrace,
+      addModule,
+      mangleExtensionUrls,
+    ];
+    for (const transform of transforms) {
+      await transform(message, exceptionValue);
     }
 
-    // Replaces any instances of moz-extension:// URLs with internal UUIDs to use
+    const requestBody = {
-    // the add-on ID instead.
+      ...this.requestBodyTemplate,
-    function mangleExtURL(string, anchored = true) {
-      let re = new RegExp(`${anchored ? "^" : ""}moz-extension://([^/]+)/`, "g");
-
-      return string.replace(re, (m0, m1) => {
-        let id = extensions.has(m1) ? extensions.get(m1).id : m1;
-        return `moz-extension://${id}/`;
-      });
-    }
-
-    // Parse the error type from the message if present (e.g. "TypeError: Whoops").
-    let errorMessage = message.errorMessage;
-    let errorName = "Error";
-    if (message.errorMessage.match(ERROR_PREFIX_RE)) {
-      const parts = message.errorMessage.split(":");
-      errorName = parts[0];
-      errorMessage = parts.slice(1).join(":").trim();
-    }
-
-    const frames = [];
-    let frame = message.stack;
-    // Avoid an infinite loop by limiting traces to 100 frames.
-    while (frame && frames.length < 100) {
-      const normalizedFrame = await this.normalizeStackFrame(frame);
-      normalizedFrame.module = mangleExtURL(normalizedFrame.module, false);
-      frames.push(normalizedFrame);
-      frame = frame.parent;
-    }
-    // Frames are sent in order from oldest to newest.
-    frames.reverse();
-
-    const requestBody = Object.assign({}, this.requestBodyTemplate, {
       timestamp: new Date().toISOString().slice(0, -1), // Remove trailing "Z"
       project: Services.prefs.getCharPref(PREF_PROJECT_ID),
       exception: {
-        values: [
+        values: [exceptionValue],
-          {
-            type: errorName,
-            value: mangleExtURL(errorMessage),
-            module: message.sourceName,
-            stacktrace: {
-              frames,
-            }
       },
-        ],
+    };
-      },
-      culprit: message.sourceName,
-    });
 
     const url = new URL(Services.prefs.getCharPref(PREF_SUBMIT_URL));
     url.searchParams.set("sentry_client", `${SDK_NAME}/${SDK_VERSION}`);
@@ -241,8 +212,36 @@ class BrowserErrorReporter {
       this.logger.warn(`Failed to send error: ${error}`);
     }
   }
+}
 
-  async normalizeStackFrame(frame) {
+function defaultFetch(...args) {
+  // Do not make network requests while running in automation
+  if (Cu.isInAutomation) {
+    return null;
+  }
+
+  return fetch(...args);
+}
+
+function addErrorMessage(message, exceptionValue) {
+  // Parse the error type from the message if present (e.g. "TypeError: Whoops").
+  let errorMessage = message.errorMessage;
+  let errorName = "Error";
+  if (message.errorMessage.match(ERROR_PREFIX_RE)) {
+    const parts = message.errorMessage.split(":");
+    errorName = parts[0];
+    errorMessage = parts.slice(1).join(":").trim();
+  }
+
+  exceptionValue.type = errorName;
+  exceptionValue.value = errorMessage;
+}
+
+async function addStacktrace(message, exceptionValue) {
+  const frames = [];
+  let frame = message.stack;
+  // Avoid an infinite loop by limiting traces to 100 frames.
+  while (frame && frames.length < 100) {
     const normalizedFrame = {
       function: frame.functionDisplayName,
       module: frame.source,
@@ -277,15 +276,43 @@ class BrowserErrorReporter {
       // do to recover in either case.
     }
 
-    return normalizedFrame;
+    frames.push(normalizedFrame);
+    frame = frame.parent;
+  }
+  // Frames are sent in order from oldest to newest.
+  frames.reverse();
+
+  exceptionValue.stacktrace = {frames};
 }
 
-  async _defaultFetch(...args) {
+function addModule(message, exceptionValue) {
-    // Do not make network requests while running in automation
+  exceptionValue.module = message.sourceName;
-    if (Cu.isInAutomation) {
-      return null;
 }
 
-    return fetch(...args);
+function mangleExtensionUrls(message, exceptionValue) {
+  const extensions = new Map();
+  for (let extension of WebExtensionPolicy.getActiveExtensions()) {
+    extensions.set(extension.mozExtensionHostname, extension);
+  }
+
+  // Replaces any instances of moz-extension:// URLs with internal UUIDs to use
+  // the add-on ID instead.
+  function mangleExtURL(string, anchored = true) {
+    if (!string) {
+      return string;
+    }
+
+    let re = new RegExp(`${anchored ? "^" : ""}moz-extension://([^/]+)/`, "g");
+
+    return string.replace(re, (m0, m1) => {
+      let id = extensions.has(m1) ? extensions.get(m1).id : m1;
+      return `moz-extension://${id}/`;
+    });
+  }
+
+  exceptionValue.value = mangleExtURL(exceptionValue.value, false);
+  exceptionValue.module = mangleExtURL(exceptionValue.module);
+  for (const frame of exceptionValue.stacktrace.frames) {
+    frame.module = mangleExtURL(frame.module);
   }
 }

browser/modules/test/browser/browser_BrowserErrorReporter.js

@@ -16,6 +16,12 @@ const PREF_PROJECT_ID = "browser.chrome.errorReporter.projectId";
 const PREF_PUBLIC_KEY = "browser.chrome.errorReporter.publicKey";
 const PREF_SAMPLE_RATE = "browser.chrome.errorReporter.sampleRate";
 const PREF_SUBMIT_URL = "browser.chrome.errorReporter.submitUrl";
+const TELEMETRY_ERROR_COLLECTED = "browser.errors.collected_count";
+const TELEMETRY_ERROR_COLLECTED_FILENAME = "browser.errors.collected_count_by_filename";
+const TELEMETRY_ERROR_COLLECTED_STACK = "browser.errors.collected_with_stack_count";
+const TELEMETRY_ERROR_REPORTED = "browser.errors.reported_success_count";
+const TELEMETRY_ERROR_REPORTED_FAIL = "browser.errors.reported_failure_count";
+const TELEMETRY_ERROR_SAMPLE_RATE = "browser.errors.sample_rate";
 
 function createScriptError(options = {}) {
   const scriptError = Cc["@mozilla.org/scripterror;1"].createInstance(Ci.nsIScriptError);
@@ -31,20 +37,8 @@ function createScriptError(options = {}) {
   return scriptError;
 }
 
-// Wrapper around Services.console.logMessage that waits for the message to be
+function noop() {
-// logged before resolving, since messages are logged asynchronously.
+  // Do nothing
-function logMessage(message) {
-  return new Promise(resolve => {
-    Services.console.registerListener({
-      observe(loggedMessage) {
-        if (loggedMessage.message === message.message) {
-          Services.console.unregisterListener(this);
-          resolve();
-        }
-      },
-    });
-    Services.console.logMessage(message);
-  });
 }
 
 // Clears the console of any previous messages. Should be called at the end of
@@ -54,21 +48,6 @@ function resetConsole() {
   Services.console.reset();
 }
 
-// Wrapper similar to logMessage, but for logStringMessage.
-function logStringMessage(message) {
-  return new Promise(resolve => {
-    Services.console.registerListener({
-      observe(loggedMessage) {
-        if (loggedMessage.message === message) {
-          Services.console.unregisterListener(this);
-          resolve();
-        }
-      },
-    });
-    Services.console.logStringMessage(message);
-  });
-}
-
 // Finds the fetch spy call for an error with a matching message.
 function fetchCallForMessage(fetchSpy, message) {
   for (const call of fetchSpy.getCalls()) {
@@ -88,117 +67,105 @@ function fetchPassedError(fetchSpy, message) {
 }
 
 add_task(async function testInitPrefDisabled() {
-  const fetchSpy = sinon.spy();
+  let listening = false;
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({
+    registerListener() {
+      listening = true;
+    },
+  });
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, false],
-    [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
   reporter.init();
-  await logMessage(createScriptError({message: "Logged while disabled"}));
+  ok(!listening, "Reporter does not listen for errors if the enabled pref is false.");
-  ok(
-    !fetchPassedError(fetchSpy, "Logged while disabled"),
-    "Reporter does not listen for errors if the enabled pref is false.",
-  );
-  reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testInitUninitPrefEnabled() {
-  const fetchSpy = sinon.spy();
+  let listening = false;
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({
+    registerListener() {
+      listening = true;
+    },
+    unregisterListener() {
+      listening = false;
+    },
+  });
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
-    [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
   reporter.init();
-  await logMessage(createScriptError({message: "Logged after init"}));
+  ok(listening, "Reporter listens for errors if the enabled pref is true.");
-  ok(
-    fetchPassedError(fetchSpy, "Logged after init"),
-    "Reporter listens for errors if the enabled pref is true.",
-  );
 
-  fetchSpy.reset();
-  ok(!fetchSpy.called, "Fetch spy was reset.");
   reporter.uninit();
-  await logMessage(createScriptError({message: "Logged after uninit"}));
+  ok(!listening, "Reporter does not listen for errors after uninit.");
-  ok(
-    !fetchPassedError(fetchSpy, "Logged after uninit"),
-    "Reporter does not listen for errors after uninit.",
-  );
-
-  resetConsole();
 });
 
 add_task(async function testInitPastMessages() {
   const fetchSpy = sinon.spy();
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({
+    fetch: fetchSpy,
+    registerListener: noop,
+    unregisterListener: noop,
+  });
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
-  await logMessage(createScriptError({message: "Logged before init"}));
-  reporter.init();
-  ok(
-    fetchPassedError(fetchSpy, "Logged before init"),
-    "Reporter collects errors logged before initialization.",
-  );
-  reporter.uninit();
   resetConsole();
+  Services.console.logMessage(createScriptError({message: "Logged before init"}));
+  reporter.init();
+
+  // Include ok() to satisfy mochitest warning for test without any assertions
+  const errorWasLogged = await TestUtils.waitForCondition(
+    () => fetchPassedError(fetchSpy, "Logged before init"),
+    "Waiting for message to be logged",
+  );
+  ok(errorWasLogged, "Reporter collects errors logged before initialization.");
+
 });
 
 add_task(async function testEnabledPrefWatcher() {
-  const fetchSpy = sinon.spy();
+  let listening = false;
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({
+    registerListener() {
+      listening = true;
+    },
+    unregisterListener() {
+      listening = false;
+    },
+  });
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, false],
-    [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
   reporter.init();
-  await logMessage(createScriptError({message: "Shouldn't report"}));
+  ok(!listening, "Reporter does not collect errors if the enable pref is false.");
-  ok(
-    !fetchPassedError(fetchSpy, "Shouldn't report"),
-    "Reporter does not collect errors if the enable pref is false.",
-  );
 
+  Services.console.logMessage(createScriptError({message: "Shouldn't report"}));
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
   ]});
-  ok(
+  ok(listening, "Reporter collects errors if the enabled pref switches to true.");
-    !fetchPassedError(fetchSpy, "Shouldn't report"),
-    "Reporter does not collect past-logged errors if it is enabled mid-run.",
-  );
-  await logMessage(createScriptError({message: "Should report"}));
-  ok(
-    fetchPassedError(fetchSpy, "Should report"),
-    "Reporter collects errors logged after the enabled pref is turned on mid-run",
-  );
-
-  reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testNonErrorLogs() {
   const fetchSpy = sinon.spy();
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({fetch: fetchSpy});
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
-  reporter.init();
+  reporter.observe({message: "Not a scripterror instance."});
-
-  await logStringMessage("Not a scripterror instance.");
   ok(
     !fetchPassedError(fetchSpy, "Not a scripterror instance."),
     "Reporter does not collect normal log messages or warnings.",
   );
 
-  await logMessage(createScriptError({
+  await reporter.observe(createScriptError({
     message: "Warning message",
     flags: Ci.nsIScriptError.warningFlag,
   }));
@@ -207,7 +174,7 @@ add_task(async function testNonErrorLogs() {
     "Reporter does not collect normal log messages or warnings.",
   );
 
-  await logMessage(createScriptError({
+  await reporter.observe(createScriptError({
     message: "Non-chrome category",
     category: "totally from a website",
   }));
@@ -216,26 +183,22 @@ add_task(async function testNonErrorLogs() {
     "Reporter does not collect normal log messages or warnings.",
   );
 
-  await logMessage(createScriptError({message: "Is error"}));
+  await reporter.observe(createScriptError({message: "Is error"}));
   ok(
     fetchPassedError(fetchSpy, "Is error"),
     "Reporter collects error messages.",
   );
-
-  reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testSampling() {
   const fetchSpy = sinon.spy();
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({fetch: fetchSpy});
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
-  reporter.init();
+  await reporter.observe(createScriptError({message: "Should log"}));
-  await logMessage(createScriptError({message: "Should log"}));
   ok(
     fetchPassedError(fetchSpy, "Should log"),
     "A 1.0 sample rate will cause the reporter to always collect errors.",
@@ -244,7 +207,7 @@ add_task(async function testSampling() {
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_SAMPLE_RATE, "0.0"],
   ]});
-  await logMessage(createScriptError({message: "Shouldn't log"}));
+  await reporter.observe(createScriptError({message: "Shouldn't log"}));
   ok(
     !fetchPassedError(fetchSpy, "Shouldn't log"),
     "A 0.0 sample rate will cause the reporter to never collect errors.",
@@ -253,26 +216,22 @@ add_task(async function testSampling() {
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_SAMPLE_RATE, ")fasdf"],
   ]});
-  await logMessage(createScriptError({message: "Also shouldn't log"}));
+  await reporter.observe(createScriptError({message: "Also shouldn't log"}));
   ok(
     !fetchPassedError(fetchSpy, "Also shouldn't log"),
     "An invalid sample rate will cause the reporter to never collect errors.",
   );
-
-  reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testNameMessage() {
   const fetchSpy = sinon.spy();
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({fetch: fetchSpy});
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
   ]});
 
-  reporter.init();
+  await reporter.observe(createScriptError({message: "No name"}));
-  await logMessage(createScriptError({message: "No name"}));
   let call = fetchCallForMessage(fetchSpy, "No name");
   let body = JSON.parse(call.args[1].body);
   is(
@@ -286,7 +245,7 @@ add_task(async function testNameMessage() {
     "Reporter uses error message as the exception value.",
   );
 
-  await logMessage(createScriptError({message: "FooError: Has name"}));
+  await reporter.observe(createScriptError({message: "FooError: Has name"}));
   call = fetchCallForMessage(fetchSpy, "Has name");
   body = JSON.parse(call.args[1].body);
   is(
@@ -300,7 +259,7 @@ add_task(async function testNameMessage() {
     "Reporter uses error message as the value parameter.",
   );
 
-  await logMessage(createScriptError({message: "FooError: Has :extra: colons"}));
+  await reporter.observe(createScriptError({message: "FooError: Has :extra: colons"}));
   call = fetchCallForMessage(fetchSpy, "Has :extra: colons");
   body = JSON.parse(call.args[1].body);
   is(
@@ -313,13 +272,11 @@ add_task(async function testNameMessage() {
     "Has :extra: colons",
     "Reporter uses error message as the value parameter.",
   );
-  reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testFetchArguments() {
   const fetchSpy = sinon.spy();
-  const reporter = new BrowserErrorReporter(fetchSpy);
+  const reporter = new BrowserErrorReporter({fetch: fetchSpy});
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
@@ -328,6 +285,7 @@ add_task(async function testFetchArguments() {
     [PREF_SUBMIT_URL, "https://errors.example.com/api/123/store/"],
   ]});
 
+  resetConsole();
   reporter.init();
   const testPageUrl = (
     "chrome://mochitests/content/browser/browser/modules/test/browser/" +
@@ -405,18 +363,18 @@ add_task(async function testFetchArguments() {
   });
 
   reporter.uninit();
-  resetConsole();
 });
 
 add_task(async function testAddonIDMangle() {
   const fetchSpy = sinon.spy();
   // Passing false here disables category checks on errors, which would
   // otherwise block errors directly from extensions.
-  const reporter = new BrowserErrorReporter(fetchSpy, false);
+  const reporter = new BrowserErrorReporter({fetch: fetchSpy, chromeOnly: false});
   await SpecialPowers.pushPrefEnv({set: [
     [PREF_ENABLED, true],
     [PREF_SAMPLE_RATE, "1.0"],
   ]});
+  resetConsole();
   reporter.init();
 
   // Create and install test add-on
@@ -447,5 +405,4 @@ add_task(async function testAddonIDMangle() {
 
   await extension.unload();
   reporter.uninit();
-  resetConsole();
 });