chore(testrunner): distinguish between TERMINATED and CRASHED (#4821)

`testRunner.run()` might have 4 different outcomes: - `ok` - all non-skipped tests passed - `failed` - some tests failed or timed out - `terminated` - process received SIGHUP/SIGINT while testrunner was running tests. This happens on CI's under certain circumstances, e.g. when VM is getting re-scheduled. - `crashed` - testrunner terminated test execution due to either `UnhandledPromiseRejection` or some of the hooks (`beforeEach/afterEach/beforeAll/afterAll`) failures. As an implication, there are 2 new test results: `terminated` and `crashed`. All possible test results are: - `ok` - test worked just fine - `skipped` - test was skipped with `xit` - `timedout` - test timed out - `failed` - test threw an exception while running - `terminated` - testrunner got terminated while running this test - `crashed` - some `beforeEach` / `afterEach` hook corresponding to this test timed out of threw an exception. This patch changes a few parts of the testrunner API: - `testRunner.run()` now returns an object `{result: string, terminationError?: Error, terminationMessage?: string}` - the same object is dispatched via `testRunner.on('finished')` event - `testRunner.on('terminated')` got removed - tests now might have `crashed` and `terminated` results - `testRunner.on('teststarted')` dispatched before running all related `beforeEach` hooks, and `testRunner.on('testfinished')` dispatched after running all related `afterEach` hooks.
puppeteer · Aug 8, 2019 · f753ec6 · f753ec6
1 parent c047624
commit f753ec6
Show file tree

Hide file tree

Showing 4 changed files with 234 additions and 111 deletions.
diff --git a/test/utils.js b/test/utils.js
@@ -215,7 +215,6 @@ const utils = module.exports = {
         result: test.result,
       });
     });
