Backed out 5 changesets (bug 1950710) for causing timeout related failures. CLOSED TREE

Backed out changeset 7a1f8fe65c63 (bug 1950710)
Backed out changeset d2514bee519f (bug 1950710)
Backed out changeset c5f6cd03c1d4 (bug 1950710)
Backed out changeset 9e57a5c12317 (bug 1950710)
Backed out changeset 482b8c741722 (bug 1950710)

browser/components/migration/MigratorBase.sys.mjs

@@ -15,6 +15,7 @@ ChromeUtils.defineESModuleGetters(lazy, {
   FirefoxProfileMigrator: "resource:///modules/FirefoxProfileMigrator.sys.mjs",
   MigrationUtils: "resource:///modules/MigrationUtils.sys.mjs",
   PlacesUtils: "resource://gre/modules/PlacesUtils.sys.mjs",
+  ResponsivenessMonitor: "resource://gre/modules/ResponsivenessMonitor.sys.mjs",
 });
 
 /**
@@ -294,8 +295,62 @@ export class MigratorBase {
       });
     };
 
+    let getHistogramIdForResourceType = (resourceType, template) => {
+      if (resourceType == lazy.MigrationUtils.resourceTypes.HISTORY) {
+        return template.replace("*", "HISTORY");
+      }
+      if (resourceType == lazy.MigrationUtils.resourceTypes.BOOKMARKS) {
+        return template.replace("*", "BOOKMARKS");
+      }
+      if (resourceType == lazy.MigrationUtils.resourceTypes.PASSWORDS) {
+        return template.replace("*", "LOGINS");
+      }
+      return null;
+    };
+
     let browserKey = this.constructor.key;
 
+    let maybeStartTelemetryStopwatch = resourceType => {
+      let histogramId = getHistogramIdForResourceType(
+        resourceType,
+        "FX_MIGRATION_*_IMPORT_MS"
+      );
+      if (histogramId) {
+        TelemetryStopwatch.startKeyed(histogramId, browserKey);
+      }
+      return histogramId;
+    };
+
+    let maybeStartResponsivenessMonitor = resourceType => {
+      let responsivenessMonitor;
+      let responsivenessHistogramId = getHistogramIdForResourceType(
+        resourceType,
+        "FX_MIGRATION_*_JANK_MS"
+      );
+      if (responsivenessHistogramId) {
+        responsivenessMonitor = new lazy.ResponsivenessMonitor();
+      }
+      return { responsivenessMonitor, responsivenessHistogramId };
+    };
+
+    let maybeFinishResponsivenessMonitor = (
+      responsivenessMonitor,
+      histogramId
+    ) => {
+      if (responsivenessMonitor) {
+        let accumulatedDelay = responsivenessMonitor.finish();
+        if (histogramId) {
+          try {
+            Services.telemetry
+              .getKeyedHistogramById(histogramId)
+              .add(browserKey, accumulatedDelay);
+          } catch (ex) {
+            console.error(histogramId, ": ", ex);
+          }
+        }
+      }
+    };
+
     let collectQuantityTelemetry = () => {
       for (let resourceType of Object.keys(
         lazy.MigrationUtils._importQuantities
@@ -369,6 +424,11 @@ export class MigratorBase {
       for (let [migrationType, itemResources] of resourcesGroupedByItems) {
         notify("Migration:ItemBeforeMigrate", migrationType);
 
+        let stopwatchHistogramId = maybeStartTelemetryStopwatch(migrationType);
+
+        let { responsivenessMonitor, responsivenessHistogramId } =
+          maybeStartResponsivenessMonitor(migrationType);
+
         let itemSuccess = false;
         for (let res of itemResources) {
           let completeDeferred = Promise.withResolvers();
@@ -388,6 +448,18 @@ export class MigratorBase {
 
               resourcesGroupedByItems.delete(migrationType);
 
+              if (stopwatchHistogramId) {
+                TelemetryStopwatch.finishKeyed(
+                  stopwatchHistogramId,
+                  browserKey
+                );
+              }
+
+              maybeFinishResponsivenessMonitor(
+                responsivenessMonitor,
+                responsivenessHistogramId
+              );
+
               if (resourcesGroupedByItems.size == 0) {
                 collectQuantityTelemetry();
 

browser/components/tabbrowser/AsyncTabSwitcher.sys.mjs

@@ -1402,18 +1402,18 @@ export class AsyncTabSwitcher {
     // the parent process might not even get MozAfterPaint delivered for it), so just
     // give up measuring this for now. :(
     Glean.performanceInteraction.tabSwitchComposite.cancel(
-      this._tabswitchCompositeTimerId
+      this._tabswitchTimerId
     );
-    this._tabswitchCompositeTimerId = null;
+    this._tabswitchTimerId = null;
   }
 
   notePaint(event) {
     if (this.switchPaintId != -1 && event.transactionId >= this.switchPaintId) {
-      if (this._tabswitchCompositeTimerId) {
+      if (this._tabswitchTimerId) {
         Glean.performanceInteraction.tabSwitchComposite.stopAndAccumulate(
-          this._tabswitchCompositeTimerId
+          this._tabswitchTimerId
         );
-        this._tabswitchCompositeTimerId = null;
+        this._tabswitchTimerId = null;
       }
       let { innerWindowId } = this.window.windowGlobalChild;
       ChromeUtils.addProfilerMarker("AsyncTabSwitch:Composited", {
@@ -1424,17 +1424,15 @@ export class AsyncTabSwitcher {
   }
 
   noteStartTabSwitch() {
-    if (this._tabswitchTotalTimerId) {
+    TelemetryStopwatch.cancel("FX_TAB_SWITCH_TOTAL_E10S_MS", this.window);
-      Glean.browserTabswitch.total.cancel(this._tabswitchTotalTimerId);
+    TelemetryStopwatch.start("FX_TAB_SWITCH_TOTAL_E10S_MS", this.window);
-    }
-    this._tabswitchTotalTimerId = Glean.browserTabswitch.total.start();
 
-    if (this._tabswitchCompositeTimerId) {
+    if (this._tabswitchTimerId) {
       Glean.performanceInteraction.tabSwitchComposite.cancel(
-        this._tabswitchCompositeTimerId
+        this._tabswitchTimerId
       );
     }
-    this._tabswitchCompositeTimerId =
+    this._tabswitchTimerId =
       Glean.performanceInteraction.tabSwitchComposite.start();
     let { innerWindowId } = this.window.windowGlobalChild;
     ChromeUtils.addProfilerMarker("AsyncTabSwitch:Start", { innerWindowId });
@@ -1443,11 +1441,13 @@ export class AsyncTabSwitcher {
   noteFinishTabSwitch() {
     // After this point the tab has switched from the content thread's point of view.
     // The changes will be visible after the next refresh driver tick + composite.
-    if (this._tabswitchTotalTimerId) {
+    let time = TelemetryStopwatch.timeElapsed(
-      Glean.browserTabswitch.total.stopAndAccumulate(
+      "FX_TAB_SWITCH_TOTAL_E10S_MS",
-        this._tabswitchTotalTimerId
+      this.window
-      );
+    );
-      this._tabswitchTotalTimerId = null;
+    if (time != -1) {
+      TelemetryStopwatch.finish("FX_TAB_SWITCH_TOTAL_E10S_MS", this.window);
+      this.log("DEBUG: tab switch time = " + time);
       let { innerWindowId } = this.window.windowGlobalChild;
       ChromeUtils.addProfilerMarker("AsyncTabSwitch:Finish", { innerWindowId });
     }
@@ -1457,15 +1457,20 @@ export class AsyncTabSwitcher {
     this.assert(!this.spinnerTab);
     let browser = this.requestedTab.linkedBrowser;
     this.assert(browser.isRemoteBrowser);
-    this._tabswitchSpinnerTimerId =
+    TelemetryStopwatch.start("FX_TAB_SWITCH_SPINNER_VISIBLE_MS", this.window);
-      Glean.browserTabswitch.spinnerVisible.start();
+    // We have a second, similar probe for capturing recordings of
+    // when the spinner is displayed for very long periods.
+    TelemetryStopwatch.start(
+      "FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS",
+      this.window
+    );
     let { innerWindowId } = this.window.windowGlobalChild;
     ChromeUtils.addProfilerMarker("AsyncTabSwitch:SpinnerShown", {
       innerWindowId,
     });
-    Glean.browserTabswitch.spinnerVisibleTrigger[this._loadTimerClearedBy].add(
+    Services.telemetry
-      1
+      .getHistogramById("FX_TAB_SWITCH_SPINNER_VISIBLE_TRIGGER")
-    );
+      .add(this._loadTimerClearedBy);
     if (AppConstants.NIGHTLY_BUILD) {
       Services.obs.notifyObservers(null, "tabswitch-spinner");
     }
@@ -1473,11 +1478,18 @@ export class AsyncTabSwitcher {
 
   noteSpinnerHidden() {
     this.assert(this.spinnerTab);
-    this.log("DEBUG: spinner hidden");
+    this.log(
-    Glean.browserTabswitch.spinnerVisible.stopAndAccumulate(
+      "DEBUG: spinner time = " +
-      this._tabswitchSpinnerTimerId
+        TelemetryStopwatch.timeElapsed(
+          "FX_TAB_SWITCH_SPINNER_VISIBLE_MS",
+          this.window
+        )
+    );
+    TelemetryStopwatch.finish("FX_TAB_SWITCH_SPINNER_VISIBLE_MS", this.window);
+    TelemetryStopwatch.finish(
+      "FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS",
+      this.window
     );
-    this._tabswitchSpinnerTimerId = null;
     let { innerWindowId } = this.window.windowGlobalChild;
     ChromeUtils.addProfilerMarker("AsyncTabSwitch:SpinnerHidden", {
       innerWindowId,

browser/components/tabbrowser/content/tabbrowser.js

@@ -1177,9 +1177,8 @@
 
       let newTab = this.getTabForBrowser(newBrowser);
 
-      let timerId;
       if (!aForceUpdate) {
-        timerId = Glean.browserTabswitch.update.start();
+        TelemetryStopwatch.start("FX_TAB_SWITCH_UPDATE_MS");
 
         if (gMultiProcessBrowser) {
           this._asyncTabSwitching = true;
@@ -1403,7 +1402,7 @@
       }
 
       if (!aForceUpdate) {
-        Glean.browserTabswitch.update.stopAndAccumulate(timerId);
+        TelemetryStopwatch.finish("FX_TAB_SWITCH_UPDATE_MS");
       }
     }
 
@@ -4276,7 +4275,7 @@
             this._getSwitcher().warmupTab(toBlurTo);
           }
         } else if (!skipPermitUnload && this._hasBeforeUnload(tab)) {
-          let timerId = Glean.browserTabclose.permitUnloadTime.start();
+          TelemetryStopwatch.start("FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS", tab);
           // We need to block while calling permitUnload() because it
           // processes the event queue and may lead to another removeTab()
           // call before permitUnload() returns.
@@ -4288,8 +4287,9 @@
             tab.linkedBrowser.asyncPermitUnload("dontUnload").then(
               ({ permitUnload }) => {
                 tab._pendingPermitUnload = false;
-                Glean.browserTabclose.permitUnloadTime.stopAndAccumulate(
+                TelemetryStopwatch.finish(
-                  timerId
+                  "FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS",
+                  tab
                 );
                 if (tab.closing) {
                   // The tab was closed by the user while we were in permitUnload, don't
@@ -4312,8 +4312,9 @@
               err => {
                 console.error("error while calling asyncPermitUnload", err);
                 tab._pendingPermitUnload = false;
-                Glean.browserTabclose.permitUnloadTime.stopAndAccumulate(
+                TelemetryStopwatch.finish(
-                  timerId
+                  "FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS",
+                  tab
                 );
               }
             )
@@ -4569,11 +4570,14 @@
 
       // Telemetry stopwatches may already be running if removeTab gets
       // called again for an already closing tab.
-      if (!aTab._closeTimeAnimTimerId && !aTab._closeTimeNoAnimTimerId) {
+      if (
+        !TelemetryStopwatch.running("FX_TAB_CLOSE_TIME_ANIM_MS", aTab) &&
+        !TelemetryStopwatch.running("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab)
+      ) {
         // Speculatevely start both stopwatches now. We'll cancel one of
         // the two later depending on whether we're animating.
-        aTab._closeTimeAnimTimerId = Glean.browserTabclose.timeAnim.start();
+        TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_ANIM_MS", aTab);
-        aTab._closeTimeNoAnimTimerId = Glean.browserTabclose.timeNoAnim.start();
+        TelemetryStopwatch.start("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab);
       }
 
       // Handle requests for synchronously removing an already
@@ -4600,10 +4604,8 @@
           skipSessionStore,
         })
       ) {
-        Glean.browserTabclose.timeAnim.cancel(aTab._closeTimeAnimTimerId);
+        TelemetryStopwatch.cancel("FX_TAB_CLOSE_TIME_ANIM_MS", aTab);
-        aTab._closeTimeAnimTimerId = null;
+        TelemetryStopwatch.cancel("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab);
-        Glean.browserTabclose.timeNoAnim.cancel(aTab._closeTimeNoAnimTimerId);
-        aTab._closeTimeNoAnimTimerId = null;
         return;
       }
 
@@ -4635,15 +4637,13 @@
         tabWidth == 0 /* fade-in transition hasn't moved yet */
       ) {
         // We're not animating, so we can cancel the animation stopwatch.
-        Glean.browserTabclose.timeAnim.cancel(aTab._closeTimeAnimTimerId);
+        TelemetryStopwatch.cancel("FX_TAB_CLOSE_TIME_ANIM_MS", aTab);
-        aTab._closeTimeAnimTimerId = null;
         this._endRemoveTab(aTab);
         return;
       }
 
       // We're animating, so we can cancel the non-animation stopwatch.
