Bug 1293318 - Always throttle environment changes and limit throttling to main pings. r=dexter

This commit is contained in:
Georg Fritzsche 2016-09-27 10:45:31 +02:00
Родитель 8568845401
Коммит cea0812b0c
5 изменённых файлов: 89 добавлений и 112 удалений

Просмотреть файл

@ -40,8 +40,6 @@ XPCOMUtils.defineLazyModuleGetter(this, "UpdateUtils",
XPCOMUtils.defineLazyModuleGetter(this, "WindowsRegistry",
"resource://gre/modules/WindowsRegistry.jsm");
const CHANGE_THROTTLE_INTERVAL_MS = 5 * 60 * 1000;
// The maximum length of a string (e.g. description) in the addons section.
const MAX_ADDON_STRING_LENGTH = 100;
// The maximum length of a string value in the settings.attribution object.
@ -757,9 +755,6 @@ 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;
@ -1443,26 +1438,13 @@ EnvironmentCache.prototype = {
_onEnvironmentChange: function (what, oldEnvironment) {
this._log.trace("_onEnvironmentChange for " + what);
// We are already skipping change events in _checkChanges if there is a pending change task running.
if (this._shutdown) {
this._log.trace("_onEnvironmentChange - Already shut down.");
return;
}
// We are already skipping change events in _checkChanges if there is a pending change task running.
let now = Policy.now();
if (this._lastEnvironmentChangeDate &&
this._delayedInitFinished &&
(CHANGE_THROTTLE_INTERVAL_MS >=
(now.getTime() - this._lastEnvironmentChangeDate.getTime()))) {
this._log.trace("_onEnvironmentChange - throttling changes, now: " + now +
", last change: " + this._lastEnvironmentChangeDate);
return;
}
if (this._delayedInitFinished) {
this._lastEnvironmentChangeDate = now;
}
for (let [name, listener] of this._changeListeners) {
try {
this._log.debug("_onEnvironmentChange - calling " + name);

Просмотреть файл

@ -96,6 +96,10 @@ const SCHEDULER_MIDNIGHT_TOLERANCE_MS = 15 * 60 * 1000;
// start asynchronous tasks to gather data.
const IDLE_TIMEOUT_SECONDS = Preferences.get("toolkit.telemetry.idleTimeout", 5 * 60);
// To avoid generating too many main pings, we ignore environment changes that
// happen within this interval since the last main ping.
const CHANGE_THROTTLE_INTERVAL_MS = 5 * 60 * 1000;
// The frequency at which we persist session data to the disk to prevent data loss
// in case of aborted sessions (currently 5 minutes).
const ABORTED_SESSION_UPDATE_INTERVAL_MS = 5 * 60 * 1000;
@ -599,6 +603,7 @@ this.TelemetrySession = Object.freeze({
Impl._profileSubsessionCounter = 0;
Impl._subsessionStartActiveTicks = 0;
Impl._subsessionStartTimeMonotonic = 0;
Impl._lastEnvironmentChangeDate = Policy.monotonicNow();
this.testUninstall();
},
/**
@ -708,6 +713,7 @@ var Impl = {
_childrenToHearFrom: null,
// monotonically-increasing id for USS reports
_nextTotalMemoryId: 1,
_lastEnvironmentChangeDate: 0,
get _log() {
@ -1518,6 +1524,8 @@ var Impl = {
yield this._saveAbortedSessionPing();
}
// The last change date for the environment, used to throttle environment changes.
this._lastEnvironmentChangeDate = Policy.monotonicNow();
TelemetryEnvironment.registerChangeListener(ENVIRONMENT_CHANGE_LISTENER,
(reason, data) => this._onEnvironmentChange(reason, data));
@ -2042,8 +2050,16 @@ var Impl = {
_onEnvironmentChange: function(reason, oldEnvironment) {
this._log.trace("_onEnvironmentChange", reason);
let payload = this.getSessionPayload(REASON_ENVIRONMENT_CHANGE, true);
let now = Policy.monotonicNow();
let timeDelta = now - this._lastEnvironmentChangeDate;
if (timeDelta <= CHANGE_THROTTLE_INTERVAL_MS) {
this._log.trace(`_onEnvironmentChange - throttling; last change was ${Math.round(timeDelta / 1000)}s ago.`);
return;
}
this._lastEnvironmentChangeDate = now;
let payload = this.getSessionPayload(REASON_ENVIRONMENT_CHANGE, true);
TelemetryScheduler.reschedulePings(REASON_ENVIRONMENT_CHANGE, payload);
let options = {

Просмотреть файл

@ -111,10 +111,12 @@ add_task(function* test_subsessionsChaining() {
// Fake the clock data to manually trigger an aborted-session ping and a daily ping.
// This is also helpful to make sure we get the archived pings in an expected order.
let now = fakeNow(2009, 9, 18, 0, 0, 0);
let monotonicNow = fakeMonotonicNow(1000);
let moveClockForward = (minutes) => {
now = futureDate(now, minutes * MILLISECONDS_PER_MINUTE);
fakeNow(now);
let ms = minutes * MILLISECONDS_PER_MINUTE;
now = fakeNow(futureDate(now, ms));
monotonicNow = fakeMonotonicNow(monotonicNow + ms);
}
// Keep track of the ping reasons we're expecting in this test.

Просмотреть файл

@ -29,9 +29,6 @@ var gHttpRoot = null;
// The URL of the data directory, on the webserver.
var gDataRoot = null;
var 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";
@ -868,8 +865,6 @@ add_task(function* test_prefWatchPolicies() {
const expectedValue = "some-test-value";
const unexpectedValue = "unexpected-test-value";
gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(gNow);
const PREFS_TO_WATCH = new Map([
[PREF_TEST_1, {what: TelemetryEnvironment.RECORD_PREF_VALUE}],
@ -927,9 +922,6 @@ 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.testWatchPreferences(PREFS_TO_WATCH);
let deferred = PromiseUtils.defer();
@ -957,8 +949,6 @@ 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");
@ -1008,9 +998,6 @@ 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);
@ -1041,9 +1028,6 @@ 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.");
@ -1072,9 +1056,6 @@ 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",
@ -1207,8 +1188,6 @@ add_task(function* test_signedAddon() {
signedState: mozinfo.addon_signing ? AddonManager.SIGNEDSTATE_SIGNED : AddonManager.SIGNEDSTATE_NOT_REQUIRED,
};
// Set the clock in the future so our changes don't get throttled.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
let deferred = PromiseUtils.defer();
TelemetryEnvironment.registerChangeListener("test_signedAddon", deferred.resolve);
@ -1234,9 +1213,6 @@ add_task(function* test_addonsFieldsLimit() {
const ADDON_INSTALL_URL = gDataRoot + "long-fields.xpi";
const ADDON_ID = "tel-longfields-xpi@tests.mozilla.org";
// Set the clock in the future so our changes don't get throttled.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
// Install the addon and wait for the TelemetryEnvironment to pick it up.
let deferred = PromiseUtils.defer();
TelemetryEnvironment.registerChangeListener("test_longFieldsAddon", deferred.resolve);
@ -1295,8 +1271,6 @@ add_task(function* test_collectionWithbrokenAddonData() {
let receivedNotifications = 0;
let registerCheckpointPromise = (aExpected) => {
gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(gNow);
return new Promise(resolve => TelemetryEnvironment.registerChangeListener(
"testBrokenAddon_collection" + aExpected, (reason, data) => {
Assert.equal(reason, "addons-changed");
@ -1318,8 +1292,6 @@ add_task(function* test_collectionWithbrokenAddonData() {
yield checkpointPromise;
assertCheckpoint(1);
// Set the clock in the future so our changes don't get throttled.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
// Now install an addon which returns the correct information.
checkpointPromise = registerCheckpointPromise(2);
yield AddonManagerTesting.installXPIFromURL(ADDON_INSTALL_URL);
@ -1348,46 +1320,6 @@ add_task(function* test_collectionWithbrokenAddonData() {
yield AddonManagerTesting.uninstallAddonByID(ADDON_ID);
});
add_task(function* test_changeThrottling() {
const PREF_TEST = "toolkit.telemetry.test.pref1";
const PREFS_TO_WATCH = new Map([
[PREF_TEST, {what: TelemetryEnvironment.RECORD_PREF_STATE}],
]);
Preferences.reset(PREF_TEST);
gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(gNow);
// Set the Environment preferences to watch.
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);
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* test_defaultSearchEngine() {
// Check that no default engine is in the environment before the search service is
// initialized.
@ -1440,8 +1372,6 @@ add_task(function* test_defaultSearchEngine() {
const SEARCH_ENGINE_URL = "http://www.example.org/?search={searchTerms}";
Services.search.addEngineWithDetails(SEARCH_ENGINE_ID, "", null, "", "get", SEARCH_ENGINE_URL);
// Set the clock in the future so our changes don't get throttled.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
// Register a new change listener and then wait for the search engine change to be notified.
let deferred = PromiseUtils.defer();
TelemetryEnvironment.registerChangeListener("testWatch_SearchDefault", deferred.resolve);
@ -1464,7 +1394,6 @@ add_task(function* test_defaultSearchEngine() {
// Cleanly install an engine from an xml file, and check if origin is
// recorded as "verified".
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
let promise = new Promise(resolve => {
TelemetryEnvironment.registerChangeListener("testWatch_SearchDefault", resolve);
});
@ -1495,7 +1424,6 @@ add_task(function* test_defaultSearchEngine() {
{"name":"engine-telemetry", "loadPath":"[other]/engine.xml", "origin":"verified"});
// Now break this engine's load path hash.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
promise = new Promise(resolve => {
TelemetryEnvironment.registerChangeListener("testWatch_SearchDefault", resolve);
});
@ -1514,8 +1442,6 @@ add_task(function* test_defaultSearchEngine() {
]);
Preferences.reset(PREF_TEST);
// Set the clock in the future so our changes don't get throttled.
gNow = fakeNow(futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE));
// Watch the test preference.
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);
deferred = PromiseUtils.defer();
@ -1588,8 +1514,6 @@ add_task(function* test_environmentShutdown() {
[PREF_TEST, {what: TelemetryEnvironment.RECORD_PREF_STATE}],
]);
Preferences.reset(PREF_TEST);
gNow = futureDate(gNow, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(gNow);
// Set up the preferences and listener, then the trigger shutdown
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);

Просмотреть файл

@ -72,6 +72,7 @@ XPCOMUtils.defineLazyGetter(this, "DATAREPORTING_PATH", function() {
});
var gClientID = null;
var gMonotonicNow = 0;
function generateUUID() {
let str = Cc["@mozilla.org/uuid-generator;1"].getService(Ci.nsIUUIDGenerator).generateUUID().toString();
@ -537,7 +538,7 @@ add_task(function* test_simplePing() {
let now = new Date(2020, 1, 1, 12, 0, 0);
let expectedDate = new Date(2020, 1, 1, 0, 0, 0);
fakeNow(now);
const monotonicStart = fakeMonotonicNow(5000);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 5000);
const expectedSessionUUID = "bd314d15-95bf-4356-b682-b6c4a8942202";
const expectedSubsessionUUID = "3e2e5f6c-74ba-4e4d-a93f-a48af238a8c7";
@ -548,7 +549,7 @@ add_task(function* test_simplePing() {
// now fake the session duration.
const SESSION_DURATION_IN_MINUTES = 15;
fakeNow(new Date(2020, 1, 1, 12, SESSION_DURATION_IN_MINUTES, 0));
fakeMonotonicNow(monotonicStart + SESSION_DURATION_IN_MINUTES * 60 * 1000);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + SESSION_DURATION_IN_MINUTES * 60 * 1000);
yield sendPing();
let ping = yield PingServer.promiseNextPing();
@ -1112,14 +1113,14 @@ add_task(function* test_environmentChange() {
return;
}
let now = new Date(2040, 1, 1, 12, 0, 0);
let timerCallback = null;
let timerDelay = null;
yield TelemetryStorage.testClearPendingPings();
PingServer.clearRequests();
fakeNow(now);
let now = fakeNow(2040, 1, 1, 12, 0, 0);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
const PREF_TEST = "toolkit.telemetry.test.pref1";
Preferences.reset(PREF_TEST);
@ -1146,9 +1147,9 @@ add_task(function* test_environmentChange() {
keyed.add("b", 1);
// Trigger and collect environment-change ping.
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
let startDay = truncateDateToDays(now);
now = futureDate(now, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(now);
now = fakeNow(futureDate(now, 10 * MILLISECONDS_PER_MINUTE));
Preferences.set(PREF_TEST, 1);
let ping = yield PingServer.promiseNextPing();
@ -1165,8 +1166,8 @@ add_task(function* test_environmentChange() {
// Trigger and collect another ping. The histograms should be reset.
startDay = truncateDateToDays(now);
now = futureDate(now, 10 * MILLISECONDS_PER_MINUTE);
fakeNow(now);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
now = fakeNow(futureDate(now, 10 * MILLISECONDS_PER_MINUTE));
Preferences.set(PREF_TEST, 2);
ping = yield PingServer.promiseNextPing();
@ -1253,7 +1254,8 @@ 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));
let now = fakeNow(new Date(2050, 1, 1, 12, 0, 0));
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);
let changePromise = new Promise(resolve =>
TelemetryEnvironment.registerChangeListener("test_fake_change", resolve));
@ -1618,16 +1620,16 @@ add_task(function* test_schedulerEnvironmentReschedules() {
yield TelemetryController.testReset();
// Set a fake current date and start Telemetry.
let nowDate = new Date(2060, 10, 18, 0, 0, 0);
fakeNow(nowDate);
let nowDate = fakeNow(2060, 10, 18, 0, 0, 0);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
let schedulerTickCallback = null;
fakeSchedulerTimer(callback => schedulerTickCallback = callback, () => {});
yield TelemetryController.testReset();
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);
// Set the current time at midnight.
let future = futureDate(nowDate, MS_IN_ONE_DAY);
fakeNow(future);
let future = fakeNow(futureDate(nowDate, MS_IN_ONE_DAY));
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
// Trigger the environment change.
Preferences.set(PREF_TEST, 1);
@ -1880,9 +1882,60 @@ add_task(function* test_userIdleAndSchedlerTick() {
checkPingFormat(receivedPing, PING_TYPE_MAIN, true, true);
Assert.equal(receivedPing.payload.info.reason, REASON_DAILY);
PingServer.resetPingHandler();
yield TelemetryController.testShutdown();
});
add_task(function* test_changeThrottling() {
if (gIsAndroid) {
// We don't support subsessions yet on Android.
return;
}
let getSubsessionCount = () => {
return TelemetrySession.getPayload().info.subsessionCounter;
};
const PREF_TEST = "toolkit.telemetry.test.pref1";
const PREFS_TO_WATCH = new Map([
[PREF_TEST, {what: TelemetryEnvironment.RECORD_PREF_STATE}],
]);
Preferences.reset(PREF_TEST);
let now = fakeNow(2050, 1, 2, 0, 0, 0);
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 10 * MILLISECONDS_PER_MINUTE);
yield TelemetryController.testReset();
Assert.equal(getSubsessionCount(), 1);
// Set the Environment preferences to watch.
TelemetryEnvironment.testWatchPreferences(PREFS_TO_WATCH);
// The first pref change should not trigger a notification.
Preferences.set(PREF_TEST, 1);
Assert.equal(getSubsessionCount(), 1);
// We should get a change notification after the 5min throttling interval.
now = fakeNow(futureDate(now, 5 * MILLISECONDS_PER_MINUTE + 1));
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 5 * MILLISECONDS_PER_MINUTE + 1);
Preferences.set(PREF_TEST, 2);
Assert.equal(getSubsessionCount(), 2);
// After that, changes should be throttled again.
now = fakeNow(futureDate(now, 1 * MILLISECONDS_PER_MINUTE));
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 1 * MILLISECONDS_PER_MINUTE);
Preferences.set(PREF_TEST, 3);
Assert.equal(getSubsessionCount(), 2);
// ... for 5min.
now = fakeNow(futureDate(now, 4 * MILLISECONDS_PER_MINUTE + 1));
gMonotonicNow = fakeMonotonicNow(gMonotonicNow + 4 * MILLISECONDS_PER_MINUTE + 1);
Preferences.set(PREF_TEST, 4);
Assert.equal(getSubsessionCount(), 3);
// Unregister the listener.
TelemetryEnvironment.unregisterChangeListener("testWatchPrefs_throttling");
});
add_task(function* stopServer() {
yield PingServer.stop();
});