Backed out changeset 1601c1a2cbaf (bug 917883) for frequent shutdown crashes.

This commit is contained in:
Ryan VanderMeulen 2014-04-29 20:34:23 -04:00
parent cde692be0d
commit 3857a44386
5 changed files with 201 additions and 141 deletions

View File

@ -30,8 +30,6 @@ 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.
@ -50,6 +48,7 @@ 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";
@ -130,7 +129,13 @@ HealthReporterState.prototype = Object.freeze({
init: function () {
return Task.spawn(function init() {
OS.File.makeDir(this._stateDir);
try {
OS.File.makeDir(this._stateDir);
} catch (ex if ex instanceof OS.FileError) {
if (!ex.becauseExists) {
throw ex;
}
}
let resetObjectState = function () {
this._s = {
@ -153,8 +158,11 @@ HealthReporterState.prototype = Object.freeze({
try {
this._s = yield CommonUtils.readJSON(this._filename);
} catch (ex if ex instanceof OS.File.Error &&
ex.becauseNoSuchFile) {
} catch (ex if ex instanceof OS.File.Error) {
if (!ex.becauseNoSuchFile) {
throw ex;
}
this._log.warn("Saved state file does not exist.");
resetObjectState();
} catch (ex) {
@ -341,8 +349,7 @@ function AbstractHealthReporter(branch, policy, sessionRecorder) {
this._shutdownRequested = false;
this._shutdownInitiated = false;
this._shutdownComplete = false;
this._deferredShutdown = Promise.defer();
this._promiseShutdown = this._deferredShutdown.promise;
this._shutdownCompleteCallback = null;
this._errors = [];
@ -379,59 +386,12 @@ AbstractHealthReporter.prototype = Object.freeze({
this._initializeStarted = true;
return Task.spawn(function*() {
TelemetryStopwatch.start(this._initHistogram, this);
TelemetryStopwatch.start(this._initHistogram, this);
try {
yield this._state.init();
this._initializeState().then(this._onStateInitialized.bind(this),
this._onInitError.bind(this));
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));
return this.onInit();
},
//----------------------------------------------------
@ -449,12 +409,43 @@ AbstractHealthReporter.prototype = Object.freeze({
this._recordError("Error during initialization", error);
this._initializeHadError = true;
this._initiateShutdown();
return Promise.reject(error);
this._initializedDeferred.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
@ -477,6 +468,24 @@ 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.");
@ -542,6 +551,7 @@ AbstractHealthReporter.prototype = Object.freeze({
// Clean up caches and reduce memory usage.
this._storage.compact();
this._initializedDeferred.resolve(this);
},
// nsIObserver to handle shutdown.
@ -552,6 +562,11 @@ 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;
@ -602,60 +617,80 @@ AbstractHealthReporter.prototype = Object.freeze({
Services.obs.removeObserver(this, "idle-daily");
} catch (ex) { }
Task.spawn(function*() {
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) {
try {
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);
yield provider.shutdown();
} catch (ex) {
this._log.warn("Error when shutting down provider: " +
CommonUtils.exceptionStr(ex));
}
}.bind(this));
}
},
onInit: function() {
return this._initializedDeferred.promise;
_onProviderManagerShutdown: function () {
this._log.info("Provider manager shut down.");
this._providerManager = null;
this._shutdownStorage();
},
_onStorageCreated: function() {
// Do nothing.
// This method provides a hook point for the test suite.
_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);
},
_onStorageClose: 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();
},
_onProviderManagerShutdown: 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);
}
},
/**
@ -665,7 +700,22 @@ AbstractHealthReporter.prototype = Object.freeze({
*/
_shutdown: function () {
this._initiateShutdown();
return this._promiseShutdown;
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;
},
_performDailyMaintenance: function () {
@ -1297,6 +1347,10 @@ 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,6 +103,7 @@ 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);
@ -123,7 +124,7 @@ add_task(function test_constructor() {
failed = false;
}
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -133,7 +134,7 @@ add_task(function test_shutdown_normal() {
// We can't send "quit-application" notification because the xpcshell runner
// will shut down!
reporter._initiateShutdown();
yield reporter._promiseShutdown;
reporter._waitForShutdown();
});
add_task(function test_shutdown_storage_in_progress() {
@ -146,7 +147,7 @@ add_task(function test_shutdown_storage_in_progress() {
reporter.init();
yield reporter._promiseShutdown;
reporter._waitForShutdown();
do_check_eq(reporter.providerManagerShutdownCount, 0);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -165,7 +166,7 @@ add_task(function test_shutdown_provider_manager_in_progress() {
reporter.init();
// This will hang if shutdown logic is busted.
yield reporter._promiseShutdown;
reporter._waitForShutdown();
do_check_eq(reporter.providerManagerShutdownCount, 1);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -183,7 +184,7 @@ add_task(function test_shutdown_when_provider_manager_errors() {
reporter.init();
// This will hang if shutdown logic is busted.
yield reporter._promiseShutdown;
reporter._waitForShutdown();
do_check_eq(reporter.providerManagerShutdownCount, 1);
do_check_eq(reporter.storageCloseCount, 1);
});
@ -220,7 +221,7 @@ add_task(function test_pull_only_providers() {
let values = yield reporter._storage.getMeasurementValues(mID);
do_check_true(values.singular.size > 0);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -251,7 +252,7 @@ add_task(function test_collect_daily() {
yield reporter.collectMeasurements();
do_check_eq(provider.collectDailyCount, 3);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -275,7 +276,7 @@ add_task(function test_remove_old_lastpayload() {
do_check_false(yield OS.File.exists(path));
}
yield reporter._state.save();
yield reporter._shutdown();
reporter._shutdown();
let o = yield CommonUtils.readJSON(reporter._state._filename);
do_check_true(o.removedOutdatedLastpayload);
@ -287,7 +288,7 @@ add_task(function test_remove_old_lastpayload() {
do_check_true(yield OS.File.exists(path));
}
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -326,7 +327,7 @@ add_task(function test_json_payload_simple() {
payload = yield reporter.getJSONPayload(true);
do_check_eq(typeof payload, "object");
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -345,7 +346,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 {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -363,7 +364,7 @@ add_task(function test_collect_and_obtain_json_payload() {
payload = yield reporter.collectAndObtainJSONPayload(true);
do_check_eq(typeof payload, "object");
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -419,7 +420,7 @@ add_task(function test_constant_only_providers_in_json_payload() {
yield deferred.promise;
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -454,7 +455,7 @@ add_task(function test_json_payload_multiple_days() {
let today = reporter._formatDate(now);
do_check_true(today in o.data.days);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -531,7 +532,7 @@ add_task(function test_json_payload_newer_version_overwrites() {
do_check_eq(o.data.days[day]["MultiMeasurementProvider.DummyMeasurement"]._v, highestVersion);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -556,7 +557,7 @@ add_task(function test_idle_daily() {
values = yield m.getValues();
do_check_eq(values.days.size, 180);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -646,7 +647,7 @@ add_task(function test_data_submission_success() {
let id = reporter.lastSubmitID;
let clientID = reporter._state.clientID;
yield reporter._shutdown();
reporter._shutdown();
// Ensure reloading state works.
reporter = yield getReporter("data_submission_success");
@ -654,7 +655,7 @@ add_task(function test_data_submission_success() {
do_check_eq(reporter.lastPingDate.getTime(), d.getTime());
do_check_eq(reporter._state.clientID, clientID);
yield reporter._shutdown();
reporter._shutdown();
} finally {
yield shutdownServer(server);
}
@ -805,7 +806,7 @@ add_task(function test_policy_accept_reject() {
do_check_false(policy.dataSubmissionPolicyAccepted);
do_check_false(reporter.willUploadData);
} finally {
yield reporter._shutdown();
reporter._shutdown();
yield shutdownServer(server);
}
});
@ -828,7 +829,7 @@ add_task(function test_error_message_scrubbing() {
reporter._recordError("Foo " + uri.spec);
do_check_eq(reporter._errors[0], "Foo <AppDataURI>");
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -854,7 +855,7 @@ add_task(function test_basic_appinfo() {
do_check_eq(payload["version"], 2);
verify(payload["geckoAppInfo"]);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -875,13 +876,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 {
yield reporter._shutdown();
reporter._shutdown();
}
});
add_task(function test_failure_if_not_initialized() {
let reporter = yield getReporter("failure_if_not_initialized");
yield reporter._shutdown();
reporter._shutdown();
let error = false;
try {
@ -909,15 +910,13 @@ 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(MESSAGE);
throw new Error("Fake error during provider manager initialization.");
};
let deferred = Promise.defer();
@ -955,9 +954,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(MESSAGE));
do_check_true(doc.errors[0].contains("Fake error during provider manager initialization"));
yield reporter._shutdown();
reporter._shutdown();
yield shutdownServer(server);
});
@ -983,7 +982,7 @@ add_task(function test_state_prefs_conversion_simple() {
do_check_false(prefs.isSet("lastSubmitID"));
do_check_false(prefs.isSet("lastPingTime"));
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -1005,7 +1004,7 @@ add_task(function test_state_no_json_object() {
do_check_eq(o.lastPingTime, 0);
do_check_eq(o.remoteIDs.length, 0);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -1026,7 +1025,7 @@ add_task(function test_state_future_version() {
do_check_eq(o.lastPingTime, 2412);
do_check_eq(o.remoteIDs.length, 1);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -1045,7 +1044,7 @@ add_task(function test_state_invalid_json() {
do_check_eq(reporter.lastPingDate.getTime(), 0);
do_check_null(reporter.lastSubmitID);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -1086,7 +1085,7 @@ add_task(function test_state_multiple_remote_ids() {
do_check_eq(o.lastPingTime, reporter.lastPingDate.getTime());
} finally {
yield shutdownServer(server);
yield reporter._shutdown();
reporter._shutdown();
}
});
@ -1118,7 +1117,7 @@ add_task(function test_state_downgrade_upgrade() {
do_check_eq(o.remoteIDs.length, 3);
do_check_eq(o.lastPingTime, now.getTime() + 1000);
} finally {
yield reporter._shutdown();
reporter._shutdown();
}
});

View File

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

View File

@ -811,8 +811,7 @@ 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<> A promise fulfilled once the connection is closed.
* This promise never rejects.
* @return Promise<>
*/
close: function () {
return Task.spawn(function doClose() {

View File

@ -4399,6 +4399,14 @@
"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",