getaddrinfo ENOTFOUND vs https registry about ied

[alexanderGugel]

Uhh that is strange. I can't really explain it, but yes, we should use of course use HTTPS.

This might have also produced an inconsistent node_modules directory (problem with way we currently prevent deadlocks), therefore you might have to blow away node_modules after ied failed. This sucks and will be resolved.

[timoxley]

Not sure this was actually resolved… the ENOTFOUND persists regardless of the https or not… sorry I think that was a red herring.

The error doesn't make any sense to me, I'm not behind a proxy and I've flushed my dnscache and tweaked my dns settings to no avail…
So I looked elsewhere for possible workarounds and I found a weird way to get ied to work – by setting the http/https agent to keepAlive connections in lib/protocol_to_agent.js:

var agentConfig = {
  keepAlive: true,
  keepAliveMsecs: 5000
}

var protocolToAgent = {
  'http:': httpProxy || new http.Agent(agentConfig),
  'https:': httpsProxy || new https.Agent(agentConfig)
}

I have seen a single ENOTFOUND error since making this change, so apparently it doesn't cure us of the problem entirely, but after multiple clean installs I have only seen the issue return that once.

---

Would be interested to see if this has any negative or positive performance impact, because this was blocking me from installing anything, I have no baseline to compare against, other than npm itself.

Compare ied and npm installing the same package.json:

ied

> rm -Rf ./node_modules && rm -Rf ~/.ied_cache
> time ied install
ied install  8.33s user 3.32s system 95% cpu 12.204 total

npm 2.14.7

> rm -rf ./node_modules # not cleaning npm cache because slow enough as-is.
> time npm install --silent
npm install --silent  51.60s user 20.30s system 114% cpu 1:02.74 total

[alexanderGugel]

Uhh that is weird. Yeah, maybe we just need to use keepAlive.

[srgpqt]

I'm also experiencing this issue sporadically with ied version 0.3.6

[timoxley]

@alexanderGugel please reopen, this was accidentally re-closed in a rebase I think.

[zeke]

I'm having this issue with 0.3.6 too:

❯ time ied install jus
[==============================] 99.93%/usr/local/lib/node_modules/ied/lib/install_cmd.js:65
        if (err) throw err
                 ^

Error: getaddrinfo ENOTFOUND registry.npmjs.org registry.npmjs.org:443
    at errnoException (dns.js:27:10)
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (dns.js:78:26)
ied install jus  2.73s user 0.70s system 79% cpu 4.340 total

❯ ied -v
ied version 0.3.6

[just-boris]

I guess that add retry request can help here.

[Qix-]

Still getting this intermittently. It was on the first install using IED, but was on a random module after a bunch of others succeeded. A retry would be great.

[just-boris]

Since 0.4.0 we are using got for request. It makes up to 5 retries on errors.

@Qix- you can help if you run ied install with NODE_DEBUG=fetch environment property set and send console output here. Maybe we can figure out something.

[Qix-]

Unfortunately I ran into other issues with ied, namely when trying to use electron-prebuilt. Had to switch back to npm.

[just-boris]

@Qix- I guess it was because postinstall scripts do not work here now. Sorry.

@alexanderGugel do we have an issue about npm lifecycle scripts? It helps guys to keep tracking it.

[zeke]

@alexanderGugel here's the output I'm getting with NODE_DEBUG=fetch:

❯ ied -v
ied version 0.4.3

❯ node -v
v5.3.0

❯ NODE_DEBUG=fetch ied install jus
FETCH 82265: fetching 8d62c1640b52d802c4442e8aaa1df67129bd91c3 from cache
FETCH 82265: fetching 22f4ee90b6fd999b4d69cada2354f3853e2f352e from cache
FETCH 82265: fetching b69bd92292322dcc07bb359cfa0eda18df9d4aa2 from cache
FETCH 82265: fetching b0da2d88b76b9c6d62855ad3a5c61aa52724d0e9 from cache
FETCH 82265: fetching 9e10b97cde14f9f70eacf8cfb2d0236eeb90e357 from cache
FETCH 82265: fetching 816cbb7405f18d5d4856c8c22196813c8a49c6e9 from cache
FETCH 82265: fetching 58445368952dd1b1dae9872742ef8256e6e44880 from cache
FETCH 82265: http://registry.npmjs.org/less/-/less-2.5.3.tgz not cached, fetching as 58445368952dd1b1dae9872742ef8256e6e44880 into /Users/z/Desktop/node_modules/.tmp/c878bdda-2256-479f-a13a-4450432c606c
FETCH 82265: fetching bc7e5a0cfe956f6be8e3d6597040758987be7457 from cache
FETCH 82265: fetching 6eaf2012ba4ae998b6ee450d32192af96b32da4b from cache
FETCH 82265: http://registry.npmjs.org/lodash/-/lodash-4.0.1.tgz not cached, fetching as 6eaf2012ba4ae998b6ee450d32192af96b32da4b into /Users/z/Desktop/node_modules/.tmp/93e9b38d-7aaa-47ed-9745-ee20644aac9b
FETCH 82265: fetching f062ed26b3501d68d49034ed9ca6c15a52f45327 from cache
FETCH 82265: fetching a4b8542c4f616fc5538b99ca0590a393334d93d1 from cache
FETCH 82265: http://registry.npmjs.org/browserify/-/browserify-12.0.2.tgz not cached, fetching as f062ed26b3501d68d49034ed9ca6c15a52f45327 into /Users/z/Desktop/node_modules/.tmp/2bef3618-38a6-4c92-983f-64f852168ba9
FETCH 82265: fetching a4c5f31b459078a36ee6ce09c40652e04cb996f1 from cache
FETCH 82265: fetching f985a6f8603854e6a0d662e2fa84d2dde893b9b4 from cache
FETCH 82265: fetching 7e327ed6314ec19e31124ace267b3b5467a4c450 from cache

