Bug 957123 - Extend error reporting of AsyncShutdown. r=froydnj

toolkit/modules/AsyncShutdown.jsm

@@ -108,6 +108,34 @@ function err(msg, error = null) {
   return log(msg, "ERROR: ", error);
 }
 
+// Utility function designed to get the current state of execution
+// of a blocker.
+// We are a little paranoid here to ensure that in case of evaluation
+// error we do not block the AsyncShutdown.
+function safeGetState(state) {
+  if (!state) {
+    return "(none)";
+  }
+  try {
+    // Evaluate state(), normalize the result into something that we can
+    // safely stringify or upload.
+    let string = JSON.stringify(state());
+    let data = JSON.parse(string);
+    // Simplify the rest of the code by ensuring that we can simply
+    // concatenate the result to a message.
+    data.toString = function() {
+      return string;
+    };
+    return data;
+  } catch (ex) {
+    try {
+      return "Error getting state: " + ex;
+    } catch (ex2) {
+      return "Could not display error";
+    }
+  }
+}
+
 /**
  * Countdown for a given duration, skipping beats if the computer is too busy,
  * sleeping or otherwise unavailable.
@@ -186,6 +214,10 @@ function getPhase(topic) {
      * resulting promise is either resolved or rejected. If
      * |condition| is not a function but another value |v|, it behaves
      * as if it were a function returning |v|.
+     * @param {function*} state Optionally, a function returning
+     * information about the current state of the blocker as an
+     * object. Used for providing more details when logging errors or
+     * crashing.
      *
      * Examples:
      * AsyncShutdown.profileBeforeChange.addBlocker("Module: just a promise",
@@ -209,11 +241,14 @@ function getPhase(topic) {
      * });
      *
      */
-    addBlocker: function(name, condition) {
+    addBlocker: function(name, condition, state = null) {
       if (typeof name != "string") {
         throw new TypeError("Expected a human-readable name as first argument");
       }
-      spinner.addBlocker({name: name, condition: condition});
+      if (state && typeof state != "function") {
+        throw new TypeError("Expected nothing or a function as third argument");
+      }
+      spinner.addBlocker({name: name, condition: condition, state: state});
     }
   });
   gPhases.set(topic, phase);
@@ -274,7 +309,7 @@ Spinner.prototype = {
     // are not satisfied yet.
     let allMonitors = [];
 
-    for (let {condition, name} of conditions) {
+    for (let {condition, name, state} of conditions) {
       // Gather all completion conditions
 
       try {
@@ -303,13 +338,15 @@ Spinner.prototype = {
           let msg = "A phase completion condition is" +
             " taking too long to complete." +
             " Condition: " + monitor.name +
-            " Phase: " + topic;
+            " Phase: " + topic +
+            " State: " + safeGetState(state);
           warn(msg);
         }, DELAY_WARNING_MS, Ci.nsITimer.TYPE_ONE_SHOT);
 
         let monitor = {
           isFrozen: true,
-          name: name
+          name: name,
+          state: state
         };
         condition = condition.then(function onSuccess() {
             timer.cancel(); // As a side-effect, this prevents |timer| from
@@ -320,7 +357,8 @@ Spinner.prototype = {
             let msg = "A completion condition encountered an error" +
                 " while we were spinning the event loop." +
                 " Condition: " + name +
-                " Phase: " + topic;
+                " Phase: " + topic +
+                " State: " + safeGetState(state);
             warn(msg, error);
             monitor.isFrozen = false;
         });
@@ -331,7 +369,8 @@ Spinner.prototype = {
           let msg = "A completion condition encountered an error" +
                 " while we were initializing the phase." +
                 " Condition: " + name +
-                " Phase: " + topic;
+                " Phase: " + topic +
+                " State: " + safeGetState(state);
           warn(msg, error);
       }
 
@@ -362,9 +401,10 @@ Spinner.prototype = {
       function onTimeout() {
         // Report the problem as best as we can, then crash.
         let frozen = [];
-        for (let {name, isFrozen} of allMonitors) {
+        let states = [];
+        for (let {name, isFrozen, state} of allMonitors) {
           if (isFrozen) {
-            frozen.push(name);
+            frozen.push({name: name, state: safeGetState(state)});
           }
         }
 
@@ -372,7 +412,7 @@ Spinner.prototype = {
               " within a reasonable amount of time. Causing a crash to" +
               " ensure that we do not leave the user with an unresponsive" +
               " process draining resources." +
-              " Conditions: " + frozen.join(", ") +
+              " Conditions: " + JSON.stringify(frozen) +
               " Phase: " + topic;
         err(msg);
         if (gCrashReporter && gCrashReporter.enabled) {

toolkit/modules/tests/xpcshell/test_AsyncShutdown.js

@@ -54,23 +54,37 @@ add_task(function test_simple_async() {
   for (let arg of [undefined, null, "foo", 100, new Error("BOOM")]) {
     for (let resolution of [arg, Promise.reject(arg)]) {
       for (let success of [false, true]) {
-        // Asynchronous phase
-        do_print("Asynchronous test with " + arg + ", " + resolution);
-        let topic = getUniqueTopic();
-        let outParam = { isFinished: false };
-        AsyncShutdown._getPhase(topic).addBlocker(
-          "Async test",
-            function() {
-              if (success) {
-                return longRunningAsyncTask(resolution, outParam);
-              } else {
-                throw resolution;
-              }
-            }
-        );
-        do_check_false(outParam.isFinished);
-        Services.obs.notifyObservers(null, topic, null);
-        do_check_eq(outParam.isFinished, success);
+        for (let state of [[null],
+                           [],
+                           [() => "some state"],
+                           [function() {
+                             throw new Error("State BOOM"); }],
+                           [function() {
+                             return {
+                               toJSON: function() {
+                                 throw new Error("State.toJSON BOOM");
+                               }
+                             };
+                           }]]) {
+          // Asynchronous phase
+          do_print("Asynchronous test with " + arg + ", " + resolution);
+          let topic = getUniqueTopic();
+          let outParam = { isFinished: false };
+          AsyncShutdown._getPhase(topic).addBlocker(
+            "Async test",
+              function() {
+                if (success) {
+                  return longRunningAsyncTask(resolution, outParam);
+                } else {
+                  throw resolution;
+                }
+              },
+              ...state
+          );
+          do_check_false(outParam.isFinished);
+          Services.obs.notifyObservers(null, topic, null);
+          do_check_eq(outParam.isFinished, success);
+        }
       }
 
       // Synchronous phase - just test that we don't throw/freeze
@@ -128,6 +142,9 @@ add_task(function test_various_failures() {
 
   exn = get_exn(() => phase.addBlocker(null, true));
   do_check_eq(exn.name, "TypeError");
+
+  exn = get_exn(() => phase.addBlocker("Test 2", () => true, "not a function"));
+  do_check_eq(exn.name, "TypeError");
 });
 
 add_task(function() {