Performance issues

[joliss]

I've spent some time digging into nvm.sh, and found the following performance bottlenecks that affect shell startup (all percentages relative to total shell startup time, 100%):

A major source of slowdown seems to be nvm_ls; it is called 3 times on startup as nvm_ls default (plus 3 times recursively, as nvm_ls iojs here).

time nvm_ls default takes 25%, so the three nvm_ls default calls account for 75% of the time.

Each nvm_ls call loses some time on nvm_has_system_node or nvm_has_system_iojs (6% each). These calls seem unnecesarily slow because of the deactivate in a subshell; I wonder if we can check for system Node and iojs once at the very beginning, before nvm is set up, and just memoize it.

There are also a bunch of calls to external commands (like here or here) sprinkled about, which each lose a small amount of time (around 1%) but add up. A big offender is this chain as well. With Bash, it's possible to use built-in functions to avoid these calls: For example, we can use [[ "$1" =~ ^iojs- ]] to test for an iojs- prefix (ref) instead of using grep or cut, or use PATTERN="${PATTERN#iojs-}" to strip said prefix (ref) instead of using sed. I use these built-ins a lot when I write fast functions, but I'm not well-versed enough in cross-shell scripting to dare attempting to make a pull request for this.

[joliss]

This is just to write up my findings in case they're helpful for someone who wants to tackle performance; feel free to close whenever.

[ljharb]

Thanks so much for researching this and writing it up!

As you acknowledged, nvm has to work on bash, dash, sh, ksh, and zsh, so strict POSIX is required - if =~ for example would work then clearly that's a better approach, I'm just not an expert on shells :-)

I'll look into what can be done. Memoizing "has system node" and "has system iojs" makes sense per-command-invocation, but I wouldn't want to memoize it for the entire shell session.

[joliss]

I'm surprised that sh/dash is actually used widely enough in practice for nvm to support it, lol. So =~ doesn't seem to exist on sh/dash, unfortunately, but sometimes there's cute tricks to do it by other built-in means (e.g. [ "${s#iojs-*}" = "" ] tests for iojs- prefix).

[ljharb]

travis-ci uses it, and nvm runs all its node tests, so even if only for that I'd maintain support :-)

[ljharb]

@joliss I've added a couple commits to reduce external calls using POSIX parameter filtering. Still looking into some of the other comments.

[cesarandreu]

@ljharb I pulled in your changes and it lowered my startup time from 320ms total to 190ms total. Nice speed boost! 👍

[ljharb]

Hooray! Thanks should go to @joliss for the impetus, and majority of the work.

[cesarandreu]

m(_ _)m thanks to you both @joliss and @ljharb!

[joliss]

So much faster, thanks @ljharb!

[banderson]

@ljharb I'm still digging in for more info, but this change triggers a failure in Jenkins when doing a git checkout and trying to source nvm.sh without a default alias configured. Since Jenkins will fail on any function failure, this triggers it.

I don't know what the best solution is yet, so just giving you a heads up!

[ljharb]

@banderson Jenkins should absolutely not fail on any function failure for nvm - internally nvm relies on non-zero exit codes a lot. If that's how you have it configured, normal usage of it will break too.

[ljharb]

@banderson See #721 about the issue you're having.

[banderson]

@ljharb awesome, thanks so much for following up, that was a huge help in finding a workaround!

[vjpr]

+1 Takes about 1 second to open a new shell for me at the moment. All nvm related.

[moander]

Any workarounds yet?

$ time nvm use v0.12.7
Now using node v0.12.7 (npm v2.11.3)

real    0m0.276s
user    0m0.200s
sys 0m0.092s

[ljharb]

@moander what shell are you using? So far the major workaround has been to not use oh-my-zsh :-) but I'm continually trying to speed things up.

[moander]

@ljharb I'm using bash on my brand new out of the box macbook :)

[ljharb]

@moander In that case, I'd love to get more info from you - what's nvm debug and nvm ls output?

[moander]

@ljharb

moander [ ~ ]$ time nvm debug
$SHELL: /bin/bash
$NVM_DIR: $HOME/.nvm
nvm current: v0.12.7
which node: $NVM_DIR/versions/node/v0.12.7/bin/node
which iojs: 
which npm: $NVM_DIR/versions/node/v0.12.7/bin/npm
npm config get prefix: $NVM_DIR/versions/node/v0.12.7
npm root -g: $NVM_DIR/versions/node/v0.12.7/lib/node_modules

