From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 21071 invoked by alias); 14 Jul 2016 00:35:02 -0000 Mailing-List: contact zsh-users-help@zsh.org; run by ezmlm Precedence: bulk X-No-Archive: yes List-Id: Zsh Users List List-Post: List-Help: X-Seq: 21773 Received: (qmail 15121 invoked from network); 14 Jul 2016 00:35:02 -0000 X-Qmail-Scanner-Diagnostics: from forward2p.cmail.yandex.net by f.primenet.com.au (envelope-from , uid 7791) with qmail-scanner-2.11 (clamdscan: 0.99.2/21882. spamassassin: 3.4.1. Clear:RC:0(77.88.31.17):SA:0(0.0/5.0):. Processed in 0.244986 secs); 14 Jul 2016 00:35:02 -0000 X-Spam-Checker-Version: SpamAssassin 3.4.1 (2015-04-28) on f.primenet.com.au X-Spam-Level: X-Spam-Status: No, score=0.0 required=5.0 tests=FREEMAIL_FROM,SPF_PASS, T_DKIM_INVALID autolearn=unavailable autolearn_force=no version=3.4.1 X-Envelope-From: kp-pav@yandex.ru X-Qmail-Scanner-Mime-Attachments: | X-Qmail-Scanner-Zip-Files: | Received-SPF: pass (ns1.primenet.com.au: SPF record at _spf-ipv4.yandex.ru designates 77.88.31.17 as permitted sender) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=yandex.ru; s=mail; t=1468456126; bh=odPN295DihOUT/7Y4tgnlAotzNOmtkYHAXi5DPSnryM=; h=From:To:In-Reply-To:References:Subject:Message-Id:Date; b=aTe13BvxmkMgSKQWuaPT7GjQq81wQXXh8dpHKXRIQo59IgOM5vy93tI61GxFIoDxE jS5KiJ8//vmqa9h/4JJ/xMg+aPN0fnK8uukUxTMKG6vMiGfqWsmsZu65O1T5yvushO YYeNyNzc9trjS/KmhS4XUqJ4hya77QkSqVeqsYmE= Authentication-Results: mxback2g.mail.yandex.net; dkim=pass header.i=@yandex.ru From: "Nikolay Aleksandrovich Pavlov (ZyX)" To: Bart Schaefer , "zsh-users@zsh.org" In-Reply-To: <160713164905.ZM22329@torch.brasslantern.com> References: <20160713213713.GB75349@xenia> <160713164905.ZM22329@torch.brasslantern.com> Subject: Re: profile prompt rendering time MIME-Version: 1.0 Message-Id: <9161468456126@web27g.yandex.ru> X-Mailer: Yamail [ http://yandex.ru ] 5.0 Date: Thu, 14 Jul 2016 03:28:46 +0300 Content-Transfer-Encoding: 8bit Content-Type: text/plain; charset=utf-8 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.