Skip to main content

⏲ Benchmarking

info

Run zi analytics to see the available ZI sub-commands for statistics and information.

Profile plugins​

~/.zshrc
zi ice atinit'zmodload zsh/zprof' \  atload'zprof | head -n 20; zmodload -u zsh/zprof'zi light z-shell/F-Sy-H
SyntaxDescription
atinit'…'loads the zsh/zprof module, shipped with Zsh, before loading the plugin – this starts the profiling.
atload'…'works after loading the plugin – shows profiling results zprof / head, unloads zsh/zprof - this stops the profiling.

While in effect, only a single plugin, in this case, z-shell/F-Sy-H, will be profiled.

The rest plugins will go on completely normally, as when plugins are loaded with light - reporting is disabled.

Less code is being run in the background, the automatic data gathering, during loading of a plugin, for the reports and the possibility to unload the plugin will be activated and the functions will not appear in the zprof report.

  • Example zprof report:
zprof
num calls    time                self                 name--------------------------------------------------------------------------- 1)  1 57,76 57,76 57,91%  57,76 57,76 57,91% _zsh_highlight_bind_widgets 2)  1 25,81 25,81 25,88%  25,81 25,81 25,88% compinit 3)  4 10,71  2,68 10,74%   8,71  2,18  8,73% --zi-shadow-autoload 4) 43  2,06  0,05  2,07%   2,06  0,05  2,07% -zi-add-report 5)  8  1,98  0,25  1,98%   1,98  0,25  1,98% compdef 6)  1  2,85  2,85  2,85%   0,87  0,87  0,87% -zi-compdef-replay 7)  1  0,68  0,68  0,68%   0,68  0,68  0,68% -zi-shadow-off 8)  1  0,79  0,79  0,79%   0,49  0,49  0,49% add-zsh-hook 9)  1  0,47  0,47  0,47%   0,47  0,47  0,47% -zi-shadow-on1)   3  0,34  0,11  0,35%   0,34  0,11  0,35% (anon)2)   4 10,91  2,73 10,94%   0,20  0,05  0,20% autoload3)   1  0,19  0,19  0,19%   0,19  0,19  0,19% -fast-highlight-fill-option-variables4)   1 25,98 25,98 26,05%   0,17  0,17  0,17% zpcompinit5)   1  2,88  2,88  2,89%   0,03  0,03  0,03% zpcdreplay6)   1  0,00  0,00  0,00%   0,00  0,00  0,00% -zi-load-plugin-----------------------------------------------------------------------------------

  • The first column is the time in milliseconds:

    • It denotes the amount of time spent in a function in total.
    • For example, --zi-shadow-autoload consumed 10.71 ms of the execution time,

  • The fourth column is also a time in milliseconds, but it denotes the amount of time spent on executing only of function's own code, it doesn't count the time spent in descendant functions that are called from the function;

    • For example, --zi-shadow-autoload spent 8.71 ms on executing only its code.

  • The table is sorted in the self-time column.

Profile .zshrc startup​

Method 1​

PROFILE_STARTUP=true to enable profiling.

Place snippet below at the top of .zshrc.

~/.zshrc
PROFILE_STARTUP=falseif [[ "$PROFILE_STARTUP" == true ]]; then  zmodload zsh/zprof  PS4=$'%D{%M%S%.} %N:%i> '  exec 3>&2 2>$HOME/startlog.$$  setopt xtrace prompt_substfi
PS4 Prompt Expansion

Zsh Sourceforge docs: Prompt Expansion

Place at the bottom of .zshrc

~/.zshrc
if [[ "$PROFILE_STARTUP" == true ]]; then  unsetopt xtrace  exec 2>&3 3>&-; zprof > ~/zshprofile$(date +'%s')fi

The next time your .zshrc is sourced it will generate 2 files in the $HOME directory.

Method 2​

Store multiple values to a variable:

~/.zshrc
# Set variabletypeset -Ag ZLOGS# Message to storezmsg() { ZLOGS+=( "\n[$1]: ${(M)$(( SECONDS * 1000 ))#*.?} ms" ); }# Start profilingtypeset -F4 SECONDS=0# <RUN SOME FUNCTIONS TO MEASURE>zmsg "Loaded functions"# <RUN SOMETHING ELSE>zmsg "Loaded something else"# <THE FINAL CODEBLOCK HERE>zmsg "Done"

Then use the $ZLOGS variable to retrieve:

❯ echo $ZLOGS[Loaded functions]: 0.0 ms[Loaded something else]: 0.0 ms[Done]: 0.1 ms