Merge pull request #415 from jamestalmage/fix-mini-reporter-logging

Fix some reporter / logging issues. Fixes #392

Author: sindresorhus

api.js

@@ -55,7 +55,13 @@ Api.prototype._runFile = function (file) {
 		.on('stats', this._handleStats)
 		.on('test', this._handleTest)
 		.on('unhandledRejections', this._handleRejections)
-		.on('uncaughtException', this._handleExceptions);
+		.on('uncaughtException', this._handleExceptions)
+		.on('stdout', this._handleOutput.bind(this, 'stdout'))
+		.on('stderr', this._handleOutput.bind(this, 'stderr'));
+};
+
+Api.prototype._handleOutput = function (channel, data) {
+	this.emit(channel, data);
 };
 
 Api.prototype._handleRejections = function (data) {

cli.js

@@ -104,6 +104,9 @@ logger.start();
 api.on('test', logger.test);
 api.on('error', logger.unhandledError);
 
+api.on('stdout', logger.stdout);
+api.on('stderr', logger.stderr);
+
 api.run()
 	.then(function () {
 		logger.finish();

lib/fork.js

@@ -8,12 +8,17 @@ var AvaError = require('./ava-error');
 var send = require('./send');
 
 module.exports = function (file, opts) {
-	opts = objectAssign({file: file}, opts);
+	opts = objectAssign({
+		file: file,
+		tty: process.stdout.isTTY ? {
+			columns: process.stdout.columns,
+			rows: process.stdout.rows
+		} : false
+	}, opts);
 
 	var ps = childProcess.fork(path.join(__dirname, 'test-worker.js'), [JSON.stringify(opts)], {
 		cwd: path.dirname(file),
-		stdio: ['ignore', process.stderr, process.stderr],
-		silent: opts.silent
+		silent: true
 	});
 
 	var relFile = path.relative('.', file);
@@ -77,6 +82,18 @@ module.exports = function (file, opts) {
 		send(ps, 'teardown');
 	});
 
+	ps.stdout.on('data', function (data) {
+		if (!opts.silent) {
+			ps.emit('stdout', data);
+		}
+	});
+
+	ps.stderr.on('data', function (data) {
+		if (!opts.silent) {
+			ps.emit('stderr', data);
+		}
+	});
+
 	promise.on = function () {
 		ps.on.apply(ps, arguments);
 

lib/logger.js

@@ -53,6 +53,22 @@ Logger.prototype.write = function (str) {
 	this.reporter.write(str);
 };
 
+Logger.prototype.stdout = function (data) {
+	if (!this.reporter.stdout) {
+		return;
+	}
+
+	this.reporter.stdout(data);
+};
+
+Logger.prototype.stderr = function (data) {
+	if (!this.reporter.stderr) {
+		return;
+	}
+
+	this.reporter.stderr(data);
+};
+
 Logger.prototype.exit = function (code) {
 	// TODO: figure out why this needs to be here to
 	// correctly flush the output when multiple test files

lib/reporters/mini.js

@@ -1,7 +1,9 @@
 'use strict';
-var logUpdate = require('log-update');
-var colors = require('../colors');
+var cliCursor = require('cli-cursor');
+var lastLineTracker = require('last-line-stream/tracker');
+var StringDecoder = require('string_decoder').StringDecoder;
 var plur = require('plur');
+var colors = require('../colors');
 var beautifyStack = require('../beautify-stack');
 
 function MiniReporter() {
@@ -14,7 +16,11 @@ function MiniReporter() {
 	this.skipCount = 0;
 	this.rejectionCount = 0;
 	this.exceptionCount = 0;
-	this.finished = false;
+	this.currentStatus = '';
+	this.statusLineCount = 0;
+	this.lastLineTracker = lastLineTracker();
+	this.stream = process.stderr;
+	this.stringDecoder = new StringDecoder();
 }
 
 module.exports = MiniReporter;
@@ -24,7 +30,7 @@ MiniReporter.prototype.start = function () {
 };
 
 MiniReporter.prototype.test = function (test) {
-	var status = '\n';
+	var status = '';
 	var title;
 
 	if (test.skip) {
@@ -61,9 +67,7 @@ MiniReporter.prototype.unhandledError = function (err) {
 };
 
 MiniReporter.prototype.finish = function () {
-	this.finished = true;
-
-	var status = '\n';
+	var status = '';
 
 	if (this.passCount > 0) {
 		status += '  ' + colors.pass(this.passCount, 'passed');
@@ -134,9 +138,76 @@ MiniReporter.prototype.finish = function () {
 };
 
 MiniReporter.prototype.write = function (str) {
-	logUpdate.stderr(str);
+	cliCursor.hide();
+	this.currentStatus = str + '\n';
+	this._update();
+	this.statusLineCount = this.currentStatus.split('\n').length;
+};
+
+MiniReporter.prototype.stdout = MiniReporter.prototype.stderr = function (data) {
+	this._update(data);
+};
+
+MiniReporter.prototype._update = function (data) {
+	var str = '';
+	var ct = this.statusLineCount;
+	var columns = process.stdout.columns;
+	var lastLine = this.lastLineTracker.lastLine();
+
+	// Terminals automatically wrap text. We only need the last log line as seen on the screen.
+	lastLine = lastLine.substring(lastLine.length - (lastLine.length % columns));
+
+	// Don't delete the last log line if it's completely empty.
+	if (lastLine.length) {
+		ct++;
+	}
+
+	// Erase the existing status message, plus the last log line.
+	str += eraseLines(ct);
+
+	// Rewrite the last log line.
+	str += lastLine;
 
-	if (this.finished) {
-		logUpdate.stderr.done();
+	if (str.length) {
+		this.stream.write(str);
+	}
+
+	if (data) {
+		// send new log data to the terminal, and update the last line status.
+		this.lastLineTracker.update(this.stringDecoder.write(data));
+		this.stream.write(data);
+	}
+
+	var currentStatus = this.currentStatus;
+	if (currentStatus.length) {
+		lastLine = this.lastLineTracker.lastLine();
+		// We need a newline at the end of the last log line, before the status message.
+		// However, if the last log line is the exact width of the terminal a newline is implied,
+		// and adding a second will cause problems.
+		if (lastLine.length % columns) {
+			currentStatus = '\n' + currentStatus;
+		}
+		// rewrite the status message.
+		this.stream.write(currentStatus);
 	}
 };
+
+// TODO(@jamestalamge): This should be fixed in log-update and ansi-escapes once we are confident it's a good solution.
+var CSI = '\u001b[';
+var ERASE_LINE = CSI + '2K';
+var CURSOR_TO_COLUMN_0 = CSI + '0G';
+var CURSOR_UP = CSI + '1A';
+
+// Returns a string that will erase `count` lines from the end of the terminal.
+function eraseLines(count) {
+	var clear = '';
+
+	for (var i = 0; i < count; i++) {
+		clear += ERASE_LINE + (i < count - 1 ? CURSOR_UP : '');
+	}
+	if (count) {
+		clear += CURSOR_TO_COLUMN_0;
+	}
+
+	return clear;
+}

lib/reporters/tap.js

@@ -78,3 +78,7 @@ TapReporter.prototype.finish = function () {
 TapReporter.prototype.write = function (str) {
 	console.log(str);
 };
+
+TapReporter.prototype.stdout = TapReporter.prototype.stderr = function (data) {
+	process.stderr.write(data);
+};

lib/reporters/verbose.js

@@ -100,3 +100,7 @@ VerboseReporter.prototype.finish = function () {
 VerboseReporter.prototype.write = function (str) {
 	console.error(str);
 };
+
+VerboseReporter.prototype.stdout = VerboseReporter.prototype.stderr = function (data) {
+	process.stderr.write(data);
+};

lib/test-worker.js

@@ -1,12 +1,27 @@
 'use strict';
+var opts = JSON.parse(process.argv[2]);
+var testPath = opts.file;
+
+// Fake TTY support
+if (opts.tty) {
+	process.stdout.isTTY = true;
+	process.stdout.columns = opts.tty.columns || 80;
+	process.stdout.rows = opts.tty.rows;
+	var tty = require('tty');
+	var isatty = tty.isatty;
+	tty.isatty = function (fd) {
+		if (fd === 1 || fd === process.stdout) {
+			return true;
+		}
+		return isatty(fd);
+	};
+}
+
 var path = require('path');
 var fs = require('fs');
 var debug = require('debug')('ava');
 var sourceMapSupport = require('source-map-support');
 
-var opts = JSON.parse(process.argv[2]);
-var testPath = opts.file;
-
 if (debug.enabled) {
 	// Forward the `time-require` `--sorted` flag.
 	// Intended for internal optimization tests only.

package.json

@@ -38,7 +38,8 @@
   },
   "scripts": {
     "test": "xo && nyc --cache --reporter=lcov --reporter=text tap --no-cov --timeout=150 test/*.js test/reporters/*.js",
-    "test-win": "tap --no-cov --reporter=classic --timeout=150 test/*.js test/reporters/*.js"
+    "test-win": "tap --no-cov --reporter=classic --timeout=150 test/*.js test/reporters/*.js",
+    "visual": "node test/visual/run-visual-tests.js"
   },
   "files": [
     "lib",
@@ -87,6 +88,7 @@
     "bluebird": "^3.0.0",
     "caching-transform": "^1.0.0",
     "chalk": "^1.0.0",
+    "cli-cursor": "^1.0.2",
     "co-with-promise": "^4.6.0",
     "commondir": "^1.0.1",
     "convert-source-map": "^1.1.2",
@@ -101,7 +103,7 @@
     "is-generator-fn": "^1.0.0",
     "is-observable": "^0.1.0",
     "is-promise": "^2.1.0",
-    "log-update": "^1.0.2",
+    "last-line-stream": "^1.0.0",
     "loud-rejection": "^1.2.0",
     "max-timeout": "^1.0.0",
     "md5-hex": "^1.2.0",
@@ -127,8 +129,10 @@
     "coveralls": "^2.11.4",
     "delay": "^1.3.0",
     "get-stream": "^1.1.0",
-    "rimraf": "^2.5.0",
+    "inquirer": "^0.11.1",
     "nyc": "^5.1.0",
+    "pify": "^2.3.0",
+    "rimraf": "^2.5.0",
     "signal-exit": "^2.1.2",
     "sinon": "^1.17.2",
     "source-map-fixtures": "^0.4.0",