Bug: Slow startup/init in ZSH

rnett commented 2 years ago

Bug report SDKMAN's initialization is slow when using ZSH, adding almost a full second to shell startup.

Profiling (zprof):

 1)    3         489.19   163.06   29.26%    489.19   163.06   29.26%  __sdkman_export_candidate_home
 2)    3         479.16   159.72   28.66%    479.16   159.72   28.66%  __sdkman_prepend_candidate_to_path
 3)    1         210.40   210.40   12.58%    210.40   210.40   12.58%  handle_completion_insecurities
 4)    1         208.75   208.75   12.48%    208.75   208.75   12.48%  detect-clipboard
 5)    4         180.70    45.17   10.81%    177.84    44.46   10.64%  (anon)
 6)    1          67.81    67.81    4.06%     64.27    64.27    3.84%  __conda_activate
 7)    2          20.83    10.42    1.25%     11.96     5.98    0.72%  compinit
 8)    2           8.87     4.44    0.53%      8.87     4.44    0.53%  compaudit
 9)    2           6.14     3.07    0.37%      6.14     3.07    0.37%  _zsh_highlight_bind_widgets
10)    1           4.71     4.71    0.28%      4.63     4.63    0.28%  _zsh_highlight_load_highlighters
11)    1           3.51     3.51    0.21%      3.51     3.51    0.21%  __add_sys_prefix_to_path
12)    1           1.65     1.65    0.10%      1.65     1.65    0.10%  _p9k_init_ssh
13)   27           1.53     0.06    0.09%      1.53     0.06    0.09%  compdef
14)    9           0.97     0.11    0.06%      0.97     0.11    0.06%  is-at-least
15)    1           0.78     0.78    0.05%      0.78     0.78    0.05%  colors
16)    6           0.67     0.11    0.04%      0.67     0.11    0.04%  add-zsh-hook
17)   11           0.88     0.08    0.05%      0.35     0.03    0.02%  apt_pref_compdef
18)    1           0.90     0.90    0.05%      0.31     0.31    0.02%  _p9k_preinit

To reproduce Add source "$HOME/.sdkman/bin/sdkman-init.sh" to .zshrc, profile using instructions from https://stevenvanbael.com/profiling-zsh-startup

Note that running the init script by itself is significantly faster, so there may be more to this.

System info

OS: Ubuntu WSL 2 5.10.16.3-microsoft-standard-WSL2
Shell and version: ZSH, 5.4.2
The output of sdk version: SDKMAN 5.12.4

helpermethod commented 2 years ago

Hi @rnett,

I can't reproduce your results on Mac. I suppose your problem is specific to WSL 2.

cristianmiranda commented 2 years ago

Hi. I'm getting the same results (running ZSH on Manjaro Linux). Is there a way to speed this up?.

rnett commented 2 years ago

I started using https://github.com/matthieusb/zsh-sdkman with much better speeds. I haven't yet noticed any differences between it and the official completion.

cristianmiranda commented 2 years ago

Works like a charm! Thanks man!

jochenwierum commented 1 year ago

I had similar problems: I spawn short lived shell sessions very often and sometimes(!) they took more than a second to start.

I found out that in my case the update check at the startup was the problem. This quick workaround in .zshrc works for me (I temporarily set the offline mode when sourcing sdkman):

local old_sdkman_offline_mode=${SDKMAN_OFFLINE_MODE:-}
export SDKMAN_OFFLINE_MODE=true

source "$HOME/.sdkman/bin/sdkman-init.sh"

if [[ -n $old_sdkman_offline_mode ]]; then
    export SDKMAN_OFFLINE_MODE=$old_sdkman_offline_mode
else
    unset SDKMAN_OFFLINE_MODE
fi
unset old_sdkman_offline_mode

I still get update notifications when I use sdkman (i.e. chdir into a directory with a .sdkmanrc file).

I'm not sure if this approach is generally good. However, in my case, it works fine :)

bitterfox commented 1 year ago

Hi, I could reproduce this issue and I investigated a bit. I'm also interested in improving sdkman-init faster to speed up my zsh session startup.

