Bug 827157 - Robust and performance sensitive recording of sessions; r=rnewman

We have introduced a new background service that captures session state
in preferences. Firefox Health Report now moves entries from preferences
to its database at payload generation time.

We've also introduced a few random APIs, such as enqueueTransaction()
and the ability for providers to have access to their own pref branch.
This commit is contained in:
Gregory Szorc 2013-01-18 22:35:07 -08:00
Родитель 3f91b9e564
Коммит a5c78091d3
14 изменённых файлов: 843 добавлений и 338 удалений

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

@ -7,13 +7,16 @@
const {classes: Cc, interfaces: Ci, utils: Cu} = Components;
Cu.import("resource://gre/modules/services/datareporting/policy.jsm");
Cu.import("resource://gre/modules/services/datareporting/sessions.jsm");
Cu.import("resource://gre/modules/XPCOMUtils.jsm");
Cu.import("resource://services-common/observers.js");
Cu.import("resource://services-common/preferences.js");
Cu.import("resource://services-common/utils.js");
const ROOT_BRANCH = "datareporting.";
const POLICY_BRANCH = ROOT_BRANCH + "policy.";
const SESSIONS_BRANCH = ROOT_BRANCH + "sessions.";
const HEALTHREPORT_BRANCH = ROOT_BRANCH + "healthreport.";
const HEALTHREPORT_LOGGING_BRANCH = HEALTHREPORT_BRANCH + "logging.";
const DEFAULT_LOAD_DELAY_MSEC = 10 * 1000;
@ -106,16 +109,38 @@ DataReportingService.prototype = Object.freeze({
this._os.removeObserver(this, "profile-after-change");
this._os.addObserver(this, "sessionstore-windows-restored", true);
this._prefs = new Preferences(HEALTHREPORT_BRANCH);
// We don't initialize the sessions recorder unless Health Report is
// around to provide pruning of data.
//
// FUTURE consider having the SessionsRecorder always enabled and/or
// living in its own XPCOM service.
if (this._prefs.get("service.enabled", true)) {
this.sessionRecorder = new SessionRecorder(SESSIONS_BRANCH);
this.sessionRecorder.onStartup();
}
// We can't interact with prefs until after the profile is present.
let policyPrefs = new Preferences(POLICY_BRANCH);
this._prefs = new Preferences(HEALTHREPORT_BRANCH);
this.policy = new DataReportingPolicy(policyPrefs, this._prefs, this);
break;
case "sessionstore-windows-restored":
this._os.removeObserver(this, "sessionstore-windows-restored");
this._os.addObserver(this, "quit-application", false);
// When the session recorder starts up above, first paint and session
// restore times likely aren't available. So, we wait until they are (here)
// and record them. In the case of session restore time, that appears
// to be set by an observer of this notification. So, we delay
// recording until the next tick of the event loop.
if (this.sessionRecorder) {
CommonUtils.nextTick(this.sessionRecorder.recordStartupFields,
this.sessionRecorder);
}
this.policy.startPolling();
// Don't initialize Firefox Health Reporter collection and submission
@ -225,7 +250,8 @@ DataReportingService.prototype = Object.freeze({
// The reporter initializes in the background.
this._healthReporter = new ns.HealthReporter(HEALTHREPORT_BRANCH,
this.policy);
this.policy,
this.sessionRecorder);
},
});

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

@ -11,7 +11,7 @@ include $(DEPTH)/config/autoconf.mk
TEST_DIRS += tests
MODULES_FILES := policy.jsm
MODULES_FILES := policy.jsm sessions.jsm
MODULES_DEST = $(FINAL_TARGET)/modules/services/datareporting
INSTALL_TARGETS += MODULES

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

