search

npm / cli

the package manager for JavaScript
https://docs.npmjs.com/cli/
Other
8.39k stars 3.12k forks source link

[BUG] `npm install` started to hang on "still idealTree buildDeps" for 60 seconds if there are dependencies pointing to specific gitlab repository url (a regression compared to npm v6) #3359

Open klesun opened 3 years ago

klesun commented 3 years ago

Is there an existing issue for this?

See https://github.com/npm/cli/issues/1991#issuecomment-853984404

Current Behavior

npm install in a fresh project with an explicit git+ssh dependency on a gitlab repo (minimal example) takes 60+ seconds, seemingly it waits for some random network timeout before proceeding the installation.

Expected Behavior

npm install should take 2-3 seconds to install dependencies of the project in minimal example like it did in npm v6.

Steps To Reproduce

See https://gitlab.com/klesun/npm-seven-issue

I reproduced this hang in Ubuntu 20.04 with npm 7.15.1 as well as MacBook Pro 2019 with npm 7.15.1

git clone https://gitlab.com/klesun/npm-seven-issue.git
cd npm-seven-issue
npm install

package.json

{
  "name": "npm-seven-issue",
  "version": "0.0.1",
  "devDependencies": {
    "npm-seven-issue-dep": "git+ssh://git@gitlab.com/klesun/npm-seven-issue-dep#5f1b313978986974d4364585e6bd3689276f1697"
  }
}

If you are using npm version prior to v7.x, for example v6.14.13, npm install should be done within 2-3 seconds.

If you are using npm version v7.0.0 or later, for example 7.15.1, npm install will hang for 60+ seconds with following text:

[....................] \ idealTree.pql-box: still idealTree buildDeps

Note, you need to remove package-lock.json and node_modules prior to retrying the npm install, otherwise issue won't reproduce.

Environment

as well as

ljharb commented 3 years ago

What happens with npm 7 latest? (v7.6 is pretty old at this point)

klesun commented 3 years ago

Like with ubuntu, when I update npm on my macbook to @latest (7.15.1) I also get the 60+ seconds hang:

klesun@klesuns-MacBook-Pro npm-seven-issue % /usr/bin/time npm install
added 1 package, and audited 2 packages in 1m
found 0 vulnerabilities
       72.94 real         1.45 user         0.26 sys
klesun@klesuns-MacBook-Pro npm-seven-issue % npm -v
7.15.1

Updated npm version in description

klesun commented 3 years ago

btw, latest yarn (1.22.10) has no such issues, only 7th npm has

cronvel commented 3 years ago

npm 7.15.1 here, it's been a week now that this bug cause troubles. On my end it either hangs on "idealTree" or "reify". It seems to stall forever (or at least 5 min). Sometime retrying multiple times do it, but sometime not. I was suspecting some registry issue/lag at first, but yarn has no issue.

midudev commented 3 years ago

I think it's related to this: https://github.com/npm/cli/issues/3257

midudev commented 3 years ago

You could try to execute this using DEBUG=* npm install so more output could be provided. :)

bperel commented 3 years ago

@midudev Here's the output that I have, after that NPM seems to hang forever. The only thing that I did before running the command was adding "playwright": "^1.12" in the dev dependencies of package.json.

I have Node v12.22.1 and NPM 7.14.0

Output