My environment is

OS: Linux 5.4.0-42-generic (Ubuntu 20.04.4 LTS)
Machine: MacBookPro16,1
Shell: zsh 5.8 (x86_64-ubuntu-linux-gnu)
SDKMAN
- script: 5.18.1
- native: 0.2.2

This is caused by this part in the sdkman-init https://github.com/sdkman/sdkman-cli/blob/41a2743e1c23910e239ab8b9ff3ecd93fa94a856/src/main/bash/sdkman-init.sh#L167-L173

__sdkman_export_candidate_home and __sdkman_prepend_candidate_to_path is called when the candidate exists in candidates dir. And it's in the loop for each candidate.

This means this issue becomes significiant if there are many candidates installed.

To reproduce this issue, install all candidates

sdk list | grep "sdk install" | sed -r "s/.*\s(.*)$/\1/" | while read line; do
  echo install $line
  sdk install $line
done

start=`date +%s%N`
export SDKMAN_DIR="$HOME/.sdkman"
[[ -s "$HOME/.sdkman/bin/sdkman-init.sh" ]] && source "$HOME/.sdkman/bin/sdkman-init.sh"
end=`date +%s%N`
duration=$((end - start))
echo sdkman $((duration/1000/1000))ms

Mesure source "$HOME/.sdkman/bin/sdkman-init.sh" like above

When only 1 candidate is installed, it's 45ms (about 5ms is overhead by above measurement for my env)

% ls ~/.sdkman/candidates ; zsh 
java/
sdkman 45ms

If all candidates are installed, it's about 225ms for my env. it's definitely slower

% ls ~/.sdkman/candidates ; zsh
activemq/      doctoolchain/    infrastructor/  ki/         mvnd/             spark/
ant/           flink/           jarviz/         kobweb/     mybatis/          springboot/
asciidoctorj/  gaiden/          java/           kotlin/     neo4jmigrations/  sshoogr/
ballerina/     gradle/          jbang/          kscript/    pierrot/          taxi/
bpipe/         gradleprofiler/  jmc/            ktx/        pomchecker/       tomcat/
btrace/        grails/          jmeter/         layrry/     quarkus/          toolkit/
concurnas/     groovy/          joern/          leiningen/  sbt/              vertx/
connor/        groovyserv/      jreleaser/      maven/      scala/            visualvm/
cuba/          hadoop/          karaf/          micronaut/  schemacrawler/    webtau/
cxf/           http4k/          kcctl/          mulefd/     skeletal/
sdkman 225ms

I got the similar results by zprof

sdkman 340ms
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)   25         153.21     6.13   46.54%    153.21     6.13   46.54%  __sdkman_export_candidate_home
 2)   25         151.02     6.04   45.88%    151.02     6.04   45.88%  __sdkman_prepend_candidate_to_path
 3)    1          22.26    22.26    6.76%     15.58    15.58    4.73%  compinit
 4)    2           6.68     3.34    2.03%      6.68     3.34    2.03%  compaudit
 5)    1           1.08     1.08    0.33%      1.08     1.08    0.33%  colors
 6)    2           0.57     0.28    0.17%      0.57     0.28    0.17%  is-at-least
 7)    1           0.49     0.49    0.15%      0.49     0.49    0.15%  add-zsh-hook
 8)    4           0.38     0.09    0.11%      0.38     0.09    0.11%  compdef
 9)    1           0.11     0.11    0.03%      0.11     0.11    0.03%  bashcompinit
10)    1           0.21     0.21    0.06%      0.08     0.08    0.02%  complete
11)    2           0.02     0.01    0.01%      0.02     0.01    0.01%  __sdkman_echo_debug

After some investigate, I figure out tr in __sdkman_export_candidate_home and grep in __sdkman_prepend_candidate_to_path is culprit and I could improve the performance by replacing alternative way in zsh.

