Node Socket timeout

[Sparticuz]

• A brief description
  Node's Socket Timeout not being respected.

//testtimeout.js
const net = require("net");

let options = {
    address: "____Good IP Address____",
    port: ____BAD PORT____,
    timeout: 1 //1 ms
}

// For the time now
var timeNow = function (note) {
    var t = new Date();
    console.log( ((t.getHours() < 10)?"0":"") + t.getHours() +":"+ ((t.getMinutes() < 10)?"0":"") + t.getMinutes() +":"+ ((t.getSeconds() < 10)?"0":"") + t.getSeconds() + " - "+note);
}

timeNow("Start");

let s = new net.Socket();
s.setTimeout(options.timeout, function() {
    s.destroy();
    timeNow("Timeout Destroy");
});
s.on('error', e => {
    s.destroy();
    timeNow(e+"Error Destroy");
});
s.connect(options.port, options.address,() => {
    s.destroy();
    timeNow("Connect Destroy");
});

• Expected results
  A near immediate failure (below is Linux kernel 4.10.2-1-ARCH

13:56:27 - Start
13:56:27 - Timeout Destroy

• Actual results (with terminal output if applicable)

13:58:11 - Start
13:58:32 - Error: connect EAGAIN ###.###.###.###:PORT - Local (0.0.0.0:60994)Error Destroy

(It's always 21 seconds)

• Your Windows build number
  15063

• Steps / All commands required to reproduce the error from a brand new installation
  node scriptname.js

• Required packages and commands to install
  node v6.10.1

[therealkenc]

Repro:

curl -sL https://deb.nodesource.com/setup_6.x | sudo -E bash -
sudo apt-get install -y nodejs
# paste his testtimeout.js file and replace with "127.0.0.1" and 3000 so it runs
strace -tt -ff node testtimeout.js 2> node.strace

strace:

[pid  1131] 11:49:46.618784 socket(AF_INET, SOCK_STREAM, IPPROTO_IP) = 11
[pid  1131] 11:49:46.618984 ioctl(11, FIONBIO, [1]) = 0
[pid  1131] 11:49:46.619040 ioctl(11, FIOCLEX) = 0
[pid  1131] 11:49:46.619089 connect(11, {sa_family=AF_INET, sin_port=htons(3000), sin_addr=inet_addr("127.0.0.1")}, 16) = -1 ECONNREFUSED (Connection refused)
[pid  1131] 11:49:47.622176 clock_gettime(CLOCK_MONOTONIC, {3188, 686734000}) = 0
[pid  1131] 11:49:47.623175 clock_gettime(CLOCK_MONOTONIC, {3188, 687685000}) = 0

It doesn't take 21 seconds here, but it definitely burps for over a full second. Node version doesn't matter, natch. The socket sequence is bog straightforward.

[Sparticuz]

Local was alot quicker, remote ip was what took forever. Try a remote address.

[therealkenc]

Yeah, confirmed. 21 seconds on the nose with random 192.168.1.whatever on local network.

[therealkenc]

@sunilmut - WskGetAddressInfo(), right? 😏

[sunilmut]

@Sparticuz - Thanks for the report and thanks @therealkenc for the trace (helpful as always). This looks like a request to support non-blocking connect(). WSL currently does not support that. Looks dupe of #1584? The 21 second timeout you are seeing is just from the TCP/IP stack unable to connect.

@Sparticuz - Is this blocking any particular scenario for you? Or, just general annoyance because of the wait? Which, I agree, also needs to be addressed.

@therealkenc

WskGetAddressInfo(), right?

No, it is just WskConnect timing out after unable to connect.

[therealkenc]

Hey, it was a guess. 🙂 Glad you tracked it anyway.

[Sparticuz]

I'm using a socket to ping a site to see if it's up or not. Just annoying, not necessarily a blocking problem.

[sunilmut]

@therealkenc - It was a good one :).

@Sparticuz - Thanks for sharing the additional details. We will use that information to prioritize it accordingly. We are aware of this issue or shortcoming, if I may. Thanks for using WSL and please keep the feedback coming.

[sunilmut]

Just an update that non-blocking connect is on it's way and will also be available on Fall Creators Update.