From 23344811d98e1b04a2de732434781d89423f2ad0 Mon Sep 17 00:00:00 2001 From: Luca Greco Date: Wed, 21 Aug 2019 19:51:52 +0000 Subject: [PATCH] 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 --HG-- extra : moz-landing-system : lando --- toolkit/components/telemetry/Scalars.yaml | 22 ++ toolkit/mozapps/extensions/Blocklist.jsm | 33 +++ .../xml-blocklist/test_blocklist_telemetry.js | 205 ++++++++++++++++++ .../test/xpcshell/xml-blocklist/xpcshell.ini | 1 + 4 files changed, 261 insertions(+) create mode 100644 toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/test_blocklist_telemetry.js diff --git a/toolkit/components/telemetry/Scalars.yaml b/toolkit/components/telemetry/Scalars.yaml index 70abee9ad4f2..c40a7ef8f039 100644 --- a/toolkit/components/telemetry/Scalars.yaml +++ b/toolkit/components/telemetry/Scalars.yaml @@ -4465,6 +4465,28 @@ qm: 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: diff --git a/toolkit/mozapps/extensions/Blocklist.jsm b/toolkit/mozapps/extensions/Blocklist.jsm index 07f236fdb14c..06f6346661bf 100644 --- a/toolkit/mozapps/extensions/Blocklist.jsm +++ b/toolkit/mozapps/extensions/Blocklist.jsm @@ -165,6 +165,35 @@ 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. @@ -2137,6 +2166,10 @@ var BlocklistXML = { "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. diff --git a/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/test_blocklist_telemetry.js b/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/test_blocklist_telemetry.js new file mode 100644 index 000000000000..fb414a775299 --- /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(` + + + `); + }; +} + +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" + ); +}); diff --git a/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini b/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini index 4794fdb95b1f..ea90cbd83871 100644 --- a/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini +++ b/toolkit/mozapps/extensions/test/xpcshell/xml-blocklist/xpcshell.ini @@ -29,6 +29,7 @@ skip-if = os == "android" [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"