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] npm 10.6.0 doesn't log anything while npm install #7425

Closed
2 tasks done
lorand-horvath opened this issue Apr 26, 2024 · 10 comments · Fixed by #7432
Closed
2 tasks done

[BUG] npm 10.6.0 doesn't log anything while npm install #7425

lorand-horvath opened this issue Apr 26, 2024 · 10 comments · Fixed by #7432
Assignees
Labels
Bug thing that needs fixing Release 10.x

Comments

@lorand-horvath
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

The latest npm 10.6.0 doesn't log anything while installing the packages with npm install. It only prints the final results. So npm is working for almost 50 seconds without notifying the user whether it is doing anything at all. The behavior is similar to npm install --loglevel silent of the previous version 10.5.2.

Expected Behavior

The logging should be displayed, showing the user that the installation is proceeding. It shouldn't be silenced completely.

Steps To Reproduce

  1. Environment: Command Prompt, npm 10.6.0, node 18.20.2
  2. npm install with an existing package.json in the root directory
  3. no loggin observed while installing the packages to node_modules

Environment

  • npm: 10.6.0
  • Node.js: 18.20.2
  • OS Name: Windows
  • System Model Name: Desktop PC
; copy and paste output from `npm config ls` here
@lorand-horvath lorand-horvath added Bug thing that needs fixing Needs Triage needs review for next steps Release 10.x labels Apr 26, 2024
@wraithgar
Copy link
Member

The progress bar in npm has been temporarily removed. It was conflicting with logging output and was generally inaccessible. What you are used to seeing is a mix of the progress bar and verbose logging (which was shown erroneously, regardless of loglevel). If you want to see the logging messages you can use --verbose.

@lorand-horvath
Copy link
Author

lorand-horvath commented Apr 26, 2024

@wraithgar I would prefer seeing some kind of progress log while npm is actually performing some work, by default. Otherwise users might confuse the silence with the process being stalled or hanging or a bug or something. Sometimes an npm install on a large project may take several minutes. Something should be displayed (some sort of spinner, progress bar, etc) while doing work that take longer than, say, 5 seconds.
Is this total silence a temporary problem? Are you going to add back some kind of progress bar in later version?

I had to revert to 10.5.2 because this was very strange, not showing anything for long periods of time - I thought something was broken.

@wraithgar
Copy link
Member

Yes it is temporary.

@henderea
Copy link

I thought something was broken

Same here, so I interrupted my npm update -gs command and then something actually was broken. As in my entire NPM install. I had to note down my global packages by looking at the contents of the install directory, then uninstall and reinstall node with NVM and install all of my stuff again.

Not a huge disaster, but definitely not great either.

So word to the wise: don't interrupt it when you have the -g flag, because you will probably break your NPM 😓

@lukekarrys lukekarrys reopened this Apr 26, 2024
@lukekarrys
Copy link
Member

lukekarrys commented Apr 26, 2024

We'll keep this open until we land a new "npm is actually doing something" visual. It probably won't be a progress bar initially but a simple spinner.

lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 27, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 28, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
@lukekarrys lukekarrys removed the Needs Triage needs review for next steps label Apr 29, 2024
@lukekarrys lukekarrys self-assigned this Apr 29, 2024
lukekarrys added a commit that referenced this issue Apr 29, 2024
Closes #7425

This is a little hard to test because everything should continue to work
without progress, as evidenced by the lack of churn in the tests and
snapshots here. The only existing tests that changed are the addition of
newlines after prompts which is new behavior as part of this PR.

I resorted to manually running some commands to get an idea of how the
various states worked together:

**`node . exec -- npm@4`**
This should show progress at the start and then hide it as it prompts
the user to install `npm@4`. `Ctrl+C` should exit from the prompt and
the error should display on the next line (this is a current bug).

**`node . audit signatures --loglevel=http`**
This should show a lot of http log messages while always keeping the
spinner on the last line of output. The spinner also should not jump
between frames regardless of how quickly the log messages show up.