/usr/local/lib/node_modules/ied/lib/install_cmd.js:65
        if (err) throw err
                 ^
RequestError: getaddrinfo ENOTFOUND registry.npmjs.org registry.npmjs.org:443
    at ClientRequest.<anonymous> (/usr/local/lib/node_modules/ied/node_modules/got/index.js:68:21)
    at ClientRequest.g (events.js:260:16)
    at emitOne (events.js:77:13)
    at ClientRequest.emit (events.js:169:7)
    at TLSSocket.socketErrorListener (_http_client.js:265:9)
    at emitOne (events.js:77:13)
    at TLSSocket.emit (events.js:169:7)
    at connectErrorNT (net.js:998:8)
    at nextTickCallbackWith2Args (node.js:455:9)
    at process._tickCallback (node.js:369:17)

[schickling]

Hitting the same problem

[timoxley]

@alexanderGugel @zeke I wonder if it's possible that the sheer number of requests is overloading the local network hardware?

[timoxley]

Though… npm somehow gets around this.

[Qix-]

If it was overloading the local hardware it shouldn't be getting DNS misses, it'd be either a refusal or a timeout I would imagine.

[timoxley]

@Qix- yeah you're probably right, the dns entries should be in the local cache anyway. Perhaps it's an issue with OS X's dns handling? @Qix- Any other ideas what could cause this?

[Qix-]

Not a clue. Seems random at best and non-reproducible at worst. :/ My favorite kind of bug. /s

Is ied using a request abstraction library underneath? Has anyone tried switching it out for something else if so?

[alexanderGugel]

@Qix- Yes, we're using got, but will be moving away from it in the RxJS rewrite. Looked through their source, but shouldn't affect timeout.

[jippi]

I'm getting hit by the same bug - though I think its a kernel issue..

If i run a ping command at the same time, i get the following error(s) at the same time ied fails to download

64 bytes from 8.8.8.8: icmp_req=332 ttl=63 time=27525 ms
64 bytes from 8.8.8.8: icmp_req=333 ttl=63 time=26547 ms
64 bytes from 8.8.8.8: icmp_req=334 ttl=63 time=25559 ms
64 bytes from 8.8.8.8: icmp_req=335 ttl=63 time=24574 ms
64 bytes from 8.8.8.8: icmp_req=336 ttl=63 time=23583 ms
WARNING: kernel is not very fresh, upgrade is recommended.
From 10.0.2.15: icmp_seq=345 Destination Host Unreachable
From 10.0.2.15: icmp_seq=346 Destination Host Unreachable
From 10.0.2.15: icmp_seq=347 Destination Host Unreachable
From 10.0.2.15: icmp_seq=348 Destination Host Unreachable
From 10.0.2.15: icmp_seq=349 Destination Host Unreachable
From 10.0.2.15: icmp_seq=350 Destination Host Unreachable
From 10.0.2.15: icmp_seq=351 Destination Host Unreachable
From 10.0.2.15: icmp_seq=352 Destination Host Unreachable
From 10.0.2.15: icmp_seq=353 Destination Host Unreachable
From 10.0.2.15: icmp_seq=354 Destination Host Unreachable
From 10.0.2.15: icmp_seq=355 Destination Host Unreachable
From 10.0.2.15: icmp_seq=356 Destination Host Unreachable
From 10.0.2.15: icmp_seq=357 Destination Host Unreachable
From 10.0.2.15: icmp_seq=358 Destination Host Unreachable
From 10.0.2.15: icmp_seq=359 Destination Host Unreachable
From 10.0.2.15: icmp_seq=360 Destination Host Unreachable
From 10.0.2.15: icmp_seq=361 Destination Host Unreachable
From 10.0.2.15: icmp_seq=362 Destination Host Unreachable
From 10.0.2.15: icmp_seq=363 Destination Host Unreachable
From 10.0.2.15: icmp_seq=364 Destination Host Unreachable
From 10.0.2.15: icmp_seq=365 Destination Host Unreachable
From 10.0.2.15: icmp_seq=366 Destination Host Unreachable
From 10.0.2.15: icmp_seq=367 Destination Host Unreachable
From 10.0.2.15: icmp_seq=368 Destination Host Unreachable
From 10.0.2.15: icmp_seq=369 Destination Host Unreachable
From 10.0.2.15: icmp_seq=370 Destination Host Unreachable
From 10.0.2.15: icmp_seq=371 Destination Host Unreachable
From 10.0.2.15: icmp_seq=372 Destination Host Unreachable
From 10.0.2.15: icmp_seq=373 Destination Host Unreachable
From 10.0.2.15: icmp_seq=374 Destination Host Unreachable
From 10.0.2.15: icmp_seq=375 Destination Host Unreachable
From 10.0.2.15: icmp_seq=376 Destination Host Unreachable
64 bytes from 8.8.8.8: icmp_req=377 ttl=63 time=2164 ms

in syslog I see the following as well

Mar 28 14:20:19 local kernel: [ 1594.666929] e1000 0000:00:03.0 eth0: Reset adapter
Mar 28 14:20:19 local kernel: [ 1594.717147] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX
Mar 28 14:20:29 local kernel: [ 1604.671478] e1000 0000:00:03.0 eth0: Reset adapter
Mar 28 14:20:29 local kernel: [ 1604.731077] e1000: eth0 NIC Link is Up 1000 Mbps Full Duplex, Flow Control: RX

in my case its running under node v5.7.0 inside vagrant on debian 7.9

it seem like the kernel/interface is getting too busy and start dropping packages - any way to throttle the number of concurrent downloads to test if it have an effect?