Bug 917883 - Use AsyncShutdown instead of spinning the event loop in healthreporter.jsm. r=gps, r=rnewman

This commit is contained in:
David Rajchenbach-Teller 2014-04-29 11:12:00 -04:00
parent 43c7cae72e
commit 99d1f55876
5 changed files with 141 additions and 201 deletions

View File

@ -30,6 +30,8 @@ Cu.import("resource://gre/modules/XPCOMUtils.jsm");
XPCOMUtils.defineLazyModuleGetter(this, "UpdateChannel",
"resource://gre/modules/UpdateChannel.jsm");
XPCOMUtils.defineLazyModuleGetter(this, "AsyncShutdown",
"resource://gre/modules/AsyncShutdown.jsm");
// Oldest year to allow in date preferences. This module was implemented in
// 2012 and no dates older than that should be encountered.
@ -48,7 +50,6 @@ const TELEMETRY_JSON_PAYLOAD_SERIALIZE = "HEALTHREPORT_JSON_PAYLOAD_SERIALIZE_MS
const TELEMETRY_PAYLOAD_SIZE_UNCOMPRESSED = "HEALTHREPORT_PAYLOAD_UNCOMPRESSED_BYTES";
const TELEMETRY_PAYLOAD_SIZE_COMPRESSED = "HEALTHREPORT_PAYLOAD_COMPRESSED_BYTES";
const TELEMETRY_UPLOAD = "HEALTHREPORT_UPLOAD_MS";
const TELEMETRY_SHUTDOWN_DELAY = "HEALTHREPORT_SHUTDOWN_DELAY_MS";
const TELEMETRY_COLLECT_CONSTANT = "HEALTHREPORT_COLLECT_CONSTANT_DATA_MS";
const TELEMETRY_COLLECT_DAILY = "HEALTHREPORT_COLLECT_DAILY_MS";
const TELEMETRY_SHUTDOWN = "HEALTHREPORT_SHUTDOWN_MS";
@ -129,13 +130,7 @@ HealthReporterState.prototype = Object.freeze({
init: function () {
return Task.spawn(function init() {
try {
OS.File.makeDir(this._stateDir);
} catch (ex if ex instanceof OS.FileError) {
if (!ex.becauseExists) {
throw ex;
}
}
OS.File.makeDir(this._stateDir);
let resetObjectState = function () {
this._s = {
@ -158,11 +153,8 @@ HealthReporterState.prototype = Object.freeze({
try {
this._s = yield CommonUtils.readJSON(this._filename);
} catch (ex if ex instanceof OS.File.Error) {
if (!ex.becauseNoSuchFile) {
throw ex;
}
} catch (ex if ex instanceof OS.File.Error &&
ex.becauseNoSuchFile) {
this._log.warn("Saved state file does not exist.");
resetObjectState();
} catch (ex) {
@ -349,7 +341,8 @@ function AbstractHealthReporter(branch, policy, sessionRecorder) {
this._shutdownRequested = false;
this._shutdownInitiated = false;
this._shutdownComplete = false;
this._shutdownCompleteCallback = null;
this._deferredShutdown = Promise.defer();
this._promiseShutdown = this._deferredShutdown.promise;
this._errors = [];
@ -386,12 +379,59 @@ AbstractHealthReporter.prototype = Object.freeze({
this._initializeStarted = true;
TelemetryStopwatch.start(this._initHistogram, this);
return Task.spawn(function*() {
TelemetryStopwatch.start(this._initHistogram, this);
this._initializeState().then(this._onStateInitialized.bind(this),
this._onInitError.bind(this));
try {
yield this._state.init();
return this.onInit();
if (!this._state._s.removedOutdatedLastpayload) {
yield this._deleteOldLastPayload();
this._state._s.removedOutdatedLastpayload = true;
// Normally we should save this to a file but it directly conflicts with
// the "application re-upgrade" decision in HealthReporterState::init()
// which specifically does not save the state to a file.
}
} catch (ex) {
this._log.error("Error deleting last payload: " +
CommonUtils.exceptionStr(ex));
}
// As soon as we have could have storage, we need to register cleanup or
// else bad things happen on shutdown.
Services.obs.addObserver(this, "quit-application", false);
// The database needs to be shut down by the end of shutdown
// phase profileBeforeChange.
AsyncShutdown.profileBeforeChange.
addBlocker("FHR: Flushing storage shutdown", this._promiseShutdown);
try {
this._storageInProgress = true;
TelemetryStopwatch.start(this._dbOpenHistogram, this);
let storage = yield Metrics.Storage(this._dbName);
TelemetryStopwatch.finish(this._dbOpenHistogram, this);
yield this._onStorageCreated();
delete this._dbOpenHistogram;
this._log.info("Storage initialized.");
this._storage = storage;
this._storageInProgress = false;
if (this._shutdownRequested) {
this._initiateShutdown();
return null;
}
yield this._initializeProviderManager();
yield this._onProviderManagerInitialized();
this._initializedDeferred.resolve();
return this.onInit();
} catch (ex) {
yield this._onInitError(ex);
this._initializedDeferred.reject(ex);
}
}.bind(this));
},
//----------------------------------------------------
@ -409,43 +449,12 @@ AbstractHealthReporter.prototype = Object.freeze({
this._recordError("Error during initialization", error);
this._initializeHadError = true;
this._initiateShutdown();
this._initializedDeferred.reject(error);
return Promise.reject(error);
// FUTURE consider poisoning prototype's functions so calls fail with a
// useful error message.
},
_initializeState: function () {
return Promise.resolve();
},
_onStateInitialized: function () {
return Task.spawn(function onStateInitialized () {
try {
if (!this._state._s.removedOutdatedLastpayload) {
yield this._deleteOldLastPayload();
this._state._s.removedOutdatedLastpayload = true;
// Normally we should save this to a file but it directly conflicts with
// the "application re-upgrade" decision in HealthReporterState::init()
// which specifically does not save the state to a file.
}
} catch (ex) {
this._log.error("Error deleting last payload: " +
CommonUtils.exceptionStr(ex));
}
// As soon as we have could storage, we need to register cleanup or
// else bad things happen on shutdown.
Services.obs.addObserver(this, "quit-application", false);
Services.obs.addObserver(this, "profile-before-change", false);
this._storageInProgress = true;
TelemetryStopwatch.start(this._dbOpenHistogram, this);
Metrics.Storage(this._dbName).then(this._onStorageCreated.bind(this),
this._onInitError.bind(this));
}.bind(this));
},
/**
* Removes the outdated lastpaylaod.json and lastpayload.json.tmp files
@ -468,24 +477,6 @@ AbstractHealthReporter.prototype = Object.freeze({
}.bind(this));
},
// Called when storage has been opened.
_onStorageCreated: function (storage) {
TelemetryStopwatch.finish(this._dbOpenHistogram, this);
delete this._dbOpenHistogram;
this._log.info("Storage initialized.");
this._storage = storage;
this._storageInProgress = false;
if (this._shutdownRequested) {
this._initiateShutdown();
return;
}
Task.spawn(this._initializeProviderManager.bind(this))
.then(this._onProviderManagerInitialized.bind(this),
this._onInitError.bind(this));
},
_initializeProviderManager: function () {
if (this._collector) {
throw new Error("Provider manager has already been initialized.");
@ -551,7 +542,6 @@ AbstractHealthReporter.prototype = Object.freeze({
// Clean up caches and reduce memory usage.
this._storage.compact();
this._initializedDeferred.resolve(this);
},
// nsIObserver to handle shutdown.
@ -562,11 +552,6 @@ AbstractHealthReporter.prototype = Object.freeze({
this._initiateShutdown();
break;
case "profile-before-change":
Services.obs.removeObserver(this, "profile-before-change");
this._waitForShutdown();
break;
case "idle-daily":
this._performDailyMaintenance();
break;
@ -617,80 +602,60 @@ AbstractHealthReporter.prototype = Object.freeze({
Services.obs.removeObserver(this, "idle-daily");
} catch (ex) { }
if (this._providerManager) {
let onShutdown = this._onProviderManagerShutdown.bind(this);
Task.spawn(this._shutdownProviderManager.bind(this))
.then(onShutdown, onShutdown);
return;
}
this._log.warn("Don't have provider manager. Proceeding to storage shutdown.");
this._shutdownStorage();
},
_shutdownProviderManager: function () {
this._log.info("Shutting down provider manager.");
for (let provider of this._providerManager.providers) {
Task.spawn(function*() {
try {
yield provider.shutdown();
} catch (ex) {
this._log.warn("Error when shutting down provider: " +
CommonUtils.exceptionStr(ex));
if (this._providerManager) {
this._log.info("Shutting down provider manager.");
for (let provider of this._providerManager.providers) {
try {
yield provider.shutdown();
} catch (ex) {
this._log.warn("Error when shutting down provider: " +
CommonUtils.exceptionStr(ex));
}
}
this._log.info("Provider manager shut down.");
this._providerManager = null;
this._onProviderManagerShutdown();
}
if (this._storage) {
this._log.info("Shutting down storage.");
try {
yield this._storage.close();
yield this._onStorageClose();
} catch (error) {
this._log.warn("Error when closing storage: " +
CommonUtils.exceptionStr(error));
}
this._storage = null;
}
this._log.warn("Shutdown complete.");
this._shutdownComplete = true;
} finally {
this._deferredShutdown.resolve();
TelemetryStopwatch.finish(TELEMETRY_SHUTDOWN, this);
}
}
}.bind(this));
},
_onProviderManagerShutdown: function () {
this._log.info("Provider manager shut down.");
this._providerManager = null;
this._shutdownStorage();
onInit: function() {
return this._initializedDeferred.promise;
},
_shutdownStorage: function () {
if (!this._storage) {
this._onShutdownComplete();
}
this._log.info("Shutting down storage.");
let onClose = this._onStorageClose.bind(this);
this._storage.close().then(onClose, onClose);
_onStorageCreated: function() {
// Do nothing.
// This method provides a hook point for the test suite.
},
_onStorageClose: function (error) {
this._log.info("Storage has been closed.");
if (error) {
this._log.warn("Error when closing storage: " +
CommonUtils.exceptionStr(error));
}
this._storage = null;
this._onShutdownComplete();
_onStorageClose: function() {
// Do nothing.
// This method provides a hook point for the test suite.
},
_onShutdownComplete: function () {
this._log.warn("Shutdown complete.");
this._shutdownComplete = true;
TelemetryStopwatch.finish(TELEMETRY_SHUTDOWN, this);
if (this._shutdownCompleteCallback) {
this._shutdownCompleteCallback();
}
},
_waitForShutdown: function () {
if (this._shutdownComplete) {
return;
}
TelemetryStopwatch.start(TELEMETRY_SHUTDOWN_DELAY, this);
try {
this._shutdownCompleteCallback = Async.makeSpinningCallback();
this._shutdownCompleteCallback.wait();
this._shutdownCompleteCallback = null;
} finally {
TelemetryStopwatch.finish(TELEMETRY_SHUTDOWN_DELAY, this);
}
_onProviderManagerShutdown: function() {
// Do nothing.
// This method provides a hook point for the test suite.
},
/**
@ -700,22 +665,7 @@ AbstractHealthReporter.prototype = Object.freeze({
*/
_shutdown: function () {
this._initiateShutdown();
this._waitForShutdown();
},
/**
* Return a promise that is resolved once the service has been initialized.
*/
onInit: function () {
if (this._initializeHadError) {
throw new Error("Service failed to initialize.");
}
if (this._initialized) {
return CommonUtils.laterTickResolvingPromise(this);
}
return this._initializedDeferred.promise;
return this._promiseShutdown;
},
_performDailyMaintenance: function () {
@ -1347,10 +1297,6 @@ this.HealthReporter.prototype = Object.freeze({
return this._policy.deleteRemoteData(reason);
},
_initializeState: function() {
return this._state.init();
},
/**
* Override default handler to incur an upload describing the error.
*/

View File

@ -103,7 +103,6 @@ add_task(function test_init() {
add_task(function test_constructor() {
let reporter = yield getReporter("constructor");
try {
do_check_eq(reporter.lastPingDate.getTime(), 0);
do_check_null(reporter.lastSubmitID);
@ -124,7 +123,7 @@ add_task(function test_constructor() {
failed = false;
}
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -134,7 +133,7 @@ add_task(function test_shutdown_normal() {
// We can't send "quit-application" notification because the xpcshell runner
// will shut down!
reporter._initiateShutdown();
reporter._waitForShutdown();
yield reporter._promiseShutdown;
});
add_task(function test_shutdown_storage_in_progress() {
@ -147,7 +146,7 @@ add_task(function test_shutdown_storage_in_progress() {
reporter.init();
reporter._waitForShutdown();
yield reporter._promiseShutdown;
do_check_eq(reporter.providerManagerShutdownCount, 0);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -166,7 +165,7 @@ add_task(function test_shutdown_provider_manager_in_progress() {
reporter.init();
// This will hang if shutdown logic is busted.
reporter._waitForShutdown();
yield reporter._promiseShutdown;
do_check_eq(reporter.providerManagerShutdownCount, 1);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -184,7 +183,7 @@ add_task(function test_shutdown_when_provider_manager_errors() {
reporter.init();
// This will hang if shutdown logic is busted.
reporter._waitForShutdown();
yield reporter._promiseShutdown;
do_check_eq(reporter.providerManagerShutdownCount, 1);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -221,7 +220,7 @@ add_task(function test_pull_only_providers() {
let values = yield reporter._storage.getMeasurementValues(mID);
do_check_true(values.singular.size > 0);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -252,7 +251,7 @@ add_task(function test_collect_daily() {
yield reporter.collectMeasurements();
do_check_eq(provider.collectDailyCount, 3);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -276,7 +275,7 @@ add_task(function test_remove_old_lastpayload() {
do_check_false(yield OS.File.exists(path));
}
yield reporter._state.save();
reporter._shutdown();
yield reporter._shutdown();
let o = yield CommonUtils.readJSON(reporter._state._filename);
do_check_true(o.removedOutdatedLastpayload);
@ -288,7 +287,7 @@ add_task(function test_remove_old_lastpayload() {
do_check_true(yield OS.File.exists(path));
}
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -327,7 +326,7 @@ add_task(function test_json_payload_simple() {
payload = yield reporter.getJSONPayload(true);
do_check_eq(typeof payload, "object");
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -346,7 +345,7 @@ add_task(function test_json_payload_dummy_provider() {
do_check_true(name in o.data.last);
do_check_eq(o.data.last[name]._v, 1);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -364,7 +363,7 @@ add_task(function test_collect_and_obtain_json_payload() {
payload = yield reporter.collectAndObtainJSONPayload(true);
do_check_eq(typeof payload, "object");
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -420,7 +419,7 @@ add_task(function test_constant_only_providers_in_json_payload() {
yield deferred.promise;
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -455,7 +454,7 @@ add_task(function test_json_payload_multiple_days() {
let today = reporter._formatDate(now);
do_check_true(today in o.data.days);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -532,7 +531,7 @@ add_task(function test_json_payload_newer_version_overwrites() {
do_check_eq(o.data.days[day]["MultiMeasurementProvider.DummyMeasurement"]._v, highestVersion);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -557,7 +556,7 @@ add_task(function test_idle_daily() {
values = yield m.getValues();
do_check_eq(values.days.size, 180);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -647,7 +646,7 @@ add_task(function test_data_submission_success() {
let id = reporter.lastSubmitID;
let clientID = reporter._state.clientID;
reporter._shutdown();
yield reporter._shutdown();
// Ensure reloading state works.
reporter = yield getReporter("data_submission_success");
@ -655,7 +654,7 @@ add_task(function test_data_submission_success() {
do_check_eq(reporter.lastPingDate.getTime(), d.getTime());
do_check_eq(reporter._state.clientID, clientID);
reporter._shutdown();
yield reporter._shutdown();
} finally {
yield shutdownServer(server);
}
@ -806,7 +805,7 @@ add_task(function test_policy_accept_reject() {
do_check_false(policy.dataSubmissionPolicyAccepted);
do_check_false(reporter.willUploadData);
} finally {
reporter._shutdown();
yield reporter._shutdown();
yield shutdownServer(server);
}
});
@ -829,7 +828,7 @@ add_task(function test_error_message_scrubbing() {
reporter._recordError("Foo " + uri.spec);
do_check_eq(reporter._errors[0], "Foo <AppDataURI>");
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -855,7 +854,7 @@ add_task(function test_basic_appinfo() {
do_check_eq(payload["version"], 2);
verify(payload["geckoAppInfo"]);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -876,13 +875,13 @@ add_task(function test_collect_when_upload_disabled() {
// We would ideally ensure the timer fires and does the right thing.
// However, testing the update timer manager is quite involved.
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
add_task(function test_failure_if_not_initialized() {
let reporter = yield getReporter("failure_if_not_initialized");
reporter._shutdown();
yield reporter._shutdown();
let error = false;
try {
@ -910,13 +909,15 @@ add_task(function test_failure_if_not_initialized() {
});
add_task(function test_upload_on_init_failure() {
let MESSAGE = "Fake error during provider manager initialization." + Math.random();
let server = new BagheeraServer();
server.start();
let reporter = yield getHealthReporter("upload_on_init_failure", server.serverURI, true);
server.createNamespace(reporter.serverNamespace);
reporter.onInitializeProviderManagerFinished = function () {
throw new Error("Fake error during provider manager initialization.");
throw new Error(MESSAGE);
};
let deferred = Promise.defer();
@ -954,9 +955,9 @@ add_task(function test_upload_on_init_failure() {
do_check_eq(doc.notInitialized, 1);
do_check_true("errors" in doc);
do_check_eq(doc.errors.length, 1);
do_check_true(doc.errors[0].contains("Fake error during provider manager initialization"));
do_check_true(doc.errors[0].contains(MESSAGE));
reporter._shutdown();
yield reporter._shutdown();
yield shutdownServer(server);
});
@ -982,7 +983,7 @@ add_task(function test_state_prefs_conversion_simple() {
do_check_false(prefs.isSet("lastSubmitID"));
do_check_false(prefs.isSet("lastPingTime"));
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -1004,7 +1005,7 @@ add_task(function test_state_no_json_object() {
do_check_eq(o.lastPingTime, 0);
do_check_eq(o.remoteIDs.length, 0);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -1025,7 +1026,7 @@ add_task(function test_state_future_version() {
do_check_eq(o.lastPingTime, 2412);
do_check_eq(o.remoteIDs.length, 1);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -1044,7 +1045,7 @@ add_task(function test_state_invalid_json() {
do_check_eq(reporter.lastPingDate.getTime(), 0);
do_check_null(reporter.lastSubmitID);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -1085,7 +1086,7 @@ add_task(function test_state_multiple_remote_ids() {
do_check_eq(o.lastPingTime, reporter.lastPingDate.getTime());
} finally {
yield shutdownServer(server);
reporter._shutdown();
yield reporter._shutdown();
}
});
@ -1117,7 +1118,7 @@ add_task(function test_state_downgrade_upgrade() {
do_check_eq(o.remoteIDs.length, 3);
do_check_eq(o.lastPingTime, now.getTime() + 1000);
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});

View File

@ -263,6 +263,6 @@ add_task(function test_healthreporter_integration () {
do_check_true("org.mozilla.appInfo.versions" in measurements);
}
} finally {
reporter._shutdown();
yield reporter._shutdown();
}
});

View File

@ -811,7 +811,8 @@ MetricsStorageSqliteBackend.prototype = Object.freeze({
* This should be called on all instances or the SQLite layer may complain
* loudly. After this has been called, the connection cannot be used.
*
* @return Promise<>
* @return Promise<> A promise fulfilled once the connection is closed.
* This promise never rejects.
*/
close: function () {
return Task.spawn(function doClose() {

View File

@ -4399,14 +4399,6 @@
"extended_statistics_ok": true,
"description": "Time (ms) spent to initialize Firefox Health Report service."
},
"HEALTHREPORT_SHUTDOWN_DELAY_MS": {
"expires_in_version": "never",
"kind": "exponential",
"high": "20000",
"n_buckets": 15,
"extended_statistics_ok": true,
"description": "Time (ms) that Firefox Health Report delays application shutdown by."
},
"HEALTHREPORT_GENERATE_JSON_PAYLOAD_MS": {
"expires_in_version": "never",
"kind": "exponential",