``` $ DEBUG=* npm install agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +1s agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +57ms1.0.0 want: ^1.12 agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +2ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +114mswant: ^1.12 agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +228mswant: ^1.12 agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +13ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +4ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +3ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +7ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +11ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +192ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +11ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +4ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +9ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +187ms10.0 agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +9mswant: ~1.1.0 agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +142ms1.1.0 agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +81ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 2, finished: 2) free +1s agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +6ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +2ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +398ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +30ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +63ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +6ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +230ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +6ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +1ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +320ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +8ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 2) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 3, finished: 3) free +632ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +7ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +508ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +9ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +80ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +5ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +79ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +8ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +68ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +7ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +111ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +7ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 3) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 4, finished: 4) free +126ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +8ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +149ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +27ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 5) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) free +108ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +41ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 4) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +2ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 5) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 7, finished: 6) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[6#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[7#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +2ms agentkeepalive sock[8#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[9#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[10#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[11#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[12#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[13#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[14#registry.npmjs.org:443::::::::true::::::::::] create, timeout 300001ms +1ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +177ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 5) will be reuse on agent free event +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 7, finished: 7) free +2ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 7) will be reuse on agent free event +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +13ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 5) will be reuse on agent free event +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) free +1ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 7, finished: 6) will be reuse on agent free event +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +61ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 5) will be reuse on agent free event +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 8) free +68ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 7, finished: 7) free +31ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) free +89ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) free +7ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) free +7ms agentkeepalive sock[10#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +49ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) free +2ms agentkeepalive sock[13#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +80ms agentkeepalive sock[11#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +71ms agentkeepalive sock[12#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +17ms agentkeepalive sock[6#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +22ms agentkeepalive sock[9#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +57ms agentkeepalive sock[8#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +50ms agentkeepalive sock[14#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +1ms agentkeepalive sock[7#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) free +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +15ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 9, finished: 8) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] reset timeout to 300001ms +1ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 7) reuse on addRequest, timeout 300001ms +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 8) free +293ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 9, finished: 9) free +2ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +14s agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[1#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) close, isError: false +1ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +5ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[5#registry.npmjs.org:443::::::::true::::::::::](requests: 5, finished: 5) close, isError: false +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +7ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[3#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) close, isError: false +0ms agentkeepalive sock[10#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +50ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[10#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[10#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +1ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[2#registry.npmjs.org:443::::::::true::::::::::](requests: 6, finished: 6) close, isError: false +1ms agentkeepalive sock[13#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +79ms agentkeepalive timeout listeners: onTimeout, onTimeout +1ms agentkeepalive sock[13#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[13#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[11#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +70ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[11#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[11#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[12#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +17ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[12#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[12#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[6#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +22ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[6#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[6#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[9#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +58ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[9#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[9#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +1ms agentkeepalive sock[8#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +49ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[8#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +1ms agentkeepalive sock[8#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[14#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +0ms agentkeepalive timeout listeners: onTimeout, onTimeout +1ms agentkeepalive sock[14#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[7#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +0ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[7#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +1ms agentkeepalive sock[7#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[14#registry.npmjs.org:443::::::::true::::::::::](requests: 1, finished: 1) close, isError: false +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 8) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +306ms agentkeepalive timeout listeners: onTimeout, onTimeout +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[4#registry.npmjs.org:443::::::::true::::::::::](requests: 8, finished: 8) close, isError: false +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 9, finished: 9) timeout after 15000ms, listeners 2, defaultTimeoutListenerCount 2, hasHttpRequest false, HttpRequest timeoutListenerCount 0 +1ms agentkeepalive timeout listeners: onTimeout, onTimeout +1ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::] is free, destroy quietly +0ms agentkeepalive sock[0#registry.npmjs.org:443::::::::true::::::::::](requests: 9, finished: 9) close, isError: false +0ms [ ] \ reify:playwright: timing reifyNode:node_modules/pngjs Completed in 82ms ```

ljharb commented 3 years ago

@bperel can you try it with v7.19.1?

bperel commented 3 years ago

@bperel can you try it with v7.19.1?

It seems to work with 7.19.1

ljharb commented 3 years ago

@klesun @cronvel @midudev can you also try with npm v7.19.1?

klesun commented 3 years ago

@ljharb tried again on same mac with v7.19.1 the minimal repro repo, but still getting the lag, 72.92 seconds:

