From eafa512c4650fbfdb38063f973984cce8990dc34 Mon Sep 17 00:00:00 2001 From: Amjad Masad Date: Tue, 6 Oct 2015 14:50:47 -0700 Subject: [PATCH 1/5] [WIP] use node-worker-farm --- package.json | 3 +- src/TestRunner.js | 74 +++++++++--------------- src/TestWorker.js | 87 ++++++++++++++--------------- src/lib/__tests__/promisify-test.js | 48 ++++++++++++++++ src/lib/promisify.js | 25 +++++++++ 5 files changed, 142 insertions(+), 95 deletions(-) create mode 100644 src/lib/__tests__/promisify-test.js create mode 100644 src/lib/promisify.js diff --git a/package.json b/package.json index 555315a0808b..2b097b534997 100644 --- a/package.json +++ b/package.json @@ -22,7 +22,8 @@ "resolve": "^1.1.6", "sane": "^1.2.0", "through": "^2.3.8", - "which": "^1.1.1" + "which": "^1.1.1", + "worker-farm": "^1.3.1" }, "devDependencies": { "jshint": "^2.8.0", diff --git a/src/TestRunner.js b/src/TestRunner.js index de25eea02334..58fa2d5c73f0 100644 --- a/src/TestRunner.js +++ b/src/TestRunner.js @@ -14,8 +14,9 @@ var assign = require('object-assign'); var promiseDone = require('./lib/promiseDone'); var through = require('through'); var utils = require('./lib/utils'); -var WorkerPool = require('node-worker-pool'); +var workerFarm = require('worker-farm'); var Console = require('./Console'); +var promisify = require('./lib/promisify'); var TEST_WORKER_PATH = require.resolve('./TestWorker'); @@ -575,56 +576,31 @@ TestRunner.prototype._createInBandTestRun = function( TestRunner.prototype._createParallelTestRun = function( testPaths, onTestResult, onRunFailure ) { - var workerPool = new WorkerPool( - this._opts.maxWorkers, - this._opts.nodePath, - this._opts.nodeArgv.concat([ - TEST_WORKER_PATH, - '--config=' + JSON.stringify(this._config) - ]) - ); + var farm = workerFarm({ + maxConcurretCallsPerWorker: 1, + maxRetries: 2, + maxConcurrentWorkers: this._opts.maxWorkers + }, TEST_WORKER_PATH); + + var runTest = promisify(farm); return this._getModuleLoaderResourceMap() - .then(function() { - return Promise.all(testPaths.map(function(testPath) { - return workerPool.sendMessage({testFilePath: testPath}) - .then(function(testResult) { - onTestResult(testPath, testResult); - }) - .catch(function(err) { - onRunFailure(testPath, err); - - // Jest uses regular worker messages to initialize workers, so - // there's no way for node-worker-pool to understand how to - // recover/re-initialize a child worker that needs to be restarted. - // (node-worker-pool can't distinguish between initialization - // messages and ephemeral "normal" messages in order to replay the - // initialization message upon booting the new, replacement worker - // process). - // - // This is mostly a limitation of node-worker-pool's initialization - // features, and ideally it would be possible to recover from a - // test that causes a worker process to exit unexpectedly. However, - // for now Jest will just fail hard if any child process exits - // unexpectedly. - // - // This will likely bite me in the ass as an unbreak now if we hit - // this issue again -- but I guess that's a faster failure than - // having Jest just hang forever without any indication as to why. - if (err.message - && /Worker process exited before /.test(err.message)) { - console.error( - 'A worker process has quit unexpectedly! This is bad news, ' + - 'shutting down now!' - ); - process.exit(1); - } - }); - })); - }) - .then(function() { - return workerPool.destroy(); - }); + .then(() => Promise.all(testPaths.map( + testPath => runTest({ config: this._config, testFilePath: testPath }) + .then(testResult => onTestResult(testPath, testResult)) + .catch(err => { + onRunFailure(testPath, err); + + if (err.type === 'ProcessTerminatedError') { + // Initialization error or some other uncaught error + console.error( + 'A worker process has quit unexpectedly! ' + + 'Most likely this an initialization error.' + ); + process.exit(1); + } + }) + ))).then(() => workerFarm.end(farm)); }; function _pathStreamToPromise(stream) { diff --git a/src/TestWorker.js b/src/TestWorker.js index 2e806496b459..60074438a886 100644 --- a/src/TestWorker.js +++ b/src/TestWorker.js @@ -7,52 +7,49 @@ */ 'use strict'; -var optimist = require('optimist'); -var TestRunner = require('./TestRunner'); -var workerUtils = require('node-worker-pool/nodeWorkerUtils'); - -if (require.main === module) { - try { - process.on('uncaughtException', workerUtils.respondWithError); - - var argv = optimist.demand(['config']).argv; - var config = JSON.parse(argv.config); - - var testRunner = null; - var onMessage = function(message) { - if (testRunner === null) { - testRunner = new TestRunner(config, { - useCachedModuleLoaderResourceMap: true, - }); +// Make sure uncaught errors are logged before we exit. +process.on('uncaughtException', (err) => { + console.error(err.stack); + process.exit(1); +}); - // Start require()ing config dependencies now. - // - // Config dependencies are entries in the config that are require()d (in - // order to be pluggable) such as 'moduleLoader' or - // 'testEnvironment'. - testRunner.preloadConfigDependencies(); - - // Start deserializing the resource map to get a potential head-start on - // that work before the first "run-test" message comes in. - // - // This is just a perf optimization -- and it is only an optimization - // some of the time (when the there is any significant idle time between - // this first initialization message and the first "run-rest" message). - // - // It is also only an optimization so long as deserialization of the - // resource map is a bottleneck (which is the case at the time of this - // writing). - testRunner.preloadResourceMap(); - } +var TestRunner = require('./TestRunner'); - return testRunner.runTest(message.testFilePath) - .catch(function(err) { - throw (err.stack || err.message || err); - }); - }; +var testRunner; + +module.exports = function(data, callback) { + if (!testRunner) { + testRunner = new TestRunner(data.config, { + useCachedModuleLoaderResourceMap: true + }); + + // Start require()ing config dependencies now. + // + // Config dependencies are entries in the config that are require()d (in + // order to be pluggable) such as 'moduleLoader' or + // 'testEnvironment'. + testRunner.preloadConfigDependencies(); + + // Start deserializing the resource map to get a potential head-start on + // that work before the first "run-test" message comes in. + // + // This is just a perf optimization -- and it is only an optimization + // some of the time (when the there is any significant idle time between + // this first initialization message and the first "run-rest" message). + // + // It is also only an optimization so long as deserialization of the + // resource map is a bottleneck (which is the case at the time of this + // writing). + testRunner.preloadResourceMap(); + } - workerUtils.startWorker(null, onMessage); - } catch (e) { - workerUtils.respondWithError(e); + try { + testRunner.runTest(data.testFilePath) + .then( + result => callback(null, result), + err => callback(err) + ); + } catch (err) { + callback(err); } -} +}; diff --git a/src/lib/__tests__/promisify-test.js b/src/lib/__tests__/promisify-test.js new file mode 100644 index 000000000000..6668ee85d032 --- /dev/null +++ b/src/lib/__tests__/promisify-test.js @@ -0,0 +1,48 @@ +/** + * Copyright (c) 2014, Facebook, Inc. All rights reserved. + * + * This source code is licensed under the BSD-style license found in the + * LICENSE file in the root directory of this source tree. An additional grant + * of patent rights can be found in the PATENTS file in the same directory. + */ +'use strict'; + +jest.dontMock('../promisify'); + +describe('promisify', () => { + var promisify; + + beforeEach(() => { + promisify = require('../promisify'); + }); + + pit('should resolve', () => { + var foo = promisify(callback => { + callback(null, 1); + }); + + return foo().then(res => { + expect(res).toBe(1); + }); + }); + + pit('should resolve with args', () => { + var foo = promisify((a, b, callback) => { + callback(null, a + b); + }); + + return foo(3, 5).then(res => { + expect(res).toBe(8); + }); + }); + + pit('should reject with args', () => { + var foo = promisify((a, b, callback) => { + callback(new Error('lol')); + }); + + return foo(3, 5).catch(err => { + expect(err.message).toBe('lol'); + }); + }); +}); diff --git a/src/lib/promisify.js b/src/lib/promisify.js new file mode 100644 index 000000000000..b56a3d7d1094 --- /dev/null +++ b/src/lib/promisify.js @@ -0,0 +1,25 @@ +/** + * Copyright (c) 2014, Facebook, Inc. All rights reserved. + * + * This source code is licensed under the BSD-style license found in the + * LICENSE file in the root directory of this source tree. An additional grant + * of patent rights can be found in the PATENTS file in the same directory. + */ +'use strict'; + +module.exports = function(fn) { + return function() { + var args = Array.prototype.slice.call(arguments); + return new Promise((resolve, reject) => { + args.push((err, res) => { + if (err) { + reject(err); + } else { + resolve(res); + } + }); + + fn.apply(this, args); + }); + } +}; From 144e2a167521e7623e33dc7ea9cde8231236adf7 Mon Sep 17 00:00:00 2001 From: Amjad Masad Date: Tue, 6 Oct 2015 15:42:51 -0700 Subject: [PATCH 2/5] Fix error reporting --- src/TestWorker.js | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/TestWorker.js b/src/TestWorker.js index 60074438a886..895e3ade0caf 100644 --- a/src/TestWorker.js +++ b/src/TestWorker.js @@ -47,9 +47,9 @@ module.exports = function(data, callback) { testRunner.runTest(data.testFilePath) .then( result => callback(null, result), - err => callback(err) + err => callback(err.stack || err.message || err) ); } catch (err) { - callback(err); + callback(err.stack || err.message || err); } }; From 242fb35459b387e360f52394b0e30f42101cc51d Mon Sep 17 00:00:00 2001 From: Amjad Masad Date: Tue, 6 Oct 2015 15:47:53 -0700 Subject: [PATCH 3/5] Simplifiy in-worker console --- src/Console.js | 110 +++-------------------- src/DefaultTestReporter.js | 23 ----- src/TestRunner.js | 12 +-- src/TestWorker.js | 3 + src/jasmineTestRunner/JasmineReporter.js | 4 - 5 files changed, 23 insertions(+), 129 deletions(-) diff --git a/src/Console.js b/src/Console.js index 9c2f65c33bf5..8c36b9b71c26 100644 --- a/src/Console.js +++ b/src/Console.js @@ -27,106 +27,24 @@ // OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE // USE OR OTHER DEALINGS IN THE SOFTWARE. -/*jshint strict:false*/ +'use strict'; var util = require('util'); - -function Console(messageQueue) { - if (!(this instanceof Console)) { - return new Console(messageQueue); +var Console = require('console').Console; +var colors = require('./lib/colors'); + +class CustomConsole extends Console { + warn() { + return super.warn( + colors.colorize(util.format.apply(this, arguments), colors.YELLOW) + ); } - Object.defineProperty(this, '_messageQueue', { - value: messageQueue, - writable: true, - enumerable: false, - configurable: true - }); - - Object.defineProperty(this, '_times', { - value: {}, - writable: true, - enumerable: false, - configurable: true - }); - - // bind the prototype functions to this Console instance - var keys = Object.keys(Console.prototype); - for (var v = 0; v < keys.length; v++) { - var k = keys[v]; - this[k] = this[k].bind(this); + error() { + return super.error( + colors.colorize(util.format.apply(this, arguments), colors.RED) + ); } } -Console.prototype.log = function() { - this._messageQueue.push({ - type: 'log', - data: util.format.apply(this, arguments) + '\n' - }); -}; - - -Console.prototype.info = Console.prototype.log; - - -Console.prototype.warn = function() { - this._messageQueue.push({ - type: 'warn', - data: util.format.apply(this, arguments) + '\n' - }); -}; - - -Console.prototype.error = function() { - this._messageQueue.push({ - type: 'error', - data: util.format.apply(this, arguments) + '\n' - }); -}; - - -Console.prototype.dir = function(object, options) { - this._messageQueue.push({ - type: 'dir', - data: util.inspect(object, util._extend({ - customInspect: false - }, options)) + '\n' - }); -}; - - -Console.prototype.time = function(label) { - this._times[label] = Date.now(); -}; - - -Console.prototype.timeEnd = function(label) { - var time = this._times[label]; - if (!time) { - throw new Error('No such label: ' + label); - } - var duration = Date.now() - time; - this.log('%s: %dms', label, duration); -}; - - -Console.prototype.trace = function() { - // TODO probably can to do this better with V8's debug object once that is - // exposed. - var err = new Error(); - err.name = 'Trace'; - err.message = util.format.apply(this, arguments); - /*jshint noarg:false*/ - Error.captureStackTrace(err, arguments.callee); - this.error(err.stack); -}; - - -Console.prototype.assert = function(expression) { - if (!expression) { - var arr = Array.prototype.slice.call(arguments, 1); - require('assert').ok(false, util.format.apply(this, arr)); - } -}; - -module.exports = Console; +module.exports = CustomConsole; diff --git a/src/DefaultTestReporter.js b/src/DefaultTestReporter.js index 5641d724f79e..13c983edf1df 100644 --- a/src/DefaultTestReporter.js +++ b/src/DefaultTestReporter.js @@ -72,8 +72,6 @@ function(config, testResult, aggregatedResults) { this.verboseLog(testResult.testResults, resultHeader); } - testResult.logMessages.forEach(this._printConsoleMessage.bind(this)); - if (!allTestsPassed) { var failureMessage = formatFailureMessage(testResult, { rootPath: config.rootDir, @@ -139,27 +137,6 @@ function (config, aggregatedResults) { this.log('Run time: ' + runTime + 's'); }; -DefaultTestReporter.prototype._printConsoleMessage = function(msg) { - switch (msg.type) { - case 'dir': - case 'log': - this._process.stdout.write(msg.data); - break; - case 'warn': - this._process.stderr.write( - this._formatMsg(msg.data, colors.YELLOW) - ); - break; - case 'error': - this._process.stderr.write( - this._formatMsg(msg.data, colors.RED) - ); - break; - default: - throw new Error('Unknown console message type!: ' + msg.type); - } -}; - DefaultTestReporter.prototype._clearWaitingOn = function() { // Don't write special chars in noHighlight mode // to get clean output for logs. diff --git a/src/TestRunner.js b/src/TestRunner.js index 58fa2d5c73f0..6f5cd79ef688 100644 --- a/src/TestRunner.js +++ b/src/TestRunner.js @@ -323,10 +323,8 @@ TestRunner.prototype.runTest = function(testFilePath) { var env = new configDeps.testEnvironment(config); var testRunner = configDeps.testRunner; - // Capture and serialize console.{log|warning|error}s so they can be passed - // around (such as through some channel back to a parent process) - var consoleMessages = []; - env.global.console = new Console(consoleMessages); + // Intercept console logs to colorize. + env.global.console = new Console(process.stdout, process.stderr); // Pass the testFilePath into the runner, so it can be used to e.g. // configure test reporter output. @@ -381,7 +379,6 @@ TestRunner.prototype.runTest = function(testFilePath) { .then(function(results) { testExecStats.end = Date.now(); - results.logMessages = consoleMessages; results.perfStats = testExecStats; results.testFilePath = testFilePath; results.coverage = @@ -524,7 +521,6 @@ TestRunner.prototype.runTests = function(testPaths, reporter) { suites: {}, tests: {}, testResults: {}, - logMessages: [] }; aggregatedResults.testResults.push(testResult); aggregatedResults.numFailedTests++; @@ -578,6 +574,10 @@ TestRunner.prototype._createParallelTestRun = function( ) { var farm = workerFarm({ maxConcurretCallsPerWorker: 1, + + // We allow for a couple of transient errors. Say something to do + // with loading/serialization of the resourcemap (which I've seen + // happen). maxRetries: 2, maxConcurrentWorkers: this._opts.maxWorkers }, TEST_WORKER_PATH); diff --git a/src/TestWorker.js b/src/TestWorker.js index 895e3ade0caf..1d98b0336a7f 100644 --- a/src/TestWorker.js +++ b/src/TestWorker.js @@ -8,6 +8,8 @@ 'use strict'; // Make sure uncaught errors are logged before we exit. +// Could be transient errors to do with loading and serializing the resouce +// map. process.on('uncaughtException', (err) => { console.error(err.stack); process.exit(1); @@ -47,6 +49,7 @@ module.exports = function(data, callback) { testRunner.runTest(data.testFilePath) .then( result => callback(null, result), + // TODO: move to error object passing (why limit to strings?). err => callback(err.stack || err.message || err) ); } catch (err) { diff --git a/src/jasmineTestRunner/JasmineReporter.js b/src/jasmineTestRunner/JasmineReporter.js index 4404058fe6b8..32e2901b3f2d 100644 --- a/src/jasmineTestRunner/JasmineReporter.js +++ b/src/jasmineTestRunner/JasmineReporter.js @@ -86,15 +86,11 @@ function (container, ancestorTitles, spec) { title: 'it ' + spec.description, ancestorTitles: ancestorTitles, failureMessages: [], - logMessages: [], numPassingAsserts: 0 }; spec.results().getItems().forEach(function(result) { switch (result.type) { - case 'log': - results.logMessages.push(result.toString()); - break; case 'expect': if (result.passed()) { results.numPassingAsserts++; From 265f7e322e495f1671cc18127ceabfd9824f4968 Mon Sep 17 00:00:00 2001 From: Amjad Masad Date: Tue, 6 Oct 2015 15:50:09 -0700 Subject: [PATCH 4/5] Get rid of node-worker-pool --- package.json | 1 - 1 file changed, 1 deletion(-) diff --git a/package.json b/package.json index 2b097b534997..2406a6098b0c 100644 --- a/package.json +++ b/package.json @@ -16,7 +16,6 @@ "lodash.template": "^3.6.2", "mkdirp": "^0.5.1", "node-haste": "^1.2.8", - "node-worker-pool": "^3.0.2", "object-assign": "^4.0.1", "optimist": "^0.6.1", "resolve": "^1.1.6", From 78ba6e6b87de242a89bb1f873e3dda5aee059a93 Mon Sep 17 00:00:00 2001 From: Amjad Masad Date: Tue, 6 Oct 2015 16:09:44 -0700 Subject: [PATCH 5/5] Fix jshint issues --- src/lib/promisify.js | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/lib/promisify.js b/src/lib/promisify.js index b56a3d7d1094..65f1d92007f2 100644 --- a/src/lib/promisify.js +++ b/src/lib/promisify.js @@ -21,5 +21,5 @@ module.exports = function(fn) { fn.apply(this, args); }); - } + }; };