test-net-connect-options-ipv6 takes way to long on OS X

[Fishrock123]

Getting this both on master and v5.x when trying to do #4392

=== release test-net-connect-options-ipv6 ===                                  
Path: parallel/test-net-connect-options-ipv6
Command: out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-net-connect-options-ipv6.js
--- TIMEOUT ---
[01:24|% 100|+ 998|-   1]: Done                            
make: *** [test] Error 1

Maybe related to #4325 and/or #4395?

cc @Trott / @mscdex?

[Trott]

This is on your local machine? What happens when you do run it directly from the command line with out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-net-connect-options-ipv6.js? Does it fail on line 35 or somewhere else or what?

[Trott]

(I ask because it's passing with no issues for me on master on OS X.)

[mscdex]

I just ran make test with master on OS X 10.10 and did not run into any errors.

[Fishrock123]

It is taking 120s on my machine to complete when run manually.

Jeremiahs-MacBook-Pro:node Jeremiah$ /usr/bin/time out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-net-connect-options-ipv6.js
client connect cb
      120.38 real         0.08 user         0.01 sys

[mscdex]

For me it returns immediately. Do you know where it's timing out?

FWIW the OS X system I'm testing on only has this in /etc/hosts:

127.0.0.1       localhost
255.255.255.255 broadcasthost
::1             localhost 

It also has (real) IPv6 addresses for lo0 and en0.

[kingroryg]

@Fishrock123 im facing a similar issue .

[Fishrock123]

Using this rough patch for logging:

diff --git a/test/parallel/test-net-connect-options-ipv6.js b/test/parallel/test-net-connect-options-ipv6.js
index 8b11612..3c937e7 100644
--- a/test/parallel/test-net-connect-options-ipv6.js
+++ b/test/parallel/test-net-connect-options-ipv6.js
@@ -7,50 +7,59 @@ if (!common.hasIPv6) {
   console.log('1..0 # Skipped: no IPv6 support');
   return;
 }
-
+console.log('1')
 const hosts = common.localIPv6Hosts;
 var hostIdx = 0;
 var host = hosts[hostIdx];
 var localhostTries = 10;

 const server = net.createServer({allowHalfOpen: true}, function(socket) {
+  console.log('2.1')
   socket.resume();
-  socket.on('end', common.mustCall(function() {}));
+  socket.on('end', common.mustCall(function() {console.log('2.2')}));
   socket.end();
 });

 server.listen(common.PORT, '::1', tryConnect);

 function tryConnect() {
+  console.log('3')
   const client = net.connect({
     host: host,
     port: common.PORT,
     family: 6,
     allowHalfOpen: true
   }, function() {
+    console.log('4')
     console.error('client connect cb');
     client.resume();
     client.on('end', common.mustCall(function() {
+      console.log('4.1')
       setTimeout(function() {
+        console.log('4.2')
         assert(client.writable);
         client.end();
       }, 10);
     }));
     client.on('close', function() {
+      console.log('5')
       server.close();
     });
   }).on('error', function(err) {
+    console.log('6.1')
     if (err.syscall === 'getaddrinfo' && err.code === 'ENOTFOUND') {
       if (host !== 'localhost' || --localhostTries === 0)
         host = hosts[++hostIdx];
-      if (host)
+      if (host) {
+        console.log('6.2')
         tryConnect();
-      else {
+      } else {
         console.log('1..0 # Skipped: no IPv6 localhost support');
         server.close();
       }
       return;
     }
+    console.log('6.3')
     throw err;
   });
 }

The output is:

Jeremiahs-MacBook-Pro:node Jeremiah$ out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-net-connect-options-ipv6.js
1
3
6.1
6.2
3
6.1
6.2
3
6.1
6.2
3
6.1
6.2
3
4
client connect cb
2.1
4.1
4.2
2.2
5

.... undo the patch, and now it works:

Jeremiahs-MacBook-Pro:node Jeremiah$ out/Release/node /Users/Jeremiah/Documents/node/test/parallel/test-net-connect-options-ipv6.js
client connect cb

No clue. Each time it re-tries tryConnect(); takes a few seconds though.

[mscdex]

@Fishrock123 What do you have in your /etc/hosts ?

[Fishrock123]

##
# Host Database
#
# localhost is used to configure the loopback interface
# when the system is booting.  Do not change this entry.
##
127.0.0.1   localhost
255.255.255.255 broadcasthost
::1             localhost 
fe80::1%lo0 localhost
# 74.208.10.249 gs.apple.com
#
104.236.136.193 test.iojs.org

fe80::1%lo0 localhost .... what
Edit: http://superuser.com/questions/241642/what-is-the-relevance-of-fe801lo0-localhost-in-etc-hosts I guess?

[Fishrock123]

@mscdex ping

[mscdex]

@Fishrock123 I added that extra localhost entry you have to the OS X system I'm testing on and it didn't affect anything for me.

[Fishrock123]

This has persisted for over a month and has made me miss linter errors.

Interestingly, this displays when the pause happens in the test runner: [00:53|% 99|+ 978|- 0]: release test-zerolengthbufferbug. Going to bisect.

[Fishrock123]

Jeremiah@Jeremiahs-MacBook-Pro ~/D/node> git bisect bad
852313af651f30818b2dc24234f9b49036cc40e3 is the first bad commit
commit 852313af651f30818b2dc24234f9b49036cc40e3
Author: Brian White <mscdex@mscdex.net>
Date:   Thu Dec 17 01:16:46 2015 -0500

    test: try other ipv6 localhost alternatives

    PR-URL: https://github.com/nodejs/node/pull/4325
    Reviewed-By: Ben Noordhuis <info@bnoordhuis.nl>
    Reviewed-By: James M Snell <jasnell@gmail.com>

:040000 040000 1ab185732afcc3525696a3d6944ab21c77562e90 f0507f779836ca6af0bab2364a1fab58fb8519d3 M  test

ping @mscdex, your commit: 852313a

[Trott]

@Fishrock123 This is still a problem for you, right?

[Fishrock123]

@Trott yes. Very much so. I've missed multiple lint issues due to this. (Maybe lint should run regardless of tests?)

[mscdex]

@Fishrock123 What version of OS X are you running?

[Fishrock123]

10.10.5

[evanlucas]

+1 to lint running before tests. Or regardless of test failure

[mscdex]

@Fishrock123 Out of curiosity, what if you temporarily restrict your /etc/hosts to just:

127.0.0.1   localhost
::1             localhost

?

[Trott]

@Fishrock123 Does this change fix it for you?

--- a/test/parallel/test-net-connect-options-ipv6.js
+++ b/test/parallel/test-net-connect-options-ipv6.js
@@ -8,7 +8,8 @@ if (!common.hasIPv6) {
   return;
 }

-const hosts = common.localIPv6Hosts;
+const hosts = process.platform === 'linux' ?
+  common.localIPv6Hosts : ['localhost'];
 var hostIdx = 0;
 var host = hosts[hostIdx];
 var localhostTries = 10;

[Trott]

@Fishrock123 wrote:

(Maybe lint should run regardless of tests?)

@evanlucas responded:

+1 to lint running before tests. Or regardless of test failure

If I'm not misreading the file, it appears that vcbuild.bat runs lint before tests on Windows. That makes a lot of sense to me--run the thing that will fail fast first. Run the thing that might take a while after that.

PR opened to do the same for make test in Makefile: #5470

[Trott]

PR #5471 should resolve this issue, I believe.