From 55d55e48ae5d4baf1ee4a7bf707125a2df2a1ac1 Mon Sep 17 00:00:00 2001 From: Jono S Xia Date: Tue, 3 May 2011 12:41:28 -0700 Subject: [PATCH] Bug 603009: Catch and report all exceptions thrown during test pilot study execution. r=dtownsend Bug 646122: Holding on to Exception objects causes crash in garbage collector. r=dtownsend Bug 645092: Stop using [deprecated] Storage methods (testpilot). r=mfinkle DONTBUILD as it is NPOTB on m-c --- .../content/debug.html | 18 +++- .../modules/experiment_data_store.js | 95 ++++++++++++++----- .../modules/remote-experiment-loader.js | 13 +++ .../modules/tasks.js | 64 ++++++++++--- 4 files changed, 152 insertions(+), 38 deletions(-) diff --git a/browser/app/profile/extensions/testpilot@labs.mozilla.com/content/debug.html b/browser/app/profile/extensions/testpilot@labs.mozilla.com/content/debug.html index 9257fbd3f92e..96537350da09 100644 --- a/browser/app/profile/extensions/testpilot@labs.mozilla.com/content/debug.html +++ b/browser/app/profile/extensions/testpilot@labs.mozilla.com/content/debug.html @@ -20,7 +20,20 @@ function reloadAllExperiments() { Components.utils.import("resource://testpilot/modules/setup.js"); - TestPilotSetup.reloadRemoteExperiments(); + TestPilotSetup.reloadRemoteExperiments(function(success) { + let errors = TestPilotSetup._remoteExperimentLoader.getLoadErrors(); + let str; + if (errors.length > 0) { + str = ""; + } else { + str = "All experiments reloaded, no errors."; + } + document.getElementById("debug").innerHTML = str; + }); } function runUnitTests() { @@ -81,8 +94,7 @@ var path = codeStore.resolveModule(null, filename); var textArea = document.getElementById("experiment-code-area"); codeStore.setLocalOverride(path, textArea.value); - reloadAllExperiments(function(success) { - document.getElementById("debug").innerHTML = "Success? " + success;}); + reloadAllExperiments(); } function showMetaData() { diff --git a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/experiment_data_store.js b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/experiment_data_store.js index 02e92ad0c56f..06e84221f44d 100644 --- a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/experiment_data_store.js +++ b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/experiment_data_store.js @@ -54,6 +54,8 @@ const TYPE_INT_32 = 0; const TYPE_DOUBLE = 1; const TYPE_STRING = 2; +const EXCEPTION_TABLE_NAME = "exceptions"; + function ExperimentDataStore(fileName, tableName, columns) { this._init(fileName, tableName, columns); } @@ -87,9 +89,17 @@ ExperimentDataStore.prototype = { + schemaClauses.join(", ") + ");"; // CreateTable creates the table only if it does not already exist: try { - this._connection = DbUtils.createTable(this._connection, - this._tableName, - schema); + DbUtils.createTable(this._connection, this._tableName, schema); + } catch(e) { + logger.warn("Error in createTable: " + e + "\n"); + } + + // Create a second table for storing exceptions for this study. It has a fixed + // name and schema: + let exceptionTableSchema = "CREATE TABLE " + EXCEPTION_TABLE_NAME + + " (time INTEGER, trace TEXT);"; + try { + DbUtils.createTable(this._connection, "exceptions", exceptionTableSchema); } catch(e) { logger.warn("Error in createTable: " + e + "\n"); } @@ -150,8 +160,21 @@ ExperimentDataStore.prototype = { insStmt.finalize(); }, + logException: function EDS_logException(exception) { + let insertSql = "INSERT INTO " + EXCEPTION_TABLE_NAME + " VALUES (?1, ?2);"; + let insStmt = this._createStatement(insertSql); + // Even though the SQL says ?1 and ?2, the param indices count from 0. + insStmt.params[0] = Date.now(); + let txt = exception.message ? exception.message : exception.toString(); + insStmt.params[1] = txt; + insStmt.executeAsync(); + insStmt.finalize(); // TODO Is this the right thing to do when calling asynchronously? + }, + getJSONRows: function EDS_getJSONRows(callback) { - let selectSql = "SELECT * FROM " + this._tableName; + // TODO why do both this function and getAllDataAsJSON exist when they both do + // the same thing? + let selectSql = "SELECT * FROM " + this._tableName; let selStmt = this._createStatement(selectSql); let records = []; let self = this; @@ -255,33 +278,61 @@ ExperimentDataStore.prototype = { selStmt.finalize(); }, - wipeAllData: function EDS_wipeAllData(callback) { - let logger = Log4Moz.repository.getLogger("TestPilot.Database"); - logger.trace("ExperimentDataStore.wipeAllData called.\n"); - let wipeSql = "DELETE FROM " + this._tableName; - let wipeStmt = this._createStatement(wipeSql); - wipeStmt.executeAsync({ + getExceptionsAsJson: function(callback) { + let selectSql = "SELECT * FROM " + EXCEPTION_TABLE_NAME; + let selStmt = this._createStatement(selectSql); + let records = []; + let self = this; + + selStmt.executeAsync({ handleResult: function(aResultSet) { - }, - handleError: function(aError) { - if (callback) { - callback(false); + for (let row = aResultSet.getNextRow(); row; + row = aResultSet.getNextRow()) { + records.push({ time: row.getDouble(0), + exception: row.getString(1)}); } }, + handleError: function(aError) { + callback(records); + }, + handleCompletion: function(aReason) { + callback(records); + } + }); + }, + + wipeAllData: function EDS_wipeAllData(callback) { + // Wipe both the data table and the exception table; call callback when both + // are wiped. + let logger = Log4Moz.repository.getLogger("TestPilot.Database"); + logger.trace("ExperimentDataStore.wipeAllData called.\n"); + let wipeDataStmt = this._createStatement("DELETE FROM " + this._tableName); + let wipeExcpStmt = this._createStatement("DELETE FROM " + EXCEPTION_TABLE_NAME); + + let numberWiped = 0; + let onComplete = function() { + numberWiped ++; + if (numberWiped == 2 && callback) { + callback(); + } + }; + wipeDataStmt.executeAsync({ + handleResult: function(aResultSet) {}, + handleError: function(aError) { onComplete(); }, handleCompletion: function(aReason) { if (aReason == Ci.mozIStorageStatementCallback.REASON_FINISHED) { logger.trace("ExperimentDataStore.wipeAllData complete.\n"); - if (callback) { - callback(true); - } - } else { - if (callback) { - callback(false); - } } + onComplete(); } }); - wipeStmt.finalize(); + wipeExcpStmt.executeAsync({ + handleResult: function(aResultSet) {}, + handleError: function(aError) { onComplete(); }, + handleCompletion: function(aReason) { onComplete(); } + }); + wipeDataStmt.finalize(); + wipeExcpStmt.finalize(); }, nukeTable: function EDS_nukeTable() { diff --git a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/remote-experiment-loader.js b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/remote-experiment-loader.js index 2824736e2eab..6a4a086ac1bb 100644 --- a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/remote-experiment-loader.js +++ b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/remote-experiment-loader.js @@ -219,6 +219,7 @@ exports.RemoteExperimentLoader.prototype = { this._studyResults = []; this._legacyStudies = []; this._experimentFileNames = []; + this._loadErrors = []; }, getLocalizedStudyInfo: function(studiesIndex) { @@ -504,12 +505,20 @@ exports.RemoteExperimentLoader.prototype = { * the module name and value = the module object. */ this._logger.trace("GetExperiments called."); let remoteExperiments = {}; + this._loadErrors = []; for each (filename in this._experimentFileNames) { this._logger.debug("GetExperiments is loading " + filename); try { remoteExperiments[filename] = this._loader.require(filename); this._logger.info("Loaded " + filename + " OK."); } catch(e) { + /* Turn the load-time errors into strings and store them, so we can display + * them on a debug page or include them with a data upload! (Don't store + * exception objects directly as that causes garbage collector problems- + * aka bug 646122) */ + let errStr = e.name + " on line " + e.lineNumber + " of file " + + e.fileName + ": " + e.message; + this._loadErrors.push(errStr); this._logger.warn("Error loading " + filename); this._logger.warn(e); } @@ -523,6 +532,10 @@ exports.RemoteExperimentLoader.prototype = { getLegacyStudies: function() { return this._legacyStudies; + }, + + getLoadErrors: function() { + return this._loadErrors; } }; diff --git a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/tasks.js b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/tasks.js index 04b5735c778d..31db0d2a17e6 100644 --- a/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/tasks.js +++ b/browser/app/profile/extensions/testpilot@labs.mozilla.com/modules/tasks.js @@ -487,29 +487,44 @@ TestPilotExperiment.prototype = { onNewWindow: function TestPilotExperiment_onNewWindow(window) { this._logger.trace("Experiment.onNewWindow called."); if (this.experimentIsRunning()) { - this._handlers.onNewWindow(window); + try { + this._handlers.onNewWindow(window); + } catch(e) { + this._dataStore.logException("onNewWindow: " + e); + } } }, onWindowClosed: function TestPilotExperiment_onWindowClosed(window) { this._logger.trace("Experiment.onWindowClosed called."); if (this.experimentIsRunning()) { - this._handlers.onWindowClosed(window); + try { + this._handlers.onWindowClosed(window); + } catch(e) { + this._dataStore.logException("onWindowClosed: " + e); + } } }, onAppStartup: function TestPilotExperiment_onAppStartup() { this._logger.trace("Experiment.onAppStartup called."); if (this.experimentIsRunning()) { - this._handlers.onAppStartup(); + try { + this._handlers.onAppStartup(); + } catch(e) { + this._dataStore.logException("onAppStartup: " + e); + } } }, onAppShutdown: function TestPilotExperiment_onAppShutdown() { this._logger.trace("Experiment.onAppShutdown called."); - // TODO the caller for this is not yet implemented if (this.experimentIsRunning()) { - this._handlers.onAppShutdown(); + try { + this._handlers.onAppShutdown(); + } catch(e) { + this._dataStore.logException("onAppShutdown: " + e); + } } }, @@ -518,7 +533,11 @@ TestPilotExperiment.prototype = { // Make sure not to call this if it's already been called: if (this.experimentIsRunning() && !this._startedUpHandlers) { this._logger.trace(" ... starting up handlers!"); - this._handlers.onExperimentStartup(this._dataStore); + try { + this._handlers.onExperimentStartup(this._dataStore); + } catch(e) { + this._dataStore.logException("onExperimentStartup: " + e); + } this._startedUpHandlers = true; } }, @@ -526,7 +545,11 @@ TestPilotExperiment.prototype = { onExperimentShutdown: function TestPilotExperiment_onShutdown() { this._logger.trace("Experiment.onExperimentShutdown called."); if (this.experimentIsRunning() && this._startedUpHandlers) { - this._handlers.onExperimentShutdown(); + try { + this._handlers.onExperimentShutdown(); + } catch(e) { + this._dataStore.logException("onExperimentShutdown: " + e); + } this._startedUpHandlers = false; } }, @@ -534,21 +557,33 @@ TestPilotExperiment.prototype = { doExperimentCleanup: function TestPilotExperiment_doExperimentCleanup() { if (this._handlers.doExperimentCleanup) { this._logger.trace("Doing experiment cleanup."); - this._handlers.doExperimentCleanup(); + try { + this._handlers.doExperimentCleanup(); + } catch(e) { + this._dataStore.logException("doExperimentCleanup: " + e); + } } }, onEnterPrivateBrowsing: function TestPilotExperiment_onEnterPrivate() { this._logger.trace("Task is entering private browsing."); if (this.experimentIsRunning()) { - this._handlers.onEnterPrivateBrowsing(); + try { + this._handlers.onEnterPrivateBrowsing(); + } catch(e) { + this._dataStore.logException("onEnterPrivateBrowsing: " + e); + } } }, onExitPrivateBrowsing: function TestPilotExperiment_onExitPrivate() { this._logger.trace("Task is exiting private browsing."); if (this.experimentIsRunning()) { - this._handlers.onExitPrivateBrowsing(); + try { + this._handlers.onExitPrivateBrowsing(); + } catch(e) { + this._dataStore.logException("onExitPrivateBrowsing: " + e); + } } }, @@ -778,9 +813,12 @@ TestPilotExperiment.prototype = { } } self._dataStore.getJSONRows(function(rows) { - json.events = rows; - callback( JSON.stringify(json) ); - }); + json.events = rows; + self._dataStore.getExceptionsAsJson(function(errs) { + json.exceptions = errs; + callback( JSON.stringify(json) ); + }); + }); }); },