Bug 1012924 - Instrumenting Expriments.jsm's AsyncShutdown. r=gfritzsche, a=sledru
authorDavid Rajchenbach-Teller <dteller@mozilla.com>
Mon, 07 Jul 2014 07:35:00 -0400
changeset 207807 dd403b084fd52d17e4cf65679203b487cb19a2d4
parent 207806 4c63c27ed22d25d66513542a74538e18f4dd8262
child 207808 06dd0707ddbf6145716949fb72ef7e69fd4c7e1d
push id3741
push userasasaki@mozilla.com
push dateMon, 21 Jul 2014 20:25:18 +0000
treeherdermozilla-beta@4d6f46f5af68 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersgfritzsche, sledru
bugs1012924
milestone32.0a2
Bug 1012924 - Instrumenting Expriments.jsm's AsyncShutdown. r=gfritzsche, a=sledru
browser/experiments/Experiments.jsm
--- a/browser/experiments/Experiments.jsm
+++ b/browser/experiments/Experiments.jsm
@@ -346,21 +346,38 @@ function AlreadyShutdownError(message="a
 AlreadyShutdownError.prototype = Object.create(Error.prototype);
 AlreadyShutdownError.prototype.constructor = AlreadyShutdownError;
 
 /**
  * Manages the experiments and provides an interface to control them.
  */
 
 Experiments.Experiments = function (policy=new Experiments.Policy()) {
-  this._log = Log.repository.getLoggerWithMessagePrefix(
-    "Browser.Experiments.Experiments",
-    "Experiments #" + gExperimentsCounter++ + "::");
+  let log = Log.repository.getLoggerWithMessagePrefix(
+      "Browser.Experiments.Experiments",
+      "Experiments #" + gExperimentsCounter++ + "::");
+
+  // At the time of this writing, Experiments.jsm has severe
+  // crashes. For forensics purposes, keep the last few log
+  // messages in memory and upload them in case of crash.
+  this._forensicsLogs = [];
+  this._forensicsLogs.length = 3;
+  this._log = Object.create(log);
+  this._log.log = (level, string, params) => {
+    this._forensicsLogs.shift();
+    this._forensicsLogs.push(level + ": " + string);
+    log.log(level, string, params);
+  };
+
   this._log.trace("constructor");
 
+  // Capture the latest error, for forensics purposes.
+  this._latestError = null;
+
+
   this._policy = policy;
 
   // This is a Map of (string -> ExperimentEntry), keyed with the experiment id.
   // It holds both the current experiments and history.
   // Map() preserves insertion order, which means we preserve the manifest order.
   // This is null until we've successfully completed loading the cache from
   // disk the first time.
   this._experiments = null;
@@ -401,30 +418,33 @@ Experiments.Experiments.prototype = {
 
     gPrefs.observe(PREF_LOGGING, configureLogging);
     gPrefs.observe(PREF_MANIFEST_URI, this.updateManifest, this);
     gPrefs.observe(PREF_ENABLED, this._toggleExperimentsEnabled, this);
 
     gPrefsTelemetry.observe(PREF_TELEMETRY_ENABLED, this._telemetryStatusChanged, this);
 
     AsyncShutdown.profileBeforeChange.addBlocker("Experiments.jsm shutdown",
-      this.uninit.bind(this));
+      this.uninit.bind(this),
+      this._getState.bind(this)
+    );
 
     this._registerWithAddonManager();
 
     this._loadTask = this._loadFromCache();
 
     return this._loadTask.then(
       () => {
         this._log.trace("_loadTask finished ok");
         this._loadTask = null;
         return this._run();
       },
       (e) => {
         this._log.error("_loadFromCache caught error: " + e);
+        this._latestError = e;
         throw e;
       }
     );
   },
 
   /**
    * Uninitialize this instance.
    *
@@ -458,22 +478,54 @@ Experiments.Experiments.prototype = {
 
     this._shutdown = true;
     if (this._mainTask) {
       try {
         this._log.trace("uninit: waiting on _mainTask");
         yield this._mainTask;
       } catch (e if e instanceof AlreadyShutdownError) {
         // We error out of tasks after shutdown via that exception.
+      } catch (e) {
+        this._latestError = e;
+        throw e;
       }
     }
 
     this._log.info("Completed uninitialization.");
   }),
 
+  // Return state information, for debugging purposes.
+  _getState: function() {
+    let state = {
+      isShutdown: this._shutdown,
+      isEnabled: gExperimentsEnabled,
+      isRefresh: this._refresh,
+      isDirty: this._dirty,
+      isFirstEvaluate: this._firstEvaluate,
+      hasLoadTask: !!this._loadTask,
+      hasMainTask: !!this._mainTask,
+      hasTimer: !!this._hasTimer,
+      hasAddonProvider: !!gAddonProvider,
+      latestLogs: this._forensicsLogs,
+      experiments: this._experiments.keys(),
+      terminateReason: this._terminateReason,
+    };
+    if (this._latestError) {
+      if (typeof this._latestError == "object") {
+        state.latestError = {
+          message: this._latestError.message,
+          stack: this._latestError.stack
+        };
+      } else {
+        state.latestError = "" + this._latestError;
+      }
+    }
+    return state;
+  },
+
   _registerWithAddonManager: function (previousExperimentsProvider) {
     this._log.trace("Registering instance with Addon Manager.");
 
     AddonManager.addAddonListener(this);
     AddonManager.addInstallListener(this);
 
     if (!gAddonProvider) {
       // The properties of this AddonType should be kept in sync with the
@@ -496,18 +548,21 @@ Experiments.Experiments.prototype = {
     this._log.trace("Unregistering instance with Addon Manager.");
 
     if (gAddonProvider) {
       this._log.trace("Unregistering previous experiment add-on provider.");
       AddonManagerPrivate.unregisterProvider(gAddonProvider);
       gAddonProvider = null;
     }
 
+    this._log.trace("Removing install listener from add-on manager.");
     AddonManager.removeInstallListener(this);
+    this._log.trace("Removing addon listener from add-on manager.");
     AddonManager.removeAddonListener(this);
+    this._log.trace("Finished unregistering with addon manager.");
   },
 
   /*
    * Change the PreviousExperimentsProvider that this instance uses.
    * For testing only.
    */
   _setPreviousExperimentsProvider: function (provider) {
     this._unregisterWithAddonManager();