-      Glean.browserTabclose.timeNoAnim.cancel(aTab._closeTimeNoAnimTimerId);
+      TelemetryStopwatch.cancel("FX_TAB_CLOSE_TIME_NO_ANIM_MS", aTab);
-      aTab._closeTimeNoAnimTimerId = null;
 
       aTab.style.maxWidth = ""; // ensure that fade-out transition happens
       aTab.removeAttribute("fadein");
@@ -4706,7 +4706,7 @@
           }
         }
 
-        let timerId = Glean.browserTabclose.permitUnloadTime.start();
+        TelemetryStopwatch.start("FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS", aTab);
 
         // We need to block while calling permitUnload() because it
         // processes the event queue and may lead to another removeTab()
@@ -4715,7 +4715,7 @@
         let { permitUnload } = browser.permitUnload();
         aTab._pendingPermitUnload = false;
 
-        Glean.browserTabclose.permitUnloadTime.stopAndAccumulate(timerId);
+        TelemetryStopwatch.finish("FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS", aTab);
 
         // If we were closed during onbeforeunload, we return false now
         // so we don't (try to) close the same tab again. Of course, we
@@ -4997,18 +4997,16 @@
       // closeWindow might wait an arbitrary length of time if we're supposed
       // to warn about closing the window, so we'll just stop the tab close
       // stopwatches here instead.