**`node . pack`**
This should immediately show the banners and output from `prepack` and
not show the spinner until the actual packing is happening.

**`node . login`**
The spinner should never while the prompt is being displayed.

**`node . view npm`**
The spinner should appear while data is being fetched and then disappear
for the rest of the command as output is being displayed. The end output
on completion should not have any spinner frames rendered on new lines
in the output. The old progress bar achieved this by calling
`npmlog.disableProgress()` but now it is able to hide the spinner
appropriately even while outputting individual lines to stdout.
@lorand-horvath
Copy link
Author

lorand-horvath commented May 1, 2024

@lukekarrys @wraithgar Thanks for taking the time to add the spinner! However, this could be improved upon, compared to how it was before in 10.5.2. My concerns are the following:

  1. The spinner is there as expected, but there's a constant blinking cursor overlapping with it and it looks a bit unfinished or buggy.
  2. The installation process seems slower. I could revert to 10.5.2 and time the installations to see what the difference is.
  3. The spinner is not enough as default information. In previous versions I really liked the way it informed the user about what was currently doing, for example during npm install, so I would very much like to see something of the sort:
\ install react@18.3.1
| install react-dom@18.3.1
/ install styled-components@6.1.9
- update vite@5.2.10
\ update vite-plugin-eslint@1.8.1
| reify etc...

Wouldn't that be nicer?

@lukekarrys
Copy link
Member

lukekarrys commented May 1, 2024

Those are good suggestions. To take them point by point:

  1. There is a way to hide the cursor which should be easy enough to do only when the spinner is visible. I will look into this and any accessibility implications it might have.
  2. I'd be interested in seeing benchmarks if you have any from before and now. Also if you run with --no-progress do you still see a performance impact?
  3. The reason we moved away from how it used to work is that the progress bar showed messages that were primarily intended for logging. They weren't tailored for usability and would often show the last completed action when the current running action was hanging which led to lots of confusion. I'm in favor of bringing something similar back but we'd first need to put all the events in place in Arborist to accurately indicate what's happening in a user-friendly manner. But that will take more time.

Im going to log these in our follow up status board issue. Thanks for taking the time to provide these feedback!

@wraithgar
Copy link
Member

You can get what you described by setting your log level to http, those were the logging messages "leaking" into the progress bar before.

@lorand-horvath
Copy link
Author

lorand-horvath commented May 1, 2024

@wraithgar I've tried npm install --loglevel http and I get a long running list with the package downloads (http fetch), which is not bad per se, but I'd like to see what is actually being installed and also other activities being performed, not only what is being downloaded (or found in cache); all of this preferably in one single progress line (the previous action needs to be overwritten to the same line), similar to how it was before in 10.5.2.

@lorand-horvath
Copy link
Author

lorand-horvath commented May 1, 2024

2. I'd be interested in seeing benchmarks if you have any from before and now. Also if you run with `--no-progress` do you still see a performance impact?

I've run several benchmarks on a certain package (react frontend app) and the difference is not so large:
npm 10.5.2: npm install finished in 1:10
npm 10.7.0: npm install finished in 1:07
npm 10.7.0: npm install --no-progress finished in 0:59

3. The reason we moved away from how it used to work is that the progress bar showed messages that were primarily intended for logging. They weren't tailored for usability and would often show the last completed action when the current running action was hanging which led to lots of confusion. I'm in favor of bringing something similar back but we'd first need to put all the events in place in Arborist to accurately indicate what's happening in a user-friendly manner. But that will take more time.

I'd very much like to see a user-friendly manner of displaying the currently performed action with npm install, I posted more details in my comment above to @wraithgar

Im going to log these in our follow up status board issue. Thanks for taking the time to provide these feedback!

Thank you @lukekarrys @wraithgar for your quick and constructive responses!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Bug thing that needs fixing Release 10.x
Projects
None yet
Development

Successfully merging a pull request may close this issue.

4 participants