How to correctly use node.js child_process.spawn() redirection on Windows?

Question

I have a clean Windows 8.1 box with lates node.js installed (v0.10.29). I have a following test code in two files:

a.js

var sub = require('child_process').spawn('node', ['b.js'], {silent: true});
sub.stdout.on("data", function (data) {console.log(data.toString());});

b.js

console.log("DEBUG 1");
console.log("DEBUG 2");
process.exit();

if i execute a.ja via:

node a.js

I will see "DEBUG 1" in console output - but not "DEBUG 2". If i remove process.exit(), both lines will be displayed correctly. This strange behavior happens both with fork and spawn.

Any hints? Same code works without problems on linux.

Update 02.07.2014

Seems this is not a race condition between exit() and log() since changing this to pure sequence produce same error:

function print(text, next) { console.log(text); next(); }
print("DEBUG 1", function () {
  print("DEBUG 2", function () {
    process.exit();
  });
});

Update 03.07.2014

silent is not listed in spawn() documentation, but it works. It is listed in fork documentation, and as I previously mentioned this problem is same with fork.

It seems that if I introduce a delay between last output and process.exit() all works correctly:

console.log("DEBUG 1");
console.log("DEBUG 2");
setTimeout(function () {process.exit();}, 10000);

But the problem manifest itself only if i pipe output to parent process: if I remove silent, both messages are displayed correctly even without delay, so it's most probably something wrong with pipe communication, not with process.exit.

More updates 03.07.2014

It was speculated in comments that process.exit() may terminate both processes (both a.ja and b.ja). No, it terminate only spawned/forked process, i checked this by adding infinite setTimeout to a.js, it happily works after b.ja is terminated, and still no "DEBUG 2" line.

Answer 1

Major edit for clarity:

The problem you face is the concurrent event between console.log('DEBUG2') and process.end(), the two of them are called (almost) at the same time, but process.end() have a higher priority, and when done, make sub stop listen to event, and so stop DEBUG2 to be printed:

In your code:

a.js                |b.js
start
spawn               |start
listen              |send('DEBUG1')
get DEBUG1          |send('DEBUG2')
start the event     |send KILL
print DEBUG1        |
get DEBUG2
start the event
get KILL
kill b.js //DEBUG2 haven t been printed

Now, if you slow down process.end:

b.js:

console.log('DEBUG1');
console.log('DEBUG2');
setTimeout(function () {
    process.end();
}, 1000);

a.js                |b.js
start
spawn               |start
listen              |send('DEBUG1')
get DEBUG1          |send('DEBUG2')
start the event     |wait
print DEBUG1        |wait
get DEBUG2          |send KILL
start the event
print DEBUG2
get KILL
kill b.js

But that's bothersome, and you can t know how many "wait" there will be. Another solution is to make b.js inherit of stdout, so there is no event to make:

a.js:

var sub = require('child_process').spawn('node', ['b.js'], {stdio:[process.stdin, process.stdout, process.stderr]});

a.js                |b.js
start
spawn               |start
listen              |print DEBUG1
                    |print DEBUG2
                    |send KILL
get KILL            |
kill b.js

Now, no bug-prone code, but you can t get what is printed in a.js. I think another solution with process.nextTick could work, but I don t know how it would work.

EDIT:

process.exit() kill b.js, which is the intended behavior. a.js see the data event end, and so have a empty event loop, and so kill itself : )