Node: A libuv upgrade in Node v6 breaks the popular david package

[mgol]

• Version: v6.0.0-rc.3 (specifically, commit c3cec1eefc9f3b55a3fb7bd623b3d921f493870d)
• Platform: Darwin mgol-mbpro.local 15.4.0 Darwin Kernel Version 15.4.0: Fri Feb 26 22:08:05 PST 2016; root:xnu-3248.40.184~3/RELEASE_X86_64 x86_64
• Subsystem: libuv

Unfortunately I don't have an isolated test case, I've only seen the david issue in all v6 RCs while it works fine in v5 & I reported it in https://github.com/alanshaw/david/issues/106. I did a git bisect, though and nailed it down to c3cec1eefc9f3b55a3fb7bd623b3d921f493870d.

[evanlucas]

/cc @saghul

[kzc]

v6.0.0-rc.2
$ david

@mgol It could be a tty issue in libuv 1.9.0.

Can you try running:

$ david | cat

or

$ david > out.txt
$ cat out.txt

[mgol]

david | cat still prints truncated output while piping output to a file and cating the file works fine.

[kzc]

I can reproduce your original truncated david output problem with v6.0.0-pre. However, both commands in my previous comment above work for me on OSX 10.9.5.

[saghul]

I'll take a look. Main suspect: https://github.com/libuv/libuv/commit/387102b2475776e5e40a3f6da5041eb674ad4abf

[mgol]

I'm on latest 10.11.4. I tried both in ZSH & Bash, same results every time.

[kzc]

If I apply this patch to master then david | cat fails (output truncated) here as well:

