Bug 1483817 - Font Inspector telemetry needs more granular OS versioning r=gl
authorMichael Ratcliffe <mratcliffe@mozilla.com>
Thu, 23 Aug 2018 19:48:17 +0000
changeset 433182 623fd496e6ea0c24428ba413e0f63ff3809121df
parent 433181 1b57bb7e8f20262f8dd09637d428422aa84ae814
child 433183 4a333f450838fbc7dd58146696e2ec9a11e84bdf
push id34500
push usertoros@mozilla.com
push dateFri, 24 Aug 2018 09:42:33 +0000
treeherdermozilla-central@043aff7fda61 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersgl
bugs1483817
milestone63.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
Bug 1483817 - Font Inspector telemetry needs more granular OS versioning r=gl - Added test to `devtools/client/inspector/test/browser_inspector_sidebarstate.js`. - Added the OS and build number to the `devtools.main::sidepanel_changed` event. - Created an `osNameAndVersion` getter inside `telemetry.js` because this can be useful whenever an OS supports new features. - Log the `devtools.main::tool_timer` event from `telemetry.toolOpened` and `telemetry.toolClosed` for the animation inspector, computed view, font inspector, layout view and rule view. - Updated the `telemetry.md` document because there is little point in breaking that change out to another bug. - Added the devtools.main::tool_timer event to Events.yaml. Differential Revision: https://phabricator.services.mozilla.com/D3982
devtools/client/inspector/test/browser_inspector_sidebarstate.js
devtools/client/inspector/toolsidebar.js
devtools/client/shared/telemetry.js
devtools/docs/frontend/telemetry.md
toolkit/components/telemetry/Events.yaml
--- a/devtools/client/inspector/test/browser_inspector_sidebarstate.js
+++ b/devtools/client/inspector/test/browser_inspector_sidebarstate.js
@@ -1,17 +1,58 @@
 /* vim: set ts=2 et sw=2 tw=80: */
 /* Any copyright is dedicated to the Public Domain.
    http://creativecommons.org/publicdomain/zero/1.0/ */
 "use strict";
 
 const TEST_URI = "data:text/html;charset=UTF-8," +
   "<h1>browser_inspector_sidebarstate.js</h1>";
