Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[BUG] <Freezes during npm install> #7814

Closed
2 tasks done
SahDhiraj opened this issue Oct 4, 2024 · 39 comments
Closed
2 tasks done

[BUG] <Freezes during npm install> #7814

SahDhiraj opened this issue Oct 4, 2024 · 39 comments
Labels
Bug thing that needs fixing Needs Triage needs review for next steps

Comments

@SahDhiraj
Copy link

Is there an existing issue for this?

  • I have searched the existing issues

This issue exists in the latest npm version

  • I am using the latest npm

Current Behavior

While running the command npm install with the latest version (V10.9.0), the installation pauses and does not proceed further.

To resolve this, I have attempted the following steps:

  1. Cleared the npm cache using npm cache clean --force.
  2. Restarted both my PC and Visual Studio Code.
  3. Deleted the package-lock.json file and the node_modules directory.
    But none of these worked.

Expected Behavior

Sould have installed the dependencies and created package-lock.json and node_modules.

Steps To Reproduce

Environment: Using Visual Studio Code with Node.js version 20.13.1.
React and TypeScript: The project uses React version 18.2.0 and TypeScript version 5.3.3.
Command: When I run npm install, the process appears to be loading continuously without any further progress.

Environment

  • npm: 10.9.0
  • Node.js: 20.13.1
  • OS Name: Ubuntu 20.04.6 LTS
  • npm config:
    `
@SahDhiraj SahDhiraj added Bug thing that needs fixing Needs Triage needs review for next steps labels Oct 4, 2024
@milaninfy
Copy link
Contributor

This type of behaviour is not easy to track without reproduction steps or other details. It would be helpful for triaging this issue if you can provide details like package.json, package-lock, npm config, logs and command used.

Is it happening for all your project or a specific one ?

@mi-lchlebowski
Copy link

mi-lchlebowski commented Oct 7, 2024

Same issue in my project. With npm 10.8.3 and below everything ok. My dockerfile:

FROM node:18.19-alpine as node

WORKDIR /home/node/frontend

RUN npm install -g npm@latest
RUN npm i -g @angular/cli@17.3.8

RUN npm i -g @angular/cli@17.3.8 takes 90 minutes. Last few runs from 3 days:
90' 18".
90' 17",
90' 23",
90' 26".

FROM node:18.19-alpine as node

WORKDIR /home/node/frontend

RUN npm install -g npm@10.8.3
RUN npm i -g @angular/cli@17.3.8

RUN npm i -g @angular/cli@17.3.8 takes few seconds

Checked on 5 machines.

@milaninfy
Copy link
Contributor

for some reason mine is not showing any delays...
are you using npm registry or custom hosted registry settings ?

~/workarea/rep $ cat dockerfile
FROM node:18.19-alpine as node

WORKDIR /home/node/frontend

RUN npm install -g npm@10.9.0
RUN npm i -g @angular/cli@17.3.8 --verbose
/workarea/rep $ docker build .
[+] Building 27.6s (8/8) FINISHED                                                                                                                                   docker:desktop-linux
 => [internal] load build definition from Dockerfile                                                                                                                                0.0s
 => => transferring dockerfile: 173B                                                                                                                                                0.0s
 => [internal] load metadata for docker.io/library/node:18.19-alpine                                                                                                                0.5s
 => [internal] load .dockerignore                                                                                                                                                   0.0s
 => => transferring context: 2B                                                                                                                                                     0.0s
 => [1/4] FROM docker.io/library/node:18.19-alpine@sha256:c7620fdecfefb96813da62519897808775230386f4c8482e972e37b8b18cb460                                                          0.0s
 => CACHED [2/4] WORKDIR /home/node/frontend                                                                                                                                        0.0s
 => [3/4] RUN npm install -g npm@10.9.0                                                                                                                                             3.2s
 => [4/4] RUN npm i -g @angular/cli@17.3.8 --verbose                                                                                                                               23.5s
 => exporting to image                                                                                                                                                              0.4s
 => => exporting layers                                                                                                                                                             0.4s
 => => writing image sha256:4b808728df586e52ff67c1be40887acd0af1795376777f9f2123631b7df2f1d8     

@mi-lchlebowski
Copy link

npm registry.

5 machines was in different locations in Poland with different ISP.

@milaninfy
Copy link
Contributor

ok then that sounds like it mostly not be registry related.
if possible, will you be able to share install log files from this command run where it takes time RUN npm i -g @angular/cli@17.3.8 -ddd in your docker step ?

@mi-lchlebowski
Copy link

It seems problem is related to high dns pool rate. I have pi-hole as dns in my network. In pi-hole log I have information about rate limiting for my IP: "Client 192.168.8.113 has been rate-limited (current config allows up to 1000 queries in 60 seconds)". It happens only in one moment during install - before line reify moves {} appears in log.
I chagned my dns to google and cloudflare ommiting pi-hole. Result in the attachment. Today times are much shorter but still too long. Below logs.
docker_build_cloudflare_dns.log
docker_build_google_dns.log
docker_build_pihole_cloudflare.log

logs with npm@10.8.3
docker_build_npm_10_8_3.log

There is no reify moves {}

@pfeileon
Copy link

pfeileon commented Oct 9, 2024

@mi-lchlebowski Do you think this is related to #4028?

@riceyrice
Copy link

I've seen something like this with npm 10.9.0 when run by docker build. Doesn't occur on the host machine. Doesn't occur with npm 10.8.3. Workaround was to pin npm to 10.8.

@dirkhekhuisascendtek
Copy link

I'm having the same issue with 10.9.0 when building docker images.

@mi-lchlebowski
Copy link

mi-lchlebowski commented Oct 10, 2024

@mi-lchlebowski Do you think this is related to #4028?

No. Issue is always in same place.

@riceyrice @dirkhekhuisascendtek please add -ddd to npm i and paste log. Maybe this will be reify move too?

IMO it may be related to dns queries. On docker there is no dns cache instead host machine.

@OrfeasZ
Copy link

OrfeasZ commented Oct 11, 2024

We've been experiencing the same issue. NPM installs from a node:20-bookworm container (with both IPv4 and IPv6 connectivity, both working correctly) sometimes take several hours to complete. I've attached a log below (with silly debug logging) of an install that took upwards of 5 hours.

You can see that npm logs npm silly idealTree buildDeps at 5 seconds, and the next log line is at 20990 seconds (after 5.8 hours).

Another thing to note is this line, where it seems it took npmjs.org almost 30 minutes to reply to the advisories call.

npm http fetch POST 200 https://registry.npmjs.org/-/npm/v1/security/advisories/bulk 1778840ms

npm-slow.log

@codeart1st
Copy link

Same here. Only get the problems with our corporate VPN. Moving back to NPM 10.8.0 helps. Goging back to 10.9.0 breaks again. Also 10.9.0 works in our office network (without VPN).
Also disabled auditing with audit=false, but the problems described above are still there.

@Clement-Z4RM
Copy link

I had the same issue when I upgraded NPM to v10.9: it freezes (the animations stops) after a while when running commands installing packages.
I downgraded to v10.8.3 and no longer have this problem.

@riceyrice
Copy link

riceyrice commented Oct 11, 2024

@riceyrice please add -ddd to npm i and paste log. Maybe this will be reify move too?

Could be - it froze for around 25 minutes, with a reify moves output just after, or maybe that fetch GET has a very silly timeout!?

#15 [base base 10/14] RUN npm ci -ddd
#15 0.441 npm verbose cli /usr/bin/node /usr/bin/npm
#15 0.441 npm info using npm@10.9.0
#15 0.441 npm info using node@v20.18.0
#15 0.441 npm silly config load:file:/usr/lib/node_modules/npm/npmrc
#15 0.441 npm silly config load:file:/app/.npmrc
#15 0.441 npm silly config load:file:/root/.npmrc
#15 0.441 npm silly config load:file:/usr/etc/npmrc
#15 0.445 npm verbose title npm ci
#15 0.445 npm verbose argv "ci" "--loglevel" "silly"
#15 0.445 npm verbose logfile logs-max:10 dir:/root/.npm/_logs/2024-10-11T08_19_02_954Z-
#15 0.447 npm verbose logfile /root/.npm/_logs/2024-10-11T08_19_02_954Z-debug-0.log
#15 0.643 npm silly logfile done cleaning log files
#15 0.681 npm silly packumentCache heap:4345298944 maxSize:1086324736 maxEntrySize:543162368
#15 0.888 npm silly idealTree buildDeps
#15 1566.7 npm http fetch GET https://registry.npmjs.org/npm attempt 1 failed with ECONNRESET
#15 1566.7 npm silly reify moves {}

npm-ci-ddd.txt

@riceyrice
Copy link

Aha, I was writing up network details in case this is some DNS thing: Docker 4.34.2 (167172) on Windows 11 with WSL2 backend, Tailscale VPN (disconnected). Connected the VPN and the delay is 5s instead:

#15 0.586 npm silly packumentCache heap:4345298944 maxSize:1086324736 maxEntrySize:543162368
#15 0.796 npm silly idealTree buildDeps
#15 5.310 npm silly reify moves {}

@milaninfy
Copy link
Contributor

Since it's not reproducible/traced even based on logs, Please provide as much information as you can, this would help greatly. just like attached Logs ( Thanks for that ), Operating system information, versions of tech stack used, configs, package file etc.

@Tofandel
Copy link

Tofandel commented Oct 14, 2024

I have the same issue and I already explained it in #4028 (comment)

Since I can reproduce it 100% of the time after npm 10.4.0, I could help providing a repro because I'm at loss on debugging this further (but because it happens only when there is a lot of dependencies it cannot really be a minimal repro, I can just copy paste my package.json from a project that has it)

@jeffrson
Copy link

jeffrson commented Oct 17, 2024

Happened to me in WSL after upgrade to NodeJS 22.10.0, which comes with npm 10.9.0, while nvm installs packages listed in ~/.nvm/default-packages.
Example for package that causes npm to hang is pm2: npm i -g pm2

Downgrade to 10.8.3 helps.

@Clement-Z4RM
Copy link

Example for package that causes npm to hang is pm2: npm i -g pm2

It's really random. I've just done npm i -g pm2 (with npm 10.9.0 / Node 22.10.0), and it worked.
I think that would be more likely to happen when installing a lot of packages (like npm i in a "big" project).

@jeffrson
Copy link

jeffrson commented Oct 17, 2024

Strangely I had a moment today where it suddenly worked. Then I cleared the cache (npm cache clean --force) and the problem reappeared. Here are the last lines of '-ddd' output:

npm silly packumentCache full:https://registry.npmjs.org/git-sha1 set size:undefined disposed:false
npm http fetch GET 200 https://registry.npmjs.org/bodec 50ms (cache miss)
npm silly packumentCache full:https://registry.npmjs.org/bodec set size:undefined disposed:false
npm silly placeDep node_modules/pm2 bodec@0.1.0 OK for: js-git@0.7.8 want: ^0.1.0
npm silly placeDep node_modules/pm2 culvert@0.1.2 OK for: js-git@0.7.8 want: ^0.1.2
npm silly placeDep node_modules/pm2 git-sha1@0.1.2 OK for: js-git@0.7.8 want: ^0.1.2
npm silly placeDep node_modules/pm2 pako@0.2.9 OK for: js-git@0.7.8 want: ^0.2.5
npm silly placeDep node_modules/pm2/node_modules/@pm2/agent lru-cache@6.0.0 OK for: semver@7.5.4 want: ^6.0.0
npm silly fetch manifest yallist@^4.0.0
npm silly packumentCache full:https://registry.npmjs.org/yallist cache-miss
npm http fetch GET 200 https://registry.npmjs.org/yallist 47ms (cache miss)
npm silly packumentCache full:https://registry.npmjs.org/yallist set size:undefined disposed:false
npm silly placeDep node_modules/pm2 yallist@4.0.0 OK for: lru-cache@6.0.0 want: ^4.0.0
npm silly placeDep node_modules/pm2 lodash@4.17.21 OK for: async@2.6.4 want: ^4.17.14
npm silly placeDep node_modules/pm2/node_modules/@pm2/io lru-cache@6.0.0 OK for: semver@7.5.4 want: ^6.0.0

Then it wait's for more than an hour. Now when I press Ctrl-C and try another time it works. Here's how the log continues, with some overlapping lines:

npm silly fetch manifest yallist@^4.0.0
npm silly packumentCache full:https://registry.npmjs.org/yallist cache-miss
npm http fetch GET 200 https://registry.npmjs.org/yallist 2ms (cache hit)
npm silly packumentCache full:https://registry.npmjs.org/yallist set size:34610 disposed:false
npm silly placeDep node_modules/pm2 yallist@4.0.0 OK for: lru-cache@6.0.0 want: ^4.0.0
npm silly placeDep node_modules/pm2 lodash@4.17.21 OK for: async@2.6.4 want: ^4.17.14
npm silly placeDep node_modules/pm2/node_modules/@pm2/io lru-cache@6.0.0 OK for: semver@7.5.4 want: ^6.0.0
npm silly reify mark retired [
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/lib/node_modules/pm2',
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/bin/pm2',
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/bin/pm2-dev',
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/bin/pm2-docker',
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/bin/pm2-runtime'
npm silly reify ]
npm silly reify moves {
npm silly reify   '/home/user/.nvm/versions/node/v22.10.0/lib/node_modules/pm2': '/home/user/.nvm/versions/node/v22.10.0/lib/node_modules/.pm2-170ltMvY',

It might be interesting, that in the second part there's a size of yallist, which is undefined in the first part:
npm silly packumentCache full:https://registry.npmjs.org/yallist set size:34610 disposed:false

@Edwardveb
Copy link

Hey, I have also noticed this bug in one of my solutions, but it seems to struggle only with older packages, as projects with up to date stuff don't seem to be affected. In my windows workstation environment in cmd everything installs and builds fine, but in docker build on the same computer, the older solutions hangs, it takes 45 minutes for npm i step, but it goes thru and doesn't crash, so I assume there is some spaghetti involved.

To people struggling with this bug in docker, an easy temporary fix is to change in the dockerfile
FROM node:latest AS node
to
FROM node:18 AS node
And then it seems to install and build as before.

@aleho
Copy link

aleho commented Oct 23, 2024

I can confirm a flood of DNS requests (15.000 and more) within a few seconds originating from my system when I run npm update --save.

The requests are all PTR requests, e.g. 100.0.168.192.in-addr.arpa, where my local IP is 192.168.0.100.

Depending on the local setup these requests might be sent to a provider DNS or at least the local router and could severely affect network performance. In any case they could explain rate-limiting, freezes and other obscure issues.

npm 10.9.0
node 20.17.0

@dahaupt
Copy link

dahaupt commented Oct 25, 2024

@aleho I can confirm the same behavior with a flood of PTR DNS requests to 35.1.16.104.in-addr.arpa.

Edit: The problem with these DNS queries no longer occurs after a downgrade to NPM v10.8.3. Then, only a few of those PTR DNS requests will be sent.

@Tofandel
Copy link

Tofandel commented Oct 28, 2024

Could this have been caused by this change 6ca609e or is ping not used during npm install?

I tried npm v10.8.3 but I still get a freeze, so the freeze for me is not caused by the DNS queries, if I downgrade version by version it starts working at 10.3.0, I'd like to add that while it's hanging, cpu is at 0% but the timer of the command stops increasing in htop

image
image

@milaninfy
Copy link
Contributor

@Tofandel as far as I know ping is not used during install.

@Tofandel
Copy link

Any idea on what I can use to debug this further? I tried the V8 profiler in a setTimeout but apparently it's not just waiting, it's actually completely frozen and the setTimeout doesn't fire once the hang occurs

What could cause such a hang where it's the actual node process that froze?

@milaninfy
Copy link
Contributor

milaninfy commented Oct 28, 2024

@Tofandel If you are consistently reproduce the issue at your end and if you want to debug it further at code level, you can setup npm-cli codebase locally and give it a try with switching to various commits from change-log.

@Tofandel
Copy link

Tofandel commented Oct 28, 2024

Yes and I found the issue and opened a PR with a fix
#4028 (comment)
https://github.com/npm/npm-install-checks/pull/120/files

@pocesar
Copy link

pocesar commented Nov 3, 2024

seeing a 25 minute freeze, doesn't respond to SIGTERM as well, only SIGKILL. reify moves {} step isn't the one that is freezing for me

node: v22.11.0
npm: v10.8.3

2206 timing idealTree:buildDeps Completed in 43683ms
2207 timing idealTree:fixDepFlags Completed in 3ms
2208 timing idealTree Completed in 43729ms
2209 timing reify:loadTrees Completed in 43730ms
2210 timing reify:diffTrees Completed in 3ms
2211 silly reify moves {}
2212 timing reify:retireShallow Completed in 1ms
2213 timing reify:createSparse Completed in 325ms
2214 timing reify:loadBundles Completed in 0ms
[...]
2357 timing reifyNode:node_modules/fsevents Completed in 1504245ms
2358 timing reifyNode:node_modules/@parcel/watcher-win32-x64 Completed in 1504245ms
2359 timing reifyNode:node_modules/@parcel/watcher-win32-ia32 Completed in 1504246ms
2360 timing reifyNode:node_modules/@parcel/watcher-win32-arm64 Completed in 1504246ms
2361 timing reifyNode:node_modules/@parcel/watcher-linux-x64-musl Completed in 1504246ms
2362 timing reifyNode:node_modules/@parcel/watcher-linux-arm64-musl Completed in 1504246ms
2363 timing reifyNode:node_modules/@parcel/watcher-linux-arm64-glibc Completed in 1504246ms
2364 timing reifyNode:node_modules/@parcel/watcher-linux-arm-glibc Completed in 1504246ms
2365 timing reifyNode:node_modules/@parcel/watcher-freebsd-x64 Completed in 1504247ms
2366 timing reifyNode:node_modules/@parcel/watcher-darwin-x64 Completed in 1504247ms
2367 timing reifyNode:node_modules/@parcel/watcher-darwin-arm64 Completed in 1504247ms
2368 timing reifyNode:node_modules/@parcel/watcher-android-arm64 Completed in 1504247ms
2369 silly audit bulk request failed undefined
2370 verbose audit error FetchError: request to https://registry.npmjs.org/-/npm/v1/security/audits/quick failed, reason: write EPIPE
2370 verbose audit error     at ClientRequest.<anonymous> (/usr/lib/node_modules/npm/node_modules/minipass-fetch/lib/index.js:130:14)
2370 verbose audit error     at ClientRequest.emit (node:events:518:28)
2370 verbose audit error     at emitErrorEvent (node:_http_client:103:11)
2370 verbose audit error     at Socket.socketErrorListener (node:_http_client:506:5)
2370 verbose audit error     at Socket.emit (node:events:518:28)
2370 verbose audit error     at emitErrorNT (node:internal/streams/destroy:170:8)
2370 verbose audit error     at emitErrorCloseNT (node:internal/streams/destroy:129:3)
2370 verbose audit error     at process.processTicksAndRejections (node:internal/process/task_queues:90:21) {
2370 verbose audit error   code: 'EPIPE',
2370 verbose audit error   errno: 'EPIPE',
2370 verbose audit error   syscall: 'write',
2370 verbose audit error   type: 'system'
2370 verbose audit error }
2371 silly audit error undefined
2372 timing auditReport:getReport Completed in 1504316ms
2373 silly audit report null
2374 timing reify:audit Completed in 1504317ms

@Tofandel
Copy link

Tofandel commented Nov 3, 2024

As I've already explained this issue has been located already and a PR is open in both node to fix the root of the issue and npm to implement a workaround

There is no need to paste more logs that don't add any significant information to the issue but noise, thank you

The issue will be fixed when either one of nodejs/node#55602 or npm/npm-install-checks#120 lands

In the meantime you can use --force --libc=glibc or downgrade to npm 10.3.0 to avoid this issue

@lyes-mersel
Copy link

I encountered the same issue after upgrading from npm 10.8.2 to 10.9.0. When trying to execute npx create-next-app@latest, it froze (the animation stopped).
To resolve this, I downgraded back to 10.8.2, and the command worked without issues.

  • System: Ubuntu 24.04 LTS
  • Node versions tested: v20.18.0 and v22.11.0

@Clement-Z4RM
Copy link

Yes it's the same issue for all of us.
As you can see above, a PR were opened to fix it.

@SleepyDeb
Copy link

SleepyDeb commented Nov 18, 2024

I have this issue on npm@10.8.2 node@20.18.0 executing npm install mongosh on Amazon Linux 2023... I'm going to reproduce the issue over another AWS account with the same AMI and I'll let you know.

image

@SleepyDeb
Copy link

SleepyDeb commented Nov 18, 2024

As I've already explained this issue has been located already and a PR is open in both node to fix the root of the issue and npm to implement a workaround

There is no need to paste more logs that don't add any significant information to the issue but noise, thank you

The issue will be fixed when either one of nodejs/node#55602 or npm/npm-install-checks#120 lands

In the meantime you can use --force --libc=glibc or downgrade to npm 10.3.0 to avoid this issue

@Tofandel I am really sorry to bother, anyway --force --libc=glibc doesn't seems to work, do you have any suggestion? did I miss something.... thx in advance!

ec2-user@ip-10-187-115-224 ~]$ npm install mongosh --force --libc=glibc
npm verbose cli /usr/bin/node-20 /usr/bin/npm
npm info using npm@10.8.2
npm info using node@v20.18.0
npm silly config load:file:/usr/lib/node_modules_20/npm/npmrc
npm silly config load:file:/home/ec2-user/.npmrc
npm silly config load:file:/etc/npmrc
npm verbose title npm install mongosh
npm verbose argv "install" "mongosh" "--force" "--libc" "glibc"
npm verbose logfile logs-max:10 dir:/home/ec2-user/.npm/_logs/2024-11-18T17_44_08_832Z-
npm verbose logfile /home/ec2-user/.npm/_logs/2024-11-18T17_44_08_832Z-debug-0.log
npm warn using --force Recommended protections disabled.
npm silly packumentCache heap:2063597568 maxSize:515899392 maxEntrySize:257949696
npm silly logfile done cleaning log files
npm silly idealTree buildDeps
npm silly fetch manifest mongosh@*
npm silly packumentCache full:https://registry.npmjs.org/mongosh cache-miss
npm http fetch GET 200 https://registry.npmjs.org/mongosh 681ms (cache revalidated)
npm silly packumentCache full:https://registry.npmjs.org/mongosh set size:291161 disposed:false
npm silly placeDep ROOT mongosh@2.3.3 OK for:  want: *
npm silly fetch manifest @mongosh/cli-repl@2.3.3
npm silly packumentCache full:https://registry.npmjs.org/@mongosh%2fcli-repl cache-miss
npm http fetch GET 200 https://registry.npmjs.org/@mongosh%2fcli-repl 1137ms (cache revalidated)
npm silly packumentCache full:https://registry.npmjs.org/@mongosh%2fcli-repl set size:701058 disposed:false
npm silly placeDep ROOT @mongosh/cli-repl@2.3.3 OK for: mongosh@2.3.3 want: 2.3.3
npm silly fetch manifest @mongodb-js/devtools-proxy-support@^0.4.1
npm silly packumentCache full:https://registry.npmjs.org/@mongodb-js%2fdevtools-proxy-support cache-miss
npm http fetch GET 200 https://registry.npmjs.org/@mongodb-js%2fdevtools-proxy-support 1100ms (cache revalidated)
[...]
npm silly placeDep node_modules/@babel/helper-compilation-targets yallist@3.1.1 OK for: lru-cache@5.1.1 want: ^3.0.2
npm silly placeDep node_modules/@isaacs/cliui ansi-regex@6.1.0 OK for: strip-ansi@7.1.0 want: ^6.0.1
npm silly placeDep node_modules/@mongosh/service-provider-node-driver node-addon-api@6.1.0 OK for: kerberos@2.1.0 want: ^6.1.0
npm silly placeDep node_modules/@mongosh/service-provider-node-driver prebuild-install@7.1.1 OK for: kerberos@2.1.0 want: 7.1.1
npm silly placeDep node_modules/@segment/analytics-node whatwg-url@5.0.0 OK for: node-fetch@2.7.0 want: ^5.0.0
npm silly fetch manifest tr46@~0.0.3
npm silly packumentCache full:https://registry.npmjs.org/tr46 cache-hit
npm silly fetch manifest webidl-conversions@^3.0.0
npm silly packumentCache full:https://registry.npmjs.org/webidl-conversions cache-hit
npm silly placeDep node_modules/@segment/analytics-node tr46@0.0.3 OK for: whatwg-url@5.0.0 want: ~0.0.3
npm silly placeDep node_modules/@segment/analytics-node webidl-conversions@3.0.1 OK for: whatwg-url@5.0.0 want: ^3.0.0
npm silly placeDep node_modules/body-parser ms@2.0.0 OK for: debug@2.6.9 want: 2.0.0
npm silly placeDep node_modules/express ms@2.0.0 OK for: debug@2.6.9 want: 2.0.0
npm silly placeDep node_modules/finalhandler ms@2.0.0 OK for: debug@2.6.9 want: 2.0.0
npm silly placeDep node_modules/run-applescript human-signals@2.1.0 OK for: execa@5.1.1 want: ^2.1.0
npm silly placeDep node_modules/run-applescript is-stream@2.0.1 OK for: execa@5.1.1 want: ^2.0.0
npm silly placeDep node_modules/run-applescript npm-run-path@4.0.1 OK for: execa@5.1.1 want: ^4.0.1
npm silly placeDep node_modules/run-applescript onetime@5.1.2 OK for: execa@5.1.1 want: ^5.1.2
npm silly placeDep node_modules/run-applescript signal-exit@3.0.7 OK for: execa@5.1.1 want: ^3.0.3
npm silly placeDep node_modules/run-applescript strip-final-newline@2.0.0 OK for: execa@5.1.1 want: ^2.0.0
npm silly fetch manifest mimic-fn@^2.1.0
npm silly packumentCache full:https://registry.npmjs.org/mimic-fn cache-hit
npm silly placeDep node_modules/run-applescript mimic-fn@2.1.0 OK for: onetime@5.1.2 want: ^2.1.0
npm silly placeDep node_modules/send/node_modules/debug ms@2.0.0 OK for: debug@2.6.9 want: 2.0.0
npm silly placeDep node_modules/string-width ansi-regex@6.1.0 OK for: strip-ansi@7.1.0 want: ^6.0.1
npm silly placeDep node_modules/wrap-ansi-cjs emoji-regex@8.0.0 OK for: string-width@4.2.3 want: ^8.0.0
npm silly placeDep node_modules/wrap-ansi ansi-regex@6.1.0 OK for: strip-ansi@7.1.0 want: ^6.0.1
npm silly reify moves {}

@Tofandel
Copy link

Tofandel commented Nov 19, 2024

Could you add timers to your output to pinpoint when it is getting stuck and use npm 10.9.0, then just post the last 5 lines of the log

@SleepyDeb
Copy link

SleepyDeb commented Nov 19, 2024

Here you are:

npm install mongosh --force --libc=glibc --timing --loglevel silly --no-progress

Anyway... I tested on another network environment, different EC2 instance kind, same AMI tough and the issue doesn't appear.
I also notice that the process doesn't die using sudo kill -9 <pid>

@Tofandel just in case, lmk if there is something I can try for you

[ec2-user@ip-10-187-115-224 test]$ npm install mongosh --force --libc=glibc --timing --loglevel silly  --no-progress
npm verbose cli /usr/bin/node-20 /usr/local/bin/npm
npm info using npm@10.9.0
npm info using node@v20.18.0
npm timing npm:load:whichnode Completed in 2ms
npm silly config load:file:/usr/local/lib/node_modules/npm/npmrc
npm silly config load:file:/home/ec2-user/test/.npmrc
npm silly config load:file:/home/ec2-user/.npmrc
npm silly config load:file:/etc/npmrc
npm timing npm:load:configload Completed in 27ms
npm timing config:load:flatten Completed in 6ms
npm timing npm:load:mkdirpcache Completed in 1ms
npm timing npm:load:mkdirplogs Completed in 0ms
npm verbose title npm install mongosh
npm verbose argv "install" "mongosh" "--force" "--libc" "glibc" "--timing" "--loglevel" "silly" "--no-progress"
[...]
npm timing idealTree:node_modules/@mongosh/cli-repl/node_modules/wrap-ansi-cjs/node_modules/emoji-regex Completed in 0ms
npm timing idealTree:node_modules/@mongosh/cli-repl/node_modules/wrap-ansi/node_modules/ansi-styles Completed in 0ms
npm silly placeDep node_modules/@mongosh/cli-repl/node_modules/wrap-ansi ansi-regex@6.1.0 OK for: strip-ansi@7.1.0 want: ^6.0.1
npm timing idealTree:node_modules/@mongosh/cli-repl/node_modules/wrap-ansi/node_modules/strip-ansi Completed in 5ms
npm timing idealTree:node_modules/@mongosh/cli-repl/node_modules/wrap-ansi/node_modules/ansi-regex Completed in 0ms
npm timing idealTree:node_modules/@mongosh/cli-repl/node_modules/send/node_modules/debug/node_modules/ms Completed in 0ms
npm timing idealTree:buildDeps Completed in 63993ms
npm timing idealTree:fixDepFlags Completed in 76ms
npm timing idealTree Completed in 64766ms

@deki
Copy link

deki commented Nov 20, 2024

@SleepyDeb as you mention EC2, please take a look at amazonlinux/amazon-linux-2023#840

@Tofandel
Copy link

Tofandel commented Nov 20, 2024

@deki Thanks, that may appear to be the case, as from the logs @SleepyDeb provided and the fact it doesn't get killed with kill -9 (any freeze that doesn't die with -9 is a kernel issue), the idealTree task did complete and it froze before starting the reify task which is unusual (it would normally freeze just after reify:loadBundles), in which case it all points to the kernel issue.

@SleepyDeb
Copy link

@deki @Tofandel it works like a charm :*D thanks so much! .... I'll update my deployment scripts to include the workaround...

 export UV_USE_IO_URING=0
 npm install mongosh 

Again, sorry to bother!

@dan-mba
Copy link

dan-mba commented Nov 21, 2024

FYI: The node fix was just released in 23.3.0

Hopefully it will be backported to the LTS versions soon

@timdorr
Copy link

timdorr commented Nov 21, 2024

A temporary fix is to just patch your local copy of npm-install-checks using @Tofandel's PR code: https://github.com/Tofandel/npm-install-checks/blob/patch-1/lib/current-env.js

You can find your node install with which node and going up from the bin path. If you use nodenv or asdf, you might need to do some deeper digging. The file is located relative to that path at ./lib/node_modules/npm/node_modules/npm-install-checks/lib/current-env.js. Here's a command to find it if you happen to use asdf:

echo $(asdf where nodejs)/lib/node_modules/npm/node_modules/npm-install-checks/lib/current-env.js

From there you can edit the file and copy in the contents of that patch file. I would leave your editor open so you can hit undo if it breaks.

Note: This is directly editing system files, so use caution! It's likely recoverable, but typos or fat fingers will render your npm install non-functional. Be sure to test that the change functions before closing your editor. I do not recommend just blindly curling or wgeting the file into place.

wraithgar pushed a commit to npm/npm-install-checks that referenced this issue Nov 21, 2024
Yes this is a bit dirty because the report is now generated once at the
beginning of a command which could be considered a side effect (but
normally treeshaking will only include it only if needed), but the whole
process.report is a weirdly built API meant for debugging and not really
meant to be used in a normal program

But somehow when the call is done in the beginning of the process, this
call is very fast, but when it's called after having run a http request
(as is currently the case, a single call takes a lot more time to
complete, it takes 40s or more on my system when called at the end of
npm upgrade) but only a few milliseconds when called at the beginning
(this is why it's best to run it outside the function at the beginning
of the process as a side effect instead of calling getReport on demand
and cache the result)

Here is a log of console.time('report') and console.timeEnd('report')
before and after the getReport call
when run in the end of the upgrade command:
⠼report: 3:10.573 (m:ss.mmm)
when run in the beginning of the process at the top level
report: 1.943ms

This fixes npm hanging npm/cli#4028,
npm/cli#7814,
npm/cli#7868
@wraithgar
Copy link
Member

This was fixed in npm 10.9.1 (via npm/npm-install-checks#120)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug thing that needs fixing Needs Triage needs review for next steps
Projects
None yet
Development

No branches or pull requests