Bug 1479740 - Track Web API calls made in the child - r=florian,mixedpuppy

The performance counter is now also used in the children, and
the ParentAPIManager.retrievePerformanceCounters() can be used
to aggregate all counters into a promise.

Differential Revision: https://phabricator.services.mozilla.com/D5399

--HG--
extra : moz-landing-system : lando

modules/libpref/init/all.js

@@ -5030,6 +5030,11 @@ pref("extensions.webextensions.ExtensionStorageIDB.enabled", false);
 // if enabled, store execution times for API calls
 pref("extensions.webextensions.enablePerformanceCounters", false);
 
+// Maximum age in milliseconds of performance counters in children
+// When reached, the counters are sent to the main process and
+// reset, so we reduce memory footprint.
+pref("extensions.webextensions.performanceCountersMaxAge", 1000);
+
 // Report Site Issue button
 pref("extensions.webcompat-reporter.newIssueEndpoint", "https://webcompat.com/issues/new");
 #if defined(MOZ_DEV_EDITION) || defined(NIGHTLY_BUILD)

toolkit/components/aboutperformance/content/aboutPerformance.js

@@ -442,7 +442,7 @@ var State = {
     }
 
     if (extensionCountersEnabled()) {
-      let extCounters = ExtensionParent.ParentAPIManager.performanceCounters;
+      let extCounters = await ExtensionParent.ParentAPIManager.retrievePerformanceCounters();
       for (let [id, apiMap] of extCounters) {
         let dispatchCount = 0, duration = 0;
         for (let [, counter] of apiMap) {

toolkit/components/extensions/ExtensionChild.jsm

@@ -28,6 +28,7 @@ XPCOMUtils.defineLazyModuleGetters(this, {
   ExtensionPageChild: "resource://gre/modules/ExtensionPageChild.jsm",
   MessageChannel: "resource://gre/modules/MessageChannel.jsm",
   NativeApp: "resource://gre/modules/NativeMessaging.jsm",
+  PerformanceCounters: "resource://gre/modules/PerformanceCounters.jsm",
   PromiseUtils: "resource://gre/modules/PromiseUtils.jsm",
 });
 
@@ -36,6 +37,10 @@ XPCOMUtils.defineLazyGetter(
   () => Cc["@mozilla.org/webextensions/extension-process-script;1"]
           .getService().wrappedJSObject);
 
+// We're using the pref to avoid loading PerformanceCounters.jsm for nothing.
+XPCOMUtils.defineLazyPreferenceGetter(this, "gTimingEnabled",
+                                      "extensions.webextensions.enablePerformanceCounters",
+                                      false);
 ChromeUtils.import("resource://gre/modules/ExtensionCommon.jsm");
 ChromeUtils.import("resource://gre/modules/ExtensionUtils.jsm");
 
@@ -863,6 +868,39 @@ class ProxyAPIImplementation extends SchemaAPIInterface {
   }
 }
 
+class ChildLocalAPIImplementation extends LocalAPIImplementation {
+  constructor(pathObj, name, childApiManager) {
+    super(pathObj, name, childApiManager.context);
+    this.childApiManagerId = childApiManager.id;
+  }
+
+  withTiming(callable) {
+    if (!gTimingEnabled) {
+      return callable();
+    }
+    let start = Cu.now() * 1000;
+    try {
+      return callable();
+    } finally {
+      let end = Cu.now() * 1000;
+      PerformanceCounters.storeExecutionTime(this.context.extension.id, this.name,
+                                             end - start, this.childApiManagerId);
+    }
+  }
+
+  callFunction(args) {
+    return this.withTiming(() => super.callFunction(args));
+  }
+
+  callFunctionNoReturn(args) {
+    return this.withTiming(() => super.callFunctionNoReturn(args));
+  }
+
+  callAsyncFunction(args, callback, requireUserInput) {
+    return this.withTiming(() => super.callAsyncFunction(args, callback, requireUserInput));
+  }
+}
+
 // We create one instance of this class for every extension context that
 // needs to use remote APIs. It uses the message manager to communicate
 // with the ParentAPIManager singleton in ExtensionParent.jsm. It
@@ -1086,7 +1124,7 @@ class ChildAPIManager {
     let obj = this.apiCan.findAPIPath(namespace);
 
     if (obj && name in obj) {
-      return new LocalAPIImplementation(obj, name, this.context);
+      return new ChildLocalAPIImplementation(obj, name, this);
     }
 
     return this.getFallbackImplementation(namespace, name);

toolkit/components/extensions/ExtensionParent.jsm

@@ -28,6 +28,7 @@ XPCOMUtils.defineLazyModuleGetters(this, {
   MessageManagerProxy: "resource://gre/modules/MessageManagerProxy.jsm",
   NativeApp: "resource://gre/modules/NativeMessaging.jsm",
   OS: "resource://gre/modules/osfile.jsm",
+  PerformanceCounters: "resource://gre/modules/PerformanceCounters.jsm",
   PrivateBrowsingUtils: "resource://gre/modules/PrivateBrowsingUtils.jsm",
   Schemas: "resource://gre/modules/Schemas.jsm",
 });
@@ -36,6 +37,10 @@ XPCOMUtils.defineLazyServiceGetters(this, {
   aomStartup: ["@mozilla.org/addons/addon-manager-startup;1", "amIAddonManagerStartup"],
 });
 
+// We're using the pref to avoid loading PerformanceCounters.jsm for nothing.
+XPCOMUtils.defineLazyPreferenceGetter(this, "gTimingEnabled",
+                                      "extensions.webextensions.enablePerformanceCounters",
+                                      false);
 ChromeUtils.import("resource://gre/modules/ExtensionCommon.jsm");
 ChromeUtils.import("resource://gre/modules/ExtensionUtils.jsm");
 
@@ -60,7 +65,6 @@ const BASE_SCHEMA = "chrome://extensions/content/schemas/manifest.json";
 const CATEGORY_EXTENSION_MODULES = "webextension-modules";
 const CATEGORY_EXTENSION_SCHEMAS = "webextension-schemas";
 const CATEGORY_EXTENSION_SCRIPTS = "webextension-scripts";
-const TIMING_ENABLED_PREF = "extensions.webextensions.enablePerformanceCounters";
 
 let schemaURLs = new Set();
 
@@ -513,8 +517,8 @@ GlobalManager = {
       ProxyMessenger.init();
       apiManager.on("extension-browser-inserted", this._onExtensionBrowser);
       this.initialized = true;
+      Services.ppmm.addMessageListener("Extension:SendPerformanceCounter", this);
     }
-
     this.extensionMap.set(extension.id, extension);
   },
 
@@ -524,6 +528,15 @@ GlobalManager = {
     if (this.extensionMap.size == 0 && this.initialized) {
       apiManager.off("extension-browser-inserted", this._onExtensionBrowser);
       this.initialized = false;
+      Services.ppmm.removeMessageListener("Extension:SendPerformanceCounter", this);
+    }
+  },
+
+  async receiveMessage({name, data}) {
+    switch (name) {
+      case "Extension:SendPerformanceCounter":
+        PerformanceCounters.merge(data.counters);
+        break;
     }
   },
 
@@ -758,9 +771,6 @@ class DevToolsExtensionPageContextParent extends ExtensionPageContextParent {
 }
 
 ParentAPIManager = {
-  // stores dispatches counts per web extension and API
-  performanceCounters: new DefaultMap(() => new DefaultMap(() => ({duration: 0, calls: 0}))),
-
   proxyContexts: new Map(),
 
   init() {
@@ -771,7 +781,6 @@ ParentAPIManager = {
     Services.mm.addMessageListener("API:Call", this);
     Services.mm.addMessageListener("API:AddListener", this);
     Services.mm.addMessageListener("API:RemoveListener", this);
-    XPCOMUtils.defineLazyPreferenceGetter(this, "_timingEnabled", TIMING_ENABLED_PREF, false);
   },
 
   attachMessageManager(extension, processMessageManager) {
@@ -889,14 +898,13 @@ ParentAPIManager = {
     }
   },
 
-  storeExecutionTime(webExtensionId, apiPath, duration) {
-    let apiCounter = this.performanceCounters.get(webExtensionId).get(apiPath);
-    apiCounter.duration += duration;
-    apiCounter.calls += 1;
+  async retrievePerformanceCounters() {
+    // getting the parent counters
+    return PerformanceCounters.getData();
   },
 
   async withTiming(data, callable) {
-    if (!this._timingEnabled) {
+    if (!gTimingEnabled) {
       return callable();
     }
     let childId = data.childId;
@@ -906,7 +914,7 @@ ParentAPIManager = {
       return callable();
     } finally {
       let end = Cu.now() * 1000;
-      this.storeExecutionTime(webExtId, data.path, end - start);
+      PerformanceCounters.storeExecutionTime(webExtId, data.path, end - start);
     }
   },
 

toolkit/components/extensions/PerformanceCounters.jsm

@@ -0,0 +1,162 @@
+/* -*- Mode: indent-tabs-mode: nil; js-indent-level: 2 -*- */
+/* vim: set sts=2 sw=2 et tw=80: */
+/* 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";
+
+/**
+ * This module contains a global counter to store API call in the current process.
+ */
+
+/* exported Counters */
+var EXPORTED_SYMBOLS = ["PerformanceCounters"];
+
+ChromeUtils.import("resource://gre/modules/ExtensionUtils.jsm");
+ChromeUtils.import("resource://gre/modules/XPCOMUtils.jsm");
+ChromeUtils.import("resource://gre/modules/DeferredTask.jsm");
+ChromeUtils.import("resource://gre/modules/Services.jsm");
+
+const {
+  DefaultMap,
+} = ExtensionUtils;
+
+XPCOMUtils.defineLazyPreferenceGetter(this, "gTimingEnabled",
+                                      "extensions.webextensions.enablePerformanceCounters",
+                                      false);
+XPCOMUtils.defineLazyPreferenceGetter(this, "gTimingMaxAge",
+                                      "extensions.webextensions.performanceCountersMaxAge",
+                                      1000);
+
+class CounterMap extends DefaultMap {
+  defaultConstructor() {
+    return new DefaultMap(() => ({duration: 0, calls: 0}));
+  }
+
+  flush() {
+    let result = new CounterMap(undefined, this);
+    this.clear();
+    return result;
+  }
+
+  merge(other) {
+    for (let [webextId, counters] of other) {
+      for (let [api, counter] of counters) {
+        let current = this.get(webextId).get(api);
+        current.calls += counter.calls;
+        current.duration += counter.duration;
+      }
+    }
+  }
+}
+
+/**
+ * Global Deferred used to send to the parent performance counters
+ * when the counter is in a child.
+ */
+var _performanceCountersSender = null;
+
+// Pre-definition of the global Counters instance.
+var PerformanceCounters = null;
+
+function _sendPerformanceCounters(childApiManagerId) {
+  let counters = PerformanceCounters.flush();
+  // No need to send empty counters.
+  if (counters.size == 0) {
+    _performanceCountersSender.arm();
+    return;
+  }
+  let options = {childId: childApiManagerId, counters: counters};
+  Services.cpmm.sendAsyncMessage("Extension:SendPerformanceCounter", options);
+  _performanceCountersSender.arm();
+}
+
+class Counters {
+  constructor() {
+    this.data = new CounterMap();
+  }
+
+  /**
+   * Returns true if performance counters are enabled.
+   *
+   * Indirection used so gTimingEnabled is not exposed direcly
+   * in PerformanceCounters -- which would prevent tests to dynamically
+   * change the preference value once PerformanceCounters.jsm is loaded.
+   *
+   * @returns {boolean}
+   */
+  get enabled() {
+    return gTimingEnabled;
+  }
+
+  /**
+   * Returns the counters max age
+   *
+   * Indirection used so gTimingMaxAge is not exposed direcly
+   * in PerformanceCounters -- which would prevent tests to dynamically
+   * change the preference value once PerformanceCounters.jsm is loaded.
+   *
+   * @returns {number}
+   */
+  get maxAge() {
+    return gTimingMaxAge;
+  }
+
+  /**
+   * Stores an execution time.
+   *
+   * @param {string} webExtensionId The web extension id.
+   * @param {string} apiPath The API path.
+   * @param {integer} duration How long the call took.
+   * @param {childApiManagerId} childApiManagerId If executed from a child, its API manager id.
+   */
+  storeExecutionTime(webExtensionId, apiPath, duration, childApiManagerId) {
+    let apiCounter = this.data.get(webExtensionId).get(apiPath);
+    apiCounter.duration += duration;
+    apiCounter.calls += 1;
+
+    // Create the global deferred task if we're in a child and
+    // it's the first time.
+    if (childApiManagerId) {
+      if (!_performanceCountersSender) {
+        _performanceCountersSender = new DeferredTask(() => {
+          _sendPerformanceCounters(childApiManagerId);
+        }, this.maxAge);
+        _performanceCountersSender.arm();
+      }
+    }
+  }
+
+  /**
+   * Merges another CounterMap into this.data
+   *
+   * Can be used by the main process to merge data received
+   * from the children.
+   *
+   * @param {CounterMap} data The map to merge.
+   */
+  merge(data) {
+    this.data.merge(data);
+  }
+
+  /**
+   * Returns the performance counters and purges them.
+   *
+   * @returns {CounterMap}
+   */
+  flush() {
+    return this.data.flush();
+  }
+
+  /**
+   * Returns the performance counters.
+   *
+   * @returns {CounterMap}
+   */
+  getData() {
+    return this.data;
+  }
+}
+
+
+PerformanceCounters = new Counters();

toolkit/components/extensions/moz.build

@@ -30,6 +30,7 @@ EXTRA_JS_MODULES += [
     'MessageManagerProxy.jsm',
     'NativeManifests.jsm',
     'NativeMessaging.jsm',
+    'PerformanceCounters.jsm',
     'ProxyScriptContext.jsm',
     'Schemas.jsm',
 ]

toolkit/components/extensions/test/xpcshell/test_ext_performance_counters.js

@@ -3,19 +3,46 @@
 "use strict";
 
 ChromeUtils.import("resource://gre/modules/ExtensionParent.jsm");
+
 const ENABLE_COUNTER_PREF = "extensions.webextensions.enablePerformanceCounters";
+const TIMING_MAX_AGE = "extensions.webextensions.performanceCountersMaxAge";
 
 let {
   ParentAPIManager,
 } = ExtensionParent;
 
+function sleep(ms) {
+  return new Promise(resolve => setTimeout(resolve, ms)); // eslint-disable-line mozilla/no-arbitrary-setTimeout
+}
+
+async function retrieveSpecificCounter(apiName, expectedCount) {
+  let currentCount = 0;
+  let data;
+  while (currentCount < expectedCount) {
+    data = await ParentAPIManager.retrievePerformanceCounters();
+    for (let [console, counters] of data) {
+      for (let [api, counter] of counters) {
+        if (api == apiName) {
+          currentCount += counter.calls;
+        }
+      }
+    }
+    await sleep(100);
+  }
+  return data;
+}
 
 async function test_counter() {
   async function background() {
-    // creating a bookmark
+    // creating a bookmark is done in the parent
     let folder = await browser.bookmarks.create({title: "Folder"});
     await browser.bookmarks.create({title: "Bookmark", url: "http://example.com",
                                     parentId: folder.id});
+
+    // getURL() is done in the child, let do three
+    browser.extension.getURL("beasts/frog.html");
+    browser.extension.getURL("beasts/frog2.html");
+    browser.extension.getURL("beasts/frog3.html");
     browser.test.sendMessage("done");
   }
 
@@ -29,15 +56,22 @@ async function test_counter() {
   let extension = ExtensionTestUtils.loadExtension(extensionData);
   await extension.startup();
   await extension.awaitMessage("done");
+
+  let counters = await retrieveSpecificCounter("getURL", 3);
   await extension.unload();
 
   // check that the bookmarks.create API was tracked
-  let counters = ParentAPIManager.performanceCounters;
   let counter = counters.get(extension.id).get("bookmarks.create");
   ok(counter.calls > 0);
   ok(counter.duration > 0);
+
+  // check that the getURL API was tracked
+  counter = counters.get(extension.id).get("getURL");
+  ok(counter.calls > 0);
+  ok(counter.duration > 0);
 }
 
 add_task(function test_performance_counter() {
-  return runWithPrefs([[ENABLE_COUNTER_PREF, true]], test_counter);
+  return runWithPrefs([[ENABLE_COUNTER_PREF, true],
+                       [TIMING_MAX_AGE, 1]], test_counter);
 });