⏲ Benchmarking
Run zi analytics
to see the available ZI sub-commands for statistics and information.
Profile plugins
zi ice atinit'zmodload zsh/zprof' \ atload'zprof | head -n 20; zmodload -u zsh/zprof'zi light z-shell/F-Sy-H
Syntax | Description |
---|---|
atinit'…' | loads thezsh/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:
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.
- For example,
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
.
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
Zsh Sourceforge docs: Prompt Expansion
Place at the bottom of .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:
# 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