From a210dd7ee2f350ffabd7d69a60f96b872b861087 Mon Sep 17 00:00:00 2001 From: Andrey Lushnikov Date: Tue, 5 Feb 2019 15:28:35 -0800 Subject: [PATCH] chore(testrunner): show 5 slowest tests on CI (#3919) Show top slowest tests on CI. Drive-by: some facelifting for the test reporter. --- test/test.js | 5 +++- utils/testrunner/Reporter.js | 43 ++++++++++++++++++++++++++-------- utils/testrunner/TestRunner.js | 18 +++++++++++--- 3 files changed, 52 insertions(+), 14 deletions(-) diff --git a/test/test.js b/test/test.js index f48b8aa4..8f0174e3 100644 --- a/test/test.js +++ b/test/test.js @@ -107,5 +107,8 @@ if (process.env.CI && testRunner.hasFocusedTestsOrSuites()) { process.exit(1); } -new Reporter(testRunner, utils.projectRoot()); +new Reporter(testRunner, { + projectFolder: utils.projectRoot(), + showSlowTests: process.env.CI ? 5 : 0, +}); testRunner.run(); diff --git a/utils/testrunner/Reporter.js b/utils/testrunner/Reporter.js index 3109765e..4657911d 100644 --- a/utils/testrunner/Reporter.js +++ b/utils/testrunner/Reporter.js @@ -20,9 +20,14 @@ const YELLOW_COLOR = '\x1b[33m'; const RESET_COLOR = '\x1b[0m'; class Reporter { - constructor(runner, testFolder = null) { + constructor(runner, options = {}) { + const { + projectFolder = null, + showSlowTests = 3, + } = options; this._runner = runner; - this._testFolder = testFolder; + this._projectFolder = projectFolder; + this._showSlowTests = showSlowTests; runner.on('started', this._onStarted.bind(this)); runner.on('terminated', this._onTerminated.bind(this)); runner.on('finished', this._onFinished.bind(this)); @@ -31,9 +36,13 @@ class Reporter { this._workersState = new Map(); } - _onStarted() { + _onStarted(runnableTests) { this._timestamp = Date.now(); - console.log(`Running ${YELLOW_COLOR}${this._runner.parallel()}${RESET_COLOR} worker(s):\n`); + const allTests = this._runner.tests(); + if (allTests.length === runnableTests.length) + console.log(`Running all ${YELLOW_COLOR}${runnableTests.length}${RESET_COLOR} tests on ${YELLOW_COLOR}${this._runner.parallel()}${RESET_COLOR} worker(s):\n`); + else + 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) { @@ -102,17 +111,31 @@ class Reporter { } } - const tests = this._runner.tests(); - const skippedTests = tests.filter(test => test.result === 'skipped'); + const skippedTests = this._runner.skippedTests(); if (skippedTests.length > 0) { console.log('\nSkipped:'); for (let i = 0; i < skippedTests.length; ++i) { const test = skippedTests[i]; - console.log(`${i + 1}) ${test.fullName}`); - console.log(` ${YELLOW_COLOR}Temporary disabled with xit${RESET_COLOR} ${formatTestLocation(test)}\n`); + console.log(`${i + 1}) ${test.fullName} (${YELLOW_COLOR}${formatTestLocation(test)}${RESET_COLOR})`); + console.log(` ${YELLOW_COLOR}Temporary disabled with xit${RESET_COLOR}`); } } + if (this._showSlowTests) { + const slowTests = this._runner.passedTests().sort((a, b) => { + const aDuration = a.endTimestamp - a.startTimestamp; + const bDuration = b.endTimestamp - b.startTimestamp; + return bDuration - aDuration; + }).slice(0, this._showSlowTests); + console.log(`\nSlowest tests:`); + for (let i = 0; i < slowTests.length; ++i) { + const test = slowTests[i]; + const duration = test.endTimestamp - test.startTimestamp; + console.log(` (${i + 1}) ${YELLOW_COLOR}${duration / 1000}s${RESET_COLOR} - ${test.fullName} (${YELLOW_COLOR}${formatTestLocation(test)}${RESET_COLOR})`); + } + } + + const tests = this._runner.tests(); const executedTests = tests.filter(test => test.result); console.log(`\nRan ${executedTests.length} of ${tests.length} test(s)`); const milliseconds = Date.now() - this._timestamp; @@ -121,7 +144,7 @@ class Reporter { } _beautifyStack(stack) { - if (!this._testFolder) + if (!this._projectFolder) return stack; const lines = stack.split('\n').map(line => ' ' + line); // Find last stack line that include testrunner code. @@ -133,7 +156,7 @@ class Reporter { if (index >= lines.length) return stack; const line = lines[index]; - const fromIndex = line.lastIndexOf(this._testFolder) + this._testFolder.length; + const fromIndex = line.lastIndexOf(this._projectFolder) + this._projectFolder.length; const toIndex = line.lastIndexOf(')'); lines[index] = line.substring(0, fromIndex) + YELLOW_COLOR + line.substring(fromIndex, toIndex) + RESET_COLOR + line.substring(toIndex); return lines.join('\n'); diff --git a/utils/testrunner/TestRunner.js b/utils/testrunner/TestRunner.js index 9569dec5..c752702c 100644 --- a/utils/testrunner/TestRunner.js +++ b/utils/testrunner/TestRunner.js @@ -108,6 +108,8 @@ class Test { // Test results this.result = null; this.error = null; + this.startTimestamp = 0; + this.endTimestamp = 0; } } @@ -267,7 +269,6 @@ class TestRunner extends EventEmitter { // Default timeout is 10 seconds. this._timeout = options.timeout === 0 ? 2147483647 : options.timeout || 10 * 1000; this._parallel = options.parallel || 1; - this._retryFailures = !!options.retryFailures; this._hasFocusedTestsOrSuites = false; @@ -322,8 +323,9 @@ class TestRunner extends EventEmitter { } async run() { - this.emit(TestRunner.Events.Started); - const pass = new TestPass(this, this._rootSuite, this._runnableTests(), this._parallel); + const runnableTests = this._runnableTests(); + this.emit(TestRunner.Events.Started, runnableTests); + const pass = new TestPass(this, this._rootSuite, runnableTests, this._parallel); const termination = await pass.run(); if (termination) this.emit(TestRunner.Events.Terminated, termination.message, termination.error); @@ -376,15 +378,25 @@ class TestRunner extends EventEmitter { return this._tests.filter(test => test.result === 'failed' || test.result === 'timedout'); } + passedTests() { + return this._tests.filter(test => test.result === 'ok'); + } + + skippedTests() { + return this._tests.filter(test => test.result === 'skipped'); + } + parallel() { return this._parallel; } _willStartTest(test, workerId) { + test.startTimestamp = Date.now(); this.emit(TestRunner.Events.TestStarted, test, workerId); } _didFinishTest(test, workerId) { + test.endTimestamp = Date.now(); this.emit(TestRunner.Events.TestFinished, test, workerId); } }