test-child-process-fork-getconnections intermittently fails

[Fishrock123]

Sometimes getting this when testing master (fe36076) on OS X 10.10.2

Jeremiahs-MacBook-Pro:io.js Jeremiah$ make test
/Applications/Xcode.app/Contents/Developer/usr/bin/make -C out BUILDTYPE=Release V=1
make[1]: Nothing to be done for `all'.
ln -fs out/Release/iojs iojs
/usr/bin/python tools/test.py --mode=release message parallel sequential -J
=== release test-child-process-fork-getconnections ===                         
Path: sequential/test-child-process-fork-getconnections
/Users/Jeremiah/Documents/io.js/test/sequential/test-child-process-fork-getconnections.js:18
          throw new Error('[c] closing by accident!');
                ^
Error: [c] closing by accident!
    at Socket.<anonymous> (/Users/Jeremiah/Documents/io.js/test/sequential/test-child-process-fork-getconnections.js:18:17)
    at emitNone (events.js:72:20)
    at Socket.emit (events.js:163:7)
    at _stream_readable.js:891:16
    at process._tickCallback (node.js:349:13)
/Users/Jeremiah/Documents/io.js/test/sequential/test-child-process-fork-getconnections.js:36
      throw new Error('child died unexpectedly!');
            ^
Error: child died unexpectedly!
    at ChildProcess.<anonymous> (/Users/Jeremiah/Documents/io.js/test/sequential/test-child-process-fork-getconnections.js:36:13)
    at emitTwo (events.js:87:13)
    at ChildProcess.emit (events.js:169:7)
    at Process.ChildProcess._handle.onexit (child_process.js:1044:12)
Command: out/Release/iojs /Users/Jeremiah/Documents/io.js/test/sequential/test-child-process-fork-getconnections.js

cc @bnoordhuis?

[Fishrock123]

Fwiw, this has happened on the CI a bunch too.

[Fishrock123]

See also node's tracking issue: nodejs/node-v0.x-archive#16805

[Fishrock123]

Not sure if this helps at all, but I applied this little debugging patch:

diff --git a/test/sequential/test-child-process-fork-getconnections.js b/test/sequential/test-child-process-fork-getconnections.js
index a587713..0f10fce 100644
--- a/test/sequential/test-child-process-fork-getconnections.js
+++ b/test/sequential/test-child-process-fork-getconnections.js
@@ -34,7 +34,7 @@ if (process.argv[2] === 'child') {

   child.on('exit', function(code, signal) {
     if (!childKilled)
-      throw new Error('child died unexpectedly!');
+      throw new Error(`child died unexpectedly with code: ${code} and signal: ${signal}!`);
   });

   var server = net.createServer();

And it exits with code 1 and a null signal.

[thefourtheye]

I glanced through the source code, but I couldn't find closingOnPurpose defined anywhere. Also, normally, this in an Event's trigger would be undefined or global object, right?

[brendanashworth]

@thefourtheye yeah, when I went through the test before, closingOnPurpose is always undefined (not sure why its there). It errors whenever .end() is emitted.

I think this in an event listener refers to the EventEmitter instance, but since you inherit from it, it refers to whatever object you're listening on.

[cjihrig]

I'm not certain, but I think there is a race condition somewhere in the code that handles passing sockets between processes (in core, not the test). I've basically rewritten this test from scratch and am seeing sockets being closed just by sending them to the child process.

[Trott]

The closingOnPurpose is really puzzling. It was added in commit b319264. In that commit, this file is the only place in the entire code base where the string closingOnPurpose appears. And on current master, that is still the case. So, yeah, if that even fires, the test bombs, no matter what. Which seems to be what's happening here.

I realize it was more than two years ago when that commit happened so any recollection may be very foggy, and he's busy CEO-ing these days, but gonna slip a /cc @isaacs in the off chance he'd like to take a look and maybe shed some light. Leftover debugging code? Always failing is actually correct behavior? Something else?

[Fishrock123]

closingOnPurpose

I can't even find it by searching the codebase at or around the original commit's time. I suspect it is leftover debug code. Let's remove it.

[Trott]

But if we yank it, does that mean the event should always throw and error or it should just be removed because it should never throw an error?

I'm inclined to try to find the right place in the code to set that property, actually. Like, "if we're here, we are trying to close this socket, so no error". But maybe there isn't one and you're right. So... ¯\_(ツ)_/¯

[brendanashworth]

Yeah, let's ditch it, it should always throw. I wouldn't set a property in the code because it appeared in a test without any comment / commit log (grunt).

[Trott]

#2609 should fix this test. I still need to submit an issue for the bug itself, but this test can be written and still test all the same stuff without tripping up on this bug.

[Trott]

#2610 opened with slightly more minimal test code to trip the bug that caused the issue here.

[Trott]

Anyone feel good enough about #2609 to give it a LGTM so we can close this issue?

I know with all the shenanigans going on right now with 4.0 looming and a new PR-landing process, this is probably the worst possible time to ask, but that won't stop me.

[Trott]

Fixed by 8ca9ea2