Bug 1444826 - Stop DAMP with explicit error on exceptions and timeouts. r=jdescottes,jmaher draft
authorAlexandre Poirot <poirot.alex@gmail.com>
Tue, 27 Mar 2018 03:44:57 -0700
changeset 773851 ae2638626c47e214b1f672c49eb2507ca88f2752
parent 773758 0742ed43363d7843cb98a4bf4b166dd97a02d62a
child 773867 b6b2bac91aee73e4905f80cd7d19f8e9e2b3bd11
push id104322
push userbmo:poirot.alex@gmail.com
push dateWed, 28 Mar 2018 16:02:07 +0000
reviewersjdescottes, jmaher
bugs1444826
milestone61.0a1
Bug 1444826 - Stop DAMP with explicit error on exceptions and timeouts. r=jdescottes,jmaher MozReview-Commit-ID: 702sQNOeQol
testing/talos/talos/talos_process.py
testing/talos/talos/tests/devtools/addon/content/damp.js
--- a/testing/talos/talos/talos_process.py
+++ b/testing/talos/talos/talos_process.py
@@ -56,27 +56,31 @@ class ProcessContext(object):
 
 
 class Reader(object):
     def __init__(self, event):
         self.output = []
         self.got_end_timestamp = False
         self.got_timeout = False
         self.timeout_message = ''
+        self.got_error = False
         self.event = event
         self.proc = None
 
     def __call__(self, line):
         if line.find('__endTimestamp') != -1:
             self.got_end_timestamp = True
             self.event.set()
         elif line == 'TART: TIMEOUT':
             self.got_timeout = True
             self.timeout_message = 'TART'
             self.event.set()
+        elif line.startswith('TEST-UNEXPECTED-FAIL | '):
+            self.got_error = True
+            self.event.set()
 
         if not (line.startswith('JavaScript error:') or
                 line.startswith('JavaScript warning:')):
             LOG.process_output(self.proc.pid, line)
             self.output.append(line)
 
 
 def run_browser(command, minidump_dir, timeout=None, on_started=None,
@@ -143,16 +147,18 @@ def run_browser(command, minidump_dir, t
                     break
             if proc.poll() is None:
                 LOG.info(
                     "Browser shutdown timed out after {0} seconds, terminating"
                     " process.".format(wait_for_quit_timeout)
                 )
         elif reader.got_timeout:
             raise TalosError('TIMEOUT: %s' % reader.timeout_message)
+        elif reader.got_error:
+            raise TalosError("unexpected error")
     finally:
         # this also handle KeyboardInterrupt
         # ensure early the process is really terminated
         return_code = None
         try:
             return_code = context.kill_process()
             if return_code is None:
                 return_code = proc.wait(1)
--- a/testing/talos/talos/tests/devtools/addon/content/damp.js
+++ b/testing/talos/talos/tests/devtools/addon/content/damp.js
@@ -16,16 +16,19 @@ XPCOMUtils.defineLazyGetter(this, "Targe
   return TargetFactory;
 });
 
 // Record allocation count in new subtests if DEBUG_DEVTOOLS_ALLOCATIONS is set to
 // "normal". Print allocation sites to stdout if DEBUG_DEVTOOLS_ALLOCATIONS is set to
 // "verbose".
 const DEBUG_ALLOCATIONS = env.get("DEBUG_DEVTOOLS_ALLOCATIONS");
 
+// Maximum time spent in one test, in milliseconds
+const TEST_TIMEOUT = 5 * 60000;
+
 function getMostRecentBrowserWindow() {
   return Services.wm.getMostRecentWindow("navigator:browser");
 }
 
 function getActiveTab(window) {
   return window.gBrowser.selectedTab;
 }
 
@@ -184,42 +187,73 @@ Damp.prototype = {
   },
 
   async testTeardown(url) {
     this.closeCurrentTab();
 
     // Force freeing memory now so that it doesn't happen during the next test
     await this.garbageCollect();
 
+    let duration = Math.round(performance.now() - this._startTime);
+    dump(`${this._currentTest} took ${duration}ms.\n`);
+
     this._runNextTest();
   },
 
   // Everything below here are common pieces needed for the test runner to function,
   // just copy and pasted from Tart with /s/TART/DAMP
 
   _win: undefined,
   _dampTab: undefined,
   _results: [],
   _config: {subtests: [], repeat: 1, rest: 100},
   _nextTestIndex: 0,
   _tests: [],
   _onSequenceComplete: 0,
+
+  // Timeout ID to guard against current test never finishing
+  _timeout: null,
+
+  // The unix time at which the current test started (ms)
+  _startTime: null,
+
+  // Name of the test currently executed (i.e. path from /tests folder)
+  _currentTest: null,
+
+  // Is DAMP finished executing? Help preventing async execution when DAMP had an error
+  _done: false,
+
   _runNextTest() {
+    window.clearTimeout(this._timeout);
+
     if (this._nextTestIndex >= this._tests.length) {
       this._onSequenceComplete();
       return;
     }
 
     let test = this._tests[this._nextTestIndex++];
+    this._startTime = performance.now();
+    this._currentTest = test;
 
-    dump("Loading test : " + test + "\n");
+    dump(`Loading test '${test}'\n`);
     let testMethod = require("chrome://damp/content/tests/" + test);
 
-    dump("Executing test : " + test + "\n");
-    testMethod();
+    this._timeout = window.setTimeout(() => {
+      this.error("Test timed out");
+    }, TEST_TIMEOUT);
+
+    dump(`Executing test '${test}'\n`);
+    let promise = testMethod();
+
+    // If test method is an async function, ensure catching its exceptions
+    if (promise && typeof(promise.catch) == "function") {
+      promise.catch(e => {
+        this.exception(e);
+      });
+    }
   },
   // Each command at the array a function which must call nextCommand once it's done
   _doSequence(tests, onComplete) {
     this._tests = tests;
     this._onSequenceComplete = onComplete;
     this._results = [];
     this._nextTestIndex = 0;
 
@@ -259,78 +293,114 @@ Damp.prototype = {
     } else {
       // alert(out);
     }
   },
 
   _onTestComplete: null,
 
   _doneInternal() {
+    // Ignore any duplicated call to this method
+    if (this._done) {
+      return;
+    }
+    this._done = true;
+
     if (this.allocationTracker) {
       this.allocationTracker.stop();
       this.allocationTracker = null;
     }
-    this._logLine("DAMP_RESULTS_JSON=" + JSON.stringify(this._results));
-    this._reportAllResults();
     this._win.gBrowser.selectedTab = this._dampTab;
 
+    if (this._results) {
+      this._logLine("DAMP_RESULTS_JSON=" + JSON.stringify(this._results));
+      this._reportAllResults();
+    }
+
     if (this._onTestComplete) {
       this._onTestComplete(JSON.parse(JSON.stringify(this._results))); // Clone results
     }
   },
 
   startAllocationTracker() {
     const { allocationTracker } = require("devtools/shared/test-helpers/allocation-tracker");
     return allocationTracker();
   },
 
-  startTest(doneCallback, config) {
-    dump("Initialize the head file with a reference to this DAMP instance\n");
-    let head = require("chrome://damp/content/tests/head.js");
-    head.initialize(this);
-
-    this._onTestComplete = function(results) {
-      TalosParentProfiler.pause("DAMP - end");
-      doneCallback(results);
-    };
-    this._config = config;
+  error(message) {
+    // Log a unique prefix in order to be interpreted as an error and stop DAMP from
+    // testing/talos/talos/talos_process.py
+    dump("TEST-UNEXPECTED-FAIL | damp | ");
 
-    this._win = Services.wm.getMostRecentWindow("navigator:browser");
-    this._dampTab = this._win.gBrowser.selectedTab;
-    this._win.gBrowser.selectedBrowser.focus(); // Unfocus the URL bar to avoid caret blink
-
-    TalosParentProfiler.resume("DAMP - start");
-
-    // Filter tests via `./mach --subtests filter` command line argument
-    let filter = Services.prefs.getCharPref("talos.subtests", "");
-
-    let tests = config.subtests.filter(test => !test.disabled)
-                               .filter(test => test.name.includes(filter));
-
-    if (tests.length === 0) {
-      dump("ERROR: Unable to find any test matching '" + filter + "'\n");
+    // Print the currently executed test, if we already started executing one
+    if (this._currentTest) {
+      dump(this._currentTest + ": ");
     }
 
-    // Run cold test only once
-    let topWindow = getMostRecentBrowserWindow();
-    if (topWindow.coldRunDAMPDone) {
-      tests = tests.filter(test => !test.cold);
-    } else {
-      topWindow.coldRunDAMPDone = true;
-    }
+    dump(message + "\n");
+
+    // Stop further test execution and immediatly close DAMP
+    this._tests = [];
+    this._results = null;
+    this._doneInternal();
+  },
+
+  exception(e) {
+    this.error(e);
+    dump(e.stack + "\n");
+  },
+
+  startTest(doneCallback, config) {
+    try {
+      dump("Initialize the head file with a reference to this DAMP instance\n");
+      let head = require("chrome://damp/content/tests/head.js");
+      head.initialize(this);
+
+      this._onTestComplete = function(results) {
+        TalosParentProfiler.pause("DAMP - end");
+        doneCallback(results);
+      };
+      this._config = config;
+
+      this._win = Services.wm.getMostRecentWindow("navigator:browser");
+      this._dampTab = this._win.gBrowser.selectedTab;
+      this._win.gBrowser.selectedBrowser.focus(); // Unfocus the URL bar to avoid caret blink
+
+      TalosParentProfiler.resume("DAMP - start");
+
+      // Filter tests via `./mach --subtests filter` command line argument
+      let filter = Services.prefs.getCharPref("talos.subtests", "");
 
-    // Construct the sequence array while filtering tests
-    let sequenceArray = [];
-    for (let test of tests) {
-      for (let r = 0; r < config.repeat; r++) {
-        sequenceArray.push(test.path);
+      let tests = config.subtests.filter(test => !test.disabled)
+                                 .filter(test => test.name.includes(filter));
+
+      if (tests.length === 0) {
+        this.error(`Unable to find any test matching '${filter}'`);
       }
-    }
+
+      // Run cold test only once
+      let topWindow = getMostRecentBrowserWindow();
+      if (topWindow.coldRunDAMPDone) {
+        tests = tests.filter(test => !test.cold);
+      } else {
+        topWindow.coldRunDAMPDone = true;
+      }
 
-    // Free memory before running the first test, otherwise we may have a GC
-    // related to Firefox startup or DAMP setup during the first test.
-    this.garbageCollect().then(() => {
-      this._doSequence(sequenceArray, this._doneInternal);
-    }).catch(e => {
-      dump("Exception while running DAMP tests: " + e + "\n" + e.stack + "\n");
-    });
+      // Construct the sequence array while filtering tests
+      let sequenceArray = [];
+      for (let test of tests) {
+        for (let r = 0; r < config.repeat; r++) {
+          sequenceArray.push(test.path);
+        }
+      }
+
+      // Free memory before running the first test, otherwise we may have a GC
+      // related to Firefox startup or DAMP setup during the first test.
+      this.garbageCollect().then(() => {
+        this._doSequence(sequenceArray, this._doneInternal);
+      }).catch(e => {
+        this.exception(e);
+      });
+    } catch (e) {
+      this.exception(e);
+    }
   }
 };