klesun@artur gits % git clone https://gitlab.com/klesun/npm-seven-issue.git
klesun@artur gits % cd npm-seven-issue
klesun@artur npm-seven-issue % DEBUG=* /usr/bin/time npm install
  agentkeepalive sock[0#gitlab.com:443::::::::true:::::::::::::] create, timeout 300001ms +0ms
  agentkeepalive sock[0#gitlab.com:443::::::::true:::::::::::::](requests: 1, finished: 1) free +404ms
  agentkeepalive sock[0#gitlab.com:443::::::::true:::::::::::::] reset timeout to 300001ms +3ms
  agentkeepalive sock[0#gitlab.com:443::::::::true:::::::::::::](requests: 2, finished: 1) reuse on addRequest, timeout 300001ms +0ms
  agentkeepalive sock[0#gitlab.com:443::::::::true:::::::::::::](requests: 2, finished: 1) close, isError: false +29ms
  agentkeepalive sock[1#gitlab.com:443::::::::true:::::::::::::] create, timeout 300001ms +10s
  agentkeepalive sock[1#gitlab.com:443::::::::true:::::::::::::](requests: 1, finished: 0) close, isError: false +41ms
  agentkeepalive sock[2#gitlab.com:443::::::::true:::::::::::::] create, timeout 300001ms +1m
  agentkeepalive sock[2#gitlab.com:443::::::::true:::::::::::::](requests: 1, finished: 0) close, isError: false +48ms
  agentkeepalive sock[3#registry.npmjs.org:443::::::::true:::::::::::::] create, timeout 300001ms +2s
  agentkeepalive sock[3#registry.npmjs.org:443::::::::true:::::::::::::](requests: 1, finished: 1) free +400ms }

added 1 package, and audited 2 packages in 1m

found 0 vulnerabilities
       72.92 real         1.65 user         0.31 sys
klesun@artur npm-seven-issue % npm --version
7.19.1
cronvel commented 3 years ago

@ljharb It seems to work now, but the bug was not 100% reproducible on my end.

ProfessorVarox commented 3 years ago

I got the same problem, but it still occurs in npm v7.19.1

npm install --verbose log:

npm verb cli [
npm verb cli   'C:\\Program Files\\nodejs\\node.exe',
npm verb cli   'C:\\Users\\johannes\\AppData\\Roaming\\npm\\node_modules\\npm\\bin\\npm-cli.js',
npm verb cli   'install',
npm verb cli   'twitch',
npm verb cli   'twitch-auth',
npm verb cli   '--verbose'
npm verb cli ]
npm info using npm@7.19.1
npm info using node@v16.0.0
npm timing npm:load:whichnode Completed in 1ms
npm timing config:load:defaults Completed in 1ms
npm timing config:load:file:C:\Users\johannes\AppData\Roaming\npm\node_modules\npm\npmrc Completed in 3ms
npm timing config:load:builtin Completed in 4ms
npm timing config:load:cli Completed in 3ms
npm timing config:load:env Completed in 1ms
npm timing config:load:file:D:\Projects\PanelWorker\.npmrc Completed in 0ms
npm timing config:load:project Completed in 1ms
npm timing config:load:file:C:\Users\johannes\.npmrc Completed in 1ms
npm timing config:load:user Completed in 1ms
npm timing config:load:file:C:\Users\johannes\AppData\Roaming\npm\etc\npmrc Completed in 0ms
npm timing config:load:global Completed in 1ms
npm timing config:load:validate Completed in 1ms
npm timing config:load:credentials Completed in 1ms
npm timing config:load:setEnvs Completed in 1ms
npm timing config:load Completed in 15ms
npm timing npm:load:configload Completed in 15ms
npm timing npm:load:setTitle Completed in 0ms
npm timing npm:load:setupLog Completed in 2ms
npm timing npm:load:cleanupLog Completed in 3ms
npm timing npm:load:configScope Completed in 0ms
npm timing npm:load:projectScope Completed in 2ms
npm timing npm:load Completed in 51ms
npm timing config:load:flatten Completed in 5ms
npm timing arborist:ctor Completed in 1ms
npm timing idealTree:init Completed in 88ms
npm timing idealTree:userRequests Completed in 3ms
npm verb shrinkwrap failed to load node_modules/.package-lock.json out of date, updated: node_modules
npm http fetch GET 200 https://registry.npmjs.org/twitch 136ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/twitch-auth 192ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fcache-decorators 46ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/tslib 44ms (cache hit)
npm http fetch GET 200 https://registry.npmjs.org/twitch-api-call 135ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/top-package 145ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/twitch-common 155ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fdeprecate 858ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2flogger 868ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2frate-limiter 884ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fshared-utils 999ms (cache revalidated)
npm timing idealTree:#root Completed in 1347ms
npm http fetch GET 200 https://registry.npmjs.org/detect-node 69ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/node-fetch 75ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@types%2fnode 87ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@types%2fnode-fetch 161ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fpromise.allsettled 1531ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fqs 1548ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/@d-fischer%2fcross-fetch 1756ms (cache revalidated)
npm timing idealTree:node_modules/twitch Completed in 1773ms
npm timing idealTree:node_modules/@d-fischer/cache-decorators Completed in 2ms
npm timing idealTree:node_modules/@d-fischer/deprecate Completed in 0ms
npm timing idealTree:node_modules/@d-fischer/logger Completed in 1ms
npm http fetch GET 200 https://registry.npmjs.org/es-abstract 69ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/array.prototype.map 72ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/define-properties 74ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/iterate-value 77ms (cache revalidated)
npm timing idealTree:node_modules/@d-fischer/rate-limiter Completed in 84ms
npm http fetch GET 200 https://registry.npmjs.org/function-bind 119ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-string 130ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/es-to-primitive 134ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/es-array-method-boxes-properly 140ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/get-intrinsic 136ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/call-bind 144ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/has 138ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/object.assign 152ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/string.prototype.trimend 155ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/iterate-iterator 155ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/es-get-iterator 157ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-regex 186ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/has-symbols 191ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-callable 191ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/object-inspect 199ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-negative-zero 203ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/unbox-primitive 201ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/string.prototype.trimstart 205ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/object-keys 222ms (cache revalidated)
npm timing idealTree:node_modules/@d-fischer/promise.allsettled Completed in 233ms
npm timing idealTree:node_modules/@d-fischer/shared-utils Completed in 0ms
npm timing idealTree:node_modules/@types/node Completed in 0ms
npm timing idealTree:node_modules/array.prototype.map Completed in 3ms
npm timing idealTree:node_modules/call-bind Completed in 2ms
npm timing idealTree:node_modules/define-properties Completed in 1ms
npm timing idealTree:node_modules/detect-node Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/which-boxed-primitive 57ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-date-object 65ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/has-bigints 69ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-symbol 78ms (cache revalidated)
npm timing idealTree:node_modules/es-abstract Completed in 89ms
npm timing idealTree:node_modules/es-array-method-boxes-properly Completed in 0ms
npm timing idealTree:node_modules/es-to-primitive Completed in 2ms
npm timing idealTree:node_modules/function-bind Completed in 0ms
npm timing idealTree:node_modules/get-intrinsic Completed in 0ms
npm timing idealTree:node_modules/has Completed in 0ms
npm timing idealTree:node_modules/has-symbols Completed in 0ms
npm timing idealTree:node_modules/is-callable Completed in 0ms
npm timing idealTree:node_modules/is-date-object Completed in 0ms
npm timing idealTree:node_modules/is-negative-zero Completed in 0ms
npm timing idealTree:node_modules/is-regex Completed in 0ms
npm timing idealTree:node_modules/is-string Completed in 0ms
npm timing idealTree:node_modules/is-symbol Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/is-set 63ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-arguments 76ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/isarray 75ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-map 78ms (cache revalidated)
npm timing idealTree:node_modules/iterate-value Completed in 83ms
npm timing idealTree:node_modules/es-get-iterator Completed in 7ms
npm timing idealTree:node_modules/is-arguments Completed in 0ms
npm timing idealTree:node_modules/is-map Completed in 0ms
npm timing idealTree:node_modules/is-set Completed in 0ms
npm timing idealTree:node_modules/iterate-iterator Completed in 0ms
npm timing idealTree:node_modules/object-inspect Completed in 0ms
npm timing idealTree:node_modules/object-keys Completed in 0ms
npm timing idealTree:node_modules/object.assign Completed in 0ms
npm timing idealTree:node_modules/string.prototype.trimend Completed in 0ms
npm timing idealTree:node_modules/string.prototype.trimstart Completed in 0ms
npm timing idealTree:node_modules/top-package Completed in 0ms
npm timing idealTree:node_modules/tslib Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/form-data 54ms (cache revalidated)
npm timing idealTree:node_modules/twitch-api-call Completed in 62ms
npm timing idealTree:node_modules/@d-fischer/cross-fetch Completed in 0ms
npm timing idealTree:node_modules/@d-fischer/qs Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/asynckit 48ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/combined-stream 64ms (cache revalidated)
npm timing idealTree:node_modules/@types/node-fetch Completed in 67ms
npm http fetch GET 200 https://registry.npmjs.org/delayed-stream 49ms (cache revalidated)
npm timing idealTree:node_modules/form-data Completed in 55ms
npm timing idealTree:node_modules/asynckit Completed in 0ms
npm timing idealTree:node_modules/combined-stream Completed in 2ms
npm timing idealTree:node_modules/delayed-stream Completed in 0ms
npm timing idealTree:node_modules/node-fetch Completed in 0ms
npm timing idealTree:node_modules/twitch-auth Completed in 0ms
npm timing idealTree:node_modules/twitch-common Completed in 0ms
npm http fetch GET 200 https://registry.npmjs.org/is-number-object 65ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-boolean-object 68ms (cache revalidated)
npm http fetch GET 200 https://registry.npmjs.org/is-bigint 89ms (cache revalidated)
npm timing idealTree:node_modules/unbox-primitive Completed in 93ms
npm timing idealTree:node_modules/has-bigints Completed in 0ms
npm timing idealTree:node_modules/which-boxed-primitive Completed in 2ms
npm timing idealTree:node_modules/is-bigint Completed in 0ms
npm timing idealTree:node_modules/is-boolean-object Completed in 0ms
npm timing idealTree:node_modules/is-number-object Completed in 0ms
npm timing idealTree:node_modules/@d-fischer/rate-limiter/node_modules/@types/node Completed in 0ms
npm timing idealTree:node_modules/es-get-iterator/node_modules/isarray Completed in 0ms
npm timing idealTree:buildDeps Completed in 3992ms
npm timing idealTree:fixDepFlags Completed in 3ms
npm timing idealTree Completed in 4094ms
npm timing reify:loadTrees Completed in 4095ms
npm timing reify:diffTrees Completed in 7ms
[         .........] / idealTree: timing reify:diffTrees Completed in 7ms

It freezes at this point and I am not able to close the cmd.exe window anymore

mogarick commented 3 years ago

Is there a workaround for this problem? I'm on npm 7.20.1 an the I try npm i when my package.json includes a gutbucket repo with git+ssh it hangs. this is the trace output in my case:

npm i --verbose        
npm verb cli [
npm verb cli   '/Users/mogarick/n/bin/node',
npm verb cli   '/Users/mogarick/n/bin/npm',
npm verb cli   'i',
npm verb cli   '--verbose'
npm verb cli ]
npm info using npm@7.20.1
npm info using node@v14.17.3
npm timing npm:load:whichnode Completed in 1ms
npm timing config:load:defaults Completed in 1ms
npm timing config:load:file:/Users/mogarick/n/lib/node_modules/npm/npmrc Completed in 2ms
npm timing config:load:builtin Completed in 2ms
npm timing config:load:cli Completed in 3ms
npm timing config:load:env Completed in 0ms
npm timing config:load:file:/Users/mogarick/code/juicy-rn/.npmrc Completed in 0ms
npm timing config:load:project Completed in 1ms
npm timing config:load:file:/Users/mogarick/.npmrc Completed in 1ms
npm timing config:load:user Completed in 1ms
npm timing config:load:file:/Users/mogarick/n/etc/npmrc Completed in 0ms
npm timing config:load:global Completed in 0ms
npm timing config:load:validate Completed in 0ms
npm timing config:load:credentials Completed in 1ms
npm timing config:load:setEnvs Completed in 1ms
npm timing config:load Completed in 10ms
npm timing npm:load:configload Completed in 10ms
npm timing npm:load:setTitle Completed in 18ms
npm timing npm:load:setupLog Completed in 0ms
npm timing config:load:flatten Completed in 2ms
npm timing npm:load:cleanupLog Completed in 2ms
npm timing npm:load:configScope Completed in 0ms
npm timing npm:load:projectScope Completed in 1ms
npm timing npm:load Completed in 38ms
npm timing arborist:ctor Completed in 1ms
npm timing idealTree:init Completed in 830ms
npm timing idealTree:userRequests Completed in 0ms
npm timing arborist:ctor Completed in 0ms
metaturso commented 3 years ago

Same issue for me on NPM 7.20.5 running on a dated version of NodeJS. Oddly enough, the install succeeds only if I run npm in --verbose mode.

RichGod93 commented 3 years ago

thanks a lot, this really helped me with the problem i had

illume commented 3 years ago

Getting a hang with npm@7.24.0 also.

When I run it like npm install --no-progress --verbose --loglevel silly I can see the same log lines repeating over and over. This shows to me there is a loop. Node crashes with a gc error on low-ish memory systems.

Not sure if this is the same issue, but I saw a related issue here: https://github.com/npm/cli/issues/3208

ED: One work around was to use a npmv6 generated package-lock.json file, then the install finished running.

gh-andre commented 2 years ago

I'm seeing the same on CentOS, npm v7.24.0. Hangs forever on idealTree buildDeps.

sudo npm install --verbose -g pm2
npm verb cli [ '/usr/bin/node', '/bin/npm', 'install', '--verbose', '-g', 'pm2' ]
npm info using npm@7.24.0
npm info using node@v16.10.0
...
npm timing npm:load Completed in 46ms
npm timing arborist:ctor Completed in 1ms
npm timing idealTree:init Completed in 8ms
npm timing idealTree:userRequests Completed in 3ms
⸨⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⠂⸩ ⠹ idealTree:lib: sill idealTree buildDeps
akyoto commented 2 years ago

npm v8.1.3 on Arch Linux also hangs forever on idealTree buildDeps when trying to install typescript.

gh-andre commented 2 years ago

I profiled npm while it was sitting on npm install lodash for 2 minutes and all it did was trying to write and update the gauge for about 5-8 seconds at a time. Not a single read. For somebody familiar with the code it should be trivial to identify what's going on - just attach a debugger and there it is.

npm-writing-indefinitely
gh-andre commented 2 years ago

I figured out why npm is hanging in the case described in my comment above. Maybe this will help others identify similar issues.

Basically, npm hangs silently for about 7 minutes (default configuration) if it cannot connect to registry.npmjs.org. In my case, this will happen for any VM created in AWS, in region us-west-2. Other regions, such as us-west-1 and use-east-1, work fine. You can test if that's what's going on in your environment with curl like this.

curl --connect-timeout 15 https://registry.npmjs.org

In a working environment you will get a JSON response right away and in an environment where it cannot connect to the npm registry, it will hang for 15 seconds and report a connection error.

I admire npm's resiliency in trying to install packages, but I wish it would report retries immediately, instead of waiting until it gives up entirely in 7 minutes, even with verbose output.

GlitchyMark commented 2 years ago

Having the same issue on ArchLinux. Here's my output when running npm update -g --verbose

npm verb cli [ '/usr/bin/node', '/usr/bin/npm', 'update', '-g', '--verbose' ] npm info using npm@8.3.0 npm info using node@v17.3.0 npm timing npm:load:whichnode Completed in 0ms npm timing config:load:defaults Completed in 1ms npm timing config:load:file:/usr/lib/node_modules/npm/npmrc Completed in 0ms npm timing config:load:builtin Completed in 0ms npm timing config:load:cli Completed in 1ms npm timing config:load:env Completed in 1ms npm timing config:load:project Completed in 0ms npm timing config:load:file:/home/lucky/.npmrc Completed in 1ms npm timing config:load:user Completed in 1ms npm timing config:load:file:/usr/etc/npmrc Completed in 1ms npm timing config:load:global Completed in 1ms npm timing config:load:validate Completed in 0ms npm timing config:load:credentials Completed in 0ms npm timing config:load:setEnvs Completed in 1ms npm timing config:load Completed in 7ms npm timing npm:load:configload Completed in 7ms npm timing npm:load:setTitle Completed in 0ms npm timing config:load:flatten Completed in 1ms npm timing npm:load:display Completed in 4ms npm verb logfile /home/lucky/.npm/_logs/2022-01-12T04_05_08_729Z-debug-0.log npm timing npm:load:logFile Completed in 2ms npm timing npm:load:timers Completed in 0ms npm timing npm:load:configScope Completed in 0ms npm timing npm:load Completed in 14ms npm timing arborist:ctor Completed in 1ms npm timing idealTree:init Completed in 2ms npm timing idealTree:userRequests Completed in 0ms (( )) | idealTree:lib: sill idealTree buildDeps

gh-andre commented 2 years ago

@MJ9001 Try the curl command above. If it times out, check the network for issues - firewall, network access control lists, etc - anything that can block IP or TCP traffic.

GlitchyMark commented 2 years ago

@gh-andre Sorry, I should've mentioned that I did try that command. I get a response in about a second with the JSON data. I didn't have any timeout issues either yesterday when troubleshooting or today when verifying.

gh-andre commented 2 years ago

@MJ9001 Seems to be a different issue then. The only thing I can think of if any of the packages come from a different npm registry and that one is inaccessible (e.g. scoped packages). Other than that, no idea. Sorry.

mattalxndr commented 2 years ago

I just had this problem and I found that I needed to figure out a problem with my network connection.

HamzataBarrie commented 2 years ago

I have the same problem, I need a help, it's from 3 days I'm looking for this problem

GlitchyMark commented 2 years ago

@HamzataBarrie Assuming you're on ArchLinux you may have had the same issue as me. I was having an issue with the official Arch npm package for some reason. I downloaded the linux distribute from the node website instead and dropped that in. Everything worked correctly after that. I didn't look further to find out why. I purged everything related to node several times prior with no success.

charliegunn commented 2 years ago

Im on mac running big sur 11.6 and have this issue too. it will install without using the sudo command but it fails to completely install do to the lack of permissions. when using sudo it hangs

tobalsgithub commented 2 years ago

This likely isn't everyone's issue, but I was struggling with any npm install after upgrading to npm 7 or npm 8, and found that my user .npmrc file had ca = "" in it. After removing that my installs sped back up to normal speeds.

huypxgear commented 2 years ago

I have same issue on npm 8.4.1 ubuntu 14.04.2 image

huypxgear commented 2 years ago

I have same issue on npm 8.4.1 ubuntu 14.04.2

image

husudosu commented 2 years ago

I have the same issue, so it seems there's no issue with my package, something NPM/Node releated.

Tried to install my package, and takes 5-10 minutes or forever to finish installing (My project has 8 dependencies right now). I've tried on Debian 10 and based on feedback from my users Windows has the same issue. Node version: v16.13.0 NPM version: 8.4.1

alexweej commented 2 years ago

Also experiencing this. node 16.14.0 and npm 8.3.1

komayama commented 2 years ago

I have get same experience still idealTree buildDeps when npm install command. so I changed npm refer registry URL for workaround then successfully installed module via npm install.

$ npm config set registry https://registry.npm.taobao.org
$ npm config get registry
meetmistry96 commented 2 years ago

Just execute the following code in your node js cmd:

1) git config --global http.sslVerify false

2) npm install

This worked for me.

Marcel0024 commented 2 years ago

I have this as well. Really annoying

ruyadorno commented 2 years ago

hi @klesun thank you so much for the minimal reproduction!

I run a quick debugging session using your npm-seven-issue-dep repo and it looks like the issue is coming from npm trying to reach for the tarball for that gitlab repo, failing to and eventually waiting too long before just falling back to cloning the repo and proceeding.

What is the problem, how can we fix it

@npm/cli-team it looks like we're potentially using a wrong URL when running the tarballTemplate for gitlab based urls in hosted-git-info, maybe that URL just changed since the original implementation in that module? It's definitely something we need to look more into, but for now I can tell that:

Based on that, I believe that this line in hosted-git-info:

https://github.com/npm/hosted-git-info/blob/702b7df467f2fd4bf46395134c62534bb966ca7b/git-host-info.js#L79

Should be updated to:

-  tarballtemplate: ({ domain, user, project, committish }) => `https://${domain}/${user}/${project}/repository/archive.tar.gz?ref=${maybeEncode(committish) || 'master'}`,
+  tarballtemplate: ({ domain, user, project, committish }) => `https://${domain}/${user}/${project}/-/archive/${maybeEncode(committish) || 'master'}/${project}.tar.gz`,

It requires more validation and testing but I hope this is a good starting point to whoever picks up this issue later. Relates to: https://github.com/npm/hosted-git-info/pull/109

Workaround

To any users running into problems trying to use a git-repo-based dependency coming from Gitlab, a possible way to work around it is by reducing the timeout limit npm config option, e.g:

npm install  --fetch-retry-mintimeout=500 --fetch-retry-maxtimeout=1000

In the example above we set the minimal timeout wait to 0.5s and the max timeout to 1s in order to reduce the waiting time, you can tweak that value to adjust to your expected network conditions.

wraithgar commented 2 years ago

@ruyadorno there was a PR I responded to here https://github.com/npm/hosted-git-info/pull/109 that is the beginning of the fix, but I couldn't confirm exactly WHAT url we are supposed to be using from the gitlab docs.

JoasE commented 2 years ago

For me it was because ng serve was still running in the background

3cp commented 2 years ago

For me, it's our local nexus npm repository setup. We are using self-signed certificate. NPM should fail out with certificate check error anyway. The freeze is very confusing.

We need to set strict-ssl false to local .npmrc file.

registry = https://sonatype-nexus.xxx/repository/npm-group/
strict-ssl = false
dresende commented 2 years ago

I tried debugging my case and it was this:

npm timing arborist:ctor Completed in 0ms
npm timing arborist:ctor Completed in 0ms
npm timing idealTree:init Completed in 9ms
npm timing idealTree:userRequests Completed in 1ms
  agentkeepalive sock[0#registry.npmjs.org:443::::::::true:::::::::::::] create, timeout 300001ms +0ms
  agentkeepalive sock[0#registry.npmjs.org:443::::::::true:::::::::::::](requests: 1, finished: 0) error: Error: unable to get local issuer certificate
    at TLSSocket.onConnectSecure (node:_tls_wrap:1530:34)
    at TLSSocket.emit (node:events:526:28)
    at TLSSocket._finishInit (node:_tls_wrap:944:8)
    at TLSWrap.ssl.onhandshakedone (node:_tls_wrap:725:12) {
  code: 'UNABLE_TO_GET_ISSUER_CERT_LOCALLY'
}, listenerCount: 2 +45ms
  agentkeepalive sock[0#registry.npmjs.org:443::::::::true:::::::::::::](requests: 1, finished: 0) close, isError: true +1ms
  agentkeepalive sock[1#registry.npmjs.org:443::::::::true:::::::::::::] create, timeout 300001ms +10s
  agentkeepalive sock[1#registry.npmjs.org:443::::::::true:::::::::::::](requests: 1, finished: 0) error: Error: unable to get local issuer certificate
    at TLSSocket.onConnectSecure (node:_tls_wrap:1530:34)
    at TLSSocket.emit (node:events:526:28)
    at TLSSocket._finishInit (node:_tls_wrap:944:8)
    at TLSWrap.ssl.onhandshakedone (node:_tls_wrap:725:12) {
  code: 'UNABLE_TO_GET_ISSUER_CERT_LOCALLY'
}, listenerCount: 2 +232ms
  agentkeepalive sock[1#registry.npmjs.org:443::::::::true:::::::::::::](requests: 1, finished: 0) close, isError: true +1ms

I opened my .npmrc and removed a line like this:

ca[]=

Instant fix.

dresende commented 2 years ago

I would recommend backing up your .npmrc (if you have anything specific, or just delete it) and try again with an empty one.

3cp commented 2 years ago

From what I saw there, the various causes are not the root cause of the hang. The root cause is that npm should not hang, it should fail out with a readable error message.

l0g1c-80m8 commented 2 years ago

I have get same experience still idealTree buildDeps when npm install command. so I changed npm refer registry URL for workaround then successfully installed module via npm install.

$ npm config set registry https://registry.npm.taobao.org
$ npm config get registry

Need help understanding this. I set my npm registry to this registry which otherwise works. npm config set registry http://registry.npmjs.org/ --global In this case however, I had to set it to the one that you suggested. Can you mention what is the fundamental difference between the two registries.

I was trying to install madge when I got this issue: npm -g install madge It is available on both registries.

forresthopkinsa commented 2 years ago

After waiting a while in verbose mode, I got this stack trace:

npm timing npm:load:logFile Completed in 4ms
npm timing npm:load:timers Completed in 0ms
npm timing npm:load:configScope Completed in 0ms
npm timing npm:load Completed in 25ms
npm timing arborist:ctor Completed in 1ms
npm timing idealTree:init Completed in 87ms
npm timing idealTree:userRequests Completed in 0ms
npm timing idealTree:#root Completed in 0ms
npm timing idealTree:buildDeps Completed in 1ms
npm timing idealTree:fixDepFlags Completed in 0ms
npm timing idealTree Completed in 92ms
npm timing arborist:ctor Completed in 0ms
npm timing reify:loadTrees Completed in 130ms
npm timing reify:diffTrees Completed in 3ms
npm timing reify:retireShallow Completed in 1ms
npm timing reify:createSparse Completed in 0ms
npm timing reify:loadBundles Completed in 0ms
npm timing reify:unpack Completed in 2ms
npm timing reify:unretire Completed in 0ms
npm timing build:queue Completed in 0ms
npm timing build:deps Completed in 1ms
npm timing build Completed in 1ms
npm timing reify:build Completed in 1ms
npm timing reify:trash Completed in 0ms
npm timing reify:save Completed in 23ms
npm verb audit error FetchError: request to https://registry.npmjs.org/-/npm/v1/security/audits/quick failed, reason: connect ETIMEDOUT 2606:4700::6810:1b23:443
npm verb audit error     at ClientRequest.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/minipass-fetch/lib/index.js:130:14)
npm verb audit error     at ClientRequest.emit (node:events:527:28)
npm verb audit error     at TLSSocket.socketErrorListener (node:_http_client:454:9)
npm verb audit error     at TLSSocket.emit (node:events:539:35)
npm verb audit error     at emitErrorNT (node:internal/streams/destroy:151:8)
npm verb audit error     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
npm verb audit error     at process.processTicksAndRejections (node:internal/process/task_queues:82:21)
npm verb audit error  FetchError: request to https://registry.npmjs.org/-/npm/v1/security/audits/quick failed, reason: connect ETIMEDOUT 2606:4700::6810:1b23:443
npm verb audit error     at ClientRequest.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/minipass-fetch/lib/index.js:130:14)
npm verb audit error     at ClientRequest.emit (node:events:527:28)
npm verb audit error     at TLSSocket.socketErrorListener (node:_http_client:454:9)
npm verb audit error     at TLSSocket.emit (node:events:539:35)
npm verb audit error     at emitErrorNT (node:internal/streams/destroy:151:8)
npm verb audit error     at emitErrorCloseNT (node:internal/streams/destroy:116:3)
npm verb audit error     at process.processTicksAndRejections (node:internal/process/task_queues:82:21) {
npm verb audit error   code: 'ETIMEDOUT',
npm verb audit error   errno: 'ETIMEDOUT',
npm verb audit error   syscall: 'connect',
npm verb audit error   address: '2606:4700::6810:1b23',
npm verb audit error   port: 443,
npm verb audit error   type: 'system'
npm verb audit error }
npm timing auditReport:getReport Completed in 150921ms
npm timing reify:audit Completed in 150921ms
npm timing reify Completed in 151065ms

After that the solution was pretty obvious, I just disabled IPv6 on my machine and then NPM worked fine.

rhysperry111 commented 2 years ago

Yeah, it seems that IPv6 is the problem here. I removed the routes for my 6in4 tunnel and it magically started working again.

I think some investigating needs to be done as searching for ipv6 in the issue tracker comes up with a bunch of closed issues, all with extremely similar symptoms, yet all being closed as they are thought to have been fixed.

itoffshore commented 2 years ago

disabling ipv6 on my main NIC fixed npm install for Ubuntu 22.04 under WSL1

Bschitter commented 2 years ago

disabling ipv6 on my main NIC fixed npm install for Ubuntu 22.04 under WSL1

Thank you so much!

disabling ipv6 for my wireless connection solved my issue on Manjaro 21.3.7 with npm 8.17.0 and nodejs 18.7.0

ebaizel commented 2 years ago

Works on MacOS if I set IPV6 to Link-local (from Automatically). Thanks for the help.