diff --git a/deps/uv/src/unix/tty.c b/deps/uv/src/unix/tty.c
index 32fa37e..e2e5cb5 100644
--- a/deps/uv/src/unix/tty.c
+++ b/deps/uv/src/unix/tty.c
@@ -80,7 +80,7 @@ int uv_tty_init(uv_loop_t* loop, uv_tty_t* tty, int fd, int readable) {
    * different struct file, hence changing its properties doesn't affect
    * other processes.
    */
-  if (type == UV_TTY) {
+  if (0 && type == UV_TTY) {
     /* Reopening a pty in master mode won't work either because the reopened
      * pty will be in slave mode (*BSD) or reopening will allocate a new
      * master/slave pair (Linux). Therefore check if the fd points to a

[kzc]

@saghul Might be an issue with uv_guess_handle not detecting a tty?

[kzc]

scratch that - uv_guess_handle correctly returns UV_TTY.

[kzc]

If this patch is applied to master with libuv 1.9.0 then david output is not truncated on OS X 10.9.5:

diff --git a/deps/uv/src/unix/tty.c b/deps/uv/src/unix/tty.c
index 32fa37e..9179ca7 100644
--- a/deps/uv/src/unix/tty.c
+++ b/deps/uv/src/unix/tty.c
@@ -135,8 +135,10 @@ skip:
   else
     flags |= UV_STREAM_WRITABLE;

+#if 0
   if (!(flags & UV_STREAM_BLOCKING))
     uv__nonblock(fd, 1);
+#endif

   uv__stream_open((uv_stream_t*) tty, fd, flags);
   tty->mode = UV_TTY_MODE_NORMAL;

[kzc]

/cc @Gottox

[kzc]

I don't think the libuv tty PR is the issue. It appears that process.stdout is not being flushed upon process exit. Making stdout blocking as per patch above can make it work, but that's just side stepping the real issue.

If the david script is changed to call process.exit() only upon encountering the process.stdout "drain" event then everything is output correctly with node master 0899ea7a5210be333ed13c730a179a86e48a56a0.

What is considered to be the correct node way of flushing stdout upon process.exit()? I think this ought to happen automatically without programmer intervention.

[kzc]

Alternate fix - leave node 6.0.0-rc with libuv 1.9.0 as is and simply apply this patch to david:

--- a/david/bin/david.js    2016-04-20 20:49:35.000000000 -0400
+++ b/david/bin/david.js    2016-04-20 21:03:42.000000000 -0400
@@ -325,7 +325,7 @@
       if (getNonWarnDepNames(deps).length ||
           getNonWarnDepNames(devDeps).length ||
           getNonWarnDepNames(optionalDeps).length) {
-        process.exit(1)
+        process.exitCode = 1
       } else {
         // Log feedback if all dependencies are up to date
         console.log(clc.green('All dependencies up to date'))

This has the effect of letting the program exit naturally without abruptly cutting off the flushing of stdout.

[jasnell]

The not flushing on exit is a bit of a long standing issue. It's on my list of things to get figured out soon-ish. In the meantime, it's possible to register an on-exit handler that can flush but you'll need to make sure everything gets done in a single go as there's no ability to nextTick or setImmediate... Node will exit immediately after the on-exit handlers are called. If you have control over when process.exit() is called, you can orchestrate a graceful exit (see https://github.com/nodejs/node/pull/6175 for an example).

[kzc]

See also: https://github.com/cowboy/node-exit

If process.exit is replaced with exit from the module above, it also appears to correctly drain stdio in david when run with node 6.0.0rc + libuv 1.9.0.

In light of these workarounds I think this node ticket can be closed and no need to revert libuv 1.9.0.

[mgol]

The not flushing on exit is a bit of a long standing issue.

Interesting. Why isn't this an issue in Node <6 then?

[kzc]

I have to admit that the current node behavior of process.exit not flushing stdout/stderr in some cases is completely counter-intuitive. In my opinion tty output streams should always be blocking to eliminate the need for such heroic workarounds.

[jasnell]

Not entirely certain but I believe this libuv update included some changes
around non-blocking I/O to stdout. If that's the case, then it makes sense
given that process.exit forces an immediate exit from the event loop.
Anything still pending, including pending I/O is dropped. The only thing
guaranteed to run are the on exit handlers.

I'm investigating ways of allowing Node to make a more graceful exit, but
that work is still pending.
On Apr 21, 2016 1:49 AM, "Michał Gołębiowski" [email protected]
wrote:

The not flushing on exit is a bit of a long standing issue.

Interesting. Why isn't this an issue in Node <6 then?

—
You are receiving this because you commented.
Reply to this email directly or view it on GitHub
https://github.com/nodejs/node/issues/6297#issuecomment-212816991

[saghul]

Any chance this can be reproduced only with core modules?

[kzc]

I'm sure given enough time it could be isolated into a standalone test case, but a simple print loop is insufficient to reproduce the issue.

The higher level question that should be addressed before any fix is attempted is whether process.exit _ought_ to flush stdout/stderr at all. If so, there are many possible solutions including making writes to stdout/stderr blocking. If not, then there is no work to do.

[jasnell]

The key challenge to making process.exit flush automatically is that the semantics of process.exit() are such that it should force the node process to exit as quickly as possible. I recently proposed adding a gracefulExit() alternative that would allow apps to do additional cleanup (including flushing stdout) but it was pointed out that the same could easily be done by applications already or provided by a userland module. Personally I'd prefer if it were built into core because it is one of those surprising usability things that tends to trip users up.

[kzc]

That's the thing, gracefulExit() was rejected because it was argued it could be done from user land. So there is a logical disconnect with this david bug report - that app is clearly relying on that same undefined behavior. Node documentation for process.exit should explicitly state that stdout and stderr are not guaranteed to be flushed as this is the current behavior and point to an example of the best prescribed Node Way(tm) to achieve flushing of these streams upon process.exit.

[jasnell]

+1. the documentation could indeed be made significant better here. Interested in doing a pull request? ;-) ... if not, maybe someone from @nodejs/documentation could look into it :-)

[kzc]

I honestly do not know what is considered the best node practise to flush stdout/stderr upon process.exit, so I'll pass on the documentation pull request.

But I agree with you that process.exit really ought to flush these streams as users from other languages would reasonably expect that behavior.

[mgol]

Another popular package that breaks on Node 6 RCs because of this change is uglify-js. The output of:

uglify-js --help

is truncated. See mishoo/UglifyJS2#1055 for more info.

I'd expect there may be more popular packages broken by this change.

EDIT: fixed the link.

[kzc]

Corrected uglify link: https://github.com/mishoo/UglifyJS2/issues/1055

I'd expect there may be more popular packages broken by this change.

You're right. But rather than reverting the libuv 1.9.0 patch or the tty redirection fix in particular, stdout and stderr should simply be made blocking. This is the process.exit() behavior that node programmers have come to expect.

[kzc]

@saghul My earlier comment about reproducibility was wrong. I simply did not output enough data.

Isolated test case demonstrating truncated stdout output with node 6 rc on a Mac Terminal:

for (var i = 1; i <= 400; ++i) {
    console.log(i + ": the quick brown fox jumps over the lazy dog.");
}
process.exit(0);

[kzc]

New twist - reproduced the same issue using node v5.10.0 release on Ubuntu 14.04 x64 using a higher loop count:

for (var i = 1; i <= 40000; ++i) {
    console.log(i + ": the quick brown fox jumps over the lazy dog.");
}
process.exit(0);

node v5.10.0 on Ubuntu 14.04 x64 truncates the output after approximately 1543 lines (it is variable).

If the same script is run with node v5.10.0 on Mac OS X 10.9.5 it will output all 40000 lines. Perhaps stdout was blocking on Mac in previous node releases.

The stdout truncating behavior upon process.exit() existed prior to merging libuv 1.9.0 on some platforms - just with a higher output threshold. So it's not strictly correct to call this behavior a regression.

Unfortunately existing node applications rely on this undefined stdout/process.exit behavior.

Where to go from here with respect to whether stdout/stderr should block or be flushed upon process.exit somehow?

[addaleax]

Is this in related to/a duplicate of #2148? Asking because @kzc’s recent code posts remind me an awful lot of test/known_issues/test-stdout-buffer-flush-on-exit.js …

[Gottox]

I don't think, that my change is directly related to this bug. But if I understand the issue correctly, there are two solutions: Making all TTY io blocking (imho, introducing special rules to std{in,out,err} results in some nasty inconsistencies) or flushing the buffer on process exit. The first one should be done in libuv. Nevertheless I find the second option promising but I do understand, that it's against the idea of the function.

[eljefedelrodeodeljefe]

Changing TTY and friends towards being blocking sounds way to drastic to me. This issue is too complex for such changes and needs some kind of design. I am seeing lots of unfortunate code around process.exit() and process.on('exit') (largely because of an unfortunate API), and an immediate action would only be documenting this even more. You can find this already in the docs though, but this won't stop people from hacking with it in application code.

[kzc]

Docs from the iojs days:

process.stderr and process.stdout are unlike other streams in io.js in that they cannot be closed (end() will throw), they never emit the finish event and that writes are always blocking.

https://iojs.org/api/process.html#process_process_stdout

and now:

process.stderr and process.stdout are unlike other streams in Node.js in that they cannot be closed (end() will throw), they never emit the 'finish' event and that writes can block when output is redirected to a file (although disks are fast and operating systems normally employ write-back caching so it should be a very rare occurrence indeed.)

https://nodejs.org/api/process.html#process_process_stdout

Did the write behavior for stdout/stderr officially change?

[bnoordhuis]

Yes, and note that the documentation was wrong for quite some time before that. The 'writes are always blocking' bit was not universally true and please don't ask me to summarize how it did work - it's complicated.

[kzc]

What is the recommended best practise for a node program to have stdout/stderr flushed upon process.exit()? Ideally the solution would work with all node versions from 0.10.x to 6.x on all supported node platforms.

I've been relying on the external module https://www.npmjs.com/package/exit to replace process.exit().

[eljefedelrodeodeljefe]

So my point is that using process.exit() might be unnecessary in most of the cases. E.g. the if-blocks in david could just return instead of exiting, can they not?

[mgol]

You can't use return in the top scope.

[kzc]

using process.exit() might be unnecessary

In theory you could do it with creative use of throw/catch and rewriting functions and nested async program logic, but it's not trivial in the general case.

Because node once documented that writes to stdout/stderr were blocking, application programmers believed it to be true and used process.exit() accordingly. Whether the docs were true at the time is not important. It set the stage for the present situation.

[targos]

You can't use return in the top scope.

You can do it in node (the code is wrapped in a function before execution).

[eljefedelrodeodeljefe]

That's correct for the REPL and the browser, modules live in a closure though. This here should work:

for (var i = 1; i <= 100000; ++i) {
    console.log(i, ": the quick brown fox jumps over the lazy dog.");
}

if (true) {
  console.log('will come here');
  return // should be equivalent to process.exit(), given that you don't catch exit somewhere
}

console.log('wont come here');

# doesn't work
node -e "return"

# this does
node -e " (function() {
   'use strict';
    return 
 }());" 

Also david could be rewritten to live inside a function.

[targos]

@bnoordhuis stdout (and sterr) can be made blocking with process.stdout._handle.setBlocking(true). Is it unreliable ? Couldn't we add this to the API ?

[kzc]

@eljefedelrodeodeljefe Don't get pre-occupied with fixing david specifically - this thread already offered a couple of viable workarounds. Think about the general case. Code would have to analyzed and rewritten by a human unless an alternative to process.exit() like the third party module exit is used.

[eljefedelrodeodeljefe]

Sure but I would vote to document to use process.on('exit') and process.exit() to be discouraged in application code, other then system programming. Because you could argue that process.exit() is kind of the emergency break, and does the right thing there.

[eljefedelrodeodeljefe]

Returning applies for every other CLI module out there.

[bnoordhuis]

stdout (and sterr) can be made blocking with process.stdout._handle.setBlocking(true). Is it unreliable ?

It's arguably too reliable. If stdout/stderr is slow (e.g. a pipe to another process that's not reading), writes will block and lock up the process.

That, by the way, is why flushing on exit is not fixable in general - not when process.exit() means 'exit now'.

[kzc]

Returning applies for every other CLI module out there.

Sure, if you want node application authors to rewrite functions and async code - yes anything is doable.

[kzc]

If stdout/stderr is slow (e.g. a pipe to another process that's not reading), writes will block and lock up the process.

There are two classes of node applications - CLI and server. The CLI apps like npm, david, uglify are not significantly impacted by blocking of stdout/stderr. I think it's safe to say that most CLI application authors would be surprised by the undocumented behavior of process.exit() not flushing stdout/stderr. As far as server apps, no mission critical node app writes to stdout/stderr except in exceptional circumstances when something is wrong. But when the application does write to the console you'd hope you'd see it if process.exit() is used.

If the node project insists that process.exit() must exit immediately without flushing stdout/stderr, please provide an official alternate mechanism to accomplish this common task. If that means use the third party module exit, that's fine. It just should be stated in the node docs.

[kzc]

stdout (and sterr) can be made blocking with process.stdout._handle.setBlocking(true)
...
Couldn't we add this to the API ?

+1 for this optional feature

[jasnell]

If calling stdout._handle.setBlocking(true) and stderr._handle.setBlocking(true) addresses the issue adequately, then one possible approach would be to add a new command-line flag to Node that causes those to be set on startup. node --blocking-stdio for instance. We'd need to verify that it would act consistently across platforms. Thoughts @bnoordhuis ?

[mgol]

@jasnell How would you apply these command line flags in scripts from npm modules? E.g. what could david do?

[ChALkeR]

@jasnell I don't think a flag would be a good idea here, because this issue (and the other stdout/stderr) issues should be fixed in a cleaner way later, and that would mean the removal of the flag.

[Qix-]

@jasnell

it's possible to register an on-exit handler that can flush

Buffered file descriptors are automatically fflush()'d upon a process exit under normal conditions (returning from main).

Does process.exit() call exit() underneath? If so, why not use something like setjmp()/longjmp() upon process.exit() and jump back to int main() with an error code to perform a 'graceful shutdown'? This would allow the actual entry point to perform any cleanup operations and, if used correctly, would call any destructors necessary without having to do a full stack unwind.

See my other response for how .setBlocking() would be a nightmare of a solution.

---

As an aside, exit() within C++ is usually a no-no for a variety of reasons (proper destruction and freeing of resources is one of the many - as seen here).

Though what's intriguing is that this _just started_ happening. Nah it didn't 'just start', as I suspected.

[Qix-]

Also, for completeness, this isn't a new issue.

nodejs/node-v0.x-archive#8329

Something probably changed in either LibUV or V8 or Node to affect timing when process.exit() is called (any major changes to the event loop lately, @jasnell?) to where we're just now seeing the side effects of exit().

---

EDIT: Oh look. exit().

void Exit(const FunctionCallbackInfo<Value>& args) {
  exit(args[0]->Int32Value());
}

which is set to process.reallyExit():

env->SetMethod(process, "reallyExit", Exit);

which is then wrapped by process.exit():

  process.exit = function(code) {
    if (code || code === 0)
      process.exitCode = code;

    if (!process._exiting) {
      process._exiting = true;
      process.emit('exit', process.exitCode || 0);
    }
    process.reallyExit(process.exitCode || 0);
  };

---

A quick solution would be to add process.stdout.flush() and process.stderr.flush().

Implementing a process.stdout.flush() and process.stderr.flush() wouldn't be a bad idea and would allow us to do something like:

  process.exit = function(code) {
    if (code || code === 0)
      process.exitCode = code;

    if (!process._exiting) {
      process._exiting = true;
      process.emit('exit', process.exitCode || 0);
    }

    process.stdout.flush();
    process.stderr.flush();
    process.reallyExit(process.exitCode || 0);
  };

[kzc]

process.stdout.flush() and process.stderr.flush()

It's not like C where the data is buffered in libc and _can_ be flushed. The unflushed data is in some Javascript data structure in V8 and the event loop has been halted.

[eljefedelrodeodeljefe]

@Qix- I agree. I am working on a patch to make the longjmp to node::Start and return to main. This alters the behaviour of a lot of other functions though, so this will gonna take a while and discussions. I don't know how to flush in this case though, and know already that solely doing the jmp will not solve the problem immediately.
Apart from that I am reading that it was generally discouraged to use longjmp in this kind of and throwing was preferred however, this won't work for us either I fear. After the longjmp we'd need to hope that v8 and the os clean properly.

[kzc]

longjmp and C++ destructors are not friends. All manner of bad things happen.

[eljefedelrodeodeljefe]

I know, but in that regard nothing is.

[bnoordhuis]

Before anyone spends too much time on it, longjmp'ing back to main() is not the solution. If you have to ask why, you need to read up on how V8, libuv and node interact.

[eljefedelrodeodeljefe]

hmm. No expert and I trust you. It wouldn't jump to main though but to right after StartNodeInstance, let v8 dispose and return to main. Though that might be slightly better than exiting directly, still not perfect.

[Qix-]

@bnoordhuis Right, but the suggestion to use longjmp wasn't necessarily playing towards destructors, but rather avoiding a call to exit(), albeit cheaply.

There is a better way to handle this function. That's all I'm getting at.

[kzc]

If you look to C and libc for historical inspiration (not implementation) there's exit(int) which performs atexit() cleanup and flushes all open output streams and there's _exit(int) which quits abruptly without any cleanup or flushing.

Obviously node's process.exit() is more a kin to libc's abrupt _exit(int). It would ideal to also offer a second officially sanctioned form of exit in core node that parallels libc's exit() functionality - much like the third party exit module already does. What it would be called is not terribly important - process.exitPlusPlus() or something else.

[Qix-]

@kzc There is, it's just not being used to flush streams.

process.exit(0); // exit, but with a little bit of cleanup
process.reallyExit(0); // exit(0);

See https://github.com/nodejs/node/issues/6297#issuecomment-214995842

[kzc]

Apparent consensus is that the present behavior of process.exit() is to remain the same so a different function will have to be created to drain stdout/stderr and exit.

Something logically equivalent to this user code polyfill using the third party exit module that is already known to work:

if (!process.exitGracefully) process.exitGracefully = require('exit');

There's not much code there:

https://github.com/cowboy/node-exit/blob/master/lib/exit.js

[Qix-]

@kzc while that's a perfectly fine temporary solution, this is a simple problem within Node proper and should be fixed :P I don't think it's a consensus that process.exit() isn't changed; it _needs_ to be changed.

[jasnell]

@kzc ... I had a proposed PR that did exactly that but the consensus was that it's something that can be easily handled in userland. Essentially, if you want to exit gracefully while letting any stdio finish, you'll need to make sure that you're not adding anything to the event loop queue so that the process exits out on it's own naturally.

[kzc]

Exiting on its own naturally doesn't work in practise with complicated nested async logic without rewriting a lot of code.

So if something like process.exitGracefully() is not added to node core all I can suggest is that everyone use the third party exit module and close this ticket.

[Qix-]

@jasnell while I agree that's what users _should_ be doing, the fact is that Node is being used as a scripting language and thus is more prone to users using pre-mature exit() calls.

Since exit() itself (at least in modern times) flushes standard FDs we should emulate that in our async environment. It shouldn't need a special function call for it. Users that haven't pushed a lot of output and that don't normally see the bug described here should be completely unaffected.

[jasnell]

@Qix- ... I agree with you :-) ... just need a PR that implements a solution that would be accepted.

[Qix-]

@jasnell Haha okay :) :+1:

[eljefedelrodeodeljefe]

@kzc I also see the need to handle this better and have it on my list, or would welcome a decent PR . node-exit's implementations is jut no proper solution. I am also hoping @Qix- would come up with something since your input above was valid.

Can we close this issue or give it a proper name that reflects what the discussion was about though?

[kzc]

node-exit's implementations is jut no proper solution.

@eljefedelrodeodeljefe What would you do differently than node-exit?

https://github.com/cowboy/node-exit/blob/master/lib/exit.js

Looks good to me, and it's known to work. Even supports closing streams other than stderr and stdout. Other than refactoring it to roll it into node proper, another solution would have to perform the same tasks.

[kzc]

@mgol Would you mind renaming this issue to something like "process.exit() ought to flush stdout/stderr"?

[jasnell]

I'd be more inclined to close this particular issue as we have a couple others already in the tracker for this particular issue. The libuv update just brought the issue more to the forefront.

[kzc]

Well, david remains broken in node 6. So not sure why this issue should be closed. Discussion can certainly move to another Issue. Which one do you recommend @jasnell?

[eljefedelrodeodeljefe]

@kzc because their is no action item for libuv e.g. rolling back the change and no action item only for david. The solution will be something around a change of exit behavior, which is not per se broken.

Concerning node-exit: this looks rather like a hack and you probably want to do this at the C or C++ layer, which was proposed already but didn't go forward. Also @jasnell had a solution, which which have added an API rather than fixing an existing one.

reopen if you don't agree, but I think this can be closed in favor for #6456