stdio buffered writes (chunked) issues & process.exit() truncation

[eljefedelrodeodeljefe]

If this is currently breaking your program, please use this temporary fix:

[process.stdout, process.stderr].forEach((s) => {
  s && s.isTTY && s._handle && s._handle.setBlocking &&
    s._handle.setBlocking(true)
})

---

• Version: v6, (likely all and backportable)
• Platform: all
• Subsystem: process

As noted in #6297 async stdio will not be flushed upon immediate process.exit(). This may lay open general deficiencies around C exit() from C++ functions not being properly unwound and is probably not just introduced by latest libuv updates. It should be considered to add flushing, providing graceful exit and/or improving unwinding C++ stacks.

cc @jasnell, @kzc, @Qix-, @bnoordhuis

Issues

Discussion has been already taking place at several places, e.g. #6297, #6456, #6379

Summaries of Proposals

proposals are not exclusive and could lead to semantically unrelated contributions.

• aid with process.stdout.flush()
• process.setBlocking(true)
• node --blocking-stdio
• longjmp() towards main at exit in C++
• move parts of process.exit() / process.reallyExit() to new method os.exit()
• golang panic()- or c++ throw-like stack unwinding

Discussions by Author (with content)

---

@ChALkeR
I tried to discuss this some time ago at IRC, but postponed it for quite a long time. Also I started the discussion of this in #1741, but I would like to extract the more specific discussion to a separate issue.

I could miss some details, but will try to give a quick overview here.

Several issues here:

1. Many calls to console.log (e.g. calling it in a loop) could chew up all the memory and die — Why does node/io.js hang when printing to the console inside a loop? #1741, Silly program or memory leak? #2970, Strange memory leaks #3171.
2. console.log has different behavior while printing to a terminal and being redirected to a file. — Why does node/io.js hang when printing to the console inside a loop? #1741 (comment).
3. Output is sometimes truncated — A libuv upgrade in Node v6 breaks the popular david package #6297, there were other ones as far as I remember.
4. The behaviour seems to differ across platforms.

As I understand it — the output has an implicit write buffer (as it's non-blocking) of unlimited size.

One approach to fixing this would be to:

1. Introduce an explicit cyclic write buffer.
2. Make writes to that cyclic buffer blocking.
3. Make writes from the buffer to the actual output non blocking.
4. When the cyclic buffer reaches it's maximum size (e.g. 10 MiB) — block further writes to the buffer until a corresponding part of it is freed.
5. On (normal) exit, make sure the buffer is flushed.

For almost all cases, except for the ones that are currently broken, this would behave as a non-blocking buffer (because writes to the buffer are considerably faster than writes from the buffer to file/terminal).

For cases when the data is being piped to the output too quickly and when the output file/terminal does not manage to output it at the same rate — the write would turn into a blocking operation. It would also be blocking at the exit until all the data is written.

Another approach would be to monitor (and limit) the size of data that is contained in the implicit buffer coming from the async queue, and make the operations block when that limit is reached.

[Qix-]

Perhaps a list of issues this would address and/or close would be helpful to include since this seems to be a sprawling issue with a lot of fragmented discussion.

[eljefedelrodeodeljefe]

Yes, just a little late in Europe :( keep 'em coming and I add them above.

[vsemozhetbyt]

Also see #6410

[vsemozhetbyt]

Considering all the clarification in the #6410, is there also a theoretical possibility that not only several I/O calls to stdout could not make it, but even one simple console.log() before process.exit() could be truncated or discarded?

[Qix-]

@vsemozhetbyt that is especially correct if I'm understanding your question correctly.

[addaleax]

@vsemozhetbyt If it’s big enough, definitely. See e.g. test/known_issues/test-stdout-buffer-flush-on-exit.js.

[eljefedelrodeodeljefe]

To reproduce you can do

require('crypto').randomBytes(100000000, function(err, buffer) {
  var token = buffer.toString('hex');
  console.log(token);
  process.exit(0)
});

Edit: @addaleax's hint: test does a similar thing. Sorry @addaleax

[kzc]

@vsemozhetbyt This output is truncated with node 6.0.0 on Mac after approx 40 lines:

node -e 'console.log("The quick brown fox jumps.\n".repeat(40000)); process.exit(7);'

node 5.x and earlier output all 40000 lines on Mac.

[vsemozhetbyt]

So now if user does not want to reflow the code all one has is to write something like

const err = {name: 'Error', message: 'something wrong'};
throw err;

instead of

console.log('Error: something wrong');
process.exit(1);

and to deal with all the uncontrolled clutter of debug output?

[kzc]

throw err;
and to deal with all the uncontrolled clutter of debug output?

For dev code, sure, but uncaught exceptions in production code is not very elegant or professional.

[kzc]

Related: #6379

Also discusses process.stdio.setBlocking(Boolean)

[eljefedelrodeodeljefe]

added @chalkers thread and updated this issue with some summaries and stuff.