Bug 1572711 - Added blocklist.lastModified_xml telemetry scalar to record extensions.blocklist.lastModified value. r=janerik,leplatrem,Gijs
authorLuca Greco <lgreco@mozilla.com>
Wed, 21 Aug 2019 19:51:52 +0000
changeset 553236 1cf0189e17311d7a7793ad4935658f03881940c6
parent 553235 002962ee07d0856c78d5c9b7bb3097f81847ca9a
child 553237 40cc2d4444019df7275ac74cc72c638d49533350
push id2165
push userffxbld-merge
push dateMon, 14 Oct 2019 16:30:58 +0000
treeherdermozilla-release@0eae18af659f [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjanerik, leplatrem, Gijs
bugs1572711
milestone70.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 1572711 - Added blocklist.lastModified_xml telemetry scalar to record extensions.blocklist.lastModified value. r=janerik,leplatrem,Gijs Differential Revision: https://phabricator.services.mozilla.com/D41733
toolkit/components/telemetry/Scalars.yaml
toolkit/mozapps/extensions/Blocklist.jsm
toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/test_blocklist_telemetry.js
toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini
--- a/toolkit/components/telemetry/Scalars.yaml
+++ b/toolkit/components/telemetry/Scalars.yaml
@@ -4460,16 +4460,38 @@ qm:
       - ttung@mozilla.com
     products:
       - 'firefox'
       - 'fennec'
       - 'geckoview'
     record_in_processes:
       - 'main'
 
+blocklist:
+  lastModified_xml:
+    bug_numbers:
+      - 1572711
+    description: >
+      Keep track of the lastupdate datetime from a successfully loaded xml blocklist,
+      set to "Invalid Date" or "Missing Date" when the timestamp is invalid or missing.
+      (based on the lastupdate attribute set on the XML document element,
+      converted from a milliseconds timestamp into a datetime string in UTC format).
+    expires: "75"
+    kind: string
+    release_channel_collection: opt-out
+    notification_emails:
+      - addons-dev-internal@mozilla.com
+      - lgreco@mozilla.com
+      - awagner@mozilla.com
+    products:
+      - 'firefox'
+      - 'fennec'
+    record_in_processes:
+      - main
+
 # The following section is for probes testing the Telemetry system. They will not be
 # submitted in pings and are only used for testing.
 telemetry.test:
   unsigned_int_kind:
     bug_numbers:
       - 1276190
     description: >
       This is a test uint type with a really long description, maybe spanning even multiple
--- a/toolkit/mozapps/extensions/Blocklist.jsm
+++ b/toolkit/mozapps/extensions/Blocklist.jsm
@@ -160,16 +160,45 @@ const PREF_BLOCKLIST_PLUGINS_COLLECTION 
 const PREF_BLOCKLIST_PLUGINS_CHECKED_SECONDS =
   "services.blocklist.plugins.checked";
 const PREF_BLOCKLIST_PLUGINS_SIGNER = "services.blocklist.plugins.signer";
 const PREF_BLOCKLIST_ADDONS_COLLECTION = "services.blocklist.addons.collection";
 const PREF_BLOCKLIST_ADDONS_CHECKED_SECONDS =
   "services.blocklist.addons.checked";
 const PREF_BLOCKLIST_ADDONS_SIGNER = "services.blocklist.addons.signer";
 
+const BlocklistTelemetry = {
+  /**
+   * Record the XML Blocklist lastModified server time into the
+   * "blocklist.lastModified_xml scalar.
+   *
+   * @param {XMLDocument} xmlDoc
+   *        The blocklist XML file to retrieve the lastupdate attribute
+   *        and record it into the "blocklist.lastModified_xml" scalar.
+   *        The scalar value is a datetime string in UTC format.
+   */
+  recordXMLBlocklistLastModified(xmlDoc) {
+    const lastUpdate =
+      xmlDoc && xmlDoc.documentElement.getAttribute("lastupdate");
+    if (lastUpdate) {
+      Services.telemetry.scalarSet(
+        "blocklist.lastModified_xml",
+        // Date(...).toUTCString will return "Invalid Date" if the
+        // timestamp isn't valid (e.g. parseInt returns NaN).
+        new Date(parseInt(lastUpdate, 10)).toUTCString()
+      );
+    } else {
+      Services.telemetry.scalarSet(
+        "blocklist.lastModified_xml",
+        "Missing Date"
+      );
+    }
+  },
+};
+
 const Utils = {
   /**
    * Checks whether this entry is valid for the current OS and ABI.
    * If the entry has an "os" property then the current OS must appear in
    * its comma separated list for it to be valid. Similarly for the
    * xpcomabi property.
    *
    * @param {Object} item
@@ -2132,16 +2161,20 @@ var BlocklistXML = {
       if (this._gfxEntries.length > 0) {
         this._notifyObserversBlocklistGFX();
       }
     } catch (e) {
       LOG(
         "Blocklist::_loadBlocklistFromXML: Error constructing blocklist " + e
       );
     }
+
+    // Record the last modified timestamp right before notify the observers.
+    BlocklistTelemetry.recordXMLBlocklistLastModified(doc);
+
     // Dispatch to mainthread because consumers may try to construct nsIPluginHost
     // again based on this notification, while we were called from nsIPluginHost
     // anyway, leading to re-entrancy.
     Services.tm.dispatchToMainThread(function() {
       Services.obs.notifyObservers(null, "blocklist-loaded");
     });
   },
 
new file mode 100644
--- /dev/null
+++ b/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/test_blocklist_telemetry.js
@@ -0,0 +1,205 @@
+/* Any copyright is dedicated to the Public Domain.
+http://creativecommons.org/publicdomain/zero/1.0/ */
+
+"use strict";
+
+const { Blocklist } = ChromeUtils.import(
+  "resource://gre/modules/Blocklist.jsm"
+);
+const { TelemetryController } = ChromeUtils.import(
+  "resource://gre/modules/TelemetryController.jsm"
+);
+const { TelemetryTestUtils } = ChromeUtils.import(
+  "resource://testing-common/TelemetryTestUtils.jsm"
+);
+
+const PREF_BLOCKLIST_URL = "extensions.blocklist.url";
+
+AddonTestUtils.init(this);
+AddonTestUtils.createAppInfo(
+  "xpcshell@tests.mozilla.org",
+  "XPCShell",
+  "1",
+  "49"
+);
+
+const serverTime = new Date();
+const lastUpdateTimestamp = serverTime.getTime() - 2000;
+const lastUpdateUTCString = new Date(lastUpdateTimestamp).toUTCString();
+
+let blocklistHandler;
+
+const server = AddonTestUtils.createHttpServer({
+  hosts: ["example.com"],
+});
+
+server.registerPathHandler("/blocklist.xml", (request, response) => {
+  if (blocklistHandler) {
+    const handler = blocklistHandler;
+    blocklistHandler = null;
+    handler(request, response);
+  } else {
+    response.setStatusLine(
+      request.httpVersion,
+      501,
+      "test blocklist handler undefined"
+    );
+    response.write("");
+  }
+});
+
+function promiseConsoleMessage(regexp) {
+  return new Promise(resolve => {
+    const listener = entry => {
+      if (regexp.test(entry.message)) {
+        Services.console.unregisterListener(listener);
+        resolve(entry);
+      }
+    };
+    Services.console.registerListener(listener);
+  });
+}
+
+async function promiseBlocklistUpdateWithError({
+  serverBlocklistHandler,
+  expectedConsoleMessage,
+}) {
+  let onceConsoleMessageLogged = promiseConsoleMessage(expectedConsoleMessage);
+  blocklistHandler = serverBlocklistHandler;
+  Blocklist.notify();
+  await onceConsoleMessageLogged;
+}
+
+async function promiseBlocklistUpdateSuccessful({ serverBlocklistHandler }) {
+  const promiseBlocklistLoaded = TestUtils.topicObserved(
+    "addon-blocklist-updated"
+  );
+  blocklistHandler = serverBlocklistHandler;
+  Blocklist.notify();
+  await promiseBlocklistLoaded;
+}
+
+function createBlocklistHandler({ lastupdate }) {
+  return (request, response) => {
+    response.setStatusLine(
+      request.httpVersion,
+      200,
+      "test successfull blocklist update"
+    );
+    response.setHeader("Last-Modified", serverTime.toUTCString());
+    response.write(`<?xml version='1.0' encoding='UTF-8'?>
+      <blocklist xmlns="http://www.mozilla.org/2006/addons-blocklist"
+                 lastupdate="${lastupdate}">
+      </blocklist>
+    `);
+  };
+}
+
+add_task(async function test_setup() {
+  Services.prefs.setCharPref(
+    PREF_BLOCKLIST_URL,
+    "http://example.com/blocklist.xml"
+  );
+
+  await AddonTestUtils.promiseStartupManager();
+  // Ensure that the telemetry event definition is loaded.
+  await TelemetryController.testSetup();
+});
+
+add_task(async function test_lastModifed_xml_on_blocklist_updates() {
+  Services.telemetry.clearScalars();
+
+  info(
+    "Verify lastModified_xml scalar is updated after a successfull blocklist update"
+  );
+
+  await promiseBlocklistUpdateSuccessful({
+    serverBlocklistHandler: createBlocklistHandler({
+      lastupdate: lastUpdateTimestamp,
+    }),
+  });
+
+  let scalars = TelemetryTestUtils.getProcessScalars("parent");
+  equal(
+    scalars["blocklist.lastModified_xml"],
+    lastUpdateUTCString,
+    "Got the expected value set on the telemetry scalar"
+  );
+
+  info(
+    "Verify lastModified_xml scalar is updated after a blocklist update failure"
+  );
+
+  await promiseBlocklistUpdateWithError({
+    serverBlocklistHandler(request, response) {
+      response.setStatusLine(
+        request.httpVersion,
+        501,
+        "test failed blocklist update"
+      );
+      response.write("");
+    },
+    expectedConsoleMessage: /^Blocklist::onXMLLoad: there was an error/,
+  });
+
+  scalars = TelemetryTestUtils.getProcessScalars("parent");
+  equal(
+    scalars["blocklist.lastModified_xml"],
+    lastUpdateUTCString,
+    "Expect the telemetry scalar to be unchanged after a failed blocklist update"
+  );
+});
+
+add_task(async function test_lastModifed_xml_on_blocklist_loaded_from_disk() {
+  Services.telemetry.clearScalars();
+
+  const { BlocklistXML } = ChromeUtils.import(
+    "resource://gre/modules/Blocklist.jsm",
+    null
+  );
+
+  // Force the blocklist to be read from file again.
+  BlocklistXML._clear();
+  await BlocklistXML.loadBlocklistAsync();
+
+  let scalars = TelemetryTestUtils.getProcessScalars("parent");
+  equal(
+    scalars["blocklist.lastModified_xml"],
+    lastUpdateUTCString,
+    "Got the expect the telemetry scalar value"
+  );
+});
+
+add_task(async function test_lastModified_xml_invalid_lastupdate_attribute() {
+  Services.telemetry.clearScalars();
+
+  await promiseBlocklistUpdateSuccessful({
+    serverBlocklistHandler: createBlocklistHandler({
+      lastupdate: "not a timestamp",
+    }),
+  });
+
+  let scalars = TelemetryTestUtils.getProcessScalars("parent");
+  equal(
+    scalars["blocklist.lastModified_xml"],
+    "Invalid Date",
+    "Expect the telemetry scalar to be unchanged"
+  );
+});
+
+add_task(async function test_lastModified_xml_on_empty_lastupdate_attribute() {
+  Services.telemetry.clearScalars();
+
+  await promiseBlocklistUpdateSuccessful({
+    serverBlocklistHandler: createBlocklistHandler({
+      lastupdate: "",
+    }),
+  });
+
+  let scalars = TelemetryTestUtils.getProcessScalars("parent");
+  equal(
+    scalars["blocklist.lastModified_xml"],
+    "Missing Date",
+    "Expect the telemetry scalar to be unchanged"
+  );
+});
--- a/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini
+++ b/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini
@@ -24,16 +24,17 @@ skip-if = os == "android"
 skip-if = os == "android"
 [test_blocklist_plugin_severities.js]
 # Bug 676992: test consistently hangs on Android
 skip-if = os == "android"
 [test_blocklist_prefs.js]
 [test_blocklist_severities.js]
 # Bug 676992: test consistently hangs on Android
 skip-if = os == "android"
+[test_blocklist_telemetry.js]
 [test_blocklist_url_parameters.js]
 # Bug 676992: test consistently hangs on Android
 skip-if = os == "android"
 [test_blocklist_url_ping_count.js]
 [test_blocklistchange.js]
 # Times out during parallel runs on desktop
 requesttimeoutfactor = 2
 [test_gfxBlacklist_Device.js]