https://github.com/sdkman/sdkman-cli/blob/41a2743e1c23910e239ab8b9ff3ecd93fa94a856/src/main/bash/sdkman-path-helpers.sh#L55 https://github.com/sdkman/sdkman-cli/blob/41a2743e1c23910e239ab8b9ff3ecd93fa94a856/src/main/bash/sdkman-path-helpers.sh#L73

Here is my improvement for zsh

-    local candidate_home_var="$(echo ${candidate_name} | tr '[:lower:]' '[:upper:]')_HOME"
+    local candidate_home_var="${candidate_name:u}_HOME"
---
-    echo "$PATH" | grep -q "$candidate_dir" || PATH="${candidate_bin_dir}:${PATH}"
+    [[ "$PATH" == *"$candidate_dir"* ]] || PATH="${candidate_bin_dir}:${PATH}"

With this patch, it's faster than before and maybe acceptable performance.

% ls ~/.sdkman/candidates ; zsh 
activemq/      btrace/     doctoolchain/    grails/      infrastructor/  jmeter/     ki/       layrry/     mvnd/             quarkus/        spark/       toolkit/
ant/           concurnas/  flink/           groovy/      jarviz/         joern/      kobweb/   leiningen/  mybatis/          sbt/            springboot/  vertx/
asciidoctorj/  connor/     gaiden/          groovyserv/  java/           jreleaser/  kotlin/   maven/      neo4jmigrations/  scala/          sshoogr/     visualvm/
ballerina/     cuba/       gradle/          hadoop/      jbang/          karaf/      kscript/  micronaut/  pierrot/          schemacrawler/  taxi/        webtau/
bpipe/         cxf/        gradleprofiler/  http4k/      jmc/            kcctl/      ktx/      mulefd/     pomchecker/       skeletal/       tomcat/
sdkman 65ms
num  calls                time                       self            name
-----------------------------------------------------------------------------------
 1)    1          21.83    21.83   43.56%     15.23    15.23   30.39%  compinit
 2)   25          14.20     0.57   28.34%     14.20     0.57   28.34%  __sdkman_prepend_candidate_to_path
 3)   25          11.32     0.45   22.60%     11.32     0.45   22.60%  __sdkman_export_candidate_home
 4)    2           6.60     3.30   13.17%      6.60     3.30   13.17%  compaudit
 5)    1           1.07     1.07    2.14%      1.07     1.07    2.14%  colors
 6)    2           0.58     0.29    1.16%      0.58     0.29    1.16%  is-at-least
 7)    1           0.51     0.51    1.02%      0.51     0.51    1.02%  add-zsh-hook
 8)    4           0.38     0.10    0.76%      0.38     0.10    0.76%  compdef
 9)    1           0.11     0.11    0.22%      0.11     0.11    0.22%  bashcompinit
10)    1           0.21     0.21    0.42%      0.08     0.08    0.16%  complete
11)    2           0.02     0.01    0.05%      0.02     0.01    0.05%  __sdkman_echo_debug

I recommend either

improve __sdkman_export_candidate_home and __sdkman_prepend_candidate_to_path by most efficient way in each shell

Generate following script when candidates dir is updated and load it in sdkman-init

export JAVA_HOME=${SDKMAN_CANDIDATES_DIR}/java/bin
export PATH="$JAVA_HOME:$PATH"
...

(however, seems the original post only contains 3 candidates are installed. so maybe WSL is just slow. maybe tr and grep is slow in WSL because of some virtual layer. it may be helpful for WSL too)

jqno commented 1 month ago

FWIW, I ran into the same issue and found out you can also lazy-load SDKman:

export SDKMAN_DIR="$HOME/.sdkman"
sdk() {
  unset -f sdk
  [[ -s "$SDKMAN_DIR/bin/sdkman-init.sh" ]] && source "$SDKMAN_DIR/bin/sdkman-init.sh"
  sdk "$@"
}

This will basically wrap the sdk function that the init script defines, in another function with the same name that first loads SDKman, and then delegates back to the original function. It makes SDKman a bit slower to invoke, but I do that waaaay less often than that I start a new shell session.

sdkman / sdkman-cli

Bug: Slow startup/init in ZSH #977