stdout/stderr buffering with TTY

[mscdex]

Recently I discovered that at least with the latest io.js (currently testing with the next branch in particular) and possibly older versions, stdout and stderr seem to be buffering when those streams refer to a TTY.

Here's a simple example that replicates the issue for me:

while (true) {
  console.error('stderr is tty? ' + process.stderr.isTTY);
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  console.error('foo bar baz quux quuz aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb cccccccccccccccccccccccccccccccc');
  require('fs').writeFileSync('/tmp/stderr_buffer_len', 'stderr buffer length=' + process.stderr._writableState.length + '\n');
}

In one terminal do tail -F /tmp/stderr_buffer_len and then in another do iojs test.js.

I also tested the same script with node v0.10.30 and the stderr buffer length is always 0.

[mscdex]

I just tested with node v0.12.6 and the same problem occurs, except I'm not able to interrupt/kill the process with ^C 😱

[brendanashworth]

Is this related to #784?

[mscdex]

@brendanashworth I'm not sure. I applied #1771 but that didn't affect things for some reason, however calling process.stderr._handle.setBlocking(true); manually before the loop does seem to fix it.

My guess is that it's because #1771 is explicitly checking for a stdout/stderr pipe (not TTY) and only setting blocking mode in that case.

[Fishrock123]

@mscdex is the result of your test case that it fails to write all of it on interrupt?

[mscdex]

@Fishrock123 When I used ^C and it worked, the process terminated immediately. It did not print anything more to the console after ^C. Is that what you mean?

[Fishrock123]

I think this is indirectly a dupe of #784. I'd defer to #1771 (comment) and #1771 (comment)

Since we have no smoke testing we have no idea if my patch (or a modified patch) might break things terribly, and it is quite hacky, I'm currently punting on it indefinitely.

[Fishrock123]

Actually, there is a slight difference, I'm not sure why, but maybe this testcase doesn't catch it.

I think the first underlying write of chunked output should effectively be synchronous (it effectively is in the other issue's testcase), but I'm not sure why that doesn't show here.

[Fishrock123]

Apparently stdout/stderr should always be blocking anyways: https://iojs.org/api/process.html#process_process_stdout...

[ChALkeR]

#1741 should be linked here.

[Trott]

#5920 is a proposed known_issues test for this, for what that's worth.

[jasnell]

@Fishrock123 @mscdex ... is this still an issue?

[mscdex]

@jasnell I haven't tested specifically but since I believe writes to TTYs are now blocking on all platforms in master/v8.x, it should only be an issue on older versions (v7.x and older).

[jasnell]

Given that we're not likely to change the defaults on the older versions for very good semver reasons, I'm inclined to close this. We can reopen if necessary

[Trott]

Are we sure this is fixed? We have a known_issues test for it and it still fails.

[Trott]

Actually, looks like I'm wrong and the test probably needs to be removed (or fixed). Closing.