real    0m0.694s
user    0m0.596s
sys 0m0.119s

moander [ ~ ]$ time nvm ls
    iojs-v2.4.0
       v0.10.40
       v0.11.16
->      v0.12.7
         system
default -> stable (-> v0.12.7)
node -> stable (-> v0.12.7) (default)
stable -> 0.12 (-> v0.12.7) (default)
unstable -> 0.11 (-> v0.11.16) (default)
iojs -> iojs-v2.4 (-> iojs-v2.4.0) (default)

real    0m0.672s
user    0m0.329s
sys 0m0.522s

[defunctzombie]

Would it be useful to maybe do shell detection and use the faster features if available? Would help local terminals where startup time is noticed and still work on travis-ci and other places where startup time is less critical.

[ljharb]

@defunctzombie what "faster features" are you thinking of exactly?

[defunctzombie]

There were some other issue comments about faster features but not in all
shells.

Basically something to drop the startup time from a pretty visible 1 second
to something less?

[ljharb]

Yes but what specific things? The concern is precisely that i don't know what in oh-my-zsh, or on a very tiny number of people's computers, slows down nvm. If I knew, I'd fix it. I absolutely already do zsh-specific detection and disable options (with clunky and annoying code) to make that shell faster, so I'm definitely open to shell-specific speedups.

I just need help figuring out what parts can be sped up that way :-)

[defunctzombie]

Gotcha. Maybe send out a tweet asking for people to poke around? It gets a lot of use so I bet lots of people would have input.

[defunctzombie]

This will likely get rejected due to the nature of nvm.sh being a one file script, but I think there is some savings to be had by just parsing less shell script. Separating out all the function bodies into files and then only running the individual files on demand in the function.

[ljharb]

@defunctzombie that approach is being considered in #337, and is quite difficult, especially considering #400 is not yet resolved.

[ljharb]

v0.26.0 has been released; it includes a number of performance improvements. @joliss, @moander, etc, would you all mind installing it and reporting back on any parts you still find to be slow?

[rfc1459]

Bash user here (with a rather simple .bashrc):

$ bash --version
GNU bash, version 4.3.11(1)-release (x86_64-pc-linux-gnu)
Copyright (C) 2013 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html>

This is free software; you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.

$ git -C ~/.nvm describe
v0.26.1

$ time nvm ls
->      v0.12.7
default -> stable (-> v0.12.7)
node -> stable (-> v0.12.7) (default)
stable -> 0.12 (-> v0.12.7) (default)
iojs -> iojs- (-> N/A) (default)

real    0m0.276s
user    0m0.000s
sys 0m0.004s

$ time nvm debug
$SHELL: /bin/bash
$NVM_DIR: $HOME/.nvm
nvm current: v0.12.7
which node: $NVM_DIR/versions/node/v0.12.7/bin/node
which iojs: 
which npm: $NVM_DIR/versions/node/v0.12.7/bin/npm
npm config get prefix: $NVM_DIR/versions/node/v0.12.7
npm root -g: $NVM_DIR/versions/node/v0.12.7/lib/node_modules

real    0m0.576s
user    0m0.540s
sys 0m0.032s

The timings appear to be similar to the ones reported by @joliss and @moander.

[moander]

nvm v0.26.1

moander [ ~ ]$ time nvm ls
    iojs-v2.4.0
       v0.10.40
       v0.11.16
->      v0.12.7
         system
default -> stable (-> v0.12.7)
node -> stable (-> v0.12.7) (default)
stable -> 0.12 (-> v0.12.7) (default)
unstable -> 0.11 (-> v0.11.16) (default)
iojs -> iojs-v2.4 (-> iojs-v2.4.0) (default)

real    0m0.662s
user    0m0.330s
sys 0m0.525s

moander [ ~ ]$ time nvm debug
$SHELL: /bin/bash
$NVM_DIR: $HOME/.nvm
nvm current: v0.12.7
which node: $NVM_DIR/versions/node/v0.12.7/bin/node
which iojs: 
which npm: $NVM_DIR/versions/node/v0.12.7/bin/npm
npm config get prefix: $NVM_DIR/versions/node/v0.12.7
npm root -g: $NVM_DIR/versions/node/v0.12.7/lib/node_modules

