nix-community / home-manager

Manage a user environment using Nix [maintainer=@rycee]
https://nix-community.github.io/home-manager/
MIT License
6.68k stars 1.75k forks source link

bug: Prezto completion module is much slower than "vanilla" prezto #2255

Closed axeltlarsson closed 2 years ago

axeltlarsson commented 3 years ago

Is there an existing issue for this?

Issue description

Hi.

I have spent the last few days trying to understand why my zsh startup time become so slow when I converted my from my usual prezto config to using home manager. I went from a startup time measured as such:

# $SHELL = /nix/store/apkv2fv89zd0knfi1l8pfyxl36xw3kzr-zsh-5.8/bin/zsh
for i in $(seq 1 10); do /usr/bin/time $SHELL -i -c exit; done

of around 0.10 seconds to 0.41 seconds using the same modules and config! 🐌

To make sure I was making a fair comparison, I tried to make a minimal reproducible example by comparing the exact same revision of prezto with the default options - one configured with home manager and the other per prezto's installation instructions.

With default modules I get 0.21 s startup with home manager.

I copied the prezto derivation from my local nix store to my ~/.zprezto (cp -R /nix/store/shwbywl4c5fj4ivsm628ari4ivayyfwz-zsh-prezto-unstable-2021-06-02/share/zsh-prezto .zprezto ) and ran prezto's setup in ~/.zprezto.

setopt EXTENDED_GLOB
for rcfile in "${ZDOTDIR:-$HOME}"/.zprezto/runcoms/^README.md(.N); do
  ln -s "$rcfile" "${ZDOTDIR:-$HOME}/.${rcfile:t}"
done

I still get 0.21 s as expected (it should be the same configuration, more or less), howerver I noticed that runcoms/zshrc is not sourcing ~/.zprezto/init.zsh but the init.zsh from the nix store, so I changed that:

# Source Prezto.
if [[ -s "${ZDOTDIR:-$HOME}/.zprezto/init.zsh" ]]; then
  source "${ZDOTDIR:-$HOME}/.zprezto/init.zsh"
fi

and re-ran the benchmark and then got excellent performance again at 0.10s, what is going on? πŸ€”

Of course I realise that the init.zsh in the nix store and the init.zsh in ~/.zprezto will actually load the modules from different locations, from the nix-store's prezto /modules and from ~/.zprezto/modules respectively. But the contents are identical!

Does anybody know what is going on here and has anyone experienced anything similar?

Furthermore, I tried to optimise the config a bit, and if I remove the completion module from my home-manager config, I get really good performance again at 0.09s which is identical to what I get with "vanilla" prezto (also without the completion module). It also appears to be the case that the more other modules are loaded, the more the completion module contributes to a slower start up time. I do not see this behaviour, at least as clearly, with a vanilla prezto setup.

Maintainer CC

@anna328p @pinpox

System information

- system: `"x86_64-darwin"`
 - host os: `Darwin 19.6.0, macOS 10.15.7`
 - multi-user?: `no`
 - sandbox: `no`
 - version: `nix-env (Nix) 2.3.14`
 - channels(axel): `"home-manager, nixpkgs-21.11pre306170.4d3e13e51b6"`
 - nixpkgs: `/Users/axel/.nix-defexpr/channels/nixpkgs`
berbiche commented 3 years ago

Hi,

Does a vanilla prezto setup also make use of compinit?

The completion module can be disabled with programs.zsh.enableCompletion = false or modified with programs.zsh.completionInit = "something"

axeltlarsson commented 3 years ago

