/* 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.EXPORTED_SYMBOLS = [ "Experiments", "ExperimentsProvider", ]; const {classes: Cc, interfaces: Ci, utils: Cu} = Components; Cu.import("resource://gre/modules/XPCOMUtils.jsm"); Cu.import("resource://gre/modules/Services.jsm"); Cu.import("resource://gre/modules/Task.jsm"); Cu.import("resource://gre/modules/Promise.jsm"); Cu.import("resource://gre/modules/osfile.jsm"); Cu.import("resource://gre/modules/Log.jsm"); Cu.import("resource://gre/modules/Preferences.jsm"); Cu.import("resource://services-common/utils.js"); Cu.import("resource://gre/modules/AsyncShutdown.jsm"); Cu.import("resource://gre/modules/Metrics.jsm"); XPCOMUtils.defineLazyModuleGetter(this, "UpdateChannel", "resource://gre/modules/UpdateChannel.jsm"); XPCOMUtils.defineLazyModuleGetter(this, "AddonManager", "resource://gre/modules/AddonManager.jsm"); XPCOMUtils.defineLazyModuleGetter(this, "TelemetryPing", "resource://gre/modules/TelemetryPing.jsm"); XPCOMUtils.defineLazyModuleGetter(this, "TelemetryLog", "resource://gre/modules/TelemetryLog.jsm"); // CertUtils.jsm doesn't expose a single "CertUtils" object like a normal .jsm // would. XPCOMUtils.defineLazyGetter(this, "CertUtils", function() { var mod = {}; Cu.import("resource://gre/modules/CertUtils.jsm", mod); return mod; }); #ifdef MOZ_CRASHREPORTER XPCOMUtils.defineLazyServiceGetter(this, "gCrashReporter", "@mozilla.org/xre/app-info;1", "nsICrashReporter"); #endif const FILE_CACHE = "experiments.json"; const OBSERVER_TOPIC = "experiments-changed"; const MANIFEST_VERSION = 1; const CACHE_VERSION = 1; const KEEP_HISTORY_N_DAYS = 180; const MIN_EXPERIMENT_ACTIVE_SECONDS = 60; const PREF_BRANCH = "experiments."; const PREF_ENABLED = "enabled"; // experiments.enabled const PREF_LOGGING = "logging"; const PREF_LOGGING_LEVEL = PREF_LOGGING + ".level"; // experiments.logging.level const PREF_LOGGING_DUMP = PREF_LOGGING + ".dump"; // experiments.logging.dump const PREF_MANIFEST_URI = "manifest.uri"; // experiments.logging.manifest.uri const PREF_MANIFEST_CHECKCERT = "manifest.cert.checkAttributes"; // experiments.manifest.cert.checkAttributes const PREF_MANIFEST_REQUIREBUILTIN = "manifest.cert.requireBuiltin"; // experiments.manifest.cert.requireBuiltin const PREF_FORCE_SAMPLE = "force-sample-value"; // experiments.force-sample-value const PREF_HEALTHREPORT_ENABLED = "datareporting.healthreport.service.enabled"; const PREF_BRANCH_TELEMETRY = "toolkit.telemetry."; const PREF_TELEMETRY_ENABLED = "enabled"; const PREF_TELEMETRY_PRERELEASE = "enabledPreRelease"; const TELEMETRY_LOG = { // log(key, [kind, experimentId, details]) ACTIVATION_KEY: "EXPERIMENT_ACTIVATION", ACTIVATION: { ACTIVATED: "ACTIVATED", // successfully activated INSTALL_FAILURE: "INSTALL_FAILURE", // failed to install the extension REJECTED: "REJECTED", // experiment was rejected because of it's conditions, // provides details on which }, // log(key, [kind, experimentId, optionalDetails...]) TERMINATION_KEY: "EXPERIMENT_TERMINATION", TERMINATION: { USERDISABLED: "USERDISABLED", // the user disabled this experiment FROM_API: "FROM_API", // the experiment disabled itself EXPIRED: "EXPIRED", // experiment expired e.g. by exceeding the end-date RECHECK: "RECHECK", // disabled after re-evaluating conditions, // provides details on which }, }; const gPrefs = new Preferences(PREF_BRANCH); const gPrefsTelemetry = new Preferences(PREF_BRANCH_TELEMETRY); let gExperimentsEnabled = false; let gExperiments = null; let gLogAppenderDump = null; let gLogger; let gLogDumping = false; function configureLogging() { if (!gLogger) { gLogger = Log.repository.getLogger("Browser.Experiments"); gLogger.addAppender(new Log.ConsoleAppender(new Log.BasicFormatter())); } gLogger.level = gPrefs.get(PREF_LOGGING_LEVEL, Log.Level.Warn); let logDumping = gPrefs.get(PREF_LOGGING_DUMP, false); if (logDumping != gLogDumping) { if (logDumping) { gLogAppenderDump = new Log.DumpAppender(new Log.BasicFormatter()); gLogger.addAppender(gLogAppenderDump); } else { gLogger.removeAppender(gLogAppenderDump); gLogAppenderDump = null; } gLogDumping = logDumping; } } // Takes an array of promises and returns a promise that is resolved once all of // them are rejected or resolved. function allResolvedOrRejected(promises) { if (!promises.length) { return Promise.resolve([]); } let countdown = promises.length; let deferred = Promise.defer(); for (let p of promises) { let helper = () => { if (--countdown == 0) { deferred.resolve(); } }; Promise.resolve(p).then(helper, helper); } return deferred.promise; } // Loads a JSON file using OS.file. file is a string representing the path // of the file to be read, options contains additional options to pass to // OS.File.read. // Returns a Promise resolved with the json payload or rejected with // OS.File.Error or JSON.parse() errors. function loadJSONAsync(file, options) { return Task.spawn(function() { let rawData = yield OS.File.read(file, options); // Read json file into a string let data; try { // Obtain a converter to read from a UTF-8 encoded input stream. let converter = new TextDecoder(); data = JSON.parse(converter.decode(rawData)); } catch (ex) { gLogger.error("Experiments: Could not parse JSON: " + file + " " + ex); throw ex; } throw new Task.Result(data); }); } function telemetryEnabled() { return gPrefsTelemetry.get(PREF_TELEMETRY_ENABLED, false) || gPrefsTelemetry.get(PREF_TELEMETRY_PRERELEASE, false); } /** * The experiments module. */ let Experiments = { /** * Provides access to the global `Experiments.Experiments` instance. */ instance: function () { if (!gExperiments) { gExperiments = new Experiments.Experiments(); } return gExperiments; }, }; /* * The policy object allows us to inject fake enviroment data from the * outside by monkey-patching. */ Experiments.Policy = function () { }; Experiments.Policy.prototype = { now: function () { return new Date(); }, random: function () { let pref = gPrefs.get(PREF_FORCE_SAMPLE); if (pref !== undefined) { let val = Number.parseFloat(pref); gLogger.debug("Experiments::Policy::random sample forced: " + val); if (IsNaN(val) || val < 0) { return 0; } if (val > 1) { return 1; } return val; } return Math.random(); }, futureDate: function (offset) { return new Date(this.now().getTime() + offset); }, oneshotTimer: function (callback, timeout, thisObj, name) { return CommonUtils.namedTimer(callback, timeout, thisObj, name); }, updatechannel: function () { return UpdateChannel.get(); }, locale: function () { let chrome = Cc["@mozilla.org/chrome/chrome-registry;1"].getService(Ci.nsIXULChromeRegistry); return chrome.getSelectedLocale("global"); }, /* * @return Promise<> Resolved with the payload data. */ healthReportPayload: function () { return Task.spawn(function*() { let reporter = Cc["@mozilla.org/datareporting/service;1"] .getService(Ci.nsISupports) .wrappedJSObject .healthReporter; yield reporter.onInit(); let payload = yield reporter.collectAndObtainJSONPayload(); throw new Task.Result(payload); }); }, telemetryPayload: function () { return TelemetryPing.getPayload(); }, }; /** * Manages the experiments and provides an interface to control them. */ Experiments.Experiments = function (policy=new Experiments.Policy()) { this._policy = policy; // This is a Map of (string -> ExperimentEntry), keyed with the experiment id. // It holds both the current experiments and history. // Map() preserves insertion order, which means we preserve the manifest order. // This is null until we've successfully completed loading the cache from // disk the first time. this._experiments = null; this._refresh = false; this._terminateReason = null; // or TELEMETRY_LOG.TERMINATION.... this._dirty = false; // Loading the cache happens once asynchronously on startup this._loadTask = null; // Ignore addon-manager notifications for addons that we are uninstalling ourself this._pendingUninstall = null; // The _main task handles all other actions: // * refreshing the manifest off the network (if _refresh) // * disabling/enabling experiments // * saving the cache (if _dirty) this._mainTask = null; // Timer for re-evaluating experiment status. this._timer = null; this._shutdown = false; this.init(); }; Experiments.Experiments.prototype = { QueryInterface: XPCOMUtils.generateQI([Ci.nsITimerCallback, Ci.nsIObserver]), init: function () { configureLogging(); gExperimentsEnabled = gPrefs.get(PREF_ENABLED, false); gLogger.trace("enabled="+gExperimentsEnabled+", "+this.enabled); gPrefs.observe(PREF_LOGGING, configureLogging); gPrefs.observe(PREF_MANIFEST_URI, this.updateManifest, this); gPrefs.observe(PREF_ENABLED, this._toggleExperimentsEnabled, this); gPrefsTelemetry.observe(PREF_TELEMETRY_ENABLED, this._telemetryStatusChanged, this); gPrefsTelemetry.observe(PREF_TELEMETRY_PRERELEASE, this._telemetryStatusChanged, this); AsyncShutdown.profileBeforeChange.addBlocker("Experiments.jsm shutdown", this.uninit.bind(this)); AddonManager.addAddonListener(this); this._loadTask = Task.spawn(this._loadFromCache.bind(this)); this._loadTask.then( () => { gLogger.trace("Experiments::_loadTask finished ok"); this._loadTask = null; this._run(); }, (e) => { gLogger.error("Experiments::_loadFromCache caught error: " + e); } ); }, /** * @return Promise<> * The promise is fulfilled when all pending tasks are finished. */ uninit: function () { if (!this._shutdown) { AddonManager.removeAddonListener(this); gPrefs.ignore(PREF_LOGGING, configureLogging); gPrefs.ignore(PREF_MANIFEST_URI, this.updateManifest, this); gPrefs.ignore(PREF_ENABLED, this._toggleExperimentsEnabled, this); gPrefsTelemetry.ignore(PREF_TELEMETRY_ENABLED, this._telemetryStatusChanged, this); gPrefsTelemetry.ignore(PREF_TELEMETRY_PRERELEASE, this._telemetryStatusChanged, this); if (this._timer) { this._timer.clear(); } } this._shutdown = true; if (this._mainTask) { return this._mainTask; } return Promise.resolve(); }, /** * Throws an exception if we've already shut down. */ _checkForShutdown: function() { if (this._shutdown) { throw Error("uninit() already called"); } }, /** * Whether the experiments feature is enabled. */ get enabled() { return gExperimentsEnabled; }, /** * Toggle whether the experiments feature is enabled or not. */ set enabled(enabled) { gLogger.trace("Experiments::set enabled(" + enabled + ")"); gPrefs.set(PREF_ENABLED, enabled); }, _toggleExperimentsEnabled: function (enabled) { gLogger.trace("Experiments::_toggleExperimentsEnabled(" + enabled + ")"); let wasEnabled = gExperimentsEnabled; gExperimentsEnabled = enabled && telemetryEnabled(); if (wasEnabled == gExperimentsEnabled) { return; } if (gExperimentsEnabled) { this.updateManifest(); } else { this.disableExperiment(); if (this._timer) { this._timer.clear(); } } }, _telemetryStatusChanged: function () { this._toggleExperimentsEnabled(gExperimentsEnabled); }, /** * Returns a promise that is resolved with an array of `ExperimentInfo` objects, * which provide info on the currently and recently active experiments. * The array is in chronological order. * * The experiment info is of the form: * { * id: , * name: , * description: , * active: , * endDate: , // epoch ms * detailURL: , * ... // possibly extended later * } * * @return Promise> Array of experiment info objects. */ getExperiments: function () { return Task.spawn(function*() { yield this._loadTask; let list = []; for (let [id, experiment] of this._experiments) { if (!experiment.startDate) { // We only collect experiments that are or were active. continue; } list.push({ id: id, name: experiment._name, description: experiment._description, active: experiment.enabled, endDate: experiment.endDate.getTime(), detailURL: experiment._homepageURL, }); } // Sort chronologically, descending. list.sort((a, b) => b.endDate - a.endDate); return list; }.bind(this)); }, /** * Determine whether another date has the same UTC day as now(). */ _dateIsTodayUTC: function (d) { let now = this._policy.now(); return stripDateToMidnight(now).getTime() == stripDateToMidnight(d).getTime(); }, /** * Obtain the entry of the most recent active experiment that was active * today. * * If no experiment was active today, this resolves to nothing. * * Assumption: Only a single experiment can be active at a time. * * @return Promise */ lastActiveToday: function () { return Task.spawn(function* getMostRecentActiveExperimentTask() { let experiments = yield this.getExperiments(); // Assumption: Ordered chronologically, descending, with active always // first. for (let experiment of experiments) { if (experiment.active) { return experiment; } if (experiment.endDate && this._dateIsTodayUTC(experiment.endDate)) { return experiment; } } return null; }.bind(this)); }, _run: function() { gLogger.trace("Experiments::_run"); this._checkForShutdown(); if (!this._mainTask) { this._mainTask = Task.spawn(this._main.bind(this)); this._mainTask.then( () => { gLogger.trace("Experiments::_main finished, scheduling next run"); this._mainTask = null; this._scheduleNextRun(); }, (e) => { gLogger.error("Experiments::_main caught error: " + e); this._mainTask = null; } ); } return this._mainTask; }, _main: function*() { do { gLogger.trace("Experiments::_main iteration"); yield this._loadTask; if (this._refresh) { yield this._loadManifest(); } yield this._evaluateExperiments(); if (this._dirty) { yield this._saveToCache(); } // If somebody called .updateManifest() or disableExperiment() // while we were running, go again right now. } while (this._refresh || this._terminateReason); }, _loadManifest: function*() { gLogger.trace("Experiments::_loadManifest"); let uri = Services.urlFormatter.formatURLPref(PREF_BRANCH + PREF_MANIFEST_URI); this._checkForShutdown(); this._refresh = false; try { let responseText = yield this._httpGetRequest(uri); gLogger.trace("Experiments::_loadManifest() - responseText=\"" + responseText + "\""); if (this._shutdown) { return; } let data = JSON.parse(responseText); this._updateExperiments(data); } catch (e) { gLogger.error("Experiments::_loadManifest - failure to fetch/parse manifest (continuing anyway): " + e); } }, /** * Fetch an updated list of experiments and trigger experiment updates. * Do only use when experiments are enabled. * * @return Promise<> * The promise is resolved when the manifest and experiment list is updated. */ updateManifest: function () { gLogger.trace("Experiments::updateManifest()"); if (!gExperimentsEnabled) { return Promise.reject(new Error("experiments are disabled")); } if (this._shutdown) { return Promise.reject(Error("uninit() alrady called")); } this._refresh = true; return this._run(); }, notify: function (timer) { gLogger.trace("Experiments::notify()"); this._checkForShutdown(); return this._run(); }, onDisabled: function (addon) { gLogger.trace("Experiments::onDisabled() - addon id: " + addon.id); if (addon.id == this._pendingUninstall) { return; } let activeExperiment = this._getActiveExperiment(); if (!activeExperiment || activeExperiment._addonId != addon.id) { return; } this.disableExperiment(); }, onUninstalled: function (addon) { gLogger.trace("Experiments::onUninstalled() - addon id: " + addon.id); if (addon.id == this._pendingUninstall) { gLogger.trace("onUninstalled: matches pending uninstall"); return; } let activeExperiment = this._getActiveExperiment(); if (!activeExperiment || activeExperiment._addonId != addon.id) { return; } this.disableExperiment(); }, _getExperimentByAddonId: function (addonId) { for (let [, entry] of this._experiments) { if (entry._addonId === addonId) { return entry; } } return null; }, /* * Helper function to make HTTP GET requests. Returns a promise that is resolved with * the responseText when the request is complete. */ _httpGetRequest: function (url) { gLogger.trace("Experiments::httpGetRequest(" + url + ")"); let xhr = Cc["@mozilla.org/xmlextras/xmlhttprequest;1"].createInstance(Ci.nsIXMLHttpRequest); try { xhr.open("GET", url); } catch (e) { gLogger.error("Experiments::httpGetRequest() - Error opening request to " + url + ": " + e); return Promise.reject(new Error("Experiments - Error opening XHR for " + url)); } let deferred = Promise.defer(); xhr.onerror = function (e) { gLogger.error("Experiments::httpGetRequest::onError() - Error making request to " + url + ": " + e.error); deferred.reject(new Error("Experiments - XHR error for " + url + " - " + e.error)); }; xhr.onload = function (event) { if (xhr.status !== 200 && xhr.state !== 0) { gLogger.error("Experiments::httpGetRequest::onLoad() - Request to " + url + " returned status " + xhr.status); deferred.reject(new Error("Experiments - XHR status for " + url + " is " + xhr.status)); return; } let certs = null; if (gPrefs.get(PREF_MANIFEST_CHECKCERT, true)) { certs = CertUtils.readCertPrefs(PREF_BRANCH + "manifest.certs."); } try { let allowNonBuiltin = !gPrefs.get(PREF_MANIFEST_REQUIREBUILTIN, true); CertUtils.checkCert(xhr.channel, allowNonBuiltin, certs); } catch (e) { gLogger.error("Experiments: manifest fetch failed certificate checks", [e]); deferred.reject(new Error("Experiments - manifest fetch failed certificate checks: " + e)); return; } deferred.resolve(xhr.responseText); }; if (xhr.channel instanceof Ci.nsISupportsPriority) { xhr.channel.priority = Ci.nsISupportsPriority.PRIORITY_LOWEST; } xhr.send(null); return deferred.promise; }, /* * Path of the cache file we use in the profile. */ get _cacheFilePath() { return OS.Path.join(OS.Constants.Path.profileDir, FILE_CACHE); }, /* * Part of the main task to save the cache to disk, called from _main. */ _saveToCache: function* () { gLogger.trace("Experiments::_saveToCache"); let path = this._cacheFilePath; let textData = JSON.stringify({ version: CACHE_VERSION, data: [e[1].toJSON() for (e of this._experiments.entries())], }); let encoder = new TextEncoder(); let data = encoder.encode(textData); let options = { tmpPath: path + ".tmp", compression: "lz4" }; yield OS.File.writeAtomic(path, data, options); this._dirty = false; gLogger.debug("Experiments._saveToCache saved to " + path); }, /* * Task function, load the cached experiments manifest file from disk. */ _loadFromCache: function*() { gLogger.trace("Experiments::_loadFromCache"); let path = this._cacheFilePath; try { let result = yield loadJSONAsync(path, { compression: "lz4" }); this._populateFromCache(result); } catch (e if e instanceof OS.File.Error && e.becauseNoSuchFile) { // No cached manifest yet. this._experiments = new Map(); } }, _populateFromCache: function (data) { gLogger.trace("Experiments::populateFromCache() - data: " + JSON.stringify(data)); // If the user has a newer cache version than we can understand, we fail // hard; no experiments should be active in this older client. if (CACHE_VERSION !== data.version) { throw new Error("Experiments::_populateFromCache() - invalid cache version"); } let experiments = new Map(); for (let item of data.data) { let entry = new Experiments.ExperimentEntry(this._policy); if (!entry.initFromCacheData(item)) { continue; } experiments.set(entry.id, entry); } this._experiments = experiments; }, /* * Update the experiment entries from the experiments * array in the manifest */ _updateExperiments: function (manifestObject) { gLogger.trace("Experiments::_updateExperiments() - experiments: " + JSON.stringify(manifestObject)); if (manifestObject.version !== MANIFEST_VERSION) { gLogger.warning("Experiments::updateExperiments() - unsupported version " + manifestObject.version); } let experiments = new Map(); // The new experiments map // Collect new and updated experiments. for (let data of manifestObject.experiments) { let entry = this._experiments.get(data.id); if (entry) { if (!entry.updateFromManifestData(data)) { gLogger.error("Experiments::updateExperiments() - Invalid manifest data for " + data.id); continue; } } else { entry = new Experiments.ExperimentEntry(this._policy); if (!entry.initFromManifestData(data)) { continue; } } if (entry.shouldDiscard()) { continue; } experiments.set(entry.id, entry); } // Make sure we keep experiments that are or were running. // We remove them after KEEP_HISTORY_N_DAYS. for (let [id, entry] of this._experiments) { if (experiments.has(id) || !entry.startDate || entry.shouldDiscard()) { gLogger.trace("Experiments::updateExperiments() - discarding entry for " + id); continue; } experiments.set(id, entry); } this._experiments = experiments; this._dirty = true; }, _getActiveExperiment: function () { let enabled = [experiment for ([,experiment] of this._experiments) if (experiment._enabled)]; if (enabled.length == 1) { return enabled[0]; } if (enabled.length > 1) { gLogger.error("Experiments::getActiveExperimentId() - should not have more than 1 active experiment"); throw new Error("have more than 1 active experiment"); } return null; }, /** * Disable an experiment by id. * @param experimentId The id of the experiment. * @param userDisabled (optional) Whether this is disabled as a result of a user action. * @return Promise<> Promise that will get resolved once the task is done or failed. */ disableExperiment: function (userDisabled=true) { gLogger.trace("Experiments::disableExperiment()"); this._terminateReason = userDisabled ? TELEMETRY_LOG.TERMINATION.USERDISABLED : TELEMETRY_LOG.TERMINATION.FROM_API; return this._run(); }, /* * Task function to check applicability of experiments, disable the active * experiment if needed and activate the first applicable candidate. */ _evaluateExperiments: function*() { gLogger.trace("Experiments::_evaluateExperiments"); this._checkForShutdown(); let activeExperiment = this._getActiveExperiment(); let activeChanged = false; let now = this._policy.now(); if (activeExperiment) { this._pendingUninstall = activeExperiment._addonId; try { let wasStopped; if (this._terminateReason) { yield activeExperiment.stop(this._terminateReason); wasStopped = true; } else { wasStopped = yield activeExperiment.maybeStop(); } if (wasStopped) { this._dirty = true; gLogger.debug("Experiments::evaluateExperiments() - stopped experiment " + activeExperiment.id); activeExperiment = null; activeChanged = true; } else if (activeExperiment.needsUpdate) { gLogger.debug("Experiments::evaluateExperiments() - updating experiment " + activeExperiment.id); try { yield activeExperiment.stop(); yield activeExperiment.start(); } catch (e) { gLogger.error(e); // On failure try the next experiment. activeExperiment = null; } this._dirty = true; activeChanged = true; } } finally { this._pendingUninstall = null; } } this._terminateReason = null; if (!activeExperiment) { for (let [id, experiment] of this._experiments) { let applicable; let reason = null; try { applicable = yield experiment.isApplicable(); } catch (e) { applicable = false; reason = e; } if (!applicable && reason && reason[0] != "was-active") { // Report this from here to avoid over-reporting. let desc = TELEMETRY_LOG.ACTIVATION; let data = [TELEMETRY_LOG.ACTIVATION.REJECTED, id]; data = data.concat(reason); TelemetryLog.log(TELEMETRY_LOG.ACTIVATION_KEY, data); } if (applicable) { gLogger.debug("Experiments::evaluateExperiments() - activating experiment " + id); try { yield experiment.start(); activeChanged = true; activeExperiment = experiment; this._dirty = true; break; } catch (e) { // On failure try the next experiment. } } } } if (activeChanged) { Services.obs.notifyObservers(null, OBSERVER_TOPIC, null); } #ifdef MOZ_CRASHREPORTER if (activeExperiment) { gCrashReporter.annotateCrashReport("ActiveExperiment", activeExperiment.id); } #endif }, /* * Schedule the soonest re-check of experiment applicability that is needed. */ _scheduleNextRun: function () { this._checkForShutdown(); if (this._timer) { this._timer.clear(); } if (!gExperimentsEnabled || this._experiments.length == 0) { return; } let time = null; let now = this._policy.now().getTime(); for (let [id, experiment] of this._experiments) { let scheduleTime = experiment.getScheduleTime(); if (scheduleTime > now) { if (time !== null) { time = Math.min(time, scheduleTime); } else { time = scheduleTime; } } } if (time === null) { // No schedule time found. return; } gLogger.trace("Experiments::scheduleExperimentEvaluation() - scheduling for "+time+", now: "+now); this._policy.oneshotTimer(this.notify, time - now, this, "_timer"); }, }; /* * Represents a single experiment. */ Experiments.ExperimentEntry = function (policy) { this._policy = policy || new Experiments.Policy(); // Is this experiment running? this._enabled = false; // When this experiment was started, if ever. this._startDate = null; // When this experiment was ended, if ever. this._endDate = null; // The condition data from the manifest. this._manifestData = null; // For an active experiment, signifies whether we need to update the xpi. this._needsUpdate = false; // A random sample value for comparison against the manifest conditions. this._randomValue = null; // When this entry was last changed for respecting history retention duration. this._lastChangedDate = null; // Has this experiment failed to activate before? this._failedStart = false; // We grab these from the addon after download. this._name = null; this._description = null; this._homepageURL = null; this._addonId = null; }; Experiments.ExperimentEntry.prototype = { MANIFEST_REQUIRED_FIELDS: new Set([ "id", "xpiURL", "xpiHash", "startTime", "endTime", "maxActiveSeconds", "appName", "channel", ]), MANIFEST_OPTIONAL_FIELDS: new Set([ "maxStartTime", "minVersion", "maxVersion", "version", "minBuildID", "maxBuildID", "buildIDs", "os", "locale", "sample", "disabled", "frozen", "jsfilter", ]), SERIALIZE_KEYS: new Set([ "_enabled", "_manifestData", "_needsUpdate", "_randomValue", "_failedStart", "_name", "_description", "_homepageURL", "_addonId", "_startDate", "_endDate", ]), DATE_KEYS: new Set([ "_startDate", "_endDate", ]), /* * Initialize entry from the manifest. * @param data The experiment data from the manifest. * @return boolean Whether initialization succeeded. */ initFromManifestData: function (data) { if (!this._isManifestDataValid(data)) { return false; } this._manifestData = data; this._randomValue = this._policy.random(); this._lastChangedDate = this._policy.now(); return true; }, get enabled() { return this._enabled; }, get id() { return this._manifestData.id; }, get startDate() { return this._startDate; }, get endDate() { if (!this._startDate) { return null; } let endTime = 0; if (!this._enabled) { return this._endDate; } let maxActiveMs = 1000 * this._manifestData.maxActiveSeconds; endTime = Math.min(1000 * this._manifestData.endTime, this._startDate.getTime() + maxActiveMs); return new Date(endTime); }, get needsUpdate() { return this._needsUpdate; }, /* * Initialize entry from the cache. * @param data The entry data from the cache. * @return boolean Whether initialization succeeded. */ initFromCacheData: function (data) { for (let key of this.SERIALIZE_KEYS) { if (!(key in data) && !this.DATE_KEYS.has(key)) { gLogger.error("ExperimentEntry::initFromCacheData() - missing required key " + key); return false; } }; if (!this._isManifestDataValid(data._manifestData)) { return false; } // Dates are restored separately from epoch ms, everything else is just // copied in. this.SERIALIZE_KEYS.forEach(key => { if (!this.DATE_KEYS.has(key)) { this[key] = data[key]; } }); this.DATE_KEYS.forEach(key => { if (key in data) { let date = new Date(); date.setTime(data[key]); this[key] = date; } }); this._lastChangedDate = this._policy.now(); return true; }, /* * Returns a JSON representation of this object. */ toJSON: function () { let obj = {}; // Dates are serialized separately as epoch ms. this.SERIALIZE_KEYS.forEach(key => { if (!this.DATE_KEYS.has(key)) { obj[key] = this[key]; } }); this.DATE_KEYS.forEach(key => { if (this[key]) { obj[key] = this[key].getTime(); } }); return obj; }, /* * Update from the experiment data from the manifest. * @param data The experiment data from the manifest. * @return boolean Whether updating succeeded. */ updateFromManifestData: function (data) { let old = this._manifestData; if (!this._isManifestDataValid(data)) { return false; } if (this._enabled) { if (old.xpiHash !== data.xpiHash) { // A changed hash means we need to update active experiments. this._needsUpdate = true; } } else if (this._failedStart && (old.xpiHash !== data.xpiHash) || (old.xpiURL !== data.xpiURL)) { // Retry installation of previously invalid experiments // if hash or url changed. this._failedStart = false; } this._manifestData = data; this._lastChangedDate = this._policy.now(); return true; }, /* * Is this experiment applicable? * @return Promise<> Resolved if the experiment is applicable. * If it is not applicable it is rejected with * a Promise which contains the reason. */ isApplicable: function () { let versionCmp = Cc["@mozilla.org/xpcom/version-comparator;1"] .getService(Ci.nsIVersionComparator); let app = Cc["@mozilla.org/xre/app-info;1"].getService(Ci.nsIXULAppInfo); let runtime = Cc["@mozilla.org/xre/app-info;1"] .getService(Ci.nsIXULRuntime); let locale = this._policy.locale(); let channel = this._policy.updatechannel(); let data = this._manifestData; let now = this._policy.now() / 1000; // The manifest times are in seconds. let minActive = MIN_EXPERIMENT_ACTIVE_SECONDS; let maxActive = data.maxActiveSeconds || 0; let startSec = (this.startDate || 0) / 1000; gLogger.trace("ExperimentEntry::isApplicable() - now=" + now + ", randomValue=" + this._randomValue + ", data=" + JSON.stringify(this._manifestData)); // Not applicable if it already ran. if (!this.enabled && this._endDate) { return Promise.reject(["was-active"]); } // Define and run the condition checks. let simpleChecks = [ { name: "failedStart", condition: () => !this._failedStart }, { name: "disabled", condition: () => !data.disabled }, { name: "frozen", condition: () => !data.frozen || this._enabled }, { name: "startTime", condition: () => now >= data.startTime }, { name: "endTime", condition: () => now < data.endTime }, { name: "maxStartTime", condition: () => !data.maxStartTime || now <= data.maxStartTime }, { name: "maxActiveSeconds", condition: () => !this._startDate || now <= (startSec + maxActive) }, { name: "appName", condition: () => !data.appName || data.appName.indexOf(app.name) != -1 }, { name: "minBuildID", condition: () => !data.minBuildID || app.platformBuildID >= data.minBuildID }, { name: "maxBuildID", condition: () => !data.maxBuildID || app.platformBuildID <= data.maxBuildID }, { name: "buildIDs", condition: () => !data.buildIDs || data.buildIDs.indexOf(app.platformBuildID) != -1 }, { name: "os", condition: () => !data.os || data.os.indexOf(runtime.OS) != -1 }, { name: "channel", condition: () => !data.channel || data.channel.indexOf(channel) != -1 }, { name: "locale", condition: () => !data.locale || data.locale.indexOf(locale) != -1 }, { name: "sample", condition: () => data.sample === undefined || this._randomValue <= data.sample }, { name: "version", condition: () => !data.version || data.version.indexOf(app.version) != -1 }, { name: "minVersion", condition: () => !data.minVersion || versionCmp.compare(app.version, data.minVersion) >= 0 }, { name: "maxVersion", condition: () => !data.maxVersion || versionCmp.compare(app.version, data.maxVersion) <= 0 }, ]; for (let check of simpleChecks) { let result = check.condition(); if (!result) { gLogger.debug("ExperimentEntry::isApplicable() - id=" + data.id + " - test '" + check.name + "' failed"); return Promise.reject([check.name]); } } if (data.jsfilter) { return this._runFilterFunction(data.jsfilter); } return Promise.resolve(true); }, /* * Run the jsfilter function from the manifest in a sandbox and return the * result (forced to boolean). */ _runFilterFunction: function (jsfilter) { gLogger.trace("ExperimentEntry::runFilterFunction() - filter: " + jsfilter); return Task.spawn(function ExperimentEntry_runFilterFunction_task() { const nullprincipal = Cc["@mozilla.org/nullprincipal;1"].createInstance(Ci.nsIPrincipal); let options = { sandboxName: "telemetry experiments jsfilter sandbox", wantComponents: false, }; let sandbox = Cu.Sandbox(nullprincipal); let context = {}; context.healthReportPayload = yield this._policy.healthReportPayload(); context.telemetryPayload = yield this._policy.telemetryPayload(); try { Cu.evalInSandbox(jsfilter, sandbox); } catch (e) { gLogger.error("ExperimentEntry::runFilterFunction() - failed to eval jsfilter: " + e.message); throw ["jsfilter-evalfailed"]; } // You can't insert arbitrarily complex objects into a sandbox, so // we serialize everything through JSON. sandbox._hr = JSON.stringify(yield this._policy.healthReportPayload()); Object.defineProperty(sandbox, "_t", { get: () => JSON.stringify(this._policy.telemetryPayload()) }); let result = false; try { result = !!Cu.evalInSandbox("filter({healthReportPayload: JSON.parse(_hr), telemetryPayload: JSON.parse(_t)})", sandbox); } catch (e) { gLogger.debug("ExperimentEntry::runFilterFunction() - filter function failed: " + e.message + ", " + e.stack); throw ["jsfilter-threw", e.message]; } finally { Cu.nukeSandbox(sandbox); } if (!result) { throw ["jsfilter-false"]; } throw new Task.Result(true); }.bind(this)); }, /* * Start running the experiment. * @return Promise<> Resolved when the operation is complete. */ start: function () { gLogger.trace("ExperimentEntry::start() for " + this.id); let deferred = Promise.defer(); let installCallback = install => { let failureHandler = (install, handler) => { let message = "AddonInstall " + handler + " for " + this.id + ", state=" + (install.state || "?") + ", error=" + install.error; gLogger.error("ExperimentEntry::start() - " + message); this._failedStart = true; TelemetryLog.log(TELEMETRY_LOG.ACTIVATION_KEY, [TELEMETRY_LOG.ACTIVATION.INSTALL_FAILURE, this.id]); deferred.reject(new Error(message)); }; let listener = { onDownloadEnded: install => { gLogger.trace("ExperimentEntry::start() - onDownloadEnded for " + this.id); }, onInstallStarted: install => { gLogger.trace("ExperimentEntry::start() - onInstallStarted for " + this.id); // TODO: this check still needs changes in the addon manager //if (install.addon.type !== "experiment") { // gLogger.error("ExperimentEntry::start() - wrong addon type"); // failureHandler({state: -1, error: -1}, "onInstallStarted"); //} let addon = install.addon; this._name = addon.name; this._addonId = addon.id; this._description = addon.description || ""; this._homepageURL = addon.homepageURL || ""; }, onInstallEnded: install => { gLogger.trace("ExperimentEntry::start() - install ended for " + this.id); this._lastChangedDate = this._policy.now(); this._startDate = this._policy.now(); this._enabled = true; TelemetryLog.log(TELEMETRY_LOG.ACTIVATION_KEY, [TELEMETRY_LOG.ACTIVATION.ACTIVATED, this.id]); deferred.resolve(); }, }; ["onDownloadCancelled", "onDownloadFailed", "onInstallCancelled", "onInstallFailed"] .forEach(what => { listener[what] = install => failureHandler(install, what) }); install.addListener(listener); install.install(); }; AddonManager.getInstallForURL(this._manifestData.xpiURL, installCallback, "application/x-xpinstall", this._manifestData.xpiHash); return deferred.promise; }, /* * Stop running the experiment if it is active. * @param terminationKind (optional) The termination kind, e.g. USERDISABLED or EXPIRED. * @param terminationReason (optional) The termination reason details for * termination kind RECHECK. * @return Promise<> Resolved when the operation is complete. */ stop: function (terminationKind, terminationReason) { gLogger.trace("ExperimentEntry::stop() - id=" + this.id + ", terminationKind=" + terminationKind); if (!this._enabled) { gLogger.warning("ExperimentEntry::stop() - experiment not enabled: " + id); return Promise.reject(); } this._enabled = false; let deferred = Promise.defer(); let updateDates = () => { let now = this._policy.now(); this._lastChangedDate = now; this._endDate = now; }; AddonManager.getAddonByID(this._addonId, addon => { if (!addon) { let message = "could not get Addon for " + this.id; gLogger.warn("ExperimentEntry::stop() - " + message); updateDates(); deferred.resolve(); return; } let listener = {}; let handler = addon => { if (addon.id !== this._addonId) { return; } updateDates(); this._logTermination(terminationKind, terminationReason); AddonManager.removeAddonListener(listener); deferred.resolve(); }; listener.onUninstalled = handler; listener.onDisabled = handler; AddonManager.addAddonListener(listener); addon.uninstall(); }); return deferred.promise; }, _logTermination: function (terminationKind, terminationReason) { if (terminationKind === undefined) { return; } if (!(terminationKind in TELEMETRY_LOG.TERMINATION)) { gLogger.warn("ExperimentEntry::stop() - unknown terminationKind " + terminationKind); return; } let data = [terminationKind, this.id]; if (terminationReason) { data = data.concat(terminationReason); } TelemetryLog.log(TELEMETRY_LOG.TERMINATION_KEY, data); }, /* * Stop if experiment stop criteria are met. * @return Promise Resolved when done stopping or checking, * the value indicates whether it was stopped. */ maybeStop: function () { gLogger.trace("ExperimentEntry::maybeStop()"); return Task.spawn(function ExperimentEntry_maybeStop_task() { let result = yield this._shouldStop(); if (result.shouldStop) { let expireReasons = ["endTime", "maxActiveSeconds"]; if (expireReasons.indexOf(result.reason[0]) != -1) { yield this.stop(TELEMETRY_LOG.TERMINATION.EXPIRED); } else { yield this.stop(TELEMETRY_LOG.TERMINATION.RECHECK, result.reason); } } throw new Task.Result(result.shouldStop); }.bind(this)); }, _shouldStop: function () { let data = this._manifestData; let now = this._policy.now() / 1000; // The manifest times are in seconds. let maxActiveSec = data.maxActiveSeconds || 0; if (!this._enabled) { return Promise.resolve({shouldStop: false}); } let deferred = Promise.defer(); this.isApplicable().then( () => deferred.resolve({shouldStop: false}), reason => deferred.resolve({shouldStop: true, reason: reason}) ); return deferred.promise; }, /* * Should this be discarded from the cache due to age? */ shouldDiscard: function () { let limit = this._policy.now(); limit.setDate(limit.getDate() - KEEP_HISTORY_N_DAYS); return (this._lastChangedDate < limit); }, /* * Get next date (in epoch-ms) to schedule a re-evaluation for this. * Returns 0 if it doesn't need one. */ getScheduleTime: function () { if (this._enabled) { let now = this._policy.now(); let startTime = this._startDate.getTime(); let maxActiveTime = startTime + 1000 * this._manifestData.maxActiveSeconds; return Math.min(1000 * this._manifestData.endTime, maxActiveTime); } if (this._endDate) { return this._endDate.getTime(); } return 1000 * this._manifestData.startTime; }, /* * Perform sanity checks on the experiment data. */ _isManifestDataValid: function (data) { gLogger.trace("ExperimentEntry::isManifestDataValid() - data: " + JSON.stringify(data)); for (let key of this.MANIFEST_REQUIRED_FIELDS) { if (!(key in data)) { gLogger.error("ExperimentEntry::isManifestDataValid() - missing required key: " + key); return false; } } for (let key in data) { if (!this.MANIFEST_OPTIONAL_FIELDS.has(key) && !this.MANIFEST_REQUIRED_FIELDS.has(key)) { gLogger.error("ExperimentEntry::isManifestDataValid() - unknown key: " + key); return false; } } return true; }, }; /** * Strip a Date down to its UTC midnight. * * This will return a cloned Date object. The original is unchanged. */ let stripDateToMidnight = function (d) { let m = new Date(d); m.setUTCHours(0, 0, 0, 0); return m; }; function ExperimentsLastActiveMeasurement1() { Metrics.Measurement.call(this); } const FIELD_DAILY_LAST_TEXT = {type: Metrics.Storage.FIELD_DAILY_LAST_TEXT}; ExperimentsLastActiveMeasurement1.prototype = Object.freeze({ __proto__: Metrics.Measurement.prototype, name: "info", version: 1, fields: { lastActive: FIELD_DAILY_LAST_TEXT, } }); this.ExperimentsProvider = function () { Metrics.Provider.call(this); this._experiments = null; }; ExperimentsProvider.prototype = Object.freeze({ __proto__: Metrics.Provider.prototype, name: "org.mozilla.experiments", measurementTypes: [ ExperimentsLastActiveMeasurement1, ], _OBSERVERS: [ OBSERVER_TOPIC, ], postInit: function () { this._experiments = Experiments.instance(); for (let o of this._OBSERVERS) { Services.obs.addObserver(this, o, false); } return Promise.resolve(); }, onShutdown: function () { for (let o of this._OBSERVERS) { Services.obs.removeObserver(this, o); } return Promise.resolve(); }, observe: function (subject, topic, data) { switch (topic) { case OBSERVER_TOPIC: this.recordLastActiveExperiment(); break; } }, collectDailyData: function () { return this.recordLastActiveExperiment(); }, recordLastActiveExperiment: function () { let m = this.getMeasurement(ExperimentsLastActiveMeasurement1.prototype.name, ExperimentsLastActiveMeasurement1.prototype.version); return this.enqueueStorageOperation(() => { return Task.spawn(function* recordTask() { let todayActive = yield this._experiments.lastActiveToday(); if (!todayActive) { this._log.info("No active experiment on this day: " + this._experiments._policy.now()); return; } this._log.info("Recording last active experiment: " + todayActive.id); yield m.setDailyLastText("lastActive", todayActive.id, this._experiments._policy.now()); }.bind(this)); }); }, });