Bug 1333233 - part 2: add telemetry for the time it takes to do individual undo operations, r?dolske,bsmedberg draft
authorGijs Kruitbosch <gijskruitbosch@gmail.com>
Thu, 26 Jan 2017 17:00:00 +0000
changeset 466820 b3789697c4f2d7fd0895f9a14a3596cda71c793f
parent 466819 0108acd4bdf6842d2d3330a43e2220bf329a3b7a
child 543523 a1c65f217db4b6c34d743d628740be86a9c584a8
push id43004
push userbmo:gijskruitbosch+bugs@gmail.com
push dateThu, 26 Jan 2017 17:08:17 +0000
reviewersdolske, bsmedberg
bugs1333233
milestone54.0a1
Bug 1333233 - part 2: add telemetry for the time it takes to do individual undo operations, r?dolske,bsmedberg MozReview-Commit-ID: Lf7roH3EswB
browser/components/migration/AutoMigrate.jsm
browser/components/migration/tests/unit/test_automigration.js
toolkit/components/telemetry/Histograms.json
--- a/browser/components/migration/AutoMigrate.jsm
+++ b/browser/components/migration/AutoMigrate.jsm
@@ -22,22 +22,24 @@ Cu.import("resource:///modules/Migration
 Cu.import("resource://gre/modules/Preferences.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 Cu.import("resource://gre/modules/Task.jsm");
 Cu.import("resource://gre/modules/XPCOMUtils.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "AsyncShutdown",
                                   "resource://gre/modules/AsyncShutdown.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "LoginHelper",
                                   "resource://gre/modules/LoginHelper.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "NewTabUtils",
+                                  "resource://gre/modules/NewTabUtils.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "OS",
                                   "resource://gre/modules/osfile.jsm");
 XPCOMUtils.defineLazyModuleGetter(this, "PlacesUtils",
                                   "resource://gre/modules/PlacesUtils.jsm");
-XPCOMUtils.defineLazyModuleGetter(this, "NewTabUtils",
-                                  "resource://gre/modules/NewTabUtils.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "TelemetryStopwatch",
+                                  "resource://gre/modules/TelemetryStopwatch.jsm");
 
 Cu.importGlobalProperties(["URL"]);
 
 /* globals kUndoStateFullPath */
 XPCOMUtils.defineLazyGetter(this, "kUndoStateFullPath", function() {
   return OS.Path.join(OS.Constants.Path.profileDir, "initialMigrationMetadata.jsonlz4");
 });
 
@@ -189,16 +191,18 @@ const AutoMigrate = {
       fileExists = yield OS.File.exists(kUndoStateFullPath);
     } catch (ex) {
       Cu.reportError(ex);
     }
     return fileExists;
   }),
 
   undo: Task.async(function* () {
+    let browserId = Preferences.get(kAutoMigrateBrowserPref, "unknown");
+    TelemetryStopwatch.startKeyed("FX_STARTUP_MIGRATION_UNDO_TOTAL_MS", browserId);
     let histogram = Services.telemetry.getHistogramById("FX_STARTUP_MIGRATION_AUTOMATED_IMPORT_UNDO");
     histogram.add(0);
     if (!(yield this.canUndo())) {
       histogram.add(5);
       throw new Error("Can't undo!");
     }
 
     this._pendingUndoTasks = true;
@@ -208,49 +212,64 @@ const AutoMigrate = {
     let readPromise = OS.File.read(kUndoStateFullPath, {
       encoding: "utf-8",
       compression: "lz4",
     });
     let stateData = this._dejsonifyUndoState(yield readPromise);
     histogram.add(12);
 
     this._errorMap = {bookmarks: 0, visits: 0, logins: 0};
-    let browserId = Preferences.get(kAutoMigrateBrowserPref, "unknown");
     let reportErrorTelemetry = (type) => {
       let histogramId = `FX_STARTUP_MIGRATION_UNDO_${type.toUpperCase()}_ERRORCOUNT`;
       Services.telemetry.getKeyedHistogramById(histogramId).add(browserId, this._errorMap[type]);
     };
+
+    let startTelemetryStopwatch = resourceType => {
+      let histogramId = `FX_STARTUP_MIGRATION_UNDO_${resourceType.toUpperCase()}_MS`;
+      TelemetryStopwatch.startKeyed(histogramId, browserId);
+    };
+    let stopTelemetryStopwatch = resourceType => {
+      let histogramId = `FX_STARTUP_MIGRATION_UNDO_${resourceType.toUpperCase()}_MS`;
+      TelemetryStopwatch.finishKeyed(histogramId, browserId);
+    };
+    startTelemetryStopwatch("bookmarks");
     yield this._removeUnchangedBookmarks(stateData.get("bookmarks")).catch(ex => {
       Cu.reportError("Uncaught exception when removing unchanged bookmarks!");
       Cu.reportError(ex);
     });
+    stopTelemetryStopwatch("bookmarks");
     reportErrorTelemetry("bookmarks");
     histogram.add(15);
 
+    startTelemetryStopwatch("visits");
     yield this._removeSomeVisits(stateData.get("visits")).catch(ex => {
       Cu.reportError("Uncaught exception when removing history visits!");
       Cu.reportError(ex);
     });
+    stopTelemetryStopwatch("visits");
     reportErrorTelemetry("visits");
     histogram.add(20);
 
+    startTelemetryStopwatch("logins");
     yield this._removeUnchangedLogins(stateData.get("logins")).catch(ex => {
       Cu.reportError("Uncaught exception when removing unchanged logins!");
       Cu.reportError(ex);
     });
+    stopTelemetryStopwatch("logins");
     reportErrorTelemetry("logins");
     histogram.add(25);
 
     // This is async, but no need to wait for it.
     NewTabUtils.links.populateCache(() => {
       NewTabUtils.allPages.update();
     }, true);
 
     this._purgeUndoState(this.UNDO_REMOVED_REASON_UNDO_USED);
     histogram.add(30);
+    TelemetryStopwatch.finishKeyed("FX_STARTUP_MIGRATION_UNDO_TOTAL_MS", browserId);
   }),
 
   _removeNotificationBars() {
     let browserWindows = Services.wm.getEnumerator("navigator:browser");
     while (browserWindows.hasMoreElements()) {
       let win = browserWindows.getNext();
       if (!win.closed) {
         for (let browser of win.gBrowser.browsers) {
--- a/browser/components/migration/tests/unit/test_automigration.js
+++ b/browser/components/migration/tests/unit/test_automigration.js
@@ -264,16 +264,26 @@ add_task(function* checkUndoRemoval() {
     "FX_STARTUP_MIGRATION_UNDO_VISITS_ERRORCOUNT",
   ];
   for (let histogramId of histograms) {
     let keyedHistogram = Services.telemetry.getKeyedHistogramById(histogramId);
     let histogramData = keyedHistogram.snapshot().automationbrowser;
     Assert.equal(histogramData.sum, 0, `Should have reported 0 errors to ${histogramId}.`);
     Assert.greaterOrEqual(histogramData.counts[0], 1, `Should have reported value of 0 one time to ${histogramId}.`);
   }
+  histograms = [
+    "FX_STARTUP_MIGRATION_UNDO_BOOKMARKS_MS",
+    "FX_STARTUP_MIGRATION_UNDO_LOGINS_MS",
+    "FX_STARTUP_MIGRATION_UNDO_VISITS_MS",
+    "FX_STARTUP_MIGRATION_UNDO_TOTAL_MS",
+  ];
+  for (let histogramId of histograms) {
+    Assert.greater(Services.telemetry.getKeyedHistogramById(histogramId).snapshot().automationbrowser.sum, 0,
+                   `Should have reported non-zero time spent using undo for ${histogramId}`);
+  }
 
   // Check that the undo removed the history visits:
   visits = PlacesUtils.history.executeQuery(query, opts);
   visits.root.containerOpen = true;
   Assert.equal(visits.root.childCount, 0, "Should have no more visits");
   visits.root.containerOpen = false;
 
   // Check that the undo removed the bookmarks:
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -5201,16 +5201,60 @@
     "expires_in_version": "58",
     "keyed": true,
     "kind": "exponential",
     "n_buckets": 20,
     "high": 100,
     "releaseChannelCollection": "opt-out",
     "description": "Indicates how many errors we find when trying to 'undo' history import. Keys are internal ids of browsers we import from, e.g. 'chrome' or 'ie', etc."
   },
+  "FX_STARTUP_MIGRATION_UNDO_BOOKMARKS_MS": {
+    "bug_numbers": [1333233],
+    "alert_emails": ["gijs@mozilla.com"],
+    "expires_in_version": "58",
+    "keyed": true,
+    "kind": "exponential",
+    "n_buckets": 20,
+    "high": 60000,
+    "releaseChannelCollection": "opt-out",
+    "description": "Indicates how long it took to undo the startup import of bookmarks, in ms. Keys are internal ids of browsers we import from, e.g. 'chrome' or 'ie', etc."
+  },
+  "FX_STARTUP_MIGRATION_UNDO_LOGINS_MS": {
+    "bug_numbers": [1333233],
+    "alert_emails": ["gijs@mozilla.com"],
+    "expires_in_version": "58",
+    "keyed": true,
+    "kind": "exponential",
+    "n_buckets": 20,
+    "high": 60000,
+    "releaseChannelCollection": "opt-out",
+    "description": "Indicates how long it took to undo the startup import of logins, in ms. Keys are internal ids of browsers we import from, e.g. 'chrome' or 'ie', etc."
+  },
+  "FX_STARTUP_MIGRATION_UNDO_VISITS_MS": {
+    "bug_numbers": [1333233],
+    "alert_emails": ["gijs@mozilla.com"],
+    "expires_in_version": "58",
+    "keyed": true,
+    "kind": "exponential",
+    "n_buckets": 20,
+    "high": 60000,
+    "releaseChannelCollection": "opt-out",
+    "description": "Indicates how long it took to undo the startup import of visits (history), in ms. Keys are internal ids of browsers we import from, e.g. 'chrome' or 'ie', etc."
+  },
+  "FX_STARTUP_MIGRATION_UNDO_TOTAL_MS": {
+    "bug_numbers": [1333233],
+    "alert_emails": ["gijs@mozilla.com"],
+    "expires_in_version": "58",
+    "keyed": true,
+    "kind": "exponential",
+    "n_buckets": 20,
+    "high": 60000,
+    "releaseChannelCollection": "opt-out",
+    "description": "Indicates how long it took to undo the entirety of the startup undo, in ms. Keys are internal ids of browsers we import from, e.g. 'chrome' or 'ie', etc."
+  },
   "FX_STARTUP_MIGRATION_DATA_RECENCY": {
     "bug_numbers": [1276694],
     "alert_emails": ["gijs@mozilla.com"],
     "expires_in_version": "57",
     "keyed": true,
     "kind": "exponential",
     "n_buckets": 50,
     "high": 8760,