@ -0,0 +1,358 @@
/* 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 = [
"SessionRecorder",
];
const {classes: Cc, interfaces: Ci, utils: Cu} = Components;
Cu.import("resource://gre/modules/XPCOMUtils.jsm");
Cu.import("resource://services-common/log4moz.js");
Cu.import("resource://services-common/preferences.js");
Cu.import("resource://services-common/utils.js");
// We automatically prune sessions older than this.
const MAX_SESSION_AGE_MS = 7 * 24 * 60 * 60 * 1000; // 7 days.
/**
* Records information about browser sessions.
*
* This serves as an interface to both current session information as
* well as a history of previous sessions.
*
* Typically only one instance of this will be installed in an
* application. It is typically managed by an XPCOM service. The
* instance is instantiated at application start; onStartup is called
* once the profile is installed; onShutdown is called during shutdown.
*
* We currently record state in preferences. However, this should be
* invisible to external consumers. We could easily swap in a different
* storage mechanism if desired.
*
* Please note the different semantics for storing times and dates in
* preferences. Full dates (notably the session start time) are stored
* as strings because preferences have a 32-bit limit on integer values
* and milliseconds since UNIX epoch would overflow. Many times are
* stored as integer offsets from the session start time because they
* should not overflow 32 bits.
*
* Since this records history of all sessions, there is a possibility
* for unbounded data aggregation. This is curtailed through:
*
* 1) An "idle-daily" observer which delete sessions older than
* MAX_SESSION_AGE_MS.
* 2) The creator of this instance explicitly calling
* `pruneOldSessions`.
*
* @param branch
* (string) Preferences branch on which to record state.
*/
this.SessionRecorder = function (branch) {
if (!branch) {
throw new Error("branch argument must be defined.");
}
if (!branch.endsWith(".")) {
throw new Error("branch argument must end with '.': " + branch);
}
this._log = Log4Moz.repository.getLogger("Services.DataReporting.SessionRecorder");
this._prefs = new Preferences(branch);
this._lastActivityWasInactive = false;
this._activeTicks = 0;
this._started = false;
this._os = Cc["@mozilla.org/observer-service;1"]
.getService(Ci.nsIObserverService);
};
SessionRecorder.prototype = Object.freeze({
QueryInterface: XPCOMUtils.generateQI([Ci.nsIObserver]),
get _currentIndex() {
return this._prefs.get("currentIndex", 0);
},
set _currentIndex(value) {
this._prefs.set("currentIndex", value);
},
get _prunedIndex() {
return this._prefs.get("prunedIndex", 0);
},
set _prunedIndex(value) {
this._prefs.set("prunedIndex", value);
},
get startDate() {
return CommonUtils.getDatePref(this._prefs, "current.startTime");
},
set _startDate(value) {
CommonUtils.setDatePref(this._prefs, "current.startTime", value);
},
get activeTicks() {
return this._prefs.get("current.activeTicks", 0);
},
incrementActiveTicks: function () {
this._prefs.set("current.activeTicks", ++this._activeTicks);
},
get totalTime() {
return this._prefs.get("current.totalTime", 0);
},
updateTotalTime: function () {
this._prefs.set("current.totalTime", Date.now() - this.startDate);
},
get main() {
return this._prefs.get("current.main", -1);
},
set _main(value) {
if (!Number.isInteger(value)) {
throw new Error("main time must be an integer.");
}
this._prefs.set("current.main", value);
},
get firstPaint() {
return this._prefs.get("current.firstPaint", -1);
},
set _firstPaint(value) {
if (!Number.isInteger(value)) {
throw new Error("firstPaint must be an integer.");
}
this._prefs.set("current.firstPaint", value);
},
get sessionRestored() {
return this._prefs.get("current.sessionRestored", -1);
},
set _sessionRestored(value) {
if (!Number.isInteger(value)) {
throw new Error("sessionRestored must be an integer.");
}
this._prefs.set("current.sessionRestored", value);
},
getPreviousSessions: function () {
let result = {};
for (let i = this._prunedIndex; i < this._currentIndex; i++) {
let s = this.getPreviousSession(i);
if (!s) {
continue;
}
result[i] = s;
}
return result;
},
getPreviousSession: function (index) {
return this._deserialize(this._prefs.get("previous." + index));
},
/**
* Prunes old, completed sessions that started earlier than the
* specified date.
*/
pruneOldSessions: function (date) {
for (let i = this._prunedIndex; i < this._currentIndex; i++) {
let s = this.getPreviousSession(i);
if (!s) {
continue;
}
if (s.startDate >= date) {
continue;
}
this._log.debug("Pruning session #" + i + ".");
this._prefs.reset("previous." + i);
this._prunedIndex = i;
}
},
recordStartupFields: function () {
let si = this._getStartupInfo();
if (!si.process) {
throw new Error("Startup info not available.");
}
for (let field of ["main", "firstPaint", "sessionRestored"]) {
if (!(field in si)) {
continue;
}
this["_" + field] = si[field].getTime() - si.process.getTime();
}
},
/**
* Perform functionality on application startup.
*
* This is typically called in a "profile-do-change" handler.
*/
onStartup: function () {
if (this._started) {
throw new Error("onStartup has already been called.");
}
let si = this._getStartupInfo();
if (!si.process) {
throw new Error("Process information not available. Misconfigured app?");
}
this._started = true;
this._os.addObserver(this, "profile-before-change", false);
this._os.addObserver(this, "user-interaction-active", false);
this._os.addObserver(this, "user-interaction-inactive", false);
this._os.addObserver(this, "idle-daily", false);
// This has the side-effect of clearing current session state.
this._moveCurrentToPrevious();
this._startDate = si.process;
this._prefs.set("current.activeTicks", 0);
this.updateTotalTime();
this.recordStartupFields();
},
/**
* Record application activity.
*/
onActivity: function (active) {
let updateActive = active && !this._lastActivityWasInactive;
this._lastActivityWasInactive = !active;
this.updateTotalTime();
if (updateActive) {
this.incrementActiveTicks();
}
},
onShutdown: function () {
this._log.info("Recording clean session shutdown.");
this._prefs.set("current.clean", true);
this.updateTotalTime();
this._os.removeObserver(this, "profile-before-change");
this._os.removeObserver(this, "user-interaction-active");
this._os.removeObserver(this, "user-interaction-inactive");
this._os.removeObserver(this, "idle-daily");
},
_CURRENT_PREFS: [
"current.startTime",
"current.activeTicks",
"current.totalTime",
"current.main",
"current.firstPaint",
"current.sessionRestored",
"current.clean",
],
// This is meant to be called only during onStartup().
_moveCurrentToPrevious: function () {
try {
if (!this.startDate.getTime()) {
this._log.info("No previous session. Is this first app run?");
return;
}
let clean = this._prefs.get("current.clean", false);
let count = this._currentIndex++;
let obj = {
s: this.startDate.getTime(),
a: this.activeTicks,
t: this.totalTime,
c: clean,
m: this.main,
fp: this.firstPaint,
sr: this.sessionRestored,
};
this._log.debug("Recording last sessions as #" + count + ".");
this._prefs.set("previous." + count, JSON.stringify(obj));
} catch (ex) {
this._log.warn("Exception when migrating last session: " +
CommonUtils.exceptionStr(ex));
} finally {
this._log.debug("Resetting prefs from last session.");
for (let pref of this._CURRENT_PREFS) {
this._prefs.reset(pref);
}
}
},
_deserialize: function (s) {
let o;
try {
o = JSON.parse(s);
} catch (ex) {
return null;
}
return {
startDate: new Date(o.s),
activeTicks: o.a,
totalTime: o.t,
clean: !!o.c,
main: o.m,
firstPaint: o.fp,
sessionRestored: o.sr,
};
},
// Implemented as a function to allow for monkeypatching in tests.
_getStartupInfo: function () {
return Cc["@mozilla.org/toolkit/app-startup;1"]
.getService(Ci.nsIAppStartup)
.getStartupInfo();
},
observe: function (subject, topic, data) {
switch (topic) {
case "profile-before-change":
this.onShutdown();
break;
case "user-interaction-active":
this.onActivity(true);
break;
case "user-interaction-inactive":
this.onActivity(false);
break;
case "idle-daily":
this.pruneOldSessions(new Date(Date.now() - MAX_SESSION_AGE_MS));
break;
}
},
});

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

