Mega PR: unhandledRejection, uncaughtException, reliable IO capture, consistent tests.

appveyor.yml

@@ -7,9 +7,10 @@ environment:
 install:
   - ps: Install-Product node $env:nodejs_version
   - set CI=true
-  - npm -g install npm@latest
+  - set AVA_APPVEYOR=true
+  - npm -g install npm@latest || (timeout 30 && npm -g install npm@latest)
   - set PATH=%APPDATA%\npm;%PATH%
-  - npm install
+  - npm install || (timeout 30 && npm install)
 matrix:
   fast_finish: true
 build: off
@@ -19,4 +20,4 @@ clone_depth: 1
 test_script:
   - node --version
   - npm --version
-  - npm run test-win
+  - npm run test-win || (timeout 30 && npm run test-win)

cli.js

@@ -45,11 +45,13 @@ var cli = meow({
 
 var testCount = 0;
 var fileCount = 0;
+var unhandledRejectionCount = 0;
+var uncaughtExceptionCount = 0;
 var errors = [];
 
 function error(err) {
 	console.error(err.stack);
-	process.exit(1);
+	flushIoAndExit(1);
 }
 
 function prefixTitle(file) {
@@ -116,11 +118,24 @@ function run(file) {
 	return fork(args)
 		.on('stats', stats)
 		.on('test', test)
+		.on('unhandledRejections', rejections)
+		.on('uncaughtException', uncaughtException)
 		.on('data', function (data) {
 			process.stdout.write(data);
 		});
 }
 
+function rejections(data) {
+	var unhandled = data.unhandledRejections;
+	log.unhandledRejections(data.file, unhandled);
+	unhandledRejectionCount += unhandled.length;
+}
+
+function uncaughtException(data) {
+	uncaughtExceptionCount++;
+	log.uncaughtException(data.file, data.uncaughtException);
+}
+
 function sum(arr, key) {
 	var result = 0;
 
@@ -145,21 +160,30 @@ function exit(results) {
 	var failed = sum(stats, 'failCount');
 
 	log.write();
-	log.report(passed, failed);
+	log.report(passed, failed, unhandledRejectionCount, uncaughtExceptionCount);
 	log.write();
 
 	if (failed > 0) {
 		log.errors(flatten(tests));
 	}
 
+	process.stdout.write('');
+
+	flushIoAndExit(
+		failed > 0 || unhandledRejectionCount > 0 || uncaughtExceptionCount > 0 ? 1 : 0
+	);
+}
+
+function flushIoAndExit(code) {
 	// TODO: figure out why this needs to be here to
 	// correctly flush the output when multiple test files
 	process.stdout.write('');
+	process.stderr.write('');
 
-	// timeout required to correctly flush stderr on Node 0.10 Windows
+	// timeout required to correctly flush io on Node 0.10 Windows
 	setTimeout(function () {
-		process.exit(failed > 0 ? 1 : 0);
-	}, 0);
+		process.exit(code);
+	}, process.env.AVA_APPVEYOR ? 500 : 0);
 }
 
 function init(files) {

index.js

@@ -4,7 +4,7 @@ var setImmediate = require('set-immediate-shim');
 var hasFlag = require('has-flag');
 var chalk = require('chalk');
 var relative = require('path').relative;
-var serializeError = require('destroy-circular');
+var serializeError = require('./lib/serialize-value');
 var Runner = require('./lib/runner');
 var log = require('./lib/logger');
 var runner = new Runner();

lib/babel.js

@@ -1,7 +1,9 @@
 'use strict';
+var loudRejection = require('loud-rejection/api')(process);
 var resolveFrom = require('resolve-from');
 var createEspowerPlugin = require('babel-plugin-espower/create');
 var requireFromString = require('require-from-string');
+var serializeValue = require('./serialize-value');
 
 var hasGenerators = parseInt(process.version.slice(1), 10) > 0;
 var testPath = process.argv[2];
@@ -32,20 +34,46 @@ module.exports = {
 	}
 };
 
+function send(name, data) {
+	process.send({name: name, data: data});
+}
+
+process.on('uncaughtException', function (exception) {
+	send('uncaughtException', {uncaughtException: serializeValue(exception)});
+});
+
 var transpiled = babel.transformFileSync(testPath, options);
 requireFromString(transpiled.code, testPath, {
 	appendPaths: module.paths
 });
 
 if (!avaRequired) {
-	console.error('No tests found in ' + testPath + ', make sure to import "ava" at the top of your test file');
-	setImmediate(function () {
-		process.exit(1);
-	});
+	throw new Error('No tests found in ' + testPath + ', make sure to import "ava" at the top of your test file');
 }
 
 process.on('message', function (message) {
-	if (message['ava-kill-command']) {
+	var command = message['ava-child-process-command'];
+	if (command) {
+		process.emit('ava-' + command, message.data);
+	}
+});
+
+process.on('ava-kill', function () {
+	setTimeout(function () {
 		process.exit(0);
+	}, process.env.AVA_APPVEYOR ? 100 : 0);
+});
+
+process.on('ava-cleanup', function () {
+	var unhandled = loudRejection.currentlyUnhandled();
+	if (unhandled.length) {
+		unhandled = unhandled.map(function (entry) {
+			return serializeValue(entry.reason);
+		});
+		send('unhandledRejections', {unhandledRejections: unhandled});
 	}
+
+	setTimeout(function () {
+		send('cleaned-up', {});
+	}, 100);
 });

lib/fork.js

@@ -18,6 +18,10 @@ module.exports = function (args) {
 
 	var ps = childProcess.fork(babel, args, options);
 
+	function send(command, data) {
+		ps.send({'ava-child-process-command': command, 'data': data});
+	}
+
 	var promise = new Promise(function (resolve, reject) {
 		var testResults;
 
@@ -26,7 +30,15 @@ module.exports = function (args) {
 
 			// after all tests are finished and results received
 			// kill the forked process, so AVA can exit safely
-			ps.send({'ava-kill-command': true});
+			send('cleanup', true);
+		});
+
+		ps.on('cleaned-up', function () {
+			send('kill', true);
+		});
+
+		ps.on('uncaughtException', function () {
+			send('cleanup', true);
 		});
 
 		ps.on('error', reject);

lib/logger.js

@@ -70,10 +70,41 @@ x.errors = function (results) {
 	});
 };
 
-x.report = function (passed, failed) {
+x.report = function (passed, failed, unhandled, uncaught) {
 	if (failed > 0) {
 		log.writelpad(chalk.red(failed, plur('test', failed), 'failed'));
 	} else {
 		log.writelpad(chalk.green(passed, plur('test', passed), 'passed'));
 	}
+	if (unhandled > 0) {
+		log.writelpad(chalk.red(unhandled, 'unhandled', plur('rejection', unhandled)));
+	}
+	if (uncaught > 0) {
+		log.writelpad(chalk.red(uncaught, 'uncaught', plur('exception', uncaught)));
+	}
+};
+
+x.unhandledRejections = function (file, rejections) {
+	if (!(rejections && rejections.length)) {
+		return;
+	}
+	rejections.forEach(function (rejection) {
+		log.write(chalk.red('Unhandled Rejection: ', file));
+		if (rejection.stack) {
+			log.writelpad(chalk.red(beautifyStack(rejection.stack)));
+		} else {
+			log.writelpad(chalk.red(JSON.stringify(rejection)));
+		}
+		log.write();
+	});
+};
+
+x.uncaughtException = function (file, error) {
+	log.write(chalk.red('Uncaught Exception: ', file));
+	if (error.stack) {
+		log.writelpad(chalk.red(beautifyStack(error.stack)));
+	} else {
+		log.writelpad(chalk.red(JSON.stringify(error)));
+	}
+	log.write();
 };

lib/serialize-value.js

@@ -0,0 +1,16 @@
+'use strict';
+var destroyCircular = require('destroy-circular');
+
+// Make a value ready for JSON.stringify() / process.send()
+
+module.exports = function serializeValue(value) {
+	if (typeof value === 'object') {
+		return destroyCircular(value);
+	}
+	if (typeof value === 'function') {
+		// JSON.stringify discards functions, leaving no context information once we serialize and send across.
+		// We replace thrown functions with a string to provide as much information to the user as possible.
+		return '[Function: ' + (value.name || 'anonymous') + ']';
+	}
+	return value;
+};

package.json

@@ -77,6 +77,7 @@
     "globby": "^3.0.1",
     "has-flag": "^1.0.0",
     "is-generator-fn": "^1.0.0",
+    "loud-rejection": "^1.2.0",
     "max-timeout": "^1.0.0",
     "meow": "^3.3.0",
     "plur": "^2.0.0",

test/fixture/loud-rejection.js

@@ -0,0 +1,9 @@
+const test = require('../../');
+
+test('creates an unhandled rejection', t => {
+	Promise.reject(new Error(`You can't handle this!`));
+
+	setTimeout(function () {
+		t.end();
+	});
+});

test/fixture/throw-anonymous-function.js

@@ -0,0 +1,7 @@
+const test = require('../../');
+
+test('throw an uncaught exception', t => {
+	setImmediate(() => {
+		throw function () {};
+	});
+});

test/fixture/throw-named-function.js

@@ -0,0 +1,9 @@
+const test = require('../../');
+
+function fooFn() {}
+
+test('throw an uncaught exception', t => {
+	setImmediate(() => {
+		throw fooFn
+	});
+});

test/fixture/uncaught-exception.js

@@ -0,0 +1,7 @@
+const test = require('../../');
+
+test('throw an uncaught exception', t => {
+	setImmediate(() => {
+		throw new Error(`Can't catch me!`)
+	});
+});

test/fork.js

@@ -28,14 +28,14 @@ test('resolves promise with tests info', function (t) {
 });
 
 test('rejects on error and streams output', function (t) {
-	var buffer = '';
-
+	t.plan(2);
 	fork(fixture('broken.js'))
-		.on('data', function (data) {
-			buffer += data;
+		.on('uncaughtException', function (data) {
+			var exception = data.uncaughtException;
+			t.ok(/no such file or directory/.test(exception.message));
 		})
 		.catch(function () {
-			t.ok(/no such file or directory/.test(buffer));
+			t.pass();
 			t.end();
 		});
 });

test/test.js

@@ -1058,14 +1058,50 @@ test('change process.cwd() to a test\'s directory', function (t) {
 
 test('Babel require hook only applies to the test file', function (t) {
 	execCli('fixture/babel-hook.js', function (err, stdout, stderr) {
-		t.ok(/exited with a non-zero exit code/.test(stderr));
-		t.ok(/Unexpected token/.test(stdout));
+		t.ok(/Unexpected token/.test(stderr));
 		t.ok(err);
 		t.is(err.code, 1);
 		t.end();
 	});
 });
 
+test('Unhandled promises will be reported to console', function (t) {
+	execCli('fixture/loud-rejection.js', function (err, stdout, stderr) {
+		t.ok(err);
+		t.ok(/You can't handle this/.test(stderr));
+		t.ok(/1 unhandled rejection[^s]/.test(stderr));
+		t.end();
+	});
+});
+
+test('uncaught exception will be reported to console', function (t) {
+	execCli('fixture/uncaught-exception.js', function (err, stdout, stderr) {
+		t.ok(err);
+		t.ok(/Can't catch me!/.test(stderr));
+		// TODO: This should get printed, but we reject the promise (ending all tests) instead of just ending that one test and reporting.
+		// t.ok(/1 uncaught exception[^s]/.test(stdout));
+		t.end();
+	});
+});
+
+test('throwing a named function will report the to the console', function (t) {
+	execCli('fixture/throw-named-function.js', function (err, stdout, stderr) {
+		t.ok(err);
+		t.ok(/\[Function: fooFn]/.test(stderr));
+		// t.ok(/1 uncaught exception[^s]/.test(stdout));
+		t.end();
+	});
+});
+
+test('throwing a anonymous function will report the function to the console', function (t) {
+	execCli('fixture/throw-anonymous-function.js', function (err, stdout, stderr) {
+		t.ok(err);
+		t.ok(/\[Function: anonymous]/.test(stderr));
+		// t.ok(/1 uncaught exception[^s]/.test(stdout));
+		t.end();
+	});
+});
+
 test('absolute paths in CLI', function (t) {
 	t.plan(2);
 
@@ -1091,9 +1127,9 @@ test('titles of both passing and failing tests and AssertionErrors are displayed
 test('empty test files creates a failure with a helpful warning', function (t) {
 	t.plan(2);
 
-	execCli('fixture/empty.js', function (err, stdout) {
+	execCli('fixture/empty.js', function (err, stdout, stderr) {
 		t.ok(err);
-		t.ok(/No tests found.*?import "ava"/.test(stdout));
+		t.ok(/No tests found.*?import "ava"/.test(stderr));
 		t.end();
 	});
 });