Bug 1371398 - Add telemetry for time spent getting and setting browser.storage.local, r?kmag draft
authorBob Silverberg <bsilverberg@mozilla.com>
Mon, 19 Jun 2017 13:00:19 -0400
changeset 603743 1d737494ba6247027ac1a85ff0fe52945ed7ee72
parent 597439 6549493e47030128986fc439cb9385eb1733de69
child 635980 14d1bae326d022f88e2889c7d135572bf8d0b956
push id66840
push userbmo:bob.silverberg@gmail.com
push dateTue, 04 Jul 2017 13:03:35 +0000
reviewerskmag
bugs1371398
milestone56.0a1
Bug 1371398 - Add telemetry for time spent getting and setting browser.storage.local, r?kmag MozReview-Commit-ID: L5HyFkTQtRR
toolkit/components/extensions/ext-c-storage.js
toolkit/components/extensions/test/xpcshell/test_ext_storage_telemetry.js
toolkit/components/extensions/test/xpcshell/xpcshell.ini
toolkit/components/telemetry/Histograms.json
--- a/toolkit/components/extensions/ext-c-storage.js
+++ b/toolkit/components/extensions/ext-c-storage.js
@@ -1,14 +1,19 @@
 "use strict";
 
 XPCOMUtils.defineLazyModuleGetter(this, "ExtensionStorage",
                                   "resource://gre/modules/ExtensionStorage.jsm");
+XPCOMUtils.defineLazyModuleGetter(this, "TelemetryStopwatch",
+                                  "resource://gre/modules/TelemetryStopwatch.jsm");
 Cu.import("resource://gre/modules/Services.jsm");
 
+const storageGetHistogram = "WEBEXT_STORAGE_LOCAL_GET_MS";
+const storageSetHistogram = "WEBEXT_STORAGE_LOCAL_SET_MS";
+
 this.storage = class extends ExtensionAPI {
   getAPI(context) {
     function sanitize(items) {
       // The schema validator already takes care of arrays (which are only allowed
       // to contain strings). Strings and null are safe values.
       if (typeof items != "object" || items === null || Array.isArray(items)) {
         return items;
       }
@@ -23,27 +28,45 @@ this.storage = class extends ExtensionAP
       for (let [key, value] of Object.entries(items)) {
         sanitized[key] = ExtensionStorage.sanitize(value, context);
       }
       return sanitized;
     }
     return {
       storage: {
         local: {
-          get: function(keys) {
-            keys = sanitize(keys);
-            return context.childManager.callParentAsyncFunction("storage.local.get", [
-              keys,
-            ]);
+          get: async function(keys) {
+            const stopwatchKey = {};
+            TelemetryStopwatch.start(storageGetHistogram, stopwatchKey);
+            try {
+              keys = sanitize(keys);
+              let result = await context.childManager.callParentAsyncFunction("storage.local.get", [
+                keys,
+              ]);
+              TelemetryStopwatch.finish(storageGetHistogram, stopwatchKey);
+              return result;
+            } catch (e) {
+              TelemetryStopwatch.cancel(storageGetHistogram, stopwatchKey);
+              throw e;
+            }
           },
-          set: function(items) {
-            items = sanitize(items);
-            return context.childManager.callParentAsyncFunction("storage.local.set", [
-              items,
-            ]);
+          set: async function(items) {
+            const stopwatchKey = {};
+            TelemetryStopwatch.start(storageSetHistogram, stopwatchKey);
+            try {
+              items = sanitize(items);
+              let result = await context.childManager.callParentAsyncFunction("storage.local.set", [
+                items,
+              ]);
+              TelemetryStopwatch.finish(storageSetHistogram, stopwatchKey);
+              return result;
+            } catch (e) {
+              TelemetryStopwatch.cancel(storageSetHistogram, stopwatchKey);
+              throw e;
+            }
           },
         },
 
         sync: {
           get: function(keys) {
             keys = sanitize(keys);
             return context.childManager.callParentAsyncFunction("storage.sync.get", [
               keys,
new file mode 100644
--- /dev/null
+++ b/toolkit/components/extensions/test/xpcshell/test_ext_storage_telemetry.js
@@ -0,0 +1,94 @@
+/* -*- Mode: indent-tabs-mode: nil; js-indent-level: 2 -*- */
+/* vim: set sts=2 sw=2 et tw=80: */
+"use strict";
+
+const HISTOGRAM_IDS = [
+  "WEBEXT_STORAGE_LOCAL_SET_MS", "WEBEXT_STORAGE_LOCAL_GET_MS",
+];
+
+function arraySum(arr) {
+  return arr.reduce((a, b) => a + b, 0);
+}
+
+add_task(async function test_telemetry_background() {
+  const server = createHttpServer();
+  server.registerDirectory("/data/", do_get_file("data"));
+
+  const BASE_URL = `http://localhost:${server.identity.primaryPort}/data`;
+
+  async function contentScript() {
+    await browser.storage.local.set({a: "b"});
+    await browser.storage.local.get("a");
+    browser.runtime.sendMessage("contentDone");
+  }
+
+  let extInfo = {
+    manifest: {
+      permissions: ["storage"],
+      content_scripts: [
+        {
+          "matches": ["http://*/*/file_sample.html"],
+          "js": ["content_script.js"],
+        },
+      ],
+    },
+    async background() {
+      browser.runtime.onMessage.addListener(msg => {
+        browser.test.sendMessage(msg);
+      });
+
+      await browser.storage.local.set({a: "b"});
+      await browser.storage.local.get("a");
+      browser.test.sendMessage("backgroundDone");
+    },
+    files: {
+      "content_script.js": contentScript,
+    },
+  };
+
+  let extension1 = ExtensionTestUtils.loadExtension(extInfo);
+  let extension2 = ExtensionTestUtils.loadExtension(extInfo);
+
+  // Initialize and clear histograms.
+  let histograms = {};
+  for (let id of HISTOGRAM_IDS) {
+    histograms[id] = Services.telemetry.getHistogramById(id);
+    histograms[id].clear();
+    equal(arraySum(histograms[id].snapshot().counts), 0,
+          `No data recorded for histogram: ${id}.`);
+  }
+
+  await extension1.startup();
+  await extension1.awaitMessage("backgroundDone");
+
+  // Telemetry from extension1's background page should be recorded.
+  for (let id in histograms) {
+    equal(arraySum(histograms[id].snapshot().counts), 1,
+          `Data recorded for histogram: ${id}.`);
+  }
+
+  await extension2.startup();
+  await extension2.awaitMessage("backgroundDone");
+
+  // Telemetry from extension2's background page should be recorded.
+  for (let id in histograms) {
+    equal(arraySum(histograms[id].snapshot().counts), 2,
+          `Additional data recorded for histogram: ${id}.`);
+  }
+
+  await extension2.unload();
+
+  // Run a content script.
+  let contentScriptPromise = extension1.awaitMessage("contentDone");
+  let contentPage = await ExtensionTestUtils.loadContentPage(`${BASE_URL}/file_sample.html`);
+  await contentScriptPromise;
+  await contentPage.close();
+
+  // Telemetry from extension1's content script should be recorded.
+  for (let id in histograms) {
+    equal(arraySum(histograms[id].snapshot().counts), 3,
+          `Data recorded in content script for histogram: ${id}.`);
+  }
+
+  await extension1.unload();
+});
--- a/toolkit/components/extensions/test/xpcshell/xpcshell.ini
+++ b/toolkit/components/extensions/test/xpcshell/xpcshell.ini
@@ -79,16 +79,17 @@ skip-if = os == "android" # Bug 1350559
 [test_ext_simple.js]
 [test_ext_startup_cache.js]
 [test_ext_storage.js]
 [test_ext_storage_sync.js]
 head = head.js head_sync.js
 skip-if = os == "android"
 [test_ext_storage_sync_crypto.js]
 skip-if = os == "android"
+[test_ext_storage_telemetry.js]
 [test_ext_themes_supported_properties.js]
 [test_ext_topSites.js]
 skip-if = os == "android"
 [test_ext_legacy_extension_context.js]
 [test_ext_legacy_extension_embedding.js]
 [test_locale_converter.js]
 [test_locale_data.js]
 [test_native_messaging.js]
--- a/toolkit/components/telemetry/Histograms.json
+++ b/toolkit/components/telemetry/Histograms.json
@@ -13452,16 +13452,38 @@
     "bug_numbers": [1297167],
     "expires_in_version": "60",
     "kind": "exponential",
     "releaseChannelCollection": "opt-out",
     "high": 50000,
     "n_buckets": 100,
     "description": "The amount of time it takes for a PageAction popup to open."
   },
+  "WEBEXT_STORAGE_LOCAL_GET_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": ["addons-dev-internal@mozilla.com"],
+    "bug_numbers": [1371398],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "releaseChannelCollection": "opt-out",
+    "high": 50000,
+    "n_buckets": 100,
+    "description": "The amount of time it takes to perform a get via storage.local."
+  },
+  "WEBEXT_STORAGE_LOCAL_SET_MS": {
+    "record_in_processes": ["main", "content"],
+    "alert_emails": ["addons-dev-internal@mozilla.com"],
+    "bug_numbers": [1371398],
+    "expires_in_version": "60",
+    "kind": "exponential",
+    "releaseChannelCollection": "opt-out",
+    "high": 50000,
+    "n_buckets": 100,
+    "description": "The amount of time it takes to perform a set via storage.local."
+  },
   "NOTIFY_OBSERVERS_LATENCY_MS": {
     "record_in_processes": ["main", "content", "gpu"],
     "alert_emails": ["michael@thelayzells.com"],
     "bug_numbers": [1368524],
     "expires_in_version": "60",
     "kind": "exponential",
     "low": 3,
     "high": 512,