@berbiche I haven't enabled programs.zsh.enableCompletion (but tested now to explicitly disable it and it didn't make a difference). What I meant was programs.zsh.prezto.pmodules including the "completion" module or not, it does use compinit but only once every 20 h (https://github.com/sorin-ionescu/prezto/blob/166cbe2fca25319db2551f0cc74a86c93259017d/modules/completion/init.zsh#L49-L64), and its behaviour should be the same whether I use it in a setup with vanilla prezto or through home manager, right? But it's not, that's what's so puzzling to me. If I delete ~/.cache/prezto I can see compinit being called on the first invocation to produce the cached zcompdump - adding an adidiontal 0.32s or so to startup:

for i in $(seq 1 10); do /usr/bin/time $SHELL -i -c exit; done
        1.13 real         0.68 user         0.40 sys
        0.41 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys
        0.41 real         0.13 user         0.27 sys
        0.40 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys
        0.40 real         0.13 user         0.26 sys

With vanilla prezto I get this:

for i in $(seq 1 10); do /usr/bin/time $SHELL -i -c exit; done
        0.47 real         0.32 user         0.13 sys
        0.10 real         0.05 user         0.04 sys
        0.10 real         0.05 user         0.04 sys
        0.10 real         0.05 user         0.04 sys
        0.10 real         0.04 user         0.04 sys
        0.10 real         0.04 user         0.04 sys
        0.10 real         0.04 user         0.04 sys
        0.10 real         0.05 user         0.04 sys
        0.10 real         0.04 user         0.04 sys
        0.10 real         0.04 user         0.04 sys

again there is a performance hit to generate the zcompdump on the first invocation - but it's much less, and more to the point, subseuquent invocations are much much quicker than what I get with home-manager's prezto configuration. So I believe something is off with home-manager's prezto configuration when using the prezto completion module.

I'll try to stury more thoroughly the behaviour of the completion module, and see why it would behave so much slower with the nix config than with the "vanilla" prezto configuration.

axeltlarsson commented 3 years ago

Update: I found a clue!

https://github.com/sorin-ionescu/prezto/blob/166cbe2fca25319db2551f0cc74a86c93259017d/modules/completion/init.zsh#L84

The unsetopt CASE_GLOB seems to be the costly line, or rather its effect on other code being executed I'm guessing. So, either commenting out that, or more conveniently setting prezto.caseSensitive = true will make the setup performant again!

Still no idea why that option unsetting has such a profound effect when using prezto with home-manager versus the vanilla setup. At least I have a work around now...

pinpox commented 3 years ago

Sadly that breaks case-insensitivity, which I find quite useful when using *. Isn't there no other way to get it fast? Does vanilla prezto have the same performance hit with that option on/off?

axeltlarsson commented 3 years ago

Vanilla prezto does not have the performance hit. It's fast either way, but with home manager I get the quite terrible performance hit unless I set zsh. caseSensitive. I don't know why though, it's a mystery to me.

Are you seeing the same behaviour? @pinpox

pinpox commented 3 years ago

@AxelTLarsson I get this result on my nixos+home-manager configuration:

Γ—  for i in $(seq 1 10); do time $SHELL -i -c exit; done
$SHELL -i -c exit  0,13s user 0,04s system 99% cpu 0,168 total
$SHELL -i -c exit  0,13s user 0,04s system 100% cpu 0,169 total
$SHELL -i -c exit  0,12s user 0,04s system 100% cpu 0,165 total
$SHELL -i -c exit  0,11s user 0,05s system 99% cpu 0,166 total
$SHELL -i -c exit  0,12s user 0,05s system 100% cpu 0,165 total
$SHELL -i -c exit  0,13s user 0,04s system 100% cpu 0,166 total
$SHELL -i -c exit  0,13s user 0,04s system 100% cpu 0,166 total
$SHELL -i -c exit  0,13s user 0,03s system 100% cpu 0,166 total
$SHELL -i -c exit  0,12s user 0,05s system 100% cpu 0,165 total
$SHELL -i -c exit  0,13s user 0,04s system 100% cpu 0,167 total

For some strange reason, when I'm in a nix-shell though, it is much faster. E.g. using nix-shell -p <some package>


Γ—  nix-shell -p htop

~ via ❄  impure (shell)
Β» for i in $(seq 1 10); do time $SHELL -i -c exit; done
exit
$SHELL -i -c exit  0,01s user 0,00s system 98% cpu 0,012 total
exit
$SHELL -i -c exit  0,01s user 0,00s system 97% cpu 0,016 total
exit
$SHELL -i -c exit  0,01s user 0,00s system 98% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,01s system 98% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,01s system 97% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,01s system 97% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,01s system 96% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,00s system 97% cpu 0,015 total
exit
$SHELL -i -c exit  0,01s user 0,01s system 98% cpu 0,016 total
exit
$SHELL -i -c exit  0,01s user 0,00s system 97% cpu 0,016 total
berbiche commented 3 years ago

@pinpox unless you have changed the shell used by nix-shell, it will always use bash.

pinpox commented 3 years ago

@pinpox unless you have changed the shell used by nix-shell, it will always use bash.

I have changed it

~ via πŸŒ™ took 26s
Β» echo $SHELL
/run/current-system/sw/bin/zsh

~ via πŸŒ™
Β» nix-shell -p htop

~ via πŸŒ™ via ❄  impure (shell)
Β» echo $SHELL
/home/pinpox/.config/zsh/plugins/zsh-nix-shell/scripts/buildShellShim.zsh

~ via πŸŒ™ via ❄  impure (shell)
Β»
axeltlarsson commented 3 years ago

@pinpox and I guess you have the completion module enabled, and thus is not able to reproduce the issue - vanilla prezto is not signigifcantly faster with the same set of plugins (whereby "completion" is one of them)?

Also, I'm guessing your second invocation experiment through nix-shell does not load the same set of plugins perhaps, or perhaps none even?

pinpox commented 3 years ago

@AxelTLarsson I'm using this zsh plugins:

For prezto I have set:

      prezto.pmodules = [ "utility" "editor" "directory" ];

All of them still work after running nix-shell, so I guess they are loaded? Maybe they are still loaded? Not sure how to verify, let me know if I provide any information to speed up prezto.

axeltlarsson commented 3 years ago

@pinpox could you try adding completion as a module? What I'm seeing is that plugin specifically worsening performance significantly with nix/home manager as opposed with vanilla prezto.

stale[bot] commented 2 years ago

Thank you for your contribution! I marked this issue as stale due to inactivity. If this remains inactive for another 7 days, I will close this issue. Please read the relevant sections below before commenting.

If you are the original author of the issue

* If this is resolved, please consider closing it so that the maintainers know not to focus on this. * If this might still be an issue, but you are not interested in promoting its resolution, please consider closing it while encouraging others to take over and reopen an issue if they care enough. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

If you are not the original author of the issue

* If you are also experiencing this issue, please add details of your situation to help with the debugging process. * If you know how to solve the issue, please consider submitting a Pull Request that addresses this issue.

Memorandum on closing issues

If you have nothing of substance to add, please refrain from commenting and allow the bot close the issue. Also, don't be afraid to manually close an issue, even if it holds valuable information.

Closed issues stay in the system for people to search, read, cross-reference, or even reopen--nothing is lost! Closing obsolete issues is an important way to help maintainers focus their time and effort.

pinpox commented 2 years ago

Sorry, I don't have the time right now to test this. If someone want's to take over please do!

JustWhateverIOnlyWantBetterCodeView commented 1 year ago

I've encountered this issue and debugged it.

As it was mentioned unsetopt CASE_GLOB causes huge performance git. The reason is that with CASE_GLOB enabled any glob like /nix/store/sn59qaijwgpf8n41khl60mfnfbxyb16x-zsh-5.9/* would be optimized as opening directory /nix/store/sn59qaijwgpf8n41khl60mfnfbxyb16x-zsh-5.9/ and then readdir on this directory. But what happens if CASE_GLOB is not set and globs are case-insensitive? Then zsh can no longer to this optimization, it must open /nix/store dir and search all of it because, there could exist a path like /nix/store/SN59qaijwgpf8n41khl60mfnfbxyb16x-zsh-5.9/ or /nix/store/sn59qaijWGPF8n41khl60mfnfbxyb16x-zsh-5.9/ (i.e., only case of letters changed). In summary unsetopt CASE_GLOB disables pure paths optimization in globbing and forces zsh to list and go though entire /nix/store.

The only reliable workaround is to set programs.zsh.prezto.caseSensitive = true. Settings it to false (the default) causes not only prezto, but literally any unrelated zsh script that globs anything inside /nix/store to be very slow (e.g. direnv).

If you really want to keep caseSensitive = false, then you could try adding it to the very end of pmodules list so no other pmodules are affected (greatly improves zsh startup time). But it be honest this option is broken and potentially harmful.

axeltlarsson commented 1 year ago

Thank you for debugging this, the explanation makes a lot of sense and I get some closure πŸ™‚.

turboMaCk commented 11 months ago

For me removing vcs_info 'prompt' from the prompt I removes the performance issues during start. You might consider trying that.

turboMaCk commented 11 months ago

Ok this is the workaround that does the trick for me (without impacting my UX):

.zshrc:

# Triger `vcs_info 'prompt'` before loading Prezto.
# We want the first call to this happen before prezto will
# `unsetopt CASE_GLOB` which will have negative effect on the performance.
# Calling this before case sensitive globing makes initial start much faster.
# see: https://github.com/nix-community/home-manager/issues/2255
autoload -Uz vcs_info
vcs_info 'prompt'

# Source Prezto.
if [[ -s "${ZDOTDIR:-$HOME}/.zprezto/init.zsh" ]]; then
  source "${ZDOTDIR:-$HOME}/.zprezto/init.zsh"
fi
JustWhateverIOnlyWantBetterCodeView commented 11 months ago

@turboMaCk Putting "completion" module at the very end of "pmodules" list (at least after "prompt") wouldn't have the same effect as your workaround?

turboMaCk commented 11 months ago

Putting "completion" module at the very end of "pmodules" list (at least after "prompt") wouldn't have the same effect as your workaround?

No that had no effect at all.

michaelpj commented 9 months ago

This caused me quite a bit of pain, so I made a PR to fix it in home-manager.

michaelpj commented 9 months ago

https://github.com/nix-community/home-manager/pull/4701