-    testRunner.on('terminated', () => dashboard.uploadAndCleanup());
     testRunner.on('finished', () => dashboard.uploadAndCleanup());
 
     function generateTestIDs(testRunner) {

diff --git a/utils/testrunner/Reporter.js b/utils/testrunner/Reporter.js
@@ -17,6 +17,7 @@
 const RED_COLOR = '\x1b[31m';
 const GREEN_COLOR = '\x1b[32m';
 const YELLOW_COLOR = '\x1b[33m';
+const MAGENTA_COLOR = '\x1b[35m';
 const RESET_COLOR = '\x1b[0m';
 
 class Reporter {
@@ -34,7 +35,6 @@ class Reporter {
     this._summary = summary;
     this._testCounter = 0;
     runner.on('started', this._onStarted.bind(this));
-    runner.on('terminated', this._onTerminated.bind(this));
     runner.on('finished', this._onFinished.bind(this));
     runner.on('teststarted', this._onTestStarted.bind(this));
     runner.on('testfinished', this._onTestFinished.bind(this));
@@ -51,9 +51,8 @@ class Reporter {
       console.log(`Running ${YELLOW_COLOR}${runnableTests.length}${RESET_COLOR} focused tests out of total ${YELLOW_COLOR}${allTests.length}${RESET_COLOR} on ${YELLOW_COLOR}${this._runner.parallel()}${RESET_COLOR} worker(s):\n`);
   }
 
-  _onTerminated(message, error) {
-    this._printTestResults();
-    console.log(`${RED_COLOR}## TERMINATED ##${RESET_COLOR}`);
+  _printTermination(result, message, error) {
+    console.log(`${RED_COLOR}## ${result.toUpperCase()} ##${RESET_COLOR}`);
     console.log('Message:');
     console.log(`  ${RED_COLOR}${message}${RESET_COLOR}`);
     if (error && error.stack) {
@@ -74,19 +73,24 @@ class Reporter {
         description = `${YELLOW_COLOR}SKIPPED${RESET_COLOR}`;
       else if (test.result === 'failed')
         description = `${RED_COLOR}FAILED${RESET_COLOR}`;
+      else if (test.result === 'crashed')
+        description = `${RED_COLOR}CRASHED${RESET_COLOR}`;
       else if (test.result === 'timedout')
         description = `${RED_COLOR}TIMEDOUT${RESET_COLOR}`;
+      else if (test.result === 'terminated')
+        description = `${MAGENTA_COLOR}TERMINATED${RESET_COLOR}`;
       else
         description = `${RED_COLOR}<UNKNOWN>${RESET_COLOR}`;
       console.log(`  ${workerId}: [${description}] ${test.fullName} (${formatTestLocation(test)})`);
     }
     process.exitCode = 2;
   }
 
-  _onFinished() {
+  _onFinished({result, terminationError, terminationMessage}) {
     this._printTestResults();
-    const failedTests = this._runner.failedTests();
-    process.exitCode = failedTests.length > 0 ? 1 : 0;
+    if (terminationMessage || terminationError)
+      this._printTermination(result, terminationMessage, terminationError);
+    process.exitCode = result === 'ok' ? 0 : 1;
   }
 
   _printTestResults() {
@@ -102,6 +106,9 @@ class Reporter {
         if (test.result === 'timedout') {
           console.log('  Message:');
           console.log(`    ${RED_COLOR}Timeout Exceeded ${this._runner.timeout()}ms${RESET_COLOR}`);
+        } else if (test.result === 'crashed') {
+          console.log('  Message:');
+          console.log(`    ${RED_COLOR}CRASHED${RESET_COLOR}`);
         } else {
           console.log('  Message:');
           console.log(`    ${RED_COLOR}${test.error.message || test.error}${RESET_COLOR}`);
@@ -189,6 +196,10 @@ class Reporter {
       ++this._testCounter;
       if (test.result === 'ok') {
         console.log(`${this._testCounter}) ${GREEN_COLOR}[ OK ]${RESET_COLOR} ${test.fullName} (${formatTestLocation(test)})`);
+      } else if (test.result === 'terminated') {
+        console.log(`${this._testCounter}) ${MAGENTA_COLOR}[ TERMINATED ]${RESET_COLOR} ${test.fullName} (${formatTestLocation(test)})`);
+      } else if (test.result === 'crashed') {
+        console.log(`${this._testCounter}) ${RED_COLOR}[ CRASHED ]${RESET_COLOR} ${test.fullName} (${formatTestLocation(test)})`);
       } else if (test.result === 'skipped') {
         console.log(`${this._testCounter}) ${YELLOW_COLOR}[SKIP]${RESET_COLOR} ${test.fullName} (${formatTestLocation(test)})`);
       } else if (test.result === 'failed') {
@@ -214,6 +225,10 @@ class Reporter {
         process.stdout.write(`${YELLOW_COLOR}*${RESET_COLOR}`);
       else if (test.result === 'failed')
         process.stdout.write(`${RED_COLOR}F${RESET_COLOR}`);
+      else if (test.result === 'crashed')
+        process.stdout.write(`${RED_COLOR}C${RESET_COLOR}`);
+      else if (test.result === 'terminated')
+        process.stdout.write(`${MAGENTA_COLOR}.${RESET_COLOR}`);
       else if (test.result === 'timedout')
         process.stdout.write(`${RED_COLOR}T${RESET_COLOR}`);
     }

diff --git a/utils/testrunner/TestRunner.js b/utils/testrunner/TestRunner.js
@@ -97,6 +97,8 @@ const TestResult = {
   Skipped: 'skipped', // User skipped the test
   Failed: 'failed', // Exception happened during running
   TimedOut: 'timedout', // Timeout Exceeded while running
+  Terminated: 'terminated', // Execution terminated
+  Crashed: 'crashed', // If testrunner crashed due to this test
 };
 
 class Test {
@@ -162,10 +164,10 @@ class TestPass {
 
   async run() {
     const terminations = [
-      createTermination.call(this, 'SIGINT', 'SIGINT received'),
-      createTermination.call(this, 'SIGHUP', 'SIGHUP received'),
-      createTermination.call(this, 'SIGTERM', 'SIGTERM received'),
-      createTermination.call(this, 'unhandledRejection', 'UNHANDLED PROMISE REJECTION'),
+      createTermination.call(this, 'SIGINT', TestResult.Terminated, 'SIGINT received'),
+      createTermination.call(this, 'SIGHUP', TestResult.Terminated, 'SIGHUP received'),
+      createTermination.call(this, 'SIGTERM', TestResult.Terminated, 'SIGTERM received'),
+      createTermination.call(this, 'unhandledRejection', TestResult.Crashed, 'UNHANDLED PROMISE REJECTION'),
     ];
     for (const termination of terminations)
       process.on(termination.event, termination.handler);
@@ -179,11 +181,11 @@ class TestPass {
       process.removeListener(termination.event, termination.handler);
     return this._termination;
 
-    function createTermination(event, message) {
+    function createTermination(event, result, message) {
       return {
         event,
         message,
-        handler: error => this._terminate(message, error)
+        handler: error => this._terminate(result, message, error)
       };
     }
   }
@@ -201,11 +203,7 @@ class TestPass {
       if (!this._workerDistribution.hasValue(child, workerId))
         continue;
       if (child instanceof Test) {
-        for (let i = 0; i < suitesStack.length; i++)
-          await this._runHook(workerId, suitesStack[i], 'beforeEach', state, child);
-        await this._runTest(workerId, child, state);
-        for (let i = suitesStack.length - 1; i >= 0; i--)
-          await this._runHook(workerId, suitesStack[i], 'afterEach', state, child);
+        await this._runTest(workerId, suitesStack, child, state);
       } else {
         suitesStack.push(child);
         await this._runSuite(workerId, suitesStack, state);
@@ -215,7 +213,7 @@ class TestPass {
     await this._runHook(workerId, currentSuite, 'afterAll', state);
   }
 
-  async _runTest(workerId, test, state) {
+  async _runTest(workerId, suitesStack, test, state) {
     if (this._termination)
       return;
     this._runner._willStartTest(test, workerId);
@@ -224,47 +222,65 @@ class TestPass {
       this._runner._didFinishTest(test, workerId);
       return;
     }
-    this._runningUserCallbacks.set(workerId, test._userCallback);
-    const error = await test._userCallback.run(state, test);
-    this._runningUserCallbacks.delete(workerId, test._userCallback);
-    if (this._termination)
-      return;
-    test.error = error;
-    if (!error)
-      test.result = TestResult.Ok;
-    else if (test.error === TimeoutError)
-      test.result = TestResult.TimedOut;
-    else
-      test.result = TestResult.Failed;
+    let crashed = false;
+    for (let i = 0; i < suitesStack.length; i++)
+      crashed = (await this._runHook(workerId, suitesStack[i], 'beforeEach', state, test)) || crashed;
+    // If some of the beofreEach hooks error'ed - terminate this test.
+    if (crashed) {
+      test.result = TestResult.Crashed;
+    } else if (this._termination) {
+      test.result = TestResult.Terminated;
+    } else {
+      // Otherwise, run the test itself if there is no scheduled termination.
+      this._runningUserCallbacks.set(workerId, test._userCallback);
+      test.error = await test._userCallback.run(state, test);
+      this._runningUserCallbacks.delete(workerId, test._userCallback);
+      if (!test.error)
+        test.result = TestResult.Ok;
+      else if (test.error === TimeoutError)
+        test.result = TestResult.TimedOut;
+      else if (test.error === TerminatedError)
+        test.result = TestResult.Terminated;
+      else
+        test.result = TestResult.Failed;
+    }
+    for (let i = suitesStack.length - 1; i >= 0; i--)
+      crashed = (await this._runHook(workerId, suitesStack[i], 'afterEach', state, test)) || crashed;
+    // If some of the afterEach hooks error'ed - then this test is considered to be crashed as well.
+    if (crashed)
+      test.result = TestResult.Crashed;
     this._runner._didFinishTest(test, workerId);
     if (this._breakOnFailure && test.result !== TestResult.Ok)
-      this._terminate(`Terminating because a test has failed and |testRunner.breakOnFailure| is enabled`, null);
+      this._terminate(TestResult.Terminated, `Terminating because a test has failed and |testRunner.breakOnFailure| is enabled`, null);
   }
 
   async _runHook(workerId, suite, hookName, ...args) {
     const hook = suite[hookName];
     if (!hook)
-      return;
+      return false;
     this._runningUserCallbacks.set(workerId, hook);
     const error = await hook.run(...args);
     this._runningUserCallbacks.delete(workerId, hook);
     if (error === TimeoutError) {
       const location = `${hook.location.fileName}:${hook.location.lineNumber}:${hook.location.columnNumber}`;
       const message = `${location} - Timeout Exceeded ${hook.timeout}ms while running "${hookName}" in suite "${suite.fullName}"`;
-      this._terminate(message, null);
-    } else if (error) {
+      return this._terminate(TestResult.Crashed, message, null);
+    }
+    if (error) {
       const location = `${hook.location.fileName}:${hook.location.lineNumber}:${hook.location.columnNumber}`;
       const message = `${location} - FAILED while running "${hookName}" in suite "${suite.fullName}"`;
-      this._terminate(message, error);
+      return this._terminate(TestResult.Crashed, message, error);
     }
+    return false;
   }
 
-  _terminate(message, error) {
+  _terminate(result, message, error) {
     if (this._termination)
-      return;
-    this._termination = {message, error};
+      return false;
+    this._termination = {result, message, error};
     for (const userCallback of this._runningUserCallbacks.valuesArray())
       userCallback.terminate();
+    return true;
   }
 }
 
@@ -351,16 +367,22 @@ class TestRunner extends EventEmitter {
     this._runningPass = new TestPass(this, this._rootSuite, runnableTests, this._parallel, this._breakOnFailure);
     const termination = await this._runningPass.run();
     this._runningPass = null;
-    if (termination)
-      this.emit(TestRunner.Events.Terminated, termination.message, termination.error);
-    else
-      this.emit(TestRunner.Events.Finished);
+    const result = {};
+    if (termination) {
+      result.result = termination.result;
+      result.terminationMessage = termination.message;
+      result.terminationError = termination.error;
+    } else {
+      result.result = this.failedTests().length ? TestResult.Failed : TestResult.Ok;
+    }
+    this.emit(TestRunner.Events.Finished, result);
+    return result;
   }
 
   terminate() {
     if (!this._runningPass)
       return;
-    this._runningPass._terminate('Terminated with |TestRunner.terminate()| call', null);
+    this._runningPass._terminate(TestResult.Terminated, 'Terminated with |TestRunner.terminate()| call', null);
   }
 
   timeout() {
@@ -405,7 +427,7 @@ class TestRunner extends EventEmitter {
   }
 
   failedTests() {
-    return this._tests.filter(test => test.result === 'failed' || test.result === 'timedout');
+    return this._tests.filter(test => test.result === 'failed' || test.result === 'timedout' || test.result === 'crashed');
   }
 
   passedTests() {
@@ -442,10 +464,9 @@ function assert(value, message) {
 
 TestRunner.Events = {
   Started: 'started',
+  Finished: 'finished',
   TestStarted: 'teststarted',
   TestFinished: 'testfinished',
-  Terminated: 'terminated',
-  Finished: 'finished',
 };
 
 module.exports = TestRunner;