Re: profile prompt rendering time

["Nikolay Aleksandrovich Pavlov (ZyX)" <kp-pav@xxxxxxxxx>]

It is rather strange to see this discussion. I would read OP post as “I installed some plugin and as the result prompt rendering appears to be slow, I need to determine *what* is slow”… up until he said explicitly “when i hit enter, start counting <…> stop counting when this prompt appears. show me elapsed time”. I have no idea how determining total execution time is going to help with slow prompt: this should change ones knowledge from “I see that prompt is slow” to “I see that prompt is slow, specifically it takes N seconds to appear”.

If OP wants more practial answer I can suggest to use `set -x`, `float SECONDS` and `PS4='+%N:%i|$SECONDS> '` with `setopt promptsubst`. E.g.:

```
(float SECONDS; PS4='+%N:%i|$SECONDS> '; setopt promptsubst; PS1='$(sleep 5)' ; set -x; echo -n; print -P "${PS1}"; echo -n)
+/bin/zsh:237|9.894828127e+05> echo -n
+/bin/zsh:237|9.894828129e+05> print -P '$(sleep 5)'
+/bin/zsh:237|9.894828156e+05> sleep 5

+/bin/zsh:237|9.894878230e+05> echo -n
```

if you are sure that problem is exactly in PS1. If not

```
% zsh
%% float SECONDS
%% setopt promptsubst
%% PS4='+%N:%i|$SECONDS> '
%% set -x
%% exit
```

For me this is giving something like

```
+term_reset:2|5.749184800e+01> emulate -L zsh                                                                                                                                                                                                  
+term_reset:3|5.749191200e+01> [[ -n /dev/pts/8 ]]                                                                                                                                                                                             
+term_reset:3|5.749194000e+01> ((  1  ))                                                                                                                                                                                                       
+term_reset:4|5.749214300e+01> _echoti rmacs                                                                                                                                                                                                   
+_echoti:2|5.749222300e+01> emulate -L zsh                                                                                                                                                                                                     
+_echoti:3|5.749227700e+01> ((  1  ))                                                                                                                                                                                                          
+_echoti:3|5.749231100e+01> echoti rmacs                                                                                                                                                                                                       
+term_reset:5|5.749236900e+01> _echoti sgr0                                                                                                                                                                                                    
+_echoti:2|5.749239800e+01> emulate -L zsh                                                                                                                                                                                                     
+_echoti:3|5.749242700e+01> ((  1  ))                                                                                                                                                                                                          
+_echoti:3|5.749245600e+01> echoti sgr0                                                                                                                                                                                                        
+term_reset:6|5.749250600e+01> _echoti cnorm
+_echoti:2|5.749253400e+01> emulate -L zsh
+_echoti:3|5.749256300e+01> ((  1  ))
+_echoti:3|5.749259200e+01> echoti cnorm
+term_reset:7|5.749264300e+01> _echoti smkx
+_echoti:2|5.749267200e+01> emulate -L zsh
+_echoti:3|5.749270000e+01> ((  1  ))
+_echoti:3|5.749272800e+01> echoti smkx
+term_reset:8|5.749277700e+01> echo -n ''
+_powerline_set_jobnum:11|5.749283300e+01> _POWERLINE_JOBNUM=0 
+_powerline_update_counter:1|5.749287800e+01> zpython '_powerline.precmd()'
+_powerline_set_main_keymap_name:1|5.749309500e+01> local REPLY
+_powerline_set_main_keymap_name:2|5.749313100e+01> _powerline_get_main_keymap_name
+_powerline_get_main_keymap_name:1|5.749315900e+01> REPLY=+_powerline_get_main_keymap_name:1|5.749467000e+01> bindkey -lL main
+_powerline_get_main_keymap_name:1|5.749315900e+01> REPLY=evi 
+_powerline_set_main_keymap_name:3|5.749628400e+01> _powerline_set_true_keymap_name evi
+_powerline_set_true_keymap_name:1|5.749633100e+01> _POWERLINE_MODE=evi 
+_powerline_set_true_keymap_name:2|5.749807400e+01> bindkey -lL evi
+_powerline_set_true_keymap_name:2|5.750009900e+01> local plm_bk='bindkey -N evi'
+_powerline_set_true_keymap_name:3|5.750017900e+01> [[ 'bindkey -N evi' == bindkey\ -A* ]]
```

which needs some post-processing to actually be useful. But if there are not much commands this output may be reviewed manually.

Quick google:“profile zsh scripts” shows that there are people also using similar approach and have already written everything necessary to do real profiling: http://blog.xebia.com/profiling-zsh-shell-scripts/. Post also mentiones zprof.