Github Progress bar noticeably slows down npm install · Issue #11283 · npm/npm ·...
source link: https://github.com/npm/npm/issues/11283
Go to the source link to view the article. You can view the picture content, updated content and better typesetting reading experience. If the link is broken, please click the button below to view the snapshot at that time.
Progress bar noticeably slows down npm install #11283
Closed
zakjan opened this issue on Jan 26, 2016 · 59 comments
Closed
Comments
Compare these runtimes of npm install
:
$ rm -r node_modules
$ npm set progress=false
$ time npm install
npm install 19.91s user 2.66s system 71% cpu 31.667 total
$ rm -r node_modules
$ npm set progress=true
$ time npm install
npm install 33.26s user 3.19s system 74% cpu 48.733 total
Npm 3.5.2. Both commands were run with already warmed-up cache. Progress bar may be responsible for up to 50% slow down.
Original source: https://twitter.com/gavinjoyce/status/691783314261331969 by @GavinJoyce
I found the original report here whilst researching how I could make npm install
faster.
It seems to yield a significant speed up for most people, all my colleagues in @intercom are seeing a significant boost. So far @kittens is the only one who hasn't reported a big difference:
https://twitter.com/sebmck/status/691911481114415104
I tried npm install
ing reactive-native
and can see a major speed improvement with npm v3.5.3
:
npm set progress=false && rm -rf ~/.npm && rm -rf node_modules && time npm install
npm install 70.27s user 22.12s system 120% cpu 1:16.85 total
npm set progress=true && rm -rf ~/.npm && rm -rf node_modules && time npm install
npm install 202.59s user 26.47s system 105% cpu 3:36.52 total
Looks like there's something in the works that might help: npm/gauge#7 (comment)
Same here. I'm running local-npm so I can rule out any network related issues:
npm set progress=false && rm -rf node_modules && time npm install
npm install 145.31s user 27.80s system 80% cpu 3:34.27 total
npm set progress=true && rm -rf node_modules && time npm install
npm install 302.40s user 27.31s system 101% cpu 5:25.79 total
That's a 41% increase in total time.
Same here npm 3.3.12
, Linux Mint 17.3 Cinnamon
npm set progress=true
rm -rf node_modules
time npm install
npm install 286,70s user 28,54s system 80% cpu 6:31,36 total
npm set progress=false
rm -rf node_modules
time npm install
npm install 137,00s user 24,83s system 73% cpu 3:41,31 total
Computer specs:
- Lenovo IdeaPad Flex 15
- Intel Core i5-4200U
- 8 GB RAM
Minor difference in my case: https://gist.github.com/Reinmar/f69303b79157f2ca5764 (npm 3.5.2, MacOS) and here.
Maybe it's OS specific?
Keep in mind that this is most likely also affected by the user's machine specs. The diff might be notably higher on lower end computers.
The diff might be notably higher on lower end computers.
I'm running OSX 10.11.2 / MacBook Pro 2015
@AgronKabashi i'm sure the slowdown would still be rationally similar. Seems like regardless of how slow the system is, most are experiencing something around a 2x slowdown.
What terminal app do you use and what font do you have selected? Also, do you have anti-aliasing enabled in your terminal?
The system might be using a fallback font for rendering the progress bar, since most "nice" programming fonts don't have line glyphs that the progress bar uses. That could be slowing things down.
Also, AA or other fancy graphical things (transparent windows) can slow down draw commands. I'd make sure your terminal is up to date or try a nightly build if it's iTerm.
I use iTerm2 Build 2.1.4
with a zsh shell. Here is my config:
I'd be curious to see a performance measurement with non-ascii anti-aliasing disabled. I suspect this is slow draw performance.
Here's my diff:
progress=false
real 1m18.456s
user 0m27.572s
sys 0m7.639s
progress=true
real 1m23.974s
user 0m40.056s
sys 0m7.364s
I'm running Inconsolata-dz for Powerline with regular anti-aliasing and non-ascii anti-aliasing disabled.
To maintain parity, here are the tests with Monaco 12pt with AA on for all fonts and a transparent window:
progress=false
real 0m51.885s
user 0m25.604s
sys 0m6.944s
progress=true
real 1m9.172s
user 0m38.643s
sys 0m7.226s
Some difference, but not huge. I wonder if someone can run it with node --prof
somehow and get a profiler dump to analyze.
Regardless of progress bar.. npm
is super slow!!
For what it's worth, I seem to be affected by this as well:
progress=false
$ time npm install ... real 1m30.147s user 1m2.716s sys 0m5.052s
$ time npm install ... real 1m17.472s user 0m58.336s sys 0m4.484s
$ time npm install ... real 1m20.335s user 1m1.436s sys 0m4.976s
progress=true
$ time npm install ... real 2m35.531s user 2m11.340s sys 0m5.628s
$ time npm install ... real 2m23.303s user 2m4.780s sys 0m5.396s
$ time npm install ... real 2m21.438s user 2m2.048s sys 0m4.880s
I'm on Ubuntu 15.04, GNOME Terminal 3.14.2, with the default font.
npm appears to be working on it in npm/gauge#7
If my modest benchmarks can help in some way:
sw_vers -productVersion
10.11.3
system_profiler SPHardwareDataType | grep Model
Model Name: MacBook Pro
Model Identifier: MacBookPro11,4
node -v
v5.5.0
npm -v
3.6.0
rm -rf ~/.npm && rm -rf node_modules
is executed for every following command:
npm install --progress=false 48.69s user 17.32s system 97% cpu 1:07.64 total
npm install --progress=true 79.44s user 17.81s system 107% cpu 1:30.77 total
npm install --progress=false --loglevel=info 50.37s user 17.66s system 104% cpu 1:05.12 total
npm install --progress=true --loglevel=silent 72.52s user 16.71s system 109% cpu 1:21.18 tota
I'm using iTerm 2.1.4 with Droid Sans Mono font.
TL;DR
Installing without the progress bar on npm causes a 20% speedup to overall install time. The slowdown is due to a hot method call that if throttled, would prevent the majority of the slowdown.
Over the past few days or so, there have been some interesting comments on twitter around npm’s progress bar and the performance cost of having it enabled.
Instead of just blindly throwing conclusions only based on running time npm i
, I decided to take a look at the cpu profile of the process using my handy fork of npm with instrumentation baked in https://github.com/samccone/npm/tree/sjs/profiler
On a cold run with a prewarmed .npm cache folder from an earlier install, I am seeing a 20% increase in the install time .. from npm i to process exit.
With Progress
Without Progress
Stepping down into the bottom up view of the cpu profiler in chrome devtools right away we can verify exactly what is eating up that 20%
With tracker on:
With tracker off:
Hmm so when the progress bar is enabled it looks like 23~% of the program time is being spent in a method called TrackerGroup.completed
inside of the are-we-there-yet
module… Let's take a closer look at exactly what is going on there
Taking a look in Cachegrind via https://github.com/jlfwong/chrome2calltree allows us to even further visulize the sheer cost of the progress bar during runtime
^ That big red blob is time spent inside of the logging
So there seems to be 3 players in progress bar game here:
Gauge https://github.com/iarna/gauge/blob/master/progress-bar.js
Are-we-there-yet https://www.npmjs.com/package/are-we-there-yet
Npmlog https://github.com/npm/npmlog/blob/master/log.js
The question is what is causing so much time to be spent in the log methods.
So then let’s look at showProgress
Alright, so it looks like we are totally skipping it if progress has been disabled.. So let’s take one more step into the gauge show code:
Well this seems to be the issue and the reason for the massive slowdown, although there is some throttling happening inside of the ProgressBar code, we are still calling into it a lot and doing quite a bit of work before we eager exit. By simplifying the logic in the method, removing the inline method definition (which is probably causing v8 to do some extra work due to scope variable binding) and upstreaming the throttling responsibility, I believe that the cost of showing the progress bar can be significantly cut down.
Jumping into this conversation, (I'm "SomeKittens", not just "Kittens"). I tried a few different packages and got different results (though I was able to repro the timings with react-native
). Trying with my own package (https://github.com/SomeKittens/gustav), I actually saw an improvement with the progress bar (though my methodology there is slightly different, I didn't rm -r ~/.npm/
). I can re-run the benchmark when I get home tonight.
Just a quick note to say that the CLI team is aware of this issue, and after @samccone's in-depth analysis (for which: thank you very much), much further contribution to the thread is likely to just be piling on.
Nice profiling tools! Noting them down
@samccone That is some legit detective work. I to you sir.
Awesome analysis as usual @samccone. Thank you
TBH I'm a bit embarrassed that I didn't push out a quick gauge patch earlier. I've been aware of this as an issue for a while and the fix was literally 10 minutes or so of effort, but it hadn't bubbled up in priority as I hadn't realized how big an impact it was having. I'd been waiting as it's addressed by the improved architecture of the rewrite (prints at a set interval, no debounce needed), but clearly it was worth doing sooner than later.
@iarna no need to be embarrassed. This only surfaced due to its immense popularity
@BookOfGreg @webysther The latest stable version of node is 4.4.5
do you recommend using the latest one E.g. v6 to avoid this issue?
@Sinewyk I'm landing a rewrite of the progress bar this week that will likely eliminate even that 5%, so my plan was to close this when that lands.
@iarna That rewrite will be part of which NPM version?
Is it possible to set progress=false
inside package.json?
Copy link
jffry commented on Jul 8, 2016
@kevinSuttle You can put progress=false
(or any other npm config) inside a file named .npmrc
in the same folder as your package.json
; see https://docs.npmjs.com/files/npmrc for details on .npmrc
I'm closing this because we landed the updated gauge ages in v3.10.0, way back in June, and there shouldn't be any more progress bar related slow downs. (It prints at a fixed interval now, so printing it shouldn't be adding a measurable amount of work.)
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
No one assigned
None yet
No milestone
Successfully merging a pull request may close this issue.
None yet
Recommend
About Joyk
Aggregate valuable and interesting links.
Joyk means Joy of geeK