real    0m0.680s
user    0m0.583s
sys 0m0.121s

[joliss]

@ljharb Yes, I get the following load times (time source ~/.nvm/nvm.sh):

0.25.4: 0.207s
0.26.0: 0.057s

That's a big improvement indeed!

[ljharb]

Awesome!

I'm going to leave this open, because zsh with oh-my-zsh is still incredibly slow - and, because speed improvements are always helpful :-)

[DavidSouther]

On ZSH, 0.27.1 is seeing a HUGE regression

% git co v0.26.1
% time ( source ./nvm.sh )
( source ./nvm.sh; ) 0.09s user 0.15s system 113% cpu 0.210 total
% git co v0.27.1
% time ( source ./nvm.sh )
( source ./nvm.sh; ) 0.51s user 0.23s system 93% cpu 0.787 total

[ljharb]

@DavidSouther since you have git, could you perhaps use git bisect to help me figure out which commit slowed it down? git bisect good to mark a good one, git bisect bad a bad one. Thanks!

[wraithan]

It appears to degrade pretty fast by the number of versions you have installed.

I commonly switch between lots of versions and have accumulated a number of versions due to updates, usually I purge this because I put my own custom builds of node in there (with special version numbers) to be able to switch to them while debugging things. I hadn't done that for a while and was up to 15 versions of node spanning 0.8 -> 5.x and 2 versions of io.js.

My boot time for my shell was getting absurdly long, I assumed it was one of my custom scripts but debugging showed nvm taking 0.93s to load on my system. 0.75s if the fs cache was warmed still. I cleaned out all the versions of node I had installed and that time decreased to 0.26s.

