Fix some reporter / logging issues. Fixes #392

[jamestalmage]

This is a partial fix for #392, and addresses a few other issues I found along the way.

1. We were passing a stdio option to child_process.fork. While that is a valid option for many methods in the child_process API, it is ignored for child_process.fork. Instead, we must pass the silent: true option and pipe ps.stderr and ps.stdout to console.
2. Because we use the silent option, process.stdout.isTTY is now false in the child process. I modified test-worker.js to fake TTY support (but only if the parent process is a tty). I'm not sure that was necessary, however, without it, it might be difficult to test tty based libraries. Comments welcome.
3. I updated the mini logger to always print it's summary output after whatever output comes from the child process, always keeping it at the bottom of the printout. The algorithm for doing so is described in a comment later in this thread.
4. I added "visual tests", a suite we can run to verify the behavior across platforms. It's already proven valuable in this thread getting feedback from users. Just testing that the "correct" ansi escape codes are printed is not sufficient, different terminal emulators handle them differently. There's no good way to automate that test, so I've just tried to make it as easy as possible to manually test.
5. I had to drop log-update to address a bug in Terminal.app. This should probably addressed upstream, but I want to verify this is a good fix before changing ansi-escapes / log-update in ways that will affect lots of other applications.

@sindresorhus @vdemedes - ready for review.

[vadimdemedes]

Do we need visual tests? As I understand, those are supposed to be executed and completed manually.

[jamestalmage]

I think it's a good idea. I wouldn't make the part of the build. Just something we can run through before cutting a release to make sure things look right

[vadimdemedes]

It's just I'm sure those tests will be forgotten often. Why can't we have automatic tests for comparing output?

[jamestalmage]

It's just I'm sure those tests will be forgotten often

We will remember when we go to cut a release. Even so I don't think that's a big deal, these aren't mission critical tests.

Why can't we have automatic tests for comparing output?

Because what is output to the stream does not reflect what you actually see. Not every terminal emulator obeys the full set of ansi codes in the same way (here is just one example). A set of visual tests let us quickly check things look right locally and on whatever VM's we have available.

[jamestalmage]

This is how mini reporter looks now (lorem ipsum content is being generated as process.stdout.write in child process). Note how the test count always stays below the logged console content.

Terminal.app on OSX is problematic (I'm running Yosemite, there is reason to believe it's fixed on newer versions). I haven't tested on Windows.

[jamestalmage]

I'd appreciate some help figuring out the last of the kinks in this from anyone who knows something about terminal cursor manipulation. I'm not sure where things are going wrong. Here's what works:

1. Windows: It just works, always. (go figure)

2. OSX iTerm, and Ubuntu terminal. It works until you end up with process.stdout.write lining up perfectly with the column width. Then you get some extra newlines. You can see this with:

   ./cli.js test/visual/text-ends-at-terminal-width.js
   

   look at the comments in that test to fully understand what it is doing.

3. Terminal.app on OSX Yosemite. Very broken. There is reason to believe it works on El Capitan, if someone could verify, that would be great.

To test, use ./cli.js test/visual/<one-of-the-visual-test-fixture-files>.js

The lorem-ipsum and text-ends-at-terminal-width tests are the best ones to look at.

Note lorem-ipsum is a misnomer now, as it prints the Gettysburg Address instead. I needed to be able to tell if characters/lines were missing from the final display and couldn't do that with lorem ipsum because I don't know Latin.

// @Qix- @vdemedes @floatdrop @sindresorhus

[ecowden]

Awesome progress!

Here's lorem-ipsum.js in Terminal.app on El Capitan:

[sindresorhus]

@jamestalmage Why not use log-update?

var logUpdate = require('log-update');
var text = '';
var i = 0;

setInterval(function () {
    text += Math.random().toString(36).replace(/[^a-z]+/g, '').substr(0, 5);
}, 150);

setInterval(function () {
    logUpdate(text + '\n\n  ' + i++ + ' passed');
}, 50);

[jamestalmage]

@ecowden - darn. That's the same crap I get on Yosemite. I was really hoping to be able to blame that on an old OS.

The _clear function is basically a modified version of logUpdate.

Using logUpdate only works if you can clear the entire text. Right now the algorithm tries to do the following:

A: New status update.

1. Clear the existing status update.
2. Write the new status update.
3. Store the new status update as lastWritten. (existingStatus would have been a better name)

This is basically identical to log-update with the exception of storing the status.

B: New log output

1. Clear the existing status update.
2. Append text to the existing log output
3. Restore the existing status update from lastWritten

---

A is pretty easy, a solved problem with log-update.

B has proven difficult. Especially if what they write to the console does not end with a line terminator (\n). My current solution is just to store the last logged line, and delete/rewrite that as well.

[jamestalmage]

The latest push looks good on everything I've tried except Terminal.app.

• iTerm on OSX
• ubuntu desktops default terminal
• Windows Command Prompt

[jamestalmage]

Finally figured out the bug. Terminal.app does something weird with cursorLeft. The following code writes a line 20 characters wider than the terminal width, then writes the cursorLeft control character:

var ansiEscapes = require('ansi-escapes');

var str = '';

for(var i = 0; i < process.stdout.columns + 20; i++) {
    str += String(i % 10);
}

process.stdout.write(str + ansiEscapes.cursorLeft);

setTimeout(function() {
    // delay so you can see where the cursor is
}, 10000);

In most terminal emulators the cursor ends up all the way to the left of the current (i.e. second) line:

In Terminal.app, it ends up all the way to the left of the first line. (It moves up a line for no apparent reason).

[jamestalmage]

I think I have found a decent cross platform solution.

I'd like a number of people to pull this down and run:

npm run visual

[sindresorhus]

@jamestalmage Awesome! All the visual tests passed perfectly now on Terminal.app OS X 10.11.2 (El Capitan).

[vadimdemedes]

Could you comment the code in this function?

[vadimdemedes]

Great research, @jamestalmage!

[jamestalmage]

@vdemedes - updated with lots of code comments and clearer variable names.

also, jamestalmage@328638d

[jamestalmage]

So, that last commit is maybe unnecessary:

var through2 = require('through2');
var assert = require('assert');

var ct1 = 0;
var ct2 = 0;

var stream = through2(function (chunk, enc, cb) {
    assert.strictEqual(ct1, ct2);
    ct2++;
    cb(null, chunk);
});

stream.pipe(process.stdout)

for (var i = 0; i < 160000; i++) {
    stream.write(String(i % 10));
    ct1++;
}

It seems through2 will always call the callback synchronously (at least when it's used the way I'm using it with last-line-stream). In that case, I just wonder if jamestalmage@328638d makes what's happening any clearer. Also, prior to that, I was using stream.push() to bypass the tracker, which is probably considered an abuse of the stream API.

[jamestalmage]

All squashed up. What do you guys think, are we good to merge?

[vadimdemedes]

Hell Yeah!

[sindresorhus]

Marvelous!

[sindresorhus]

Should we open a new issue about matching console.log output to the relevant test, discussed in #392?

[jamestalmage]

Done => #420