+const OPTOUT = Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTOUT;
+
+const TELEMETRY_DATA = [
+  {
+    timestamp: null,
+    category: "devtools.main",
+    method: "tool_timer",
+    object: "computedview",
+    value: null,
+    extra: {
+      time_open: ""
+    }
+  },
+  {
+    timestamp: null,
+    category: "devtools.main",
+    method: "tool_timer",
+    object: "layoutview",
+    value: null,
+    extra: {
+      time_open: ""
+    }
+  },
+  {
+    timestamp: null,
+    category: "devtools.main",
+    method: "tool_timer",
+    object: "ruleview",
+    value: null,
+    extra: {
+      time_open: ""
+    }
+  }
+];
 
 add_task(async function() {
+  // Let's reset the counts.
+  Services.telemetry.clearEvents();
+
+  // Ensure no events have been logged
+  const snapshot = Services.telemetry.snapshotEvents(OPTOUT, true);
+  ok(!snapshot.parent, "No events have been logged for the main process");
+
   let { inspector, toolbox } = await openInspectorForURL(TEST_URI);
 
   info("Selecting computed view.");
   inspector.sidebar.select("computedview");
 
   is(inspector.sidebar.getCurrentTabID(), "computedview",
     "Computed View is selected");
 
@@ -29,9 +70,31 @@ add_task(async function() {
 
   if (!inspector.sidebar.getCurrentTabID()) {
     info("Default sidebar still to be selected, adding select listener.");
     await inspector.sidebar.once("select");
   }
 
   is(inspector.sidebar.getCurrentTabID(), "layoutview",
      "Layout view is selected by default.");
+
+  checkTelemetryResults();
 });
+
+function checkTelemetryResults() {
+  const snapshot = Services.telemetry.snapshotEvents(OPTOUT, true);
+  const events = snapshot.parent.filter(event => event[1] === "devtools.main" &&
+                                                 event[2] === "tool_timer"
+  );
+
+  for (const i in TELEMETRY_DATA) {
+    const [ timestamp, category, method, object, value, extra ] = events[i];
+    const expected = TELEMETRY_DATA[i];
+
+    // ignore timestamp
+    ok(timestamp > 0, "timestamp is greater than 0");
+    ok(extra.time_open > 0, "time_open is greater than 0");
+    is(category, expected.category, "category is correct");
+    is(method, expected.method, "method is correct");
+    is(object, expected.object, "object is correct");
+    is(value, expected.value, "value is correct");
+  }
+}
--- a/devtools/client/inspector/toolsidebar.js
+++ b/devtools/client/inspector/toolsidebar.js
@@ -330,25 +330,27 @@ ToolSidebar.prototype = {
     if (currentToolId === previousToolId || !this._telemetry) {
       // Skip telemetry if the tool id did not change or telemetry is unavailable.
       return;
     }
 
     currentToolId = this.getTelemetryPanelNameOrOther(currentToolId);
 
     if (previousToolId) {
-      previousToolId = this.getTelemetryPanelNameOrOther(previousToolId);
+      const sessionId = this._toolPanel._toolbox.sessionId;
 
-      this._telemetry.toolClosed(previousToolId);
+      previousToolId = this.getTelemetryPanelNameOrOther(previousToolId);
+      this._telemetry.toolClosed(previousToolId, sessionId);
 
       this._telemetry.recordEvent("devtools.main", "sidepanel_changed", "inspector", null,
         {
           "oldpanel": previousToolId,
           "newpanel": currentToolId,
-          "session_id": this._toolPanel._toolbox.sessionId
+          "os": this._telemetry.osNameAndVersion,
+          "session_id": sessionId
         }
       );
     }
     this._telemetry.toolOpened(currentToolId);
   },
 
   /**
    * Returns a panel id in the case of built in panels or "other" in the case of
--- a/devtools/client/shared/telemetry.js
+++ b/devtools/client/shared/telemetry.js
@@ -8,16 +8,17 @@
  * Comprehensive documentation is in docs/frontend/telemetry.md
  */
 
 "use strict";
 
 const Services = require("Services");
 const { TelemetryStopwatch } = require("resource://gre/modules/TelemetryStopwatch.jsm");
 const { getNthPathExcluding } = require("devtools/shared/platform/stack");
+const { TelemetryEnvironment } = require("resource://gre/modules/TelemetryEnvironment.jsm");
 
 // Object to be shared among all instances.
 const PENDING_EVENTS = new Map();
 const PENDING_EVENT_PROPERTIES = new Map();
 
 class Telemetry {
   constructor() {
     // Bind pretty much all functions so that callers do not need to.
@@ -31,16 +32,32 @@ class Telemetry {
     this.recordEvent = this.recordEvent.bind(this);
     this.setEventRecordingEnabled = this.setEventRecordingEnabled.bind(this);
     this.preparePendingEvent = this.preparePendingEvent.bind(this);
     this.addEventProperty = this.addEventProperty.bind(this);
     this.toolOpened = this.toolOpened.bind(this);
     this.toolClosed = this.toolClosed.bind(this);
   }
 
+  get osNameAndVersion() {
+    const osInfo = TelemetryEnvironment.currentEnvironment.system.os;
+
+    if (!osInfo) {
+      return "Unknown OS";
+    }
+
+    let osVersion = `${osInfo.name} ${osInfo.version}`;
+
+    if (osInfo.windowsBuildNumber) {
+      osVersion += `.${osInfo.windowsBuildNumber}`;
+    }
+
+    return osVersion;
+  }
+
   /**
    * Time since the system wide epoch. This is not a monotonic timer but
    * can be used across process boundaries.
    */
   msSystemNow() {
     return Services.telemetry.msSystemNow();
   }
 
@@ -552,41 +569,77 @@ class Telemetry {
    */
   toolOpened(id) {
     const charts = getChartsFromToolId(id);
 
     if (!charts) {
       return;
     }
 
+    if (charts.useTimedEvent) {
+      if (id === "newanimationinspector") {
+        id = "animationinspector";
+      }
+
+      this.preparePendingEvent("devtools.main", "tool_timer", id, null, [
+        "os",
+        "time_open",
+        "session_id"
+      ]);
+      this.addEventProperty("devtools.main", "tool_timer", id, null,
+                            "time_open", this.msSystemNow());
+    }
     if (charts.timerHist) {
       this.start(charts.timerHist, this);
     }
     if (charts.countHist) {
       this.getHistogramById(charts.countHist).add(true);
     }
     if (charts.countScalar) {
       this.scalarAdd(charts.countScalar, 1);
     }
   }
 
   /**
    * Sends telemetry pings to indicate that a tool has been closed.
    *
    * @param {String} id
    *        The ID of the tool opened.
+   * @param {String} sessionId
+   *        Optional toolbox session id used only when a tool's chart has a
+   *        useTimedEvent property set to true.
    *
    * NOTE: This method is designed for tools that send multiple probes on open,
    *       one of those probes being a counter and the other a timer. If you
    *       only have one probe you should be using another method.
    */
-  toolClosed(id) {
+  toolClosed(id, sessionId) {
     const charts = getChartsFromToolId(id);
 
-    if (charts && charts.timerHist) {
+    if (!charts) {
+      return;
+    }
+
+    if (charts.useTimedEvent) {
+      if (id === "newanimationinspector") {
+        id = "animationinspector";
+      }
+
+      const sig = `devtools.main,tool_timer,${id},null`;
+      const event = PENDING_EVENTS.get(sig);
+      const time = this.msSystemNow() - event.extra.time_open;
+
+      this.addEventProperties("devtools.main", "tool_timer", id, null, {
+        "time_open": time,
+        "os": this.osNameAndVersion,
+        "session_id": sessionId
+      });
+    }
+
+    if (charts.timerHist) {
       this.finish(charts.timerHist, this);
     }
   }
 }
 
 /**
  * Returns the telemetry charts for a specific tool.
  *
@@ -596,49 +649,45 @@ class Telemetry {
  */
 function getChartsFromToolId(id) {
   if (!id) {
     return null;
   }
 
   const lowerCaseId = id.toLowerCase();
 
+  let useTimedEvent = null;
   let timerHist = null;
   let countHist = null;
   let countScalar = null;
 
   id = id.toUpperCase();
 
   if (id === "PERFORMANCE") {
     id = "JSPROFILER";
   }
   if (id === "NEWANIMATIONINSPECTOR") {
     id = "ANIMATIONINSPECTOR";
   }
 
   switch (id) {
     case "ABOUTDEBUGGING":
-    case "ANIMATIONINSPECTOR":
     case "BROWSERCONSOLE":
     case "CANVASDEBUGGER":
-    case "COMPUTEDVIEW":
     case "DEVELOPERTOOLBAR":
     case "DOM":
-    case "FONTINSPECTOR":
     case "INSPECTOR":
     case "JSBROWSERDEBUGGER":
     case "JSDEBUGGER":
     case "JSPROFILER":
-    case "LAYOUTVIEW":
     case "MEMORY":
     case "NETMONITOR":
     case "OPTIONS":
     case "PAINTFLASHING":
     case "RESPONSIVE":
-    case "RULEVIEW":
     case "SCRATCHPAD":
     case "SHADEREDITOR":
     case "STORAGE":
     case "STYLEEDITOR":
     case "TOOLBOX":
     case "WEBAUDIOEDITOR":
     case "WEBCONSOLE":
     case "WEBIDE":
@@ -649,27 +698,37 @@ function getChartsFromToolId(id) {
     case "APPLICATION":
       timerHist = `DEVTOOLS_${id}_TIME_ACTIVE_SECONDS`;
       countScalar = `devtools.${lowerCaseId}.opened_count`;
       break;
     case "ACCESSIBILITY_PICKER":
       timerHist = `DEVTOOLS_${id}_TIME_ACTIVE_SECONDS`;
       countScalar = `devtools.accessibility.picker_used_count`;
       break;
+    case "ANIMATIONINSPECTOR":
+    case "COMPUTEDVIEW":
+    case "FONTINSPECTOR":
+    case "LAYOUTVIEW":
+    case "RULEVIEW":
+      useTimedEvent = true;
+      timerHist = `DEVTOOLS_${id}_TIME_ACTIVE_SECONDS`;
+      countHist = `DEVTOOLS_${id}_OPENED_COUNT`;
+      break;
     default:
       timerHist = `DEVTOOLS_CUSTOM_TIME_ACTIVE_SECONDS`;
       countHist = `DEVTOOLS_CUSTOM_OPENED_COUNT`;
   }
 
   if (!timerHist || (!countHist && !countScalar)) {
     throw new Error(`getChartsFromToolId cannot be called without a timer ` +
                     `histogram and either a count histogram or count scalar.`);
   }
 
   return {
+    useTimedEvent: useTimedEvent,
     timerHist: timerHist,
     countHist: countHist,
     countScalar: countScalar
   };
 }
 
 /**
  * Displays the first caller and calling line outside of this file in the
--- a/devtools/docs/frontend/telemetry.md
+++ b/devtools/docs/frontend/telemetry.md
@@ -337,17 +337,17 @@ This is best shown via an example:
 
 "use strict";
 
 const { Toolbox } = require("devtools/client/framework/toolbox");
 
 const URL = "data:text/html;charset=utf8,browser_toolbox_telemetry_close.js";
 const OPTOUT = Ci.nsITelemetry.DATASET_RELEASE_CHANNEL_OPTOUT;
 const { SIDE, BOTTOM } = Toolbox.HostType;
-const DATA = [
+const TELEMETRY_DATA = [
   {
     timestamp: null,
     category: "devtools.main",
     method: "close",
     object: "tools",
     value: null,
     extra: {
       host: "right",
@@ -393,19 +393,19 @@ async function openAndCloseToolbox(toolI
 function checkResults() {
   const snapshot = Services.telemetry.snapshotEvents(OPTOUT, true);
   const events = snapshot.parent.filter(event => event[1] === "devtools.main" &&
                                                  event[2] === "close" &&
                                                  event[3] === "tools" &&
                                                  event[4] === null
   );
 
-  for (let i in DATA) {
+  for (const i in TELEMETRY_DATA) {
     const [ timestamp, category, method, object, value, extra ] = events[i];
-    const expected = DATA[i];
+    const expected = TELEMETRY_DATA[i];
 
     // ignore timestamp
     ok(timestamp > 0, "timestamp is greater than 0");
     is(category, expected.category, "category is correct");
     is(method, expected.method, "method is correct");
     is(object, expected.object, "object is correct");
     is(value, expected.value, "value is correct");
 
--- a/toolkit/components/telemetry/Events.yaml
+++ b/toolkit/components/telemetry/Events.yaml
@@ -533,16 +533,17 @@ devtools.main:
     notification_emails: ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"]
     record_in_processes: ["main"]
     description: User has switched sidepanel tabs.
     release_channel_collection: opt-out
     expiry_version: never
     extra_keys:
       oldpanel: The panel the user is switching from
       newpanel: The panel the user is switching to
+      os: The OS name and version e.g. "Linux 4.4.0-1014-aws", "Darwin 14.5.0", "Windows_NT 6.1.7601" or "Windows_NT 10.0.15063." This can be used to make sense of data when a feature is only available from a particular operating system build number.
       session_id: The start time of the session in milliseconds since epoch (Unix Timestamp) e.g. 1396381378123.
   edit_resend:
     objects: ["netmonitor"]
     bug_numbers: [1463171]
     notification_emails: ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"]
     record_in_processes: ["main"]
     description: User has executed edit / resend in the netmonitor.
     release_channel_collection: opt-out
@@ -683,8 +684,20 @@ devtools.main:
     bug_numbers: [1463104]
     notification_emails: ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"]
     record_in_processes: ["main"]
     description: User has expanded an object in the web console.
     release_channel_collection: opt-out
     expiry_version: never
     extra_keys:
       session_id: The start time of the session in milliseconds since epoch (Unix Timestamp) e.g. 1396381378123.
+  tool_timer:
+    objects: ["animationinspector", "computedview", "fontinspector", "layoutview", "ruleview"]
+    bug_numbers: [1483817]
+    notification_emails: ["dev-developer-tools@lists.mozilla.org", "hkirschner@mozilla.com"]
+    record_in_processes: ["main"]
+    description: The amount of time a tool was opened for.
+    release_channel_collection: opt-out
+    expiry_version: never
+    extra_keys:
+      time_open: Time open.
+      os: The OS name and version e.g. "Linux 4.4.0-1014-aws", "Darwin 14.5.0", "Windows_NT 6.1.7601" or "Windows_NT 10.0.15063." This can be used to make sense of data when a feature is only available from a particular operating system build number.
+      session_id: The start time of the session in milliseconds since epoch (Unix Timestamp) e.g. 1396381378123.