⏲ ベンチマーク
統計およびレポートに使用可能なコマンドを表示するには、 zi analytics を実行します。
プラグインをプロファイルする
zi ice atinit'zmodload zsh/zprof' \
atload'zprof | head -n 20; zmodload -u zsh/zprof'
zi light z-shell/F-Sy-H
| 構文 | 説明 |
|---|---|
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:
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-on
10) 3 0,34 0,11 0,35% 0,34 0,11 0,35% (anon)
11) 4 10,91 2,73 10,94% 0,20 0,05 0,20% autoload
12) 1 0,19 0,19 0,19% 0,19 0,19 0,19% -fast-highlight-fill-option-variables
13) 1 25,98 25,98 26,05% 0,17 0,17 0,17% zicompinit
14) 1 2,88 2,88 2,89% 0,03 0,03 0,03% zicdreplay
15) 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-autoloadconsumed 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 is called from the function:
- For example,
--zi-shadow-autoloadspent 8.71 ms on executing only its code
The table is sorted in the self-time column.
.zshrc起動時のプロファイル
方法1
PROFILE_STARTUP=trueでプロファイリングを有効にします。
以下を .zshrc の最上部に配置します。
PROFILE_STARTUP=false
if [[ "$PROFILE_STARTUP" == true ]]; then
zmodload zsh/zprof
PS4=$'%D{%M%S%.} %N:%i> '
exec 3>&2 2>$HOME/startlog.$$
setopt xtrace prompt_subst
fi
Zsh Sourceforge docs: プロンプトの展開
.zshrcの最下部に配置します。
if [[ "$PROFILE_STARTUP" == true ]]; then
unsetopt xtrace
exec 2>&3 3>&-; zprof > ~/zshprofile$(date +'%s')
fi
次回 .zshrcがロードされるとき、2つのファイルが$HOME ディレクトリ以下に生成されます。
方法2
Store multiple values to a variable:
# Set variable
typeset -Ag ZLOGS
# Message to store
zmsg() { ZLOGS+=( "\n[$1]: ${(M)$(( SECONDS * 1000 ))#*.?} ms" ); }
# Start profiling
typeset -F4 SECONDS=0
# <RUN SOME FUNCTIONS TO MEASURE>
zmsg "Loaded functions"
# <RUN SOMETHING ELSE>
zmsg "Loaded something else"
# <THE FINAL CODE BLOCK HERE>
zmsg "Done"
Then use the $ZLOGS variable to retrieve:
[Loaded functions]: 0.0 ms
[Loaded something else]: 0.0 ms
[Done]: 0.1 ms