1.1 --- /dev/null Thu Jan 01 00:00:00 1970 +0000
1.2 +++ b/browser/experiments/test/xpcshell/test_telemetry.js Wed Dec 31 06:09:35 2014 +0100
1.3 @@ -0,0 +1,334 @@
1.4 +/* Any copyright is dedicated to the Public Domain.
1.5 + * http://creativecommons.org/publicdomain/zero/1.0/ */
1.6 +
1.7 +"use strict";
1.8 +
1.9 +Cu.import("resource://testing-common/httpd.js");
1.10 +Cu.import("resource://gre/modules/TelemetryLog.jsm");
1.11 +let bsp = Cu.import("resource:///modules/experiments/Experiments.jsm");
1.12 +
1.13 +
1.14 +const FILE_MANIFEST = "experiments.manifest";
1.15 +const MANIFEST_HANDLER = "manifests/handler";
1.16 +
1.17 +const SEC_IN_ONE_DAY = 24 * 60 * 60;
1.18 +const MS_IN_ONE_DAY = SEC_IN_ONE_DAY * 1000;
1.19 +
1.20 +
1.21 +let gProfileDir = null;
1.22 +let gHttpServer = null;
1.23 +let gHttpRoot = null;
1.24 +let gDataRoot = null;
1.25 +let gReporter = null;
1.26 +let gPolicy = null;
1.27 +let gManifestObject = null;
1.28 +let gManifestHandlerURI = null;
1.29 +
1.30 +const TLOG = bsp.TELEMETRY_LOG;
1.31 +
1.32 +let gGlobalScope = this;
1.33 +function loadAddonManager() {
1.34 + let ns = {};
1.35 + Cu.import("resource://gre/modules/Services.jsm", ns);
1.36 + let head = "../../../../toolkit/mozapps/extensions/test/xpcshell/head_addons.js";
1.37 + let file = do_get_file(head);
1.38 + let uri = ns.Services.io.newFileURI(file);
1.39 + ns.Services.scriptloader.loadSubScript(uri.spec, gGlobalScope);
1.40 + createAppInfo("xpcshell@tests.mozilla.org", "XPCShell", "1", "1.9.2");
1.41 + startupManager();
1.42 +}
1.43 +
1.44 +function checkEvent(event, id, data)
1.45 +{
1.46 + do_print("Checking message " + id);
1.47 + Assert.equal(event[0], id, "id should match");
1.48 + Assert.ok(event[1] > 0, "timestamp should be greater than 0");
1.49 +
1.50 + if (data === undefined) {
1.51 + Assert.equal(event.length, 2, "event array should have 2 entries");
1.52 + } else {
1.53 + Assert.equal(event.length, data.length + 2, "event entry count should match expected count");
1.54 + for (var i = 0; i < data.length; ++i) {
1.55 + Assert.equal(typeof(event[i + 2]), "string", "event entry should be a string");
1.56 + Assert.equal(event[i + 2], data[i], "event entry should match expected entry");
1.57 + }
1.58 + }
1.59 +}
1.60 +
1.61 +function run_test() {
1.62 + run_next_test();
1.63 +}
1.64 +
1.65 +add_task(function* test_setup() {
1.66 + loadAddonManager();
1.67 + gProfileDir = do_get_profile();
1.68 +
1.69 + gHttpServer = new HttpServer();
1.70 + gHttpServer.start(-1);
1.71 + let port = gHttpServer.identity.primaryPort;
1.72 + gHttpRoot = "http://localhost:" + port + "/";
1.73 + gDataRoot = gHttpRoot + "data/";
1.74 + gManifestHandlerURI = gHttpRoot + MANIFEST_HANDLER;
1.75 + gHttpServer.registerDirectory("/data/", do_get_cwd());
1.76 + gHttpServer.registerPathHandler("/" + MANIFEST_HANDLER, (request, response) => {
1.77 + response.setStatusLine(null, 200, "OK");
1.78 + response.write(JSON.stringify(gManifestObject));
1.79 + response.processAsync();
1.80 + response.finish();
1.81 + });
1.82 + do_register_cleanup(() => gHttpServer.stop(() => {}));
1.83 +
1.84 + disableCertificateChecks();
1.85 +
1.86 + Services.prefs.setBoolPref(PREF_EXPERIMENTS_ENABLED, true);
1.87 + Services.prefs.setIntPref(PREF_LOGGING_LEVEL, 0);
1.88 + Services.prefs.setBoolPref(PREF_LOGGING_DUMP, true);
1.89 + Services.prefs.setCharPref(PREF_MANIFEST_URI, gManifestHandlerURI);
1.90 + Services.prefs.setIntPref(PREF_FETCHINTERVAL, 0);
1.91 +
1.92 + gReporter = yield getReporter("json_payload_simple");
1.93 + yield gReporter.collectMeasurements();
1.94 + let payload = yield gReporter.getJSONPayload(true);
1.95 + do_register_cleanup(() => gReporter._shutdown());
1.96 +
1.97 + gPolicy = new Experiments.Policy();
1.98 + let dummyTimer = { cancel: () => {}, clear: () => {} };
1.99 + patchPolicy(gPolicy, {
1.100 + updatechannel: () => "nightly",
1.101 + healthReportPayload: () => Promise.resolve(payload),
1.102 + oneshotTimer: (callback, timeout, thisObj, name) => dummyTimer,
1.103 + });
1.104 +
1.105 + yield removeCacheFile();
1.106 +});
1.107 +
1.108 +// Test basic starting and stopping of experiments.
1.109 +
1.110 +add_task(function* test_telemetryBasics() {
1.111 + // Check TelemetryLog instead of TelemetryPing.getPayload().log because
1.112 + // TelemetryPing gets Experiments.instance() and side-effects log entries.
1.113 +
1.114 + const OBSERVER_TOPIC = "experiments-changed";
1.115 + let observerFireCount = 0;
1.116 + let expectedLogLength = 0;
1.117 +
1.118 + // Dates the following tests are based on.
1.119 +
1.120 + let baseDate = new Date(2014, 5, 1, 12);
1.121 + let startDate1 = futureDate(baseDate, 50 * MS_IN_ONE_DAY);
1.122 + let endDate1 = futureDate(baseDate, 100 * MS_IN_ONE_DAY);
1.123 + let startDate2 = futureDate(baseDate, 150 * MS_IN_ONE_DAY);
1.124 + let endDate2 = futureDate(baseDate, 200 * MS_IN_ONE_DAY);
1.125 +
1.126 + // The manifest data we test with.
1.127 +
1.128 + gManifestObject = {
1.129 + "version": 1,
1.130 + experiments: [
1.131 + {
1.132 + id: EXPERIMENT1_ID,
1.133 + xpiURL: gDataRoot + EXPERIMENT1_XPI_NAME,
1.134 + xpiHash: EXPERIMENT1_XPI_SHA1,
1.135 + startTime: dateToSeconds(startDate1),
1.136 + endTime: dateToSeconds(endDate1),
1.137 + maxActiveSeconds: 10 * SEC_IN_ONE_DAY,
1.138 + appName: ["XPCShell"],
1.139 + channel: ["nightly"],
1.140 + },
1.141 + {
1.142 + id: EXPERIMENT2_ID,
1.143 + xpiURL: gDataRoot + EXPERIMENT2_XPI_NAME,
1.144 + xpiHash: EXPERIMENT2_XPI_SHA1,
1.145 + startTime: dateToSeconds(startDate2),
1.146 + endTime: dateToSeconds(endDate2),
1.147 + maxActiveSeconds: 10 * SEC_IN_ONE_DAY,
1.148 + appName: ["XPCShell"],
1.149 + channel: ["nightly"],
1.150 + },
1.151 + ],
1.152 + };
1.153 +
1.154 + // Data to compare the result of Experiments.getExperiments() against.
1.155 +
1.156 + let experimentListData = [
1.157 + {
1.158 + id: EXPERIMENT2_ID,
1.159 + name: "Test experiment 2",
1.160 + description: "And yet another experiment that experiments experimentally.",
1.161 + },
1.162 + {
1.163 + id: EXPERIMENT1_ID,
1.164 + name: EXPERIMENT1_NAME,
1.165 + description: "Yet another experiment that experiments experimentally.",
1.166 + },
1.167 + ];
1.168 +
1.169 + let experiments = new Experiments.Experiments(gPolicy);
1.170 +
1.171 + // Trigger update, clock set to before any activation.
1.172 + // Use updateManifest() to provide for coverage of that path.
1.173 +
1.174 + let now = baseDate;
1.175 + defineNow(gPolicy, now);
1.176 +
1.177 + yield experiments.updateManifest();
1.178 + let list = yield experiments.getExperiments();
1.179 + Assert.equal(list.length, 0, "Experiment list should be empty.");
1.180 +
1.181 + expectedLogLength += 2;
1.182 + let log = TelemetryLog.entries();
1.183 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.184 + checkEvent(log[log.length-2], TLOG.ACTIVATION_KEY,
1.185 + [TLOG.ACTIVATION.REJECTED, EXPERIMENT1_ID, "startTime"]);
1.186 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.187 + [TLOG.ACTIVATION.REJECTED, EXPERIMENT2_ID, "startTime"]);
1.188 +
1.189 + // Trigger update, clock set for experiment 1 to start.
1.190 +
1.191 + now = futureDate(startDate1, 5 * MS_IN_ONE_DAY);
1.192 + defineNow(gPolicy, now);
1.193 +
1.194 + yield experiments.updateManifest();
1.195 + list = yield experiments.getExperiments();
1.196 + Assert.equal(list.length, 1, "Experiment list should have 1 entry now.");
1.197 +
1.198 + expectedLogLength += 1;
1.199 + log = TelemetryLog.entries();
1.200 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries. Got " + log.toSource());
1.201 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.202 + [TLOG.ACTIVATION.ACTIVATED, EXPERIMENT1_ID]);
1.203 +
1.204 + // Trigger update, clock set for experiment 1 to stop.
1.205 +
1.206 + now = futureDate(endDate1, 1000);
1.207 + defineNow(gPolicy, now);
1.208 +
1.209 + yield experiments.updateManifest();
1.210 + list = yield experiments.getExperiments();
1.211 + Assert.equal(list.length, 1, "Experiment list should have 1 entry.");
1.212 +
1.213 + expectedLogLength += 2;
1.214 + log = TelemetryLog.entries();
1.215 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.216 + checkEvent(log[log.length-2], TLOG.TERMINATION_KEY,
1.217 + [TLOG.TERMINATION.EXPIRED, EXPERIMENT1_ID]);
1.218 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.219 + [TLOG.ACTIVATION.REJECTED, EXPERIMENT2_ID, "startTime"]);
1.220 +
1.221 + // Trigger update, clock set for experiment 2 to start with invalid hash.
1.222 +
1.223 + now = startDate2;
1.224 + defineNow(gPolicy, now);
1.225 + gManifestObject.experiments[1].xpiHash = "sha1:0000000000000000000000000000000000000000";
1.226 +
1.227 + yield experiments.updateManifest();
1.228 + list = yield experiments.getExperiments();
1.229 + Assert.equal(list.length, 1, "Experiment list should have 1 entries.");
1.230 +
1.231 + expectedLogLength += 1;
1.232 + log = TelemetryLog.entries();
1.233 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.234 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.235 + [TLOG.ACTIVATION.INSTALL_FAILURE, EXPERIMENT2_ID]);
1.236 +
1.237 + // Trigger update, clock set for experiment 2 to properly start now.
1.238 +
1.239 + now = futureDate(now, MS_IN_ONE_DAY);
1.240 + defineNow(gPolicy, now);
1.241 + gManifestObject.experiments[1].xpiHash = EXPERIMENT2_XPI_SHA1;
1.242 +
1.243 + yield experiments.updateManifest();
1.244 + list = yield experiments.getExperiments();
1.245 + Assert.equal(list.length, 2, "Experiment list should have 2 entries.");
1.246 +
1.247 + expectedLogLength += 1;
1.248 + log = TelemetryLog.entries();
1.249 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.250 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.251 + [TLOG.ACTIVATION.ACTIVATED, EXPERIMENT2_ID]);
1.252 +
1.253 + // Fake user uninstall of experiment via add-on manager.
1.254 +
1.255 + now = futureDate(now, MS_IN_ONE_DAY);
1.256 + defineNow(gPolicy, now);
1.257 +
1.258 + yield experiments.disableExperiment(TLOG.TERMINATION.ADDON_UNINSTALLED);
1.259 + list = yield experiments.getExperiments();
1.260 + Assert.equal(list.length, 2, "Experiment list should have 2 entries.");
1.261 +
1.262 + expectedLogLength += 1;
1.263 + log = TelemetryLog.entries();
1.264 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.265 + checkEvent(log[log.length-1], TLOG.TERMINATION_KEY,
1.266 + [TLOG.TERMINATION.ADDON_UNINSTALLED, EXPERIMENT2_ID]);
1.267 +
1.268 + // Trigger update with experiment 1a ready to start.
1.269 +
1.270 + now = futureDate(now, MS_IN_ONE_DAY);
1.271 + defineNow(gPolicy, now);
1.272 + gManifestObject.experiments[0].id = EXPERIMENT3_ID;
1.273 + gManifestObject.experiments[0].endTime = dateToSeconds(futureDate(now, 50 * MS_IN_ONE_DAY));
1.274 +
1.275 + yield experiments.updateManifest();
1.276 + list = yield experiments.getExperiments();
1.277 + Assert.equal(list.length, 3, "Experiment list should have 3 entries.");
1.278 +
1.279 + expectedLogLength += 1;
1.280 + log = TelemetryLog.entries();
1.281 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.282 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.283 + [TLOG.ACTIVATION.ACTIVATED, EXPERIMENT3_ID]);
1.284 +
1.285 + // Trigger disable of an experiment via the API.
1.286 +
1.287 + now = futureDate(now, MS_IN_ONE_DAY);
1.288 + defineNow(gPolicy, now);
1.289 +
1.290 + yield experiments.disableExperiment(TLOG.TERMINATION.FROM_API);
1.291 + list = yield experiments.getExperiments();
1.292 + Assert.equal(list.length, 3, "Experiment list should have 3 entries.");
1.293 +
1.294 + expectedLogLength += 1;
1.295 + log = TelemetryLog.entries();
1.296 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.297 + checkEvent(log[log.length-1], TLOG.TERMINATION_KEY,
1.298 + [TLOG.TERMINATION.FROM_API, EXPERIMENT3_ID]);
1.299 +
1.300 + // Trigger update with experiment 1a ready to start.
1.301 +
1.302 + now = futureDate(now, MS_IN_ONE_DAY);
1.303 + defineNow(gPolicy, now);
1.304 + gManifestObject.experiments[0].id = EXPERIMENT4_ID;
1.305 + gManifestObject.experiments[0].endTime = dateToSeconds(futureDate(now, 50 * MS_IN_ONE_DAY));
1.306 +
1.307 + yield experiments.updateManifest();
1.308 + list = yield experiments.getExperiments();
1.309 + Assert.equal(list.length, 4, "Experiment list should have 4 entries.");
1.310 +
1.311 + expectedLogLength += 1;
1.312 + log = TelemetryLog.entries();
1.313 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.314 + checkEvent(log[log.length-1], TLOG.ACTIVATION_KEY,
1.315 + [TLOG.ACTIVATION.ACTIVATED, EXPERIMENT4_ID]);
1.316 +
1.317 + // Trigger experiment termination by something other than expiry via the manifest.
1.318 +
1.319 + now = futureDate(now, MS_IN_ONE_DAY);
1.320 + defineNow(gPolicy, now);
1.321 + gManifestObject.experiments[0].os = "Plan9";
1.322 +
1.323 + yield experiments.updateManifest();
1.324 + list = yield experiments.getExperiments();
1.325 + Assert.equal(list.length, 4, "Experiment list should have 4 entries.");
1.326 +
1.327 + expectedLogLength += 1;
1.328 + log = TelemetryLog.entries();
1.329 + Assert.equal(log.length, expectedLogLength, "Telemetry log should have " + expectedLogLength + " entries.");
1.330 + checkEvent(log[log.length-1], TLOG.TERMINATION_KEY,
1.331 + [TLOG.TERMINATION.RECHECK, EXPERIMENT4_ID, "os"]);
1.332 +
1.333 + // Cleanup.
1.334 +
1.335 + yield experiments.uninit();
1.336 + yield removeCacheFile();
1.337 +});
