test: continue running tests after crash, report crashes separately (#1362)

This commit is contained in:
Dmitry Gozman 2020-03-12 17:32:53 -07:00 committed by GitHub
parent cfd3ae25fb
commit 0d7cb29329
No known key found for this signature in database
GPG key ID: 4AEE18F83AFDEB23
3 changed files with 132 additions and 106 deletions

View file

@ -138,7 +138,7 @@ new Reporter(testRunner, {
}); });
// await utils.initializeFlakinessDashboardIfNeeded(testRunner); // await utils.initializeFlakinessDashboardIfNeeded(testRunner);
testRunner.run().then(result => { testRunner.run({ totalTimeout: process.env.CI ? 15 * 60 * 1000 : 0 }).then(result => {
process.exit(result.exitCode); process.exit(result.exitCode);
}); });

View file

@ -37,7 +37,6 @@ class Reporter {
runner.on('finished', this._onFinished.bind(this)); runner.on('finished', this._onFinished.bind(this));
runner.on('teststarted', this._onTestStarted.bind(this)); runner.on('teststarted', this._onTestStarted.bind(this));
runner.on('testfinished', this._onTestFinished.bind(this)); runner.on('testfinished', this._onTestFinished.bind(this));
this._workersState = new Map();
} }
_onStarted(runnableTests) { _onStarted(runnableTests) {
@ -62,48 +61,33 @@ class Reporter {
} }
} }
_printTermination(result, message, error) { _printFailedResult(result) {
console.log(colors.red(`## ${result.toUpperCase()} ##`)); console.log(colors.red(`## ${result.result.toUpperCase()} ##`));
console.log('Message:'); if (result.message) {
console.log(` ${colors.red(message)}`); console.log('Message:');
if (error && error.stack) { console.log(` ${colors.red(result.message)}`);
console.log('Stack:');
console.log(padLines(error.stack, 2));
} }
console.log('WORKERS STATE');
const workerIds = Array.from(this._workersState.keys()); for (let i = 0; i < result.errors.length; i++) {
workerIds.sort((a, b) => a - b); const { message, error, workerId, tests } = result.errors[i];
for (const workerId of workerIds) { console.log(`\n${colors.magenta('NON-TEST ERROR #' + i)}: ${message}`);
const {isRunning, test} = this._workersState.get(workerId); if (error && error.stack)
let description = ''; console.log(padLines(error.stack, 2));
if (isRunning) const lastTests = tests.slice(tests.length - Math.min(10, tests.length));
description = colors.yellow('RUNNING'); if (lastTests.length)
else if (test.result === 'ok') console.log(`WORKER STATE`);
description = colors.green('OK'); for (let j = 0; j < lastTests.length; j++)
else if (test.result === 'skipped') this._printVerboseTestResult(j, lastTests[j], workerId);
description = colors.yellow('SKIPPED');
else if (test.result === 'failed')
description = colors.red('FAILED');
else if (test.result === 'crashed')
description = colors.red('CRASHED');
else if (test.result === 'timedout')
description = colors.red('TIMEDOUT');
else if (test.result === 'terminated')
description = colors.magenta('TERMINATED');
else
description = colors.red('<UNKNOWN>');
console.log(` ${workerId}: [${description}] ${test.fullName} (${formatLocation(test.location)})`);
} }
console.log(''); console.log('');
console.log(''); console.log('');
process.exitCode = 2;
} }
_onFinished({result, terminationError, terminationMessage}) { _onFinished(result) {
this._printTestResults(); this._printTestResults();
if (terminationMessage || terminationError) if (!result.ok())
this._printTermination(result, terminationMessage, terminationError); this._printFailedResult(result);
process.exitCode = result === 'ok' ? 0 : 1; process.exitCode = result.exitCode;
} }
_printTestResults() { _printTestResults() {
@ -171,11 +155,9 @@ class Reporter {
} }
_onTestStarted(test, workerId) { _onTestStarted(test, workerId) {
this._workersState.set(workerId, {test, isRunning: true});
} }
_onTestFinished(test, workerId) { _onTestFinished(test, workerId) {
this._workersState.set(workerId, {test, isRunning: false});
if (this._verbose) { if (this._verbose) {
++this._testCounter; ++this._testCounter;
this._printVerboseTestResult(this._testCounter, test, workerId); this._printVerboseTestResult(this._testCounter, test, workerId);
@ -240,7 +222,11 @@ class Reporter {
console.log(''); console.log('');
} else { } else {
console.log(' Message:'); console.log(' Message:');
console.log(` ${colors.red(test.error.message || test.error)}`); let message = '' + (test.error.message || test.error);
if (test.error.stack && message.includes(test.error.stack))
message = message.substring(0, message.indexOf(test.error.stack));
if (message)
console.log(` ${colors.red(message)}`);
if (test.error.stack) { if (test.error.stack) {
console.log(' Stack:'); console.log(' Stack:');
let stack = test.error.stack; let stack = test.error.stack;

View file

@ -125,30 +125,73 @@ class Suite {
} }
} }
class Result {
constructor() {
this.result = TestResult.Ok;
this.exitCode = 0;
this.message = '';
this.errors = [];
}
setResult(result, message) {
if (!this.ok())
return;
this.result = result;
this.message = message || '';
if (result === TestResult.Ok)
this.exitCode = 0;
else if (result === TestResult.Terminated)
this.exitCode = 130;
else if (result === TestResult.Crashed)
this.exitCode = 2;
else
this.exitCode = 1;
}
addError(message, error, worker) {
const data = { message, error, tests: [] };
if (worker) {
data.workerId = worker._workerId;
data.tests = worker._runTests.slice();
}
this.errors.push(data);
}
ok() {
return this.result === TestResult.Ok;
}
}
class TestWorker { class TestWorker {
constructor(testPass, workerId, parallelIndex) { constructor(testPass, workerId, parallelIndex) {
this._testPass = testPass; this._testPass = testPass;
this._state = { parallelIndex }; this._state = { parallelIndex };
this._suiteStack = []; this._suiteStack = [];
this._termination = false; this._terminating = false;
this._workerId = workerId; this._workerId = workerId;
this._runningUserCallback = null; this._runningTestCallback = null;
this._runningHookCallback = null;
this._runTests = [];
} }
terminate() { terminate(terminateHooks) {
this._termination = true; this._terminating = true;
if (this._runningUserCallback) if (this._runningTestCallback)
this._runningUserCallback.terminate(); this._runningTestCallback.terminate();
if (terminateHooks && this._runningHookCallback)
this._runningHookCallback.terminate();
} }
_markTerminated(test) { _markTerminated(test) {
if (!this._termination) if (!this._terminating)
return false; return false;
test.result = TestResult.Terminated; test.result = TestResult.Terminated;
return true; return true;
} }
async runTest(test) { async runTest(test) {
this._runTests.push(test);
if (this._markTerminated(test)) if (this._markTerminated(test))
return; return;
@ -202,10 +245,10 @@ class TestWorker {
await this._runHook(test, this._suiteStack[i], 'beforeEach'); await this._runHook(test, this._suiteStack[i], 'beforeEach');
if (!test.error && !this._markTerminated(test)) { if (!test.error && !this._markTerminated(test)) {
this._runningUserCallback = test._userCallback;
await this._testPass._willStartTestBody(this, test); await this._testPass._willStartTestBody(this, test);
this._runningTestCallback = test._userCallback;
test.error = await test._userCallback.run(this._state, test); test.error = await test._userCallback.run(this._state, test);
this._runningUserCallback = null; this._runningTestCallback = null;
if (!test.error) if (!test.error)
test.result = TestResult.Ok; test.result = TestResult.Ok;
else if (test.error === TimeoutError) else if (test.error === TimeoutError)
@ -228,10 +271,9 @@ class TestWorker {
return true; return true;
await this._testPass._willStartHook(this, suite, hook, hookName); await this._testPass._willStartHook(this, suite, hook, hookName);
// TODO: do we want hooks to be terminatable? Perhaps, only on SIGTERM? this._runningHookCallback = hook;
this._runningUserCallback = hook;
let error = await hook.run(this._state, test); let error = await hook.run(this._state, test);
this._runningUserCallback = null; this._runningHookCallback = null;
if (error) { if (error) {
const location = `${hook.location.fileName}:${hook.location.lineNumber}:${hook.location.columnNumber}`; const location = `${hook.location.fileName}:${hook.location.lineNumber}:${hook.location.columnNumber}`;
@ -239,18 +281,19 @@ class TestWorker {
// Prefer terminated result over any hook failures. // Prefer terminated result over any hook failures.
test.result = error === TerminatedError ? TestResult.Terminated : TestResult.Crashed; test.result = error === TerminatedError ? TestResult.Terminated : TestResult.Crashed;
} }
let message;
if (error === TimeoutError) { if (error === TimeoutError) {
error = new Error(`${location} - Timeout Exceeded ${hook.timeout}ms while running "${hookName}" in suite "${suite.fullName}"`); message = `${location} - Timeout Exceeded ${hook.timeout}ms while running "${hookName}" in suite "${suite.fullName}"`;
error.stack = ''; error = null;
} else if (error === TerminatedError) { } else if (error === TerminatedError) {
error = new Error(`${location} - TERMINATED while running "${hookName}" in suite "${suite.fullName}"`); message = `${location} - TERMINATED while running "${hookName}" in suite "${suite.fullName}"`;
error.stack = ''; error = null;
} else { } else {
if (error.stack) if (error.stack)
await this._testPass._runner._sourceMapSupport.rewriteStackTraceWithSourceMaps(error); await this._testPass._runner._sourceMapSupport.rewriteStackTraceWithSourceMaps(error);
error.message = `${location} - FAILED while running "${hookName}" in suite "${suite.fullName}": ` + error.message; message = `${location} - FAILED while running "${hookName}" in suite "${suite.fullName}": `;
} }
await this._testPass._didFailHook(this, suite, hook, hookName, error); await this._testPass._didFailHook(this, suite, hook, hookName, message, error);
test.error = error; test.error = error;
return false; return false;
} }
@ -271,11 +314,12 @@ class TestPass {
constructor(runner, parallel, breakOnFailure) { constructor(runner, parallel, breakOnFailure) {
this._runner = runner; this._runner = runner;
this._workers = []; this._workers = [];
this._nextWorkerId = 0; this._nextWorkerId = 1;
this._parallel = parallel; this._parallel = parallel;
this._breakOnFailure = breakOnFailure; this._breakOnFailure = breakOnFailure;
this._termination = null; this._errors = [];
this._hookErrors = []; this._result = new Result();
this._terminating = false;
} }
async run(testList) { async run(testList) {
@ -293,6 +337,7 @@ class TestPass {
test.result = null; test.result = null;
test.error = null; test.error = null;
} }
this._result = new Result();
const parallel = Math.min(this._parallel, testList.length); const parallel = Math.min(this._parallel, testList.length);
const workerPromises = []; const workerPromises = [];
@ -304,13 +349,16 @@ class TestPass {
for (const termination of terminations) for (const termination of terminations)
process.removeListener(termination.event, termination.handler); process.removeListener(termination.event, termination.handler);
return this._termination;
if (this._runner.failedTests().length)
this._result.setResult(TestResult.Failed, '');
return this._result;
function createTermination(event, result, message) { function createTermination(event, result, message) {
return { return {
event, event,
message, message,
handler: error => this._terminate(result, message, error) handler: error => this._terminate(result, message, event === 'SIGTERM', event.startsWith('SIG') ? null : error)
}; };
} }
} }
@ -318,7 +366,7 @@ class TestPass {
async _runWorker(testIndex, testList, parallelIndex) { async _runWorker(testIndex, testList, parallelIndex) {
let worker = new TestWorker(this, this._nextWorkerId++, parallelIndex); let worker = new TestWorker(this, this._nextWorkerId++, parallelIndex);
this._workers[parallelIndex] = worker; this._workers[parallelIndex] = worker;
while (!this._termination) { while (!worker._terminating) {
let skipped = 0; let skipped = 0;
while (skipped < testList.length && testList[testIndex].result !== null) { while (skipped < testList.length && testList[testIndex].result !== null) {
testIndex = (testIndex + 1) % testList.length; testIndex = (testIndex + 1) % testList.length;
@ -337,7 +385,8 @@ class TestPass {
// Something went wrong during test run, let's use a fresh worker. // Something went wrong during test run, let's use a fresh worker.
await worker.shutdown(); await worker.shutdown();
if (this._breakOnFailure) { if (this._breakOnFailure) {
await this._terminate(TestResult.Terminated, `Terminating because a test has failed and |testRunner.breakOnFailure| is enabled`, null); const message = `Terminating because a test has failed and |testRunner.breakOnFailure| is enabled`;
await this._terminate(TestResult.Terminated, message, false /* force */, null /* error */);
return; return;
} }
worker = new TestWorker(this, this._nextWorkerId++, parallelIndex); worker = new TestWorker(this, this._nextWorkerId++, parallelIndex);
@ -347,16 +396,16 @@ class TestPass {
await worker.shutdown(); await worker.shutdown();
} }
async _terminate(result, message, error) { async _terminate(result, message, force, error) {
if (this._termination) debug('testrunner')(`TERMINATED result = ${result}, message = ${message}`);
return false;
if (error && error.stack)
await this._runner._sourceMapSupport.rewriteStackTraceWithSourceMaps(error);
this._termination = { result, message, error };
this._willTerminate(this._termination);
for (const worker of this._workers) for (const worker of this._workers)
worker.terminate(); worker.terminate(force /* terminateHooks */);
return true; this._result.setResult(result, message);
if (error) {
if (error.stack)
await this._runner._sourceMapSupport.rewriteStackTraceWithSourceMaps(error);
this._result.addError(message, error);
}
} }
async _willStartTest(worker, test) { async _willStartTest(worker, test) {
@ -381,20 +430,15 @@ class TestPass {
debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" started for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`); debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" started for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`);
} }
async _didFailHook(worker, suite, hook, hookName, error) { async _didFailHook(worker, suite, hook, hookName, message, error) {
debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" FAILED for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`); debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" FAILED for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`);
this._hookErrors.push(error); this._result.addError(message, error, worker);
// Note: we can skip termination and report all errors in the end. this._result.setResult(TestResult.Crashed, message);
await this._terminate(TestResult.Crashed, error.message, error);
} }
async _didCompleteHook(worker, suite, hook, hookName) { async _didCompleteHook(worker, suite, hook, hookName) {
debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" OK for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`); debug('testrunner:hook')(`[${worker._workerId}] "${hookName}" OK for "${suite.fullName}" (${hook.location.fileName + ':' + hook.location.lineNumber})`);
} }
_willTerminate(termination) {
debug('testrunner')(`TERMINTED result = ${termination.result}, message = ${termination.message}`);
}
} }
function specBuilder(defaultTimeout, action) { function specBuilder(defaultTimeout, action) {
@ -529,36 +573,32 @@ class TestRunner extends EventEmitter {
this._currentSuite[hookName] = hook; this._currentSuite[hookName] = hook;
} }
async run() { async run(options = {}) {
const { totalTimeout = 0 } = options;
let session = this._debuggerLogBreakpointLines.size ? await setLogBreakpoints(this._debuggerLogBreakpointLines) : null; let session = this._debuggerLogBreakpointLines.size ? await setLogBreakpoints(this._debuggerLogBreakpointLines) : null;
const runnableTests = this.runnableTests(); const runnableTests = this.runnableTests();
this.emit(TestRunner.Events.Started, runnableTests); this.emit(TestRunner.Events.Started, runnableTests);
const result = {}; let result = new Result();
if (this._crashIfTestsAreFocusedOnCI && process.env.CI && this.hasFocusedTestsOrSuites()) { if (this._crashIfTestsAreFocusedOnCI && process.env.CI && this.hasFocusedTestsOrSuites()) {
result.result = TestResult.Crashed; result.setResult(TestResult.Crashed, '"focused" tests or suites are probitted on CI');
result.exitCode = 2;
result.terminationMessage = '"focused" tests or suites are probitted on CI';
} else { } else {
this._runningPass = new TestPass(this, this._parallel, this._breakOnFailure); let timeoutId;
const termination = await this._runningPass.run(runnableTests).catch(e => { const timeoutPromise = new Promise(resolve => {
console.error(e); const timeoutResult = new Result();
throw e; timeoutResult.setResult(TestResult.Crashed, `Total timeout of ${totalTimeout}ms reached.`);
if (totalTimeout)
timeoutId = setTimeout(resolve.bind(null, timeoutResult), totalTimeout);
}); });
this._runningPass = null; try {
if (termination) { this._runningPass = new TestPass(this, this._parallel, this._breakOnFailure);
result.result = termination.result; result = await Promise.race([
result.exitCode = 130; this._runningPass.run(runnableTests).catch(e => { console.error(e); throw e; }),
result.terminationMessage = termination.message; timeoutPromise,
result.terminationError = termination.error; ]);
} else { this._runningPass = null;
if (this.failedTests().length) { } finally {
result.result = TestResult.Failed; clearTimeout(timeoutId);
result.exitCode = 1;
} else {
result.result = TestResult.Ok;
result.exitCode = 0;
}
} }
} }
this.emit(TestRunner.Events.Finished, result); this.emit(TestRunner.Events.Finished, result);
@ -570,7 +610,7 @@ class TestRunner extends EventEmitter {
async terminate() { async terminate() {
if (!this._runningPass) if (!this._runningPass)
return; return;
await this._runningPass._terminate(TestResult.Terminated, 'Terminated with |TestRunner.terminate()| call', null); await this._runningPass._terminate(TestResult.Terminated, 'Terminated with |TestRunner.terminate()| call', true /* force */, null /* error */);
} }
timeout() { timeout() {