Bug 1143714 - Throttle Telemetry environment changes. r=vladan

toolkit/components/telemetry/TelemetryEnvironment.jsm

@@ -31,6 +31,15 @@ XPCOMUtils.defineLazyModuleGetter(this, "ProfileAge",
 XPCOMUtils.defineLazyModuleGetter(this, "UpdateChannel",
                                   "resource://gre/modules/UpdateChannel.jsm");
 
+const CHANGE_THROTTLE_INTERVAL_MS = 5 * 60 * 1000;
+
+/**
+ * This is a policy object used to override behavior for testing.
+ */
+let Policy = {
+  now: () => new Date(),
+};
+
 var gGlobalEnvironment;
 function getGlobal() {
   if (!gGlobalEnvironment) {
@@ -628,6 +637,9 @@ function EnvironmentCache() {
   // A map of listeners that will be called on environment changes.
   this._changeListeners = new Map();
 
+  // The last change date for the environment, used to throttle environment changes.
+  this._lastEnvironmentChangeDate = null;
+
   // A map of watched preferences which trigger an Environment change when
   // modified. Every entry contains a recording policy (RECORD_PREF_*).
   this._watchedPrefs = DEFAULT_ENVIRONMENT_PREFS;
@@ -1065,7 +1077,16 @@ EnvironmentCache.prototype = {
     }
 
     // We are already skipping change events in _checkChanges if there is a pending change task running.
-    // Further throttling is coming in bug 1143714.
+    let now = Policy.now();
+    if (this._lastEnvironmentChangeDate &&
+        (CHANGE_THROTTLE_INTERVAL_MS >=
+         (now.getTime() - this._lastEnvironmentChangeDate.getTime()))) {
+      this._log.trace("_onEnvironmentChange - throttling changes, now: " + now +
+                      ", last change: " + this._lastEnvironmentChangeDate);
+      return;
+    }
+
+    this._lastEnvironmentChangeDate = now;
 
     for (let [name, listener] of this._changeListeners) {
       try {

toolkit/components/telemetry/tests/unit/head.js

@@ -9,6 +9,10 @@ const gIsMac = ("@mozilla.org/xpcom/mac-utils;1" in Components.classes);
 const gIsAndroid =  ("@mozilla.org/android/bridge;1" in Components.classes);
 const gIsGonk = ("@mozilla.org/cellbroadcast/gonkservice;1" in Components.classes);
 
+const MILLISECONDS_PER_MINUTE = 60 * 1000;
+const MILLISECONDS_PER_HOUR = 60 * MILLISECONDS_PER_MINUTE;
+const MILLISECONDS_PER_DAY = 24 * MILLISECONDS_PER_HOUR;
+
 const HAS_DATAREPORTINGSERVICE = "@mozilla.org/datareporting/service;1" in Components.classes;
 
 let gOldAppInfo = null;
@@ -87,6 +91,23 @@ function fakeSchedulerTimer(set, clear) {
   session.Policy.clearSchedulerTickTimeout = clear;
 }
 
+// Fake the current date.
+function fakeNow(date) {
+  let session = Cu.import("resource://gre/modules/TelemetrySession.jsm");
+  session.Policy.now = () => date;
+  let environment = Cu.import("resource://gre/modules/TelemetryEnvironment.jsm");
+  environment.Policy.now = () => date;
+}
+
+// Return a date that is |offset| ms in the future from |date|.
+function futureDate(date, offset) {
+  return new Date(date.getTime() + offset);
+}
+
+function truncateToDays(aMsec) {
+  return Math.floor(aMsec / MILLISECONDS_PER_DAY);
+}
+
 // Set logging preferences for all the tests.
 Services.prefs.setCharPref("toolkit.telemetry.log.level", "Trace");
 Services.prefs.setBoolPref("toolkit.telemetry.log.dump", true);

toolkit/components/telemetry/tests/unit/test_TelemetryEnvironment.js

@@ -27,6 +27,9 @@ let gHttpRoot = null;
 // The URL of the data directory, on the webserver.
 let gDataRoot = null;
 
+let gNow = new Date(2010, 1, 1, 12, 0, 0);
+fakeNow(gNow);
+
 const PLATFORM_VERSION = "1.9.2";
 const APP_VERSION = "1";
 const APP_ID = "xpcshell@tests.mozilla.org";
@@ -43,7 +46,6 @@ const PARTNER_ID = "NicePartner-ID-3785";
 const GFX_VENDOR_ID = "0xabcd";
 const GFX_DEVICE_ID = "0x1234";
 
-const MILLISECONDS_PER_DAY = 24 * 60 * 60 * 1000;
 // The profile reset date, in milliseconds (Today)
 const PROFILE_RESET_DATE_MS = Date.now();
 // The profile creation date, in milliseconds (Yesterday).
@@ -175,10 +177,6 @@ function spoofPartnerInfo() {
   }
 }
 
-function truncateToDays(aMsec) {
-  return Math.floor(aMsec / MILLISECONDS_PER_DAY);
-}
-
 /**
  * Check that a value is a string and not empty.
  *
@@ -613,6 +611,8 @@ add_task(function* test_prefWatchPolicies() {
   const PREF_TEST_4 = "toolkit.telemetry.test.pref_old";
 
   const expectedValue = "some-test-value";
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
 
   let prefsToWatch = {};
   prefsToWatch[PREF_TEST_1] = TelemetryEnvironment.RECORD_PREF_VALUE;
@@ -662,6 +662,9 @@ add_task(function* test_prefWatch_prefReset() {
   // Set the preference to a non-default value.
   Preferences.set(PREF_TEST, false);
 
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+
   // Set the Environment preferences to watch.
   TelemetryEnvironment._watchPreferences(prefsToWatch);
   let deferred = PromiseUtils.defer();
@@ -689,6 +692,8 @@ add_task(function* test_addonsWatch_InterestingChange() {
   let receivedNotifications = 0;
 
   let registerCheckpointPromise = (aExpected) => {
+    gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+    fakeNow(gNow);
     return new Promise(resolve => TelemetryEnvironment.registerChangeListener(
       "testWatchAddons_Changes" + aExpected, (reason, data) => {
         Assert.equal(reason, "addons-changed");
@@ -738,6 +743,9 @@ add_task(function* test_pluginsWatch_Add() {
     return;
   }
 
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+
   Assert.equal(TelemetryEnvironment.currentEnvironment.addons.activePlugins.length, 1);
 
   let newPlugin = new PluginTag(PLUGIN2_NAME, PLUGIN2_DESC, PLUGIN2_VERSION, true);
@@ -768,6 +776,9 @@ add_task(function* test_pluginsWatch_Remove() {
     return;
   }
 
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+
   // Find the test plugin.
   let plugin = gInstalledPlugins.find(plugin => (plugin.name == PLUGIN2_NAME));
   Assert.ok(plugin, "The test plugin must exist.");
@@ -796,6 +807,9 @@ add_task(function* test_addonsWatch_NotInterestingChange() {
   const DICTIONARY_ADDON_INSTALL_URL = gDataRoot + "dictionary.xpi";
   const INTERESTING_ADDON_INSTALL_URL = gDataRoot + "restartless.xpi";
 
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+
   let receivedNotification = false;
   let deferred = PromiseUtils.defer();
   TelemetryEnvironment.registerChangeListener("testNotInteresting",
@@ -879,6 +893,45 @@ add_task(function* test_addonsAndPlugins() {
   Assert.equal(data.addons.persona, personaId, "The correct Persona Id must be reported.");
 });
 
+add_task(function* test_changeThrottling() {
+  const PREF_TEST = "toolkit.telemetry.test.pref1";
+  let prefsToWatch = {};
+  prefsToWatch[PREF_TEST] = TelemetryEnvironment.RECORD_PREF_STATE;
+  Preferences.reset(PREF_TEST);
+
+  gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+
+  // Set the Environment preferences to watch.
+  TelemetryEnvironment._watchPreferences(prefsToWatch);
+  let deferred = PromiseUtils.defer();
+  let changeCount = 0;
+  TelemetryEnvironment.registerChangeListener("testWatchPrefs_throttling", () => {
+    ++changeCount;
+    deferred.resolve();
+  });
+
+  // The first pref change should trigger a notification.
+  Preferences.set(PREF_TEST, 1);
+  yield deferred.promise;
+  Assert.equal(changeCount, 1);
+
+  // We should only get a change notification for second of the following changes.
+  deferred = PromiseUtils.defer();
+  gNow = futureDate(gNow, MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+  Preferences.set(PREF_TEST, 2);
+  gNow = futureDate(gNow, 5 * MILLISECONDS_PER_MINUTE);
+  fakeNow(gNow);
+  Preferences.set(PREF_TEST, 3);
+  yield deferred.promise;
+
+  Assert.equal(changeCount, 2);
+
+  // Unregister the listener.
+  TelemetryEnvironment.unregisterChangeListener("testWatchPrefs_throttling");
+});
+
 add_task(function*() {
   do_test_finished();
 });

toolkit/components/telemetry/tests/unit/test_TelemetrySession.js

@@ -99,6 +99,13 @@ function generateUUID() {
   return str.substring(1, str.length - 1);
 }
 
+function truncateDateToDays(date) {
+  return new Date(date.getFullYear(),
+                  date.getMonth(),
+                  date.getDate(),
+                  0, 0, 0, 0);
+}
+
 function sendPing() {
   TelemetrySession.gatherStartup();
   if (gServerStarted) {
@@ -123,15 +130,6 @@ function wrapWithExceptionHandler(f) {
   return wrapper;
 }
 
-function futureDate(date, offset) {
-  return new Date(date.getTime() + offset);
-}
-
-function fakeNow(date) {
-  let session = Cu.import("resource://gre/modules/TelemetrySession.jsm");
-  session.Policy.now = () => date;
-}
-
 function fakeGenerateUUID(sessionFunc, subsessionFunc) {
   let session = Cu.import("resource://gre/modules/TelemetrySession.jsm");
   session.Policy.generateSessionUUID = sessionFunc;
@@ -1113,7 +1111,6 @@ add_task(function* test_environmentChange() {
   }
 
   let now = new Date(2040, 1, 1, 12, 0, 0);
-  let nowDay = new Date(2040, 1, 1, 0, 0, 0);
   let timerCallback = null;
   let timerDelay = null;
 
@@ -1144,6 +1141,10 @@ add_task(function* test_environmentChange() {
   keyed.add("b", 1);
 
   // Trigger and collect environment-change ping.
+  let startDay = truncateDateToDays(now);
+  now = futureDate(now, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(now);
+
   Preferences.set(PREF_TEST, 1);
   let request = yield gRequestIterator.next();
   Assert.ok(!!request);
@@ -1153,12 +1154,16 @@ add_task(function* test_environmentChange() {
   Assert.equal(ping.environment.settings.userPrefs[PREF_TEST], undefined);
   Assert.equal(ping.payload.info.reason, REASON_ENVIRONMENT_CHANGE);
   let subsessionStartDate = new Date(ping.payload.info.subsessionStartDate);
-  Assert.equal(subsessionStartDate.toISOString(), nowDay.toISOString());
+  Assert.equal(subsessionStartDate.toISOString(), startDay.toISOString());
 
   Assert.equal(ping.payload.histograms[COUNT_ID].sum, 1);
   Assert.equal(ping.payload.keyedHistograms[KEYED_ID]["a"].sum, 1);
 
   // Trigger and collect another ping. The histograms should be reset.
+  startDay = truncateDateToDays(now);
+  now = futureDate(now, 10 * MILLISECONDS_PER_MINUTE);
+  fakeNow(now);
+
   Preferences.set(PREF_TEST, 2);
   request = yield gRequestIterator.next();
   Assert.ok(!!request);
@@ -1168,7 +1173,7 @@ add_task(function* test_environmentChange() {
   Assert.equal(ping.environment.settings.userPrefs[PREF_TEST], 1);
   Assert.equal(ping.payload.info.reason, REASON_ENVIRONMENT_CHANGE);
   subsessionStartDate = new Date(ping.payload.info.subsessionStartDate);
-  Assert.equal(subsessionStartDate.toISOString(), nowDay.toISOString());
+  Assert.equal(subsessionStartDate.toISOString(), startDay.toISOString());
 
   Assert.equal(ping.payload.histograms[COUNT_ID].sum, 0);
   Assert.deepEqual(ping.payload.keyedHistograms[KEYED_ID], {});
@@ -1248,6 +1253,7 @@ add_task(function* test_savedSessionData() {
   // Watch a test preference, trigger and environment change and wait for it to propagate.
 
   // _watchPreferences triggers a subsession notification
+  fakeNow(new Date(2050, 1, 1, 12, 0, 0));
   TelemetryEnvironment._watchPreferences(prefsToWatch);
   let changePromise = new Promise(resolve =>
     TelemetryEnvironment.registerChangeListener("test_fake_change", resolve));
@@ -1487,7 +1493,7 @@ add_task(function* test_schedulerEnvironmentReschedules() {
   gRequestIterator = Iterator(new Request());
 
   // Set a fake current date and start Telemetry.
-  let nowDate = new Date(2009, 10, 18, 0, 00, 0);
+  let nowDate = new Date(2060, 10, 18, 0, 00, 0);
   fakeNow(nowDate);
   let schedulerTickCallback = null;
   fakeSchedulerTimer(callback => schedulerTickCallback = callback, () => {});