-      if (aTab._closeTimeAnimTimerId) {
+      TelemetryStopwatch.finish(
-        Glean.browserTabclose.timeAnim.stopAndAccumulate(
+        "FX_TAB_CLOSE_TIME_ANIM_MS",
-          aTab._closeTimeAnimTimerId
+        aTab,
-        );
+        true /* aCanceledOkay */
-        aTab._closeTimeAnimTimerId = null;
+      );
-      }
+      TelemetryStopwatch.finish(
-      if (aTab._closeTimeNoAnimTimerId) {
+        "FX_TAB_CLOSE_TIME_NO_ANIM_MS",
-        Glean.browserTabclose.timeNoAnim.stopAndAccumulate(
+        aTab,
-          aTab._closeTimeNoAnimTimerId
+        true /* aCanceledOkay */
-        );
+      );
-        aTab._closeTimeNoAnimTimerId = null;
-      }
 
       if (aCloseWindow) {
         this._windowIsClosing = closeWindow(

browser/components/tabbrowser/metrics.yaml

@@ -294,155 +294,3 @@ tabgroup:
     labels:
       - inside
       - outside
-
-browser.tabswitch:
-  update:
-    type: timing_distribution
-    description: >
-      Firefox: Time in ms spent updating UI in response to a tab switch
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_SWITCH_UPDATE_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1489524
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1489524
-    notification_emails:
-      - perf-telemetry-alerts@mozilla.com
-      - mconley@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_SWITCH_UPDATE_MS
-
-  total:
-    type: timing_distribution
-    description: >
-      Firefox: Time in ms between tab selection and tab content paint in e10s
-      windows
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_SWITCH_TOTAL_E10S_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1156592
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1489524
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1156592
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1489524
-    notification_emails:
-      - mconley@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_SWITCH_TOTAL_E10S_MS
-
-  spinner_visible:
-    type: timing_distribution
-    description: >
-      Firefox: If the spinner interstitial displays during tab switching,
-      records the time in ms the graphic is visible
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_SWITCH_SPINNER_VISIBLE_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1156592
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1156592
-    notification_emails:
-      - mconley@mozilla.com
-      - dothayer@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_SWITCH_SPINNER_VISIBLE_MS
-
-  spinner_visible_trigger:
-    type: labeled_counter
-    description: >
-      Diagnostic probe to aid in categorizing tab switch spinners. Records what
-      most recently set the loadTimer to null if a spinner was displayed.
-
-      This metric was generated to correspond to the Legacy Telemetry
-      categorical histogram FX_TAB_SWITCH_SPINNER_VISIBLE_TRIGGER.
-    labels:
-      - none
-      - preActions
-      - postActions
-      - onLoadTimeout
-      - onLayersReady
-      - onSizeModeOrOcc
-      - onEndSwapDocShells
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1442068
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1442068
-    notification_emails:
-      - dothayer@mozilla.com
-    expires: never
-    telemetry_mirror: h#FX_TAB_SWITCH_SPINNER_VISIBLE_TRIGGER
-
-browser.tabclose:
-  time_anim:
-    type: timing_distribution
-    description: >
-      Firefox: Time taken from the point of closing a tab (with animation), to
-      the browser element being removed from the DOM. (ms).
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_CLOSE_TIME_ANIM_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1488952
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1488952
-    notification_emails:
-      - mconley@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_CLOSE_TIME_ANIM_MS
-
-  time_no_anim:
-    type: timing_distribution
-    description: >
-      Firefox: Time taken from the point of closing a tab (without animation) to
-      the browser element being removed from the DOM. (ms).
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_CLOSE_TIME_NO_ANIM_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1714255
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1730041
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1754640
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1714255
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1730041
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1754640
-    notification_emails:
-      - mconley@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_CLOSE_TIME_NO_ANIM_MS
-
-  permit_unload_time:
-    type: timing_distribution
-    description: >
-      Firefox: Time taken to run permitUnload on a browser during tab close to
-      see whether or not we're allowed to close the tab (ms).
-
-      This metric was generated to correspond to the Legacy Telemetry
-      exponential histogram FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS.
-    time_unit: millisecond
-    bugs:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1714255
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1730041
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1754640
-    data_reviews:
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1340842
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1714255
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1730041
-      - https://bugzilla.mozilla.org/show_bug.cgi?id=1754640
-    notification_emails:
-      - mconley@mozilla.com
-    expires: never
-    telemetry_mirror: FX_TAB_CLOSE_PERMIT_UNLOAD_TIME_MS

browser/components/tabbrowser/test/browser/tabs/browser_tabSpinnerProbe.js

@@ -1,7 +1,8 @@
 "use strict";
 
 /**
- * Tests the FX_TAB_SWITCH_SPINNER_VISIBLE_MS telemetry probe
+ * Tests the FX_TAB_SWITCH_SPINNER_VISIBLE_MS and
+ * FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS telemetry probes
  */
 const MIN_HANG_TIME = 500; // ms
 const MAX_HANG_TIME = 5 * 1000; // ms
@@ -42,8 +43,9 @@ function hangContentProcess(browser, aMs) {
 /**
  * A generator intended to be run as a Task. It tests one of the tab spinner
  * telemetry probes.
- * @param {String} aProbe The probe to test. Should be:
+ * @param {String} aProbe The probe to test. Should be one of:
  *                  - FX_TAB_SWITCH_SPINNER_VISIBLE_MS
+ *                  - FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS
  */
 async function testProbe(aProbe) {
   info(`Testing probe: ${aProbe}`);
@@ -97,3 +99,4 @@ add_setup(async function () {
 });
 
 add_task(testProbe.bind(null, "FX_TAB_SWITCH_SPINNER_VISIBLE_MS"));
+add_task(testProbe.bind(null, "FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS"));

dom/chrome-webidl/TelemetryStopwatch.webidl

@@ -68,6 +68,29 @@ namespace TelemetryStopwatch {
    */
   boolean cancel(HistogramID histogram, optional object? obj = null);
 
+  /**
+   * Returns the elapsed time for a particular stopwatch. Primarily for
+   * debugging purposes. Must be called prior to finish.
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *                    if an invalid name is given, the function will
+   *                    throw.
+   *
+   * @param obj - Optional parameter which associates the histogram
+   *              timer with the given object.
+   *
+   * @param canceledOkay - Optional parameter which will suppress any
+   *                       warnings that normally fire when a stopwatch
+   *                       is finished after being cancelled. Defaults
+   *                       to false.
+   *
+   * @returns Time in milliseconds or -1 if the stopwatch was not
+   *          found.
+   */
+  long timeElapsed(HistogramID histogram,
+                   optional object? obj = null,
+                   optional boolean canceledOkay = false);
+
   /**
    * Stops the timer associated with the given histogram (and object),
    * calculates the time delta between start and finish, and adds the value
@@ -90,6 +113,116 @@ namespace TelemetryStopwatch {
                  optional object? obj = null,
                  optional boolean canceledOkay = false);
 
+  /**
+   * Starts a timer associated with a keyed telemetry histogram. The timer can
+   * be directly associated with a histogram and its key. Similarly to
+   * @see{TelemetryStopwatch.start} the histogram and its key can be associated
+   * with an object. Each key may have multiple associated objects and each
+   * object can be associated with multiple keys.
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *
+   * @param key - a string which must be a valid histgram key.
+   *
+   * @param obj - Optional parameter. If specified, the timer is
+   *              associated with this object, meaning that multiple
+   *              timers for the same histogram may be run
+   *              concurrently,as long as they are associated with
+   *              different objects.
+   * @param [options.inSeconds=false] - record elapsed time for this
+   *         histogram in seconds instead of milliseconds. Defaults to
+   *         false.
+   *
+   * @returns True if the timer was successfully started, false
+   *          otherwise. If a timer already exists, it can't be
+   *          started again, and the existing one will be cleared in
+   *          order to avoid measurements errors.
+   */
+  boolean startKeyed(HistogramID histogram, HistogramKey key,
+                     optional object? obj = null,
+                     optional TelemetryStopwatchOptions options = {});
+
+  /**
+   * Returns whether a timer associated with a telemetry histogram is currently
+   * running. Similarly to @see{TelemetryStopwatch.running} the timer and its
+   * key can be associated with an object. Each key may have multiple associated
+   * objects and each object can be associated with multiple keys.
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *
+   * @param key - a string which must be a valid histgram key.
+   *
+   * @param obj - Optional parameter. If specified, the timer is
+   *              associated with this object, meaning that multiple
+   *              timers for the same histogram may be run
+   *              concurrently, as long as they are associated with
+   *              different objects.
+   *
+   * @returns True if the timer exists and is currently running.
+   */
+  boolean runningKeyed(HistogramID histogram, HistogramKey key,
+                       optional object? obj = null);
+
+  /**
+   * Deletes the timer associated with a keyed histogram. Important: Only use
+   * this method when a legitimate cancellation should be done.
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *
+   * @param key - a string which must be a valid histgram key.
+   *
+   * @param obj - Optional parameter. If specified, the timer
+   *              associated with this object is deleted.
+   *
+   * @returns True if the timer exist and it was cleared, False
+   *          otherwise.
+   */
+  boolean cancelKeyed(HistogramID histogram, HistogramKey key,
+                      optional object? obj = null);
+
+  /**
+   * Returns the elapsed time for a particular stopwatch. Primarily for
+   * debugging purposes. Cannot be called after finish().
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *
+   * @param key - a string which must be a valid histgram key.
+   *
+   * @param obj - Optional parameter. If specified, the timer
+   *              associated with this object is used to calculate
+   *              the elapsed time.
+   *
+   * @returns Time in milliseconds or -1 if the stopwatch was not
+   *          found.
+   */
+  long timeElapsedKeyed(HistogramID histogram, HistogramKey key,
+                        optional object? obj = null,
+                        optional boolean canceledOkay = false);
+
+  /**
+   * Stops the timer associated with the given keyed histogram (and object),
+   * calculates the time delta between start and finish, and adds the value
+   * to the keyed histogram.
+   *
+   * @param histogram - a string which must be a valid histogram name.
+   *
+   * @param key - a string which must be a valid histgram key.
+   *
+   * @param obj - optional parameter which associates the histogram
+   *              timer with the given object.
+   *
+   * @param canceledOkay - Optional parameter which will suppress any
+   *                       warnings that normally fire when a stopwatch
+   *                       is finished after being cancelled. Defaults
+   *                       to false.
+   *
+   * @returns True if the timer was succesfully stopped and the data
+   *          was added to the histogram, false otherwise.
+   */
+  boolean finishKeyed(HistogramID histogram, HistogramKey key,
+                      optional object? obj = null,
+                      optional boolean canceledOkay = false);
+
   /**
    * Set the testing mode. Used by tests.
    */

toolkit/components/telemetry/Histograms.json

@@ -6677,6 +6677,19 @@
     "releaseChannelCollection": "opt-out",
     "description": "Firefox: If the spinner interstitial displays during tab switching, records the time in ms the graphic is visible"
   },
+  "FX_TAB_SWITCH_SPINNER_VISIBLE_LONG_MS": {
+    "record_in_processes": ["main"],
+    "products": ["firefox"],
+    "alert_emails": ["mconley@mozilla.com", "dothayer@mozilla.com"],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "low": 1000,
+    "high": 64000,
+    "n_buckets": 7,
+    "bug_numbers": [1301104],
+    "releaseChannelCollection": "opt-out",
+    "description": "Firefox: If the spinner interstitial displays during tab switching, records the time in ms the graphic is visible. This probe is similar to FX_TAB_SWITCH_SPINNER_VISIBLE_MS, but is for truly degenerate cases."
+  },
   "FX_TAB_SWITCH_SPINNER_VISIBLE_TRIGGER": {
     "record_in_processes": ["main"],
     "products": ["firefox"],

toolkit/components/telemetry/core/Stopwatch.cpp

@@ -104,8 +104,12 @@ class Timer final : public mozilla::LinkedListElement<RefPtr<Timer>> {
   bool mInSeconds;
 };
 
-#define TIMER_KEYS_IID \
+#define TIMER_KEYS_IID                               \
-  {0xef707178, 0x1544, 0x46e2, {0xa3, 0xf5, 0x98, 0x38, 0xba, 0x60, 0xfd, 0x8f}}
+  {                                                  \
+    0xef707178, 0x1544, 0x46e2, {                    \
+      0xa3, 0xf5, 0x98, 0x38, 0xba, 0x60, 0xfd, 0x8f \
+    }                                                \
+  }
 
 class TimerKeys final : public nsISupports {
  public:
@@ -609,32 +613,76 @@ void Timers::AnnotateHang(mozilla::BackgroundHangAnnotations& aAnnotations) {
 bool Stopwatch::Start(const dom::GlobalObject& aGlobal,
                       const nsAString& aHistogram, JS::Handle<JSObject*> aObj,
                       const dom::TelemetryStopwatchOptions& aOptions) {
-  return Timers::Singleton().Start(aGlobal.Context(), aHistogram, aObj,
+  return StartKeyed(aGlobal, aHistogram, VoidString(), aObj, aOptions);
-                                   VoidString(), aOptions.mInSeconds);
+}
+/* static */
+bool Stopwatch::StartKeyed(const dom::GlobalObject& aGlobal,
+                           const nsAString& aHistogram, const nsAString& aKey,
+                           JS::Handle<JSObject*> aObj,
+                           const dom::TelemetryStopwatchOptions& aOptions) {
+  return Timers::Singleton().Start(aGlobal.Context(), aHistogram, aObj, aKey,
+                                   aOptions.mInSeconds);
 }
 
 /* static */
 bool Stopwatch::Running(const dom::GlobalObject& aGlobal,
                         const nsAString& aHistogram,
                         JS::Handle<JSObject*> aObj) {
+  return RunningKeyed(aGlobal, aHistogram, VoidString(), aObj);
+}
+
+/* static */
+bool Stopwatch::RunningKeyed(const dom::GlobalObject& aGlobal,
+                             const nsAString& aHistogram, const nsAString& aKey,
+                             JS::Handle<JSObject*> aObj) {
+  return TimeElapsedKeyed(aGlobal, aHistogram, aKey, aObj, true) != -1;
+}
+
+/* static */
+int32_t Stopwatch::TimeElapsed(const dom::GlobalObject& aGlobal,
+                               const nsAString& aHistogram,
+                               JS::Handle<JSObject*> aObj, bool aCanceledOkay) {
+  return TimeElapsedKeyed(aGlobal, aHistogram, VoidString(), aObj,
+                          aCanceledOkay);
+}
+
+/* static */
+int32_t Stopwatch::TimeElapsedKeyed(const dom::GlobalObject& aGlobal,
+                                    const nsAString& aHistogram,
+                                    const nsAString& aKey,
+                                    JS::Handle<JSObject*> aObj,
+                                    bool aCanceledOkay) {
   return Timers::Singleton().TimeElapsed(aGlobal.Context(), aHistogram, aObj,
-                                         VoidString(), true) != -1;
+                                         aKey, aCanceledOkay);
 }
 
 /* static */
 bool Stopwatch::Finish(const dom::GlobalObject& aGlobal,
                        const nsAString& aHistogram, JS::Handle<JSObject*> aObj,
                        bool aCanceledOkay) {
-  return Timers::Singleton().Finish(aGlobal.Context(), aHistogram, aObj,
+  return FinishKeyed(aGlobal, aHistogram, VoidString(), aObj, aCanceledOkay);
-                                    VoidString(), aCanceledOkay) != -1;
+}
+
+/* static */
+bool Stopwatch::FinishKeyed(const dom::GlobalObject& aGlobal,
+                            const nsAString& aHistogram, const nsAString& aKey,
+                            JS::Handle<JSObject*> aObj, bool aCanceledOkay) {
+  return Timers::Singleton().Finish(aGlobal.Context(), aHistogram, aObj, aKey,
+                                    aCanceledOkay) != -1;
 }
 
 /* static */
 bool Stopwatch::Cancel(const dom::GlobalObject& aGlobal,
                        const nsAString& aHistogram,
                        JS::Handle<JSObject*> aObj) {
-  return Timers::Singleton().Delete(aGlobal.Context(), aHistogram, aObj,
+  return CancelKeyed(aGlobal, aHistogram, VoidString(), aObj);
-                                    VoidString());
+}
+
+/* static */
+bool Stopwatch::CancelKeyed(const dom::GlobalObject& aGlobal,
+                            const nsAString& aHistogram, const nsAString& aKey,
+                            JS::Handle<JSObject*> aObj) {
+  return Timers::Singleton().Delete(aGlobal.Context(), aHistogram, aObj, aKey);
 }
 
 /* static */

toolkit/components/telemetry/core/Stopwatch.h

@@ -25,9 +25,34 @@ class Stopwatch {
   static bool Cancel(const GlobalObject& global, const nsAString& histogram,
                      JS::Handle<JSObject*> obj);
 
+  static int32_t TimeElapsed(const GlobalObject& global,
+                             const nsAString& histogram,
+                             JS::Handle<JSObject*> obj, bool canceledOkay);
+
   static bool Finish(const GlobalObject& global, const nsAString& histogram,
                      JS::Handle<JSObject*> obj, bool canceledOkay);
 
+  static bool StartKeyed(const GlobalObject& global, const nsAString& histogram,
+                         const nsAString& key, JS::Handle<JSObject*> obj,
+                         const dom::TelemetryStopwatchOptions& options);
+
+  static bool RunningKeyed(const GlobalObject& global,
+                           const nsAString& histogram, const nsAString& key,
+                           JS::Handle<JSObject*> obj);
+
+  static bool CancelKeyed(const GlobalObject& global,
+                          const nsAString& histogram, const nsAString& key,
+                          JS::Handle<JSObject*> obj);
+
+  static int32_t TimeElapsedKeyed(const GlobalObject& global,
+                                  const nsAString& histogram,
+                                  const nsAString& key,
+                                  JS::Handle<JSObject*> obj, bool canceledOkay);
+
+  static bool FinishKeyed(const GlobalObject& global,
+                          const nsAString& histogram, const nsAString& key,
+                          JS::Handle<JSObject*> obj, bool canceledOkay);
+
   static void SetTestModeEnabled(const GlobalObject& global, bool testing);
 };
 

toolkit/components/telemetry/docs/collection/measuring-time.rst

@@ -9,7 +9,7 @@ From JavaScript
 ===============
 JavaScript can measure elapsed time using TelemetryStopwatch.
 
-``TelemetryStopwatch`` is a helper that simplifies recording elapsed time (in milliseconds) into histograms.
+``TelemetryStopwatch`` is a helper that simplifies recording elapsed time (in milliseconds) into histograms (plain or keyed).
 
 API:
 
@@ -24,6 +24,14 @@ API:
       running(histogramId, aObject);
       cancel(histogramId, aObject);
       finish(histogramId, aObject);
+      // Start, check if running, cancel & finish recording elapsed time into a
+      // keyed histogram.
+      // |key| specifies the key to record into.
+      // |aObject| is optional and used as above.
+      startKeyed(histogramId, key, aObject);
+      runningKeyed(histogramId, key, aObject);
+      cancelKeyed(histogramId, key, aObject);
+      finishKeyed(histogramId, key, aObject);
     };
 
 Example:

toolkit/components/telemetry/tests/unit/test_TelemetryStopwatch.js

@@ -3,11 +3,12 @@
 
 const HIST_NAME = "TELEMETRY_SEND_SUCCESS";
 const HIST_NAME2 = "RANGE_CHECKSUM_ERRORS";
+const KEYED_HIST = { id: "TELEMETRY_INVALID_PING_TYPE_SUBMITTED", key: "TEST" };
 
 var refObj = {},
   refObj2 = {};
 
-var originalCount1, originalCount2;
+var originalCount1, originalCount2, originalCount3;
 
 function run_test() {
   let histogram = Telemetry.getHistogramById(HIST_NAME);
@@ -18,6 +19,10 @@ function run_test() {
   snapshot = histogram.snapshot();
   originalCount2 = Object.values(snapshot.values).reduce((a, b) => (a += b), 0);
 
+  histogram = Telemetry.getKeyedHistogramById(KEYED_HIST.id);
+  snapshot = histogram.snapshot()[KEYED_HIST.key] || { values: [] };
+  originalCount3 = Object.values(snapshot.values).reduce((a, b) => (a += b), 0);
+
   Assert.ok(TelemetryStopwatch.start("mark1"));
   Assert.ok(TelemetryStopwatch.start("mark2"));
 
@@ -109,6 +114,52 @@ function run_test() {
   Assert.ok(!TelemetryStopwatch.finish(HIST_NAME));
   Assert.ok(!TelemetryStopwatch.finish(HIST_NAME, refObj));
 
+  // Verify that keyed histograms can be started.
+  Assert.ok(!TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1"));
+  Assert.ok(!TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2"));
+  Assert.ok(!TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1", refObj));
+  Assert.ok(!TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2", refObj));
+
+  Assert.ok(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1"));
+  Assert.ok(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY2"));
+  Assert.ok(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1", refObj));
+  Assert.ok(TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY2", refObj));
+
+  Assert.ok(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1"));
+  Assert.ok(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2"));
+  Assert.ok(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY1", refObj));
+  Assert.ok(TelemetryStopwatch.runningKeyed("HISTOGRAM", "KEY2", refObj));
+
+  // Restarting keyed histograms should fail.
+  Assert.ok(!TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1"));
+  Assert.ok(!TelemetryStopwatch.startKeyed("HISTOGRAM", "KEY1", refObj));
+
+  // Finishing a stopwatch of a non existing histogram should return false.
+  Assert.ok(!TelemetryStopwatch.finishKeyed("HISTOGRAM", "KEY2"));
+  Assert.ok(!TelemetryStopwatch.finishKeyed("HISTOGRAM", "KEY2", refObj));
+
+  // Starting & finishing a keyed stopwatch for an existing histogram should work.
+  Assert.ok(TelemetryStopwatch.startKeyed(KEYED_HIST.id, KEYED_HIST.key));
+  Assert.ok(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, KEYED_HIST.key));
+  // Verify that TS.finish deleted the timers
+  Assert.ok(!TelemetryStopwatch.runningKeyed(KEYED_HIST.id, KEYED_HIST.key));
+
+  // Verify that they can be used again
+  Assert.ok(TelemetryStopwatch.startKeyed(KEYED_HIST.id, KEYED_HIST.key));
+  Assert.ok(TelemetryStopwatch.finishKeyed(KEYED_HIST.id, KEYED_HIST.key));
+
+  Assert.ok(!TelemetryStopwatch.finishKeyed("unknown-mark", "unknown-key"));
+  Assert.ok(!TelemetryStopwatch.finishKeyed(KEYED_HIST.id, "unknown-key"));
+
+  // Verify that keyed histograms can only be canceled through "keyed" API.
+  Assert.ok(TelemetryStopwatch.startKeyed(KEYED_HIST.id, KEYED_HIST.key));
+  Assert.throws(
+    () => TelemetryStopwatch.cancel(KEYED_HIST.id, KEYED_HIST.key),
+    /is not an object/
+  );
+  Assert.ok(TelemetryStopwatch.cancelKeyed(KEYED_HIST.id, KEYED_HIST.key));
+  Assert.ok(!TelemetryStopwatch.cancelKeyed(KEYED_HIST.id, KEYED_HIST.key));
+
   finishTest();
 }
 
@@ -132,4 +183,14 @@ function finishTest() {
     3,
     "The correct number of histograms were added for histogram 2."
   );
+
+  histogram = Telemetry.getKeyedHistogramById(KEYED_HIST.id);
+  snapshot = histogram.snapshot()[KEYED_HIST.key];
+  newCount = Object.values(snapshot.values).reduce((a, b) => (a += b), 0);
+
+  Assert.equal(
+    newCount - originalCount3,
+    2,
+    "The correct number of histograms were added for histogram 3."
+  );
 }

toolkit/modules/ResponsivenessMonitor.sys.mjs

@@ -0,0 +1,42 @@
+/* This Source Code Form is subject to the terms of the Mozilla Public
+ * 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/. */
+
+export function ResponsivenessMonitor(intervalMS = 100) {
+  this._intervalMS = intervalMS;
+  this._prevTimestamp = Date.now();
+  this._accumulatedDelay = 0;
+  this._timer = Cc["@mozilla.org/timer;1"].createInstance(Ci.nsITimer);
+  this._timer.initWithCallback(
+    this,
+    this._intervalMS,
+    Ci.nsITimer.TYPE_REPEATING_SLACK
+  );
+}
+
+ResponsivenessMonitor.prototype = {
+  QueryInterface: ChromeUtils.generateQI(["nsINamed", "nsITimerCallback"]),
+
+  name: "ResponsivenessMonitor",
+
+  notify() {
+    let now = Date.now();
+    this._accumulatedDelay += Math.max(
+      0,
+      now - this._prevTimestamp - this._intervalMS
+    );
+    this._prevTimestamp = now;
+  },
+
+  abort() {
+    if (this._timer) {
+      this._timer.cancel();
+      this._timer = null;
+    }
+  },
+
+  finish() {
+    this.abort();
+    return this._accumulatedDelay;
+  },
+};

toolkit/modules/moz.build

@@ -108,6 +108,9 @@ with Files("PrivateBrowsingUtils.sys.mjs"):
 with Files("Promise*.sys.mjs"):
     BUG_COMPONENT = ("Toolkit", "Async Tooling")
 
+with Files("ResponsivenessMonitor.sys.mjs"):
+    BUG_COMPONENT = ("Firefox", "Migration")
+
 with Files("ShortcutUtils.sys.mjs"):
     BUG_COMPONENT = ("Firefox", "Toolbars and Customization")
 
@@ -199,6 +202,7 @@ EXTRA_JS_MODULES += [
     "Region.sys.mjs",
     "RemotePageAccessManager.sys.mjs",
     "ResetProfile.sys.mjs",
+    "ResponsivenessMonitor.sys.mjs",
     "SelectionUtils.sys.mjs",
     "ServiceRequest.sys.mjs",
     "ShortcutUtils.sys.mjs",

tools/@types/lib.gecko.dom.d.ts

@@ -24610,10 +24610,16 @@ declare namespace SessionStoreUtils {
 
 declare namespace TelemetryStopwatch {
     function cancel(histogram: HistogramID, obj?: any): boolean;
+    function cancelKeyed(histogram: HistogramID, key: HistogramKey, obj?: any): boolean;
     function finish(histogram: HistogramID, obj?: any, canceledOkay?: boolean): boolean;
+    function finishKeyed(histogram: HistogramID, key: HistogramKey, obj?: any, canceledOkay?: boolean): boolean;
     function running(histogram: HistogramID, obj?: any): boolean;
+    function runningKeyed(histogram: HistogramID, key: HistogramKey, obj?: any): boolean;
     function setTestModeEnabled(testing?: boolean): void;
     function start(histogram: HistogramID, obj?: any, options?: TelemetryStopwatchOptions): boolean;
+    function startKeyed(histogram: HistogramID, key: HistogramKey, obj?: any, options?: TelemetryStopwatchOptions): boolean;
+    function timeElapsed(histogram: HistogramID, obj?: any, canceledOkay?: boolean): number;
+    function timeElapsedKeyed(histogram: HistogramID, key: HistogramKey, obj?: any, canceledOkay?: boolean): number;
 }
 
 declare namespace TestUtils {