@ -0,0 +1,16 @@
/* Any copyright is dedicated to the Public Domain.
* http://creativecommons.org/publicdomain/zero/1.0/ */
"use strict";
// We need to initialize the profile or OS.File may not work. See bug 810543.
do_get_profile();
(function initTestingInfrastructure() {
let ns = {};
Components.utils.import("resource://testing-common/services-common/logging.js",
ns);
ns.initTestLogging();
}).call(this);

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

@ -0,0 +1,222 @@
/* Any copyright is dedicated to the Public Domain.
* http://creativecommons.org/publicdomain/zero/1.0/ */
"use strict";
const {utils: Cu} = Components;
Cu.import("resource://gre/modules/commonjs/promise/core.js");
Cu.import("resource://gre/modules/services/datareporting/sessions.jsm");
Cu.import("resource://gre/modules/Services.jsm");
Cu.import("resource://services-common/utils.js");
function run_test() {
run_next_test();
}
function monkeypatchStartupInfo(recorder, start=new Date(), offset=500) {
Object.defineProperty(recorder, "_getStartupInfo", {
value: function _getStartupInfo() {
return {
process: start,
main: new Date(start.getTime() + offset),
firstPaint: new Date(start.getTime() + 2 * offset),
sessionRestored: new Date(start.getTime() + 3 * offset),
};
}
});
}
function sleep(wait) {
let deferred = Promise.defer();
let timer = CommonUtils.namedTimer(function onTimer() {
deferred.resolve();
}, wait, deferred.promise, "_sleepTimer");
return deferred.promise;
}
function getRecorder(name, start, offset) {
let recorder = new SessionRecorder("testing." + name + ".");
monkeypatchStartupInfo(recorder, start, offset);
return recorder;
}
add_test(function test_basic() {
let recorder = getRecorder("basic");
recorder.onStartup();
recorder.onShutdown();
run_next_test();
});
add_task(function test_current_properties() {
let now = new Date();
let recorder = getRecorder("current_properties", now);
yield sleep(25);
recorder.onStartup();
do_check_eq(recorder.startDate.getTime(), now.getTime());
do_check_eq(recorder.activeTicks, 0);
do_check_true(recorder.totalTime > 0);
do_check_eq(recorder.main, 500);
do_check_eq(recorder.firstPaint, 1000);
do_check_eq(recorder.sessionRestored, 1500);
recorder.incrementActiveTicks();
do_check_eq(recorder.activeTicks, 1);
recorder.onShutdown();
});
add_task(function test_previous_clean() {
let now = new Date();
let recorder = getRecorder("previous_clean", now);
yield sleep(25);
recorder.onStartup();
recorder.incrementActiveTicks();
recorder.incrementActiveTicks();
yield sleep(25);
recorder.onShutdown();
let total = recorder.totalTime;
yield sleep(25);
let now2 = new Date();
let recorder2 = getRecorder("previous_clean", now2, 100);
yield sleep(25);
recorder2.onStartup();
do_check_eq(recorder2.startDate.getTime(), now2.getTime());
do_check_eq(recorder2.main, 100);
do_check_eq(recorder2.firstPaint, 200);
do_check_eq(recorder2.sessionRestored, 300);
let sessions = recorder2.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 1);
do_check_true(0 in sessions);
let session = sessions[0];
do_check_true(session.clean);
do_check_eq(session.startDate.getTime(), now.getTime());
do_check_eq(session.main, 500);
do_check_eq(session.firstPaint, 1000);
do_check_eq(session.sessionRestored, 1500);
do_check_eq(session.totalTime, total);
do_check_eq(session.activeTicks, 2);
recorder2.onShutdown();
});
add_task(function test_previous_abort() {
let now = new Date();
let recorder = getRecorder("previous_abort", now);
yield sleep(25);
recorder.onStartup();
recorder.incrementActiveTicks();
yield sleep(25);
let total = recorder.totalTime;
yield sleep(25);
let now2 = new Date();
let recorder2 = getRecorder("previous_abort", now2);
yield sleep(25);
recorder2.onStartup();
let sessions = recorder2.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 1);
do_check_true(0 in sessions);
let session = sessions[0];
do_check_false(session.clean);
do_check_eq(session.totalTime, total);
recorder.onShutdown();
recorder2.onShutdown();
});
add_task(function test_multiple_sessions() {
for (let i = 0; i < 10; i++) {
let recorder = getRecorder("multiple_sessions");
yield sleep(25);
recorder.onStartup();
for (let j = 0; j < i; j++) {
recorder.incrementActiveTicks();
}
yield sleep(25);
recorder.onShutdown();
yield sleep(25);
}
let recorder = getRecorder("multiple_sessions");
recorder.onStartup();
let sessions = recorder.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 10);
for (let [i, session] in Iterator(sessions)) {
do_check_eq(session.activeTicks, i);
if (i > 0) {
do_check_true(session.startDate.getTime() > sessions[i-1].startDate.getTime());
}
}
// #6 is preserved since >=.
let threshold = sessions[6].startDate;
recorder.pruneOldSessions(threshold);
sessions = recorder.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 4);
recorder.pruneOldSessions(threshold);
sessions = recorder.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 4);
do_check_eq(recorder._prunedIndex, 5);
recorder.onShutdown();
});
add_task(function test_record_activity() {
let recorder = getRecorder("record_activity");
yield sleep(25);
recorder.onStartup();
let total = recorder.totalTime;
yield sleep(25);
for (let i = 0; i < 3; i++) {
Services.obs.notifyObservers(null, "user-interaction-active", null);
yield sleep(25);
do_check_true(recorder.totalTime > total);
total = recorder.totalTime;
}
do_check_eq(recorder.activeTicks, 3);
// Now send inactive. We should increment total time but not active.
Services.obs.notifyObservers(null, "user-interaction-inactive", null);
do_check_eq(recorder.activeTicks, 3);
do_check_true(recorder.totalTime > total);
total = recorder.totalTime;
yield sleep(25);
// If we send active again, this should be counted as inactive.
Services.obs.notifyObservers(null, "user-interaction-active", null);
do_check_eq(recorder.activeTicks, 3);
do_check_true(recorder.totalTime > total);
total = recorder.totalTime;
yield sleep(25);
// If we send active again, this should be counted as active.
Services.obs.notifyObservers(null, "user-interaction-active", null);
do_check_eq(recorder.activeTicks, 4);
Services.obs.notifyObservers(null, "user-interaction-active", null);
do_check_eq(recorder.activeTicks, 5);
recorder.onShutdown();
});

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

@ -1,5 +1,6 @@
[DEFAULT]
head =
head = head.js
tail =
[test_policy.js]
[test_session_recorder.js]

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

@ -83,7 +83,7 @@ const DEFAULT_DATABASE_NAME = "healthreport.sqlite";
* @param policy
* (HealthReportPolicy) Policy driving execution of HealthReporter.
*/
function HealthReporter(branch, policy) {
function HealthReporter(branch, policy, sessionRecorder) {
if (!branch.endsWith(".")) {
throw new Error("Branch must end with a period (.): " + branch);
}
@ -95,6 +95,7 @@ function HealthReporter(branch, policy) {
this._log = Log4Moz.repository.getLogger("Services.HealthReport.HealthReporter");
this._log.info("Initializing health reporter instance against " + branch);
this._branch = branch;
this._prefs = new Preferences(branch);
if (!this.serverURI) {
@ -106,6 +107,7 @@ function HealthReporter(branch, policy) {
}
this._policy = policy;
this.sessionRecorder = sessionRecorder;
this._dbName = this._prefs.get("dbName") || DEFAULT_DATABASE_NAME;
@ -539,6 +541,8 @@ HealthReporter.prototype = Object.freeze({
Cu.import(uri, ns);
let provider = new ns[entry]();
provider.initPreferences(this._branch + "provider.");
provider.healthReporter = this;
promises.push(this.registerProvider(provider));
} catch (ex) {
this._log.warn("Error registering provider from category manager: " +

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

@ -355,6 +355,8 @@ SysInfoProvider.prototype = Object.freeze({
*
* The fields within the current session are moved to daily session fields when
* the application is shut down.
*
* This measurement is backed by the SessionRecorder, not the database.
*/
function CurrentSessionMeasurement() {
Metrics.Measurement.call(this);
@ -364,36 +366,34 @@ CurrentSessionMeasurement.prototype = Object.freeze({
__proto__: Metrics.Measurement.prototype,
name: "current",
version: 1,
LAST_NUMERIC_FIELDS: [
// Day on which the session was started.
// This is used to determine which day the record will be moved under when
// moved to daily sessions.
"startDay",
// Time in milliseconds the session was active for.
"activeTime",
// Total time in milliseconds of the session.
"totalTime",
// Startup times, in milliseconds.
"main",
"firstPaint",
"sessionRestored",
],
version: 2,
configureStorage: function () {
return Task.spawn(function configureStorage() {
for (let field of this.LAST_NUMERIC_FIELDS) {
yield this.registerStorageField(field, this.storage.FIELD_LAST_NUMERIC);
}
}.bind(this));
return Promise.resolve();
},
/**
* All data is stored in prefs, so we have a custom implementation.
*/
getValues: function () {
let sessions = this.provider.healthReporter.sessionRecorder;
let fields = new Map();
let now = new Date();
fields.set("startDay", [now, Metrics.dateToDays(sessions.startDate)]);
fields.set("activeTicks", [now, sessions.activeTicks]);
fields.set("totalTime", [now, sessions.totalTime]);
fields.set("main", [now, sessions.main]);
fields.set("firstPaint", [now, sessions.firstPaint]);
fields.set("sessionRestored", [now, sessions.sessionRestored]);
return Promise.resolve({
days: new Metrics.DailyValues(),
singular: fields,
});
},
});
/**
* Records a history of all application sessions.
*/
@ -405,15 +405,15 @@ PreviousSessionsMeasurement.prototype = Object.freeze({
__proto__: Metrics.Measurement.prototype,
name: "previous",
version: 1,
version: 2,
DAILY_DISCRETE_NUMERIC_FIELDS: [
// Milliseconds of sessions that were properly shut down.
"cleanActiveTime",
"cleanActiveTicks",
"cleanTotalTime",
// Milliseconds of sessions that were not properly shut down.
"abortedActiveTime",
"abortedActiveTicks",
"abortedTotalTime",
// Startup times in milliseconds.
@ -453,11 +453,6 @@ PreviousSessionsMeasurement.prototype = Object.freeze({
*/
this.SessionsProvider = function () {
Metrics.Provider.call(this);
this._startDate = null;
this._currentActiveTime = null;
this._lastActivityDate = null;
this._lastActivityWasInactive = false;
};
SessionsProvider.prototype = Object.freeze({
@ -467,183 +462,32 @@ SessionsProvider.prototype = Object.freeze({
measurementTypes: [CurrentSessionMeasurement, PreviousSessionsMeasurement],
_OBSERVERS: ["user-interaction-active", "user-interaction-inactive"],
collectConstantData: function () {
let previous = this.getMeasurement("previous", 2);
onInit: function () {
return Task.spawn(this._onInit.bind(this));
return this.storage.enqueueTransaction(this._recordAndPruneSessions.bind(this));
},
_onInit: function () {
// We could cross day boundary between the application started and when
// this code is called. Meh.
let now = new Date();
this._startDate = now;
let current = this.getMeasurement("current", 1);
_recordAndPruneSessions: function () {
this._log.info("Moving previous sessions from session recorder to storage.");
let recorder = this.healthReporter.sessionRecorder;
let sessions = recorder.getPreviousSessions();
this._log.debug("Found " + Object.keys(sessions).length + " previous sessions.");
// Initialization occurs serially so we don't need to enqueue
// storage operations.
let currentData = yield this.storage.getMeasurementLastValuesFromMeasurementID(current.id);
let daily = this.getMeasurement("previous", 2);
// Normal shutdown should purge all data for this measurement. If
// there is data here, the session was aborted.
if (currentData.size) {
this._log.info("Data left over from old session. Counting as aborted.");
yield Task.spawn(this._moveCurrentToDaily.bind(this, currentData, true));
}
for each (let session in sessions) {
let type = session.clean ? "clean" : "aborted";
let date = session.startDate;
yield daily.addDailyDiscreteNumeric(type + "ActiveTicks", session.activeTicks, date);
yield daily.addDailyDiscreteNumeric(type + "TotalTime", session.totalTime, date);
this._currentActiveTime = 0;
this._lastActivityDate = now;
this._log.debug("Registering new/current session.");
yield current.setLastNumeric("activeTime", 0, now);
yield current.setLastNumeric("totalTime", 0, now);
yield current.setLastNumeric("startDay", this._dateToDays(now), now);
let si = this._getStartupInfo();
for (let field of ["main", "firstPaint", "sessionRestored"]) {
if (!(field in si)) {
continue;
for (let field of ["main", "firstPaint", "sessionRestored"]) {
yield daily.addDailyDiscreteNumeric(field, session[field], date);
}
// si.process is the Date when the process actually started.
let value = si[field] - si.process;
yield current.setLastNumeric(field, value, now);
}
for (let channel of this._OBSERVERS) {
Services.obs.addObserver(this, channel, false);
}
},
onShutdown: function () {
for (let channel of this._OBSERVERS) {
Services.obs.removeObserver(this, channel);
}
return Task.spawn(this._onShutdown.bind(this));
},
_onShutdown: function () {
this._log.debug("Recording clean shutdown.");
yield this.recordBrowserActivity(true);
let current = this.getMeasurement("current", 1);
let self = this;
yield this.enqueueStorageOperation(function doShutdown() {
return Task.spawn(function shutdownTask() {
let data = yield self.storage.getMeasurementLastValuesFromMeasurementID(current.id);
yield self._moveCurrentToDaily(data, false);
});
});
},
/**
* Record browser activity.
*
* This should be called periodically to update the stored times of how often
* the user was active with the browser.
*
* The underlying browser activity observer fires every 5 seconds if there
* is activity. If there is inactivity, it fires after 5 seconds of inactivity
* and doesn't fire again until there is activity.
*
* @param active
* (bool) Whether the browser was active or inactive.
*/
recordBrowserActivity: function (active) {
// There is potential for clock skew to result in incorrect measurements
// here. We should count ticks instead of calculating intervals.
// FUTURE count ticks not intervals.
let now = new Date();
this._log.trace("Recording browser activity. Active? " + !!active);
let m = this.getMeasurement("current", 1);
let updateActive = active && !this._lastActivityWasInactive;
this._lastActivityWasInactive = !active;
if (updateActive) {
this._currentActiveTime += now - this._lastActivityDate;
}
this._lastActivityDate = now;
let totalTime = now - this._startDate;
let activeTime = this._currentActiveTime;
return this.enqueueStorageOperation(function op() {
let promise = m.setLastNumeric("totalTime", totalTime, now);
if (!updateActive) {
return promise;
}
return m.setLastNumeric("activeTime", activeTime, now);
});
},
_moveCurrentToDaily: function (fields, aborted) {
this._log.debug("Moving current session to past. Aborted? " + aborted);
let current = this.getMeasurement("current", 1);
function clearCurrent() {
current.deleteLastNumeric("startDay");
current.deleteLastNumeric("activeTime");
current.deleteLastNumeric("totalTime");
current.deleteLastNumeric("main");
current.deleteLastNumeric("firstPaint");
return current.deleteLastNumeric("sessionRestored");
}
// We should never have incomplete values. But if we do, handle it
// gracefully.
if (!fields.has("startDay") || !fields.has("activeTime") || !fields.has("totalTime")) {
yield clearCurrent();
return;
}
let daily = this.getMeasurement("previous", 1);
let startDays = fields.get("startDay")[1];
let activeTime = fields.get("activeTime")[1];
let totalTime = fields.get("totalTime")[1];
let date = this._daysToDate(startDays);
let type = aborted ? "aborted" : "clean";
yield daily.addDailyDiscreteNumeric(type + "ActiveTime", activeTime, date);
yield daily.addDailyDiscreteNumeric(type + "TotalTime", totalTime, date);
for (let field of ["main", "firstPaint", "sessionRestored"]) {
if (!fields.has(field)) {
this._log.info(field + " field not recorded for current session.");
continue;
}
yield daily.addDailyDiscreteNumeric(field, fields.get(field)[1], date);
}
yield clearCurrent();
},
observe: function (subject, topic, data) {
switch (topic) {
case "user-interaction-active":
this.recordBrowserActivity(true);
break;
case "user-interaction-inactive":
this.recordBrowserActivity(false);
break;
}
},
// Implemented as a function to allow for monkeypatching in tests.
_getStartupInfo: function () {
return Cc["@mozilla.org/toolkit/app-startup;1"]
.getService(Ci.nsIAppStartup)
.getStartupInfo();
recorder.pruneOldSessions(new Date());
},
});

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

@ -8,9 +8,9 @@ const {utils: Cu} = Components;
Cu.import("resource://gre/modules/commonjs/promise/core.js");
Cu.import("resource://gre/modules/Metrics.jsm");
Cu.import("resource://gre/modules/Services.jsm");
Cu.import("resource://gre/modules/Task.jsm");
Cu.import("resource://gre/modules/services-common/utils.js");
Cu.import("resource://gre/modules/services/datareporting/sessions.jsm");
Cu.import("resource://gre/modules/services/healthreport/providers.jsm");
@ -27,25 +27,15 @@ add_test(function test_constructor() {
add_task(function test_init() {
let storage = yield Metrics.Storage("init");
let provider = new SessionsProvider();
provider.initPreferences("testing.init.");
yield provider.init(storage);
yield provider.shutdown();
yield storage.close();
});
function getProvider(name, now=new Date()) {
return Task.spawn(function () {
let storage = yield Metrics.Storage(name);
let provider = new SessionsProvider();
monkeypatchStartupInfo(provider, now);
yield provider.init(storage);
throw new Task.Result([provider, storage]);
});
}
function monkeypatchStartupInfo(provider, start=new Date(), offset=500) {
Object.defineProperty(provider, "_getStartupInfo", {
function monkeypatchStartupInfo(recorder, start=new Date(), offset=500) {
Object.defineProperty(recorder, "_getStartupInfo", {
value: function _getStartupInfo() {
return {
process: start,
@ -57,150 +47,114 @@ function monkeypatchStartupInfo(provider, start=new Date(), offset=500) {
});
}
add_task(function test_record_current_on_init() {
let [provider, storage] = yield getProvider("record_current_on_init");
function sleep(wait) {
let deferred = Promise.defer();
let timer = CommonUtils.namedTimer(function onTimer() {
deferred.resolve();
}, wait, deferred.promise, "_sleepTimer");
return deferred.promise;
}
function getProvider(name, now=new Date(), init=true) {
return Task.spawn(function () {
let storage = yield Metrics.Storage(name);
let provider = new SessionsProvider();
provider.initPreferences("testing." + name + ".healthreport.provider.");
let recorder = new SessionRecorder("testing." + name + ".sessions.");
monkeypatchStartupInfo(recorder, now);
provider.healthReporter = {sessionRecorder: recorder};
recorder.onStartup();
if (init) {
yield provider.init(storage);
}
throw new Task.Result([provider, storage, recorder]);
});
}
add_task(function test_current_session() {
let now = new Date();
let [provider, storage, recorder] = yield getProvider("current_session", now);
let current = provider.getMeasurement("current", 1);
yield sleep(25);
recorder.onActivity(true);
let current = provider.getMeasurement("current", 2);
let values = yield current.getValues();
let fields = values.singular;
do_check_eq(fields.size, 6);
for (let field of ["startDay", "activeTicks", "totalTime", "main", "firstPaint", "sessionRestored"]) {
do_check_true(fields.has(field));
}
do_check_eq(fields.get("startDay")[1], Metrics.dateToDays(now));
do_check_eq(fields.get("totalTime")[1], recorder.totalTime);
do_check_eq(fields.get("activeTicks")[1], 1);
do_check_eq(fields.get("main")[1], 500);
do_check_eq(fields.get("firstPaint")[1], 1000);
do_check_eq(fields.get("sessionRestored")[1], 1500);
do_check_eq(fields.get("startDay")[1], provider._dateToDays(now));
do_check_eq(fields.get("activeTime")[1], 0);
do_check_eq(fields.get("totalTime")[1], 0);
yield provider.shutdown();
yield storage.close();
});
add_task(function test_current_moved_on_shutdown() {
let [provider, storage] = yield getProvider("current_moved_on_shutdown");
add_task(function test_collect() {
let now = new Date();
let [provider, storage, recorder] = yield getProvider("collect");
let previous = provider.getMeasurement("previous", 1);
recorder.onShutdown();
yield sleep(25);
yield provider.shutdown();
// This relies on undocumented behavior of the underlying measurement not
// being invalidated on provider shutdown. If this breaks, we should rewrite
// the test and not hold up implementation changes.
let values = yield previous.getValues();
do_check_eq(values.days.size, 1);
do_check_true(values.days.hasDay(now));
let fields = values.days.getDay(now);
// 3 startup + 2 clean.
do_check_eq(fields.size, 5);
for (let field of ["cleanActiveTime", "cleanTotalTime", "main", "firstPaint", "sessionRestored"]) {
do_check_true(fields.has(field));
do_check_true(Array.isArray(fields.get(field)));
do_check_eq(fields.get(field).length, 1);
for (let i = 0; i < 5; i++) {
let recorder2 = new SessionRecorder("testing.collect.sessions.");
recorder2.onStartup();
yield sleep(25);
recorder2.onShutdown();
yield sleep(25);
}
do_check_eq(fields.get("main")[0], 500);
do_check_eq(fields.get("firstPaint")[0], 1000);
do_check_eq(fields.get("sessionRestored")[0], 1500);
do_check_true(fields.get("cleanActiveTime")[0] > 0);
do_check_true(fields.get("cleanTotalTime")[0] > 0);
recorder = new SessionRecorder("testing.collect.sessions.");
recorder.onStartup();
yield storage.close();
});
yield provider.collectConstantData();
let sessions = recorder.getPreviousSessions();
do_check_eq(Object.keys(sessions).length, 0);
add_task(function test_detect_abort() {
let [provider, storage] = yield getProvider("detect_abort");
let now = new Date();
let m = provider.getMeasurement("current", 1);
let original = yield m.getValues().singular;
let provider2 = new SessionsProvider();
monkeypatchStartupInfo(provider2);
yield provider2.init(storage);
let previous = provider.getMeasurement("previous", 1);
let values = yield previous.getValues();
let daily = provider.getMeasurement("previous", 2);
let values = yield daily.getValues();
do_check_true(values.days.hasDay(now));
do_check_eq(values.days.size, 1);
let day = values.days.getDay(now);
do_check_eq(day.size, 5);
do_check_true(day.has("abortedActiveTime"));
do_check_true(day.has("abortedTotalTime"));
do_check_eq(day.get("abortedActiveTime")[0], 0);
do_check_eq(day.get("abortedTotalTime")[0], 0);
yield provider.shutdown();
yield provider2.shutdown();
yield storage.close();
});
// This isn't a perfect test because we only simulate the observer
// notifications. We should probably supplement this with a mochitest.
add_task(function test_record_browser_activity() {
let [provider, storage] = yield getProvider("record_browser_activity");
function waitOnDB () {
return provider.enqueueStorageOperation(function () {
return storage._connection.execute("SELECT 1");
});
for (let field of ["cleanActiveTicks", "cleanTotalTime", "main", "firstPaint", "sessionRestored"]) {
do_check_true(day.has(field));
do_check_true(Array.isArray(day.get(field)));
do_check_eq(day.get(field).length, 6);
}
let current = provider.getMeasurement("current", 1);
// Fake an aborted sessions.
let recorder2 = new SessionRecorder("testing.collect.sessions.");
recorder2.onStartup();
do_check_eq(Object.keys(recorder.getPreviousSessions()).length, 1);
yield provider.collectConstantData();
do_check_eq(Object.keys(recorder.getPreviousSessions()).length, 0);
Services.obs.notifyObservers(null, "user-interaction-active", null);
yield waitOnDB();
values = yield daily.getValues();
day = values.days.getDay(now);
for (let field of ["abortedActiveTicks", "abortedTotalTime"]) {
do_check_true(day.has(field));
do_check_true(Array.isArray(day.get(field)));
do_check_eq(day.get(field).length, 1);
}
let values = yield current.getValues();
let fields = values.singular;
let activeTime = fields.get("activeTime")[1];
let totalTime = fields.get("totalTime")[1];
do_check_eq(activeTime, totalTime);
do_check_true(activeTime > 0);
// Another active should have similar effects.
Services.obs.notifyObservers(null, "user-interaction-active", null);
yield waitOnDB();
values = yield current.getValues();
fields = values.singular;
do_check_true(fields.get("activeTime")[1] > activeTime);
activeTime = fields.get("activeTime")[1];
totalTime = fields.get("totalTime")[1];
do_check_eq(activeTime, totalTime);
// Now send inactive. We should increment total time but not active.
Services.obs.notifyObservers(null, "user-interaction-inactive", null);
yield waitOnDB();
values = yield current.getValues();
fields = values.singular;
do_check_eq(fields.get("activeTime")[1], activeTime);
totalTime = fields.get("totalTime")[1];
do_check_true(totalTime > activeTime);
// If we send an active again, this should be counted as inactive.
Services.obs.notifyObservers(null, "user-interaction-active", null);
yield waitOnDB();
values = yield current.getValues();
fields = values.singular;
do_check_eq(fields.get("activeTime")[1], activeTime);
do_check_true(fields.get("totalTime")[1] > totalTime);
do_check_neq(fields.get("activeTime")[1], fields.get("totalTime")[1]);
activeTime = fields.get("activeTime")[1];
totalTime = fields.get("totalTime")[1];
// Another active should increment active this time.
Services.obs.notifyObservers(null, "user-interaction-active", null);
yield waitOnDB();
values = yield current.getValues();
fields = values.singular;
do_check_true(fields.get("activeTime")[1] > activeTime);
do_check_true(fields.get("totalTime")[1] > totalTime);
recorder.onShutdown();
recorder2.onShutdown();
yield provider.shutdown();
yield storage.close();

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

@ -15,6 +15,7 @@ Cu.import("resource://gre/modules/services/metrics/storage.jsm");
this.Metrics = {
Collector: Collector,
DailyValues: DailyValues,
Measurement: Measurement,
Provider: Provider,
Storage: MetricsStorageBackend,

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

@ -14,6 +14,7 @@ const {utils: Cu} = Components;
Cu.import("resource://gre/modules/commonjs/promise/core.js");
Cu.import("resource://gre/modules/Task.jsm");
Cu.import("resource://services-common/log4moz.js");
Cu.import("resource://services-common/preferences.js");
Cu.import("resource://services-common/utils.js");
@ -405,6 +406,23 @@ Provider.prototype = Object.freeze({
return m;
},
/**
* Initializes preferences storage for this provider.
*
* Providers are allocated preferences storage under a pref branch named
* after the provider.
*
* This function is typically only called by the entity that constructs the
* Provider instance.
*/
initPreferences: function (branchParent) {
if (!branchParent.endsWith(".")) {
throw new Error("branchParent must end with '.': " + branchParent);
}
this._prefs = new Preferences(branchParent + this.name + ".");
},
init: function (storage) {
if (this.storage !== null) {
throw new Error("Provider() not called. Did the sub-type forget to call it?");

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

@ -5,6 +5,7 @@
"use strict";
this.EXPORTED_SYMBOLS = [
"DailyValues",
"MetricsStorageBackend",
"dateToDays",
"daysToDate",
@ -43,9 +44,9 @@ function daysToDate(days) {
*
* All days are defined in terms of UTC (as opposed to local time).
*/
function DailyValues() {
this.DailyValues = function () {
this._days = new Map();
}
};
DailyValues.prototype = Object.freeze({
__iterator__: function () {
@ -1263,6 +1264,18 @@ MetricsStorageSqliteBackend.prototype = Object.freeze({
return deferred.promise;
},
/**
* Enqueue a function to be performed as a transaction.
*
* The passed function should be a generator suitable for calling with
* `executeTransaction` from the SQLite connection.
*/
enqueueTransaction: function (func, type) {
return this.enqueueOperation(
this._connection.executeTransaction.bind(this._connection, func, type)
);
},
_popAndPerformQueuedOperation: function () {
if (!this._queuedOperations.length || this._queuedInProgress) {
return;

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

@ -7,6 +7,7 @@ const {utils: Cu} = Components;
Cu.import("resource://gre/modules/Metrics.jsm");
Cu.import("resource://gre/modules/Task.jsm");
Cu.import("resource://services-common/preferences.js");
Cu.import("resource://testing-common/services/metrics/mocks.jsm");
@ -60,6 +61,18 @@ add_task(function test_init() {
yield storage.close();
});
add_test(function test_prefs_integration() {
let branch = "testing.prefs_integration.";
let provider = new DummyProvider();
provider.initPreferences(branch);
let prefs = new Preferences(branch);
prefs.set("DummyProvider.foo", "bar");
do_check_eq(provider._prefs.get("foo"), "bar");
run_next_test();
});
add_task(function test_default_collectors() {
let provider = new DummyProvider();
let storage = yield Metrics.Storage("default_collectors");

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

@ -357,6 +357,41 @@ add_task(function test_enqueue_operation_reject_promise() {
yield backend.close();
});
add_task(function test_enqueue_transaction() {
let backend = yield Metrics.Storage("enqueue_transaction");
let mID = yield backend.registerMeasurement("foo", "bar", 1);
let fID = yield backend.registerField(mID, "baz", backend.FIELD_DAILY_COUNTER);
let now = new Date();
yield backend.incrementDailyCounterFromFieldID(fID, now);
yield backend.enqueueTransaction(function transaction() {
yield backend.incrementDailyCounterFromFieldID(fID, now);
});
let count = yield backend.getDailyCounterCountFromFieldID(fID, now);
do_check_eq(count, 2);
let errored = false;
try {
yield backend.enqueueTransaction(function aborted() {
yield backend.incrementDailyCounterFromFieldID(fID, now);
throw new Error("Some error.");
});
} catch (ex) {
errored = true;
} finally {
do_check_true(errored);
}
count = yield backend.getDailyCounterCountFromFieldID(fID, now);
do_check_eq(count, 2);
yield backend.close();
});
add_task(function test_increment_daily_counter_basic() {
let backend = yield Metrics.Storage("increment_daily_counter_basic");