Bug 1499418 - [1.3] Add GeckoView page load and startup performance telemetry probes. r=snorp,chutten,jchen

mobile/android/chrome/geckoview/GeckoViewProgressChild.js

@@ -5,11 +5,16 @@
 
 ChromeUtils.import("resource://gre/modules/GeckoViewChildModule.jsm");
 ChromeUtils.import("resource://gre/modules/XPCOMUtils.jsm");
+ChromeUtils.import("resource://gre/modules/GeckoViewTelemetry.jsm");
 
 XPCOMUtils.defineLazyModuleGetters(this, {
   Services: "resource://gre/modules/Services.jsm",
 });
 
+const PAGE_LOAD_PROGRESS_PROBE =
+  new HistogramStopwatch("GV_PAGE_LOAD_PROGRESS_MS", content);
+const PAGE_LOAD_PROBE = new HistogramStopwatch("GV_PAGE_LOAD_MS", content);
+
 class GeckoViewProgressChild extends GeckoViewChildModule {
   onInit() {
     debug `onInit`;
@@ -44,26 +49,35 @@ class GeckoViewProgressChild extends GeckoViewChildModule {
     }
 
     const uri = aRequest.QueryInterface(Ci.nsIChannel).URI.displaySpec;
+
+    if (aRequest.URI.schemeIs("about")) {
+      return;
+    }
+
     debug `onStateChange: uri=${uri}`;
 
     if (aStateFlags & Ci.nsIWebProgressListener.STATE_START) {
+      PAGE_LOAD_PROBE.start();
       ProgressTracker.start(uri);
     } else if ((aStateFlags & Ci.nsIWebProgressListener.STATE_STOP) &&
                !aWebProgress.isLoadingDocument) {
+      PAGE_LOAD_PROBE.finish();
       ProgressTracker.stop();
     } else if (aStateFlags & Ci.nsIWebProgressListener.STATE_REDIRECTING) {
+      PAGE_LOAD_PROBE.start();
       ProgressTracker.start(uri);
     }
   }
 
   onLocationChange(aWebProgress, aRequest, aLocationURI, aFlags) {
-    debug `onLocationChange: location=${aLocationURI.displaySpec},
-                             flags=${aFlags}`;
-
-    if (!aWebProgress || !aWebProgress.isTopLevel) {
+    if (!aWebProgress || !aWebProgress.isTopLevel ||
+        !aLocationURI || aLocationURI.schemeIs("about")) {
       return;
     }
 
+    debug `onLocationChange: location=${aLocationURI.displaySpec},
+                             flags=${aFlags}`;
+
     if (aFlags & Ci.nsIWebProgressListener.LOCATION_CHANGE_ERROR_PAGE) {
       ProgressTracker.stop();
     } else {
@@ -82,6 +96,7 @@ const ProgressTracker = {
     debug `ProgressTracker start ${aUri}`;
 
     if (this._tracking) {
+      PAGE_LOAD_PROGRESS_PROBE.cancel();
       this.stop();
     }
 
@@ -101,6 +116,8 @@ const ProgressTracker = {
       return;
     }
 
+    PAGE_LOAD_PROGRESS_PROBE.start();
+
     data.uri = aUri;
     data.pageStart = true;
     this.updateProgress();
@@ -252,6 +269,8 @@ const ProgressTracker = {
       return;
     }
 
+    const now = content.performance.now();
+
     let progress = 0;
 
     if (data.pageStart) {
@@ -272,7 +291,7 @@ const ProgressTracker = {
 
     data.totalReceived = 1;
     data.totalExpected = 1;
-    const channelOverdue = content.performance.now() - 300;
+    const channelOverdue = now - 300;
 
     for (let channel in data.channels) {
       if (data.channels[channel].max < 1 &&
@@ -296,7 +315,8 @@ const ProgressTracker = {
       progress += data.totalReceived / data.totalExpected * a;
     }
 
-    debug `ProgressTracker onProgressChangeUpdate ${this._debugData()} ${data.totalReceived}/${data.totalExpected} progress=${progress}`;
+    debug `ProgressTracker updateProgress data=${this._debugData()}
+           progress=${progress}`;
 
     if (data.prev >= progress) {
       return;
@@ -308,6 +328,10 @@ const ProgressTracker = {
     });
 
     data.prev = progress;
+
+    if (progress === 100) {
+      PAGE_LOAD_PROGRESS_PROBE.finish();
+    }
   },
 };
 

mobile/android/chrome/geckoview/geckoview.js

@@ -10,6 +10,7 @@ XPCOMUtils.defineLazyModuleGetters(this, {
   E10SUtils: "resource://gre/modules/E10SUtils.jsm",
   EventDispatcher: "resource://gre/modules/Messaging.jsm",
   GeckoViewUtils: "resource://gre/modules/GeckoViewUtils.jsm",
+  HistogramStopwatch: "resource://gre/modules/GeckoViewTelemetry.jsm",
   Services: "resource://gre/modules/Services.jsm",
 });
 
@@ -31,6 +32,11 @@ var ModuleManager = {
   },
 
   init(aBrowser, aModules) {
+    const MODULES_INIT_PROBE =
+      new HistogramStopwatch("GV_STARTUP_MODULES_MS", aBrowser);
+
+    MODULES_INIT_PROBE.start();
+
     const initData = this._initData;
     this._browser = aBrowser;
     this._settings = initData.settings;
@@ -73,6 +79,8 @@ var ModuleManager = {
 
       this._modules.clear();
     });
+
+    MODULES_INIT_PROBE.finish();
   },
 
   get window() {

mobile/android/geckoview/src/main/java/org/mozilla/gecko/GeckoThread.java

@@ -5,6 +5,7 @@
 
 package org.mozilla.gecko;
 
+import org.mozilla.gecko.TelemetryUtils;
 import org.mozilla.gecko.annotation.RobocopTarget;
 import org.mozilla.gecko.annotation.WrapForJNI;
 import org.mozilla.gecko.mozglue.GeckoLoader;
@@ -126,6 +127,8 @@ public class GeckoThread extends Thread {
     @WrapForJNI
     private static int uiThreadId;
 
+    private static TelemetryUtils.Timer sInitTimer;
+
     // Main process parameters
     public static final int FLAG_DEBUGGING = 1 << 0; // Debugging mode.
     public static final int FLAG_PRELOAD_CHILD = 1 << 1; // Preload child during main thread start.
@@ -177,6 +180,8 @@ public class GeckoThread extends Thread {
             return false;
         }
 
+        sInitTimer = new TelemetryUtils.UptimeTimer("GV_STARTUP_RUNTIME_MS");
+
         mInitInfo = info;
 
         mInitInfo.extras = (info.extras != null) ? new Bundle(info.extras) : new Bundle(3);
@@ -569,6 +574,11 @@ public class GeckoThread extends Thread {
         final boolean result = sNativeQueue.checkAndSetState(expectedState, newState);
         if (result) {
             Log.d(LOGTAG, "State changed to " + newState);
+
+            if (sInitTimer != null && isRunning()) {
+                sInitTimer.stop();
+                sInitTimer = null;
+            }
         }
         return result;
     }

mobile/android/modules/geckoview/GeckoViewTelemetry.jsm

@@ -0,0 +1,37 @@
+/* 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/. */
+"use strict";
+
+var EXPORTED_SYMBOLS = ["HistogramStopwatch"];
+
+// A helper for histogram timer probes.
+class HistogramStopwatch {
+  constructor(aName, aAssociated) {
+    this._name = aName;
+    this._obj = aAssociated;
+  }
+
+  isRunning() {
+    return TelemetryStopwatch.running(this._name, this._obj);
+  }
+
+  start() {
+    if (this.isRunning()) {
+      this.cancel();
+    }
+    TelemetryStopwatch.start(this._name, this._obj);
+  }
+
+  finish() {
+    TelemetryStopwatch.finish(this._name, this._obj);
+  }
+
+  cancel() {
+    TelemetryStopwatch.cancel(this._name, this._obj);
+  }
+
+  timeElapsed() {
+    return TelemetryStopwatch.timeElapsed(this._name, this._obj, false);
+  }
+}

mobile/android/modules/geckoview/moz.build

@@ -19,6 +19,7 @@ EXTRA_JS_MODULES += [
     'GeckoViewRemoteDebugger.jsm',
     'GeckoViewSettings.jsm',
     'GeckoViewTab.jsm',
+    'GeckoViewTelemetry.jsm',
     'GeckoViewTrackingProtection.jsm',
     'GeckoViewUtils.jsm',
     'LoadURIDelegate.jsm',

toolkit/components/telemetry/Histograms.json

@@ -14256,5 +14256,57 @@
     "releaseChannelCollection": "opt-out",
     "alert_emails": ["ttung@mozilla.com"],
     "description": "Time (ms) for the QuotaManager to initialize repositories."
+  },
+  "GV_PAGE_LOAD_PROGRESS_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": [
+      "geckoview-team@mozilla.com",
+      "esawin@mozilla.com"
+    ],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 100000,
+    "n_buckets": 100,
+    "bug_numbers": [1499418],
+    "description": "GeckoView: The time between page load progress start (0) and completion (100) in ms."
+  },
+  "GV_PAGE_LOAD_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": [
+      "geckoview-team@mozilla.com",
+      "esawin@mozilla.com"
+    ],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 100000,
+    "n_buckets": 100,
+    "bug_numbers": [1499418],
+    "description": "GeckoView: Time taken to load a page in ms. This includes all static contents, no dynamic content. Loading of about: pages is not counted."
+  },
+  "GV_STARTUP_RUNTIME_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": [
+      "geckoview-team@mozilla.com",
+      "esawin@mozilla.com"
+    ],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 10000,
+    "n_buckets": 50,
+    "bug_numbers": [1499418],
+    "description": "GeckoView: Time taken to initialize GeckoRuntime in ms."
+  },
+  "GV_STARTUP_MODULES_MS": {
+    "record_in_processes": ["main"],
+    "alert_emails": [
+      "geckoview-team@mozilla.com",
+      "esawin@mozilla.com"
+    ],
+    "expires_in_version": "never",
+    "kind": "exponential",
+    "high": 5000,
+    "n_buckets": 50,
+    "bug_numbers": [1499418],
+    "description": "GeckoView: Time taken to initialize all GeckoView modules in ms."
   }
 }