So folks sharing times should also share how many versions of node they have installed and whether the fs cache would already be hot (such as if you just ran the source nvm.sh command or haven't done any significant fs operations since the last time you sourced it, keep in mind whether you source it in your shell init)

[ljharb]

Interesting! I have 35 versions of node/iojs installed (one for every minor) and I've never once run into any speed issues, but I also don't use zsh or oh-my-zsh which some people have reported speed issues with when used with nvm.

[wraithan]

@ljharb I'm using bash. I can double check the version when I get to work tomorrow.

[mcm]

@ljharb Messing around with this on my system trying to track down why its noticeably slower since upgrading from OS X 10.10 to 10.11. I have zsh installed from homebrew, and I'm using zprezto rather than oh-my-zsh. Unfortunately I don't have any numbers from before the upgrade, it MAY have been just as slow and I didn't notice. Before I started messing around, this is what it looked like:

~/t/zsh_slow_nvm ❯❯❯ time (source /usr/local/opt/nvm/nvm.sh)

real 0.86s
user 0.46s
sys 0.35s
~/t/zsh_slow_nvm ❯❯❯

Curiously, I happened to consider that I have coreutils installed from homebrew, and I'm using the gnu-utilities module in zprezto, which creates shell functions to redirect to the GNU versions of the core utilities (for reference, https://github.com/sorin-ionescu/prezto/blob/master/modules/gnu-utility/init.zsh). Just by unsetting the shell function for [ and echo:

~/t/zsh_slow_nvm ❯❯❯ time (source /usr/local/opt/nvm/nvm.sh)

real 0.43s
user 0.31s
sys 0.13s
~/t/zsh_slow_nvm ❯❯❯

I'm going to see if there are others that specifically impact the performance, as it still loads WAY faster in bash on my system than in zsh, and report back anything else I find.

benevolence:zsh_slow_nvm steve$ time source /usr/local/opt/nvm/nvm.sh

real 0m0.428s
user 0m0.331s
sys 0m0.117s
benevolence:zsh_slow_nvm steve$

(edit: correct time outputs because I'm silly)

[ljharb]

@mcm: nvm is not supported under homebrew - if you brew uninstall it, and install it properly with the curl script in the readme, do you see the same performance numbers?

[mcm]

So it turns out, I was reading the time outputs wrong (and doing wrong stuff in general going back and forth between zsh and bash). The time is very similar between bash and zsh when NOT calling the ZSH function for [ and echo.

I will install from the curl script and let you know if this changes it without overriding those functions.

[mcm]

@ljharb Ok, so I ran it all of the various combinations to see what was the fastest. I'm curious why the time difference when installed via homebrew vs curl but if homebrew is unsupported, doesn't matter to me, I'll go with the supported option from here.

Either way, the gnu-utilities definitely impacts performance, whether installed via homebrew or curl. It causes less of a difference in shell startup time than actually running commands like "nvm ls", where its definitely noticeable (I actually see "nvm ls" output each line individually when the GNU utilities are enabled).

I wonder how many people with oh-my-zsh are using the GNU utilities as well, or if it sets up similar functions, or anything along those lines that is causing their issues. With those disabled, ZSH becomes comparable to bash for all uses.

ZSH:

~ ❯❯❯ time zsh -i -c exit  # without NVM, for comparison

real    0.66s
user    0.38s
sys 0.26s
~ ❯❯❯ time zsh -i -c exit  # with NVM from homebrew, with gnu-utilities

real    1.12s
user    0.69s
sys 0.38s
~ ❯❯❯ time zsh -i -c exit  # with NVM from curl, with gnu-utilities

real    0.77s
user    0.42s
sys 0.31s
~ ❯❯❯ time zsh -i -c exit  # with NVM from homebrew, without gnu-utilities

real    0.90s
user    0.62s
sys 0.27s
~ ❯❯❯ time zsh -i -c exit  # with NVM from curl, without gnu-utilities

real    0.55s
user    0.35s
sys 0.20s
~ ❯❯❯ time (nvm ls) # with NVM from curl, with gnu-utilities

->       system
node -> stable (-> N/A) (default)
iojs -> N/A (default)

real    1.36s
user    0.49s
sys 0.76s
~ ❯❯❯ time (nvm ls)  # with NVM from curl, without gnu-utilities

->       system
node -> stable (-> N/A) (default)
iojs -> N/A (default)

real    0.27s
user    0.12s
sys 0.21s
~ ❯❯❯

BASH:

benevolence:~ steve$ source /usr/local/opt/nvm/nvm.sh 
benevolence:~ steve$ time nvm ls

->       system
node -> stable (-> N/A) (default)
iojs -> N/A (default)

real    0m0.289s
user    0m0.145s
sys 0m0.219s
benevolence:~ steve$ source ~/.nvm/nvm.sh 
benevolence:~ steve$ time nvm ls

->       system
node -> stable (-> N/A) (default)
iojs -> N/A (default)

real    0m0.291s
user    0m0.146s
sys 0m0.219s
benevolence:~ steve$

[ljharb]

Thanks, I really appreciate the legwork.

[mcm]

No problem, glad to help. My last note, if I set a function in bash to use the g[ binary from coreutils, rather than the shell builtin, I get the same slowdown in bash that I do in ZSH.

[netei]

After Investigating a bit, I found out that they are two parts that are taking a lot of time :

nvm use 5 takes about 700ms on my machine, with hot cache. I found out two lines of the code that together take up for 650ms.

First is the nvm_print_npm_version check (about 200ms with hot cache).

nvm_print_npm_version() {
  if nvm_has "npm"; then
    echo " (npm v$(npm --version 2>/dev/null))"
  fi
}

I found out that you can use the following command

nvm use 5 --silent to not print the version

Maybe it would make sense to tell to use that instead in the .bashrc ?

Second is the nvm_die_on_prefix() function (about 450ms with hot cache)

It is specifically this line :

NVM_NPM_PREFIX="$(NPM_CONFIG_LOGLEVEL=warn npm config get prefix)"

I don' understand the internals of nvm to know exactly if and why this part is important and how we could speed it up a bit.

[ljharb]

@netei Thanks for the research! nvm use doesn't belong in your bashrc - the proper thing to do there is to make a default alias, or use an .nvmrc file.

nvm_die_on_prefix is slow because it has to call npm config get prefix, and that's slow. There's no faster way that I know of to search all the config file locations and env vars npm looks in :-/

[jedwards1211]

nvm takes at least 3 seconds to start up for me in bash which seems a lot higher than other times I see here 😢 I'm on a 2011 MacBook that generally performs pretty well. Does anyone have any tips on what might be wrong with my system?