Bug 1444826 - Stop DAMP with explicit error on exceptions and timeouts. r=jdescottes,jmaher
authorAlexandre Poirot <poirot.alex@gmail.com>
Tue, 27 Mar 2018 03:44:57 -0700
changeset 410593 84ba9406ef28f591ac98702ee3bcf0a656bb3cf2
parent 410592 d4ffee5831765d4ee616d3dd88c601268db5fb31
child 410594 3d25026d07ef61dcb7951a9afd4c3cd6d4f8af22
push id33733
push useraciure@mozilla.com
push dateThu, 29 Mar 2018 22:05:29 +0000
treeherdermozilla-central@7ca58ce09779 [default view] [failures only]
perfherder[talos] [build metrics] [platform microbench] (compared to previous push)
reviewersjdescottes, jmaher
bugs1444826
milestone61.0a1
first release with
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
last release without
nightly linux32
nightly linux64
nightly mac
nightly win32
nightly win64
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);
+    }
   }
 };