Patch 8.2.4712
Problem: Only get profiling information after exiting.
Solution: Add "profile dump" and "profile stop". (Marco Hinz, Yegappan
Lakshmanan, closes #10107)
Files: runtime/doc/repeat.txt, src/profiler.c,
src/testdir/test_profile.vim
*** ../vim-8.2.4711/runtime/doc/repeat.txt 2022-03-22 12:13:49.147376718
+0000
--- runtime/doc/repeat.txt 2022-04-08 13:21:03.134823741 +0100
***************
*** 1007,1024 ****
:prof[ile] start {fname} *:prof* *:profile* *E750*
! Start profiling, write the output in {fname} upon exit.
"~/" and environment variables in {fname} will be expanded.
If {fname} already exists it will be silently overwritten.
The variable |v:profiling| is set to one.
:prof[ile] pause
! Don't profile until the following ":profile continue". Can be
used when doing something that should not be counted (e.g., an
external command). Does not nest.
:prof[ile] continue
! Continue profiling after ":profile pause".
:prof[ile] func {pattern}
Profile function that matches the pattern {pattern}.
--- 1043,1066 ----
:prof[ile] start {fname} *:prof* *:profile* *E750*
! Start profiling, write the output in {fname} upon exit or when
! a `:profile stop` or `:profile dump` command is invoked.
"~/" and environment variables in {fname} will be expanded.
If {fname} already exists it will be silently overwritten.
The variable |v:profiling| is set to one.
+ :prof[ile] stop
+ Write the collected profiling information to the logfile and
+ stop profiling. You can use the `:profile start` command to
+ clear the profiling statistics and start profiling again.
+
:prof[ile] pause
! Don't profile until the following `:profile continue`. Can be
used when doing something that should not be counted (e.g., an
external command). Does not nest.
:prof[ile] continue
! Continue profiling after `:profile pause`.
:prof[ile] func {pattern}
Profile function that matches the pattern {pattern}.
***************
*** 1035,1045 ****
after this command. A :profile command in the script itself
won't work.
:profd[el] ... *:profd*
*:profdel*
Stop profiling for the arguments specified. See |:breakdel|
! for the arguments.
!
You must always start with a ":profile start fname" command. The resulting
file is written when Vim exits. For example, to profile one specific
--- 1077,1093 ----
after this command. A :profile command in the script itself
won't work.
+ :prof[ile] dump
+ Write the current state of profiling to the logfile
+ immediately. After running this command, Vim continues to
+ collect the profiling statistics.
:profd[el] ... *:profd*
*:profdel*
Stop profiling for the arguments specified. See |:breakdel|
! for the arguments. Examples: >
! profdel func MyFunc
! profdel file MyScript.vim
! profdel here
You must always start with a ":profile start fname" command. The resulting
file is written when Vim exits. For example, to profile one specific
*** ../vim-8.2.4711/src/profiler.c 2022-03-15 10:53:01.547462727 +0000
--- src/profiler.c 2022-04-08 13:15:22.031023805 +0100
***************
*** 299,304 ****
--- 299,380 ----
static proftime_T pause_time;
/*
+ * Reset all profiling information.
+ */
+ static void
+ profile_reset(void)
+ {
+ int id;
+ int todo;
+ hashtab_T *functbl;
+ hashitem_T *hi;
+
+ // Reset sourced files.
+ for (id = 1; id <= script_items.ga_len; id++)
+ {
+ scriptitem_T *si = SCRIPT_ITEM(id);
+ if (si->sn_prof_on)
+ {
+ si->sn_prof_on = FALSE;
+ si->sn_pr_force = FALSE;
+ profile_zero(&si->sn_pr_child);
+ si->sn_pr_nest = 0;
+ si->sn_pr_count = 0;
+ profile_zero(&si->sn_pr_total);
+ profile_zero(&si->sn_pr_self);
+ profile_zero(&si->sn_pr_start);
+ profile_zero(&si->sn_pr_children);
+ ga_clear(&si->sn_prl_ga);
+ profile_zero(&si->sn_prl_start);
+ profile_zero(&si->sn_prl_children);
+ profile_zero(&si->sn_prl_wait);
+ si->sn_prl_idx = -1;
+ si->sn_prl_execed = 0;
+ }
+ }
+
+ // Reset functions.
+ functbl = func_tbl_get();
+ todo = (int)functbl->ht_used;
+
+ for (hi = functbl->ht_array; todo > 0; ++hi)
+ {
+ ufunc_T *fp;
+ int i;
+
+ if (HASHITEM_EMPTY(hi))
+ continue;
+
+ todo--;
+ fp = HI2UF(hi);
+ if (fp->uf_prof_initialized)
+ {
+ fp->uf_profiling = 0;
+ fp->uf_prof_initialized = FALSE;
+ fp->uf_tm_count = 0;
+ profile_zero(&fp->uf_tm_total);
+ profile_zero(&fp->uf_tm_self);
+ profile_zero(&fp->uf_tm_children);
+
+ for (i = 0; i < fp->uf_lines.ga_len; i++)
+ {
+ fp->uf_tml_count[i] = 0;
+ profile_zero(&fp->uf_tml_total[i]);
+ profile_zero(&fp->uf_tml_self[i]);
+ }
+
+ profile_zero(&fp->uf_tml_start);
+ profile_zero(&fp->uf_tml_children);
+ profile_zero(&fp->uf_tml_wait);
+ fp->uf_tml_idx = -1;
+ fp->uf_tml_execed = 0;
+ }
+ }
+
+ VIM_CLEAR(profile_fname);
+ }
+
+ /*
* ":profile cmd args"
*/
void
***************
*** 313,319 ****
if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL)
{
! vim_free(profile_fname);
profile_fname = expand_env_save_opt(e, TRUE);
do_profiling = PROF_YES;
profile_zero(&prof_wait_time);
--- 389,395 ----
if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL)
{
! VIM_CLEAR(profile_fname);
profile_fname = expand_env_save_opt(e, TRUE);
do_profiling = PROF_YES;
profile_zero(&prof_wait_time);
***************
*** 321,326 ****
--- 397,409 ----
}
else if (do_profiling == PROF_NONE)
emsg(_(e_first_use_profile_start_fname));
+ else if (STRCMP(eap->arg, "stop") == 0)
+ {
+ profile_dump();
+ do_profiling = PROF_NONE;
+ set_vim_var_nr(VV_PROFILING, 0L);
+ profile_reset();
+ }
else if (STRCMP(eap->arg, "pause") == 0)
{
if (do_profiling == PROF_YES)
***************
*** 336,341 ****
--- 419,426 ----
}
do_profiling = PROF_YES;
}
+ else if (STRCMP(eap->arg, "dump") == 0)
+ profile_dump();
else
{
// The rest is similar to ":breakadd".
***************
*** 353,368 ****
static char *pexpand_cmds[] = {
"start",
#define PROFCMD_START 0
"pause",
! #define PROFCMD_PAUSE 1
"continue",
! #define PROFCMD_CONTINUE 2
"func",
! #define PROFCMD_FUNC 3
"file",
! #define PROFCMD_FILE 4
NULL
! #define PROFCMD_LAST 5
};
/*
--- 438,457 ----
static char *pexpand_cmds[] = {
"start",
#define PROFCMD_START 0
+ "stop",
+ #define PROFCMD_STOP 1
"pause",
! #define PROFCMD_PAUSE 2
"continue",
! #define PROFCMD_CONTINUE 3
"func",
! #define PROFCMD_FUNC 4
"file",
! #define PROFCMD_DUMP 5
! "dump",
! #define PROFCMD_FILE 6
NULL
! #define PROFCMD_LAST 7
};
/*
*** ../vim-8.2.4711/src/testdir/test_profile.vim 2022-03-15
10:53:01.551462719 +0000
--- src/testdir/test_profile.vim 2022-04-08 13:15:22.031023805 +0100
***************
*** 428,436 ****
call delete('Xprofile_file.log')
endfunc
func Test_profile_completion()
call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
! call assert_equal('"profile continue file func pause start', @:)
call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
call assert_match('^"profile start.* test_profile\.vim', @:)
--- 428,530 ----
call delete('Xprofile_file.log')
endfunc
+ " Test for ':profile stop' and ':profile dump' commands
+ func Test_profile_stop_dump()
+ call delete('Xprof1.out')
+ call delete('Xprof2.out')
+ call delete('Xprof3.out')
+ func Xprof_test1()
+ return "Hello"
+ endfunc
+ func Xprof_test2()
+ return "World"
+ endfunc
+
+ " Test for ':profile stop'
+ profile start Xprof1.out
+ profile func Xprof_test1
+ call Xprof_test1()
+ profile stop
+
+ let lines = readfile('Xprof1.out')
+ call assert_equal(17, len(lines))
+ call assert_equal('FUNCTION Xprof_test1()', lines[0])
+ call assert_match('Defined:.*test_profile.vim:', lines[1])
+ call assert_equal('Called 1 time', lines[2])
+ call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
+ call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
+ call assert_equal('', lines[5])
+ call assert_equal('count total (s) self (s)', lines[6])
+ call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7])
+ call assert_equal('', lines[8])
+ call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[9])
+ call assert_equal('count total (s) self (s) function', lines[10])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[11])
+ call assert_equal('', lines[12])
+ call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[13])
+ call assert_equal('count total (s) self (s) function', lines[14])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[15])
+ call assert_equal('', lines[16])
+
+ " Test for ':profile stop' for a different function
+ profile start Xprof2.out
+ profile func Xprof_test2
+ call Xprof_test2()
+ profile stop
+ let lines = readfile('Xprof2.out')
+ call assert_equal(17, len(lines))
+ call assert_equal('FUNCTION Xprof_test2()', lines[0])
+ call assert_match('Defined:.*test_profile.vim:', lines[1])
+ call assert_equal('Called 1 time', lines[2])
+ call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
+ call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
+ call assert_equal('', lines[5])
+ call assert_equal('count total (s) self (s)', lines[6])
+ call assert_match('^\s*1\s\+.*\sreturn "World"$', lines[7])
+ call assert_equal('', lines[8])
+ call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[9])
+ call assert_equal('count total (s) self (s) function', lines[10])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$', lines[11])
+ call assert_equal('', lines[12])
+ call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[13])
+ call assert_equal('count total (s) self (s) function', lines[14])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test2()$', lines[15])
+ call assert_equal('', lines[16])
+
+ " Test for ':profile dump'
+ profile start Xprof3.out
+ profile func Xprof_test1
+ profile func Xprof_test2
+ call Xprof_test1()
+ profile dump
+ " dump the profile once and verify the contents
+ let lines = readfile('Xprof3.out')
+ call assert_equal(17, len(lines))
+ call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[11])
+ call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Xprof_test1()$', lines[15])
+ " dump the profile again and verify the contents
+ call Xprof_test2()
+ profile dump
+ profile stop
+ let lines = readfile('Xprof3.out')
+ call assert_equal(28, len(lines))
+ call assert_equal('FUNCTION Xprof_test1()', lines[0])
+ call assert_match('^\s*1\s\+.*\sreturn "Hello"$', lines[7])
+ call assert_equal('FUNCTION Xprof_test2()', lines[9])
+ call assert_match('^\s*1\s\+.*\sreturn "World"$', lines[16])
+
+ delfunc Xprof_test1
+ delfunc Xprof_test2
+ call delete('Xprof1.out')
+ call delete('Xprof2.out')
+ call delete('Xprof3.out')
+ endfunc
+
+ " Test for :profile sub-command completion
func Test_profile_completion()
call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
! call assert_equal('"profile continue dump file func pause start stop', @:)
call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
call assert_match('^"profile start.* test_profile\.vim', @:)
***************
*** 481,486 ****
--- 575,582 ----
call assert_fails("profile func Foo", 'E750:')
call assert_fails("profile pause", 'E750:')
call assert_fails("profile continue", 'E750:')
+ call assert_fails("profile stop", 'E750:')
+ call assert_fails("profile dump", 'E750:')
endfunc
func Test_profile_truncate_mbyte()
*** ../vim-8.2.4711/src/version.c 2022-04-08 11:56:09.179436450 +0100
--- src/version.c 2022-04-08 13:17:11.730967517 +0100
***************
*** 748,749 ****
--- 748,751 ----
{ /* Add new patch number below this line */
+ /**/
+ 4712,
/**/
--
The chat program is in public domain. This is not the GNU public license.
If it breaks then you get to keep both pieces.
-- Copyright notice for the chat program
/// Bram Moolenaar -- [email protected] -- http://www.Moolenaar.net \\\
/// \\\
\\\ sponsor Vim, vote for features -- http://www.Vim.org/sponsor/ ///
\\\ help me help AIDS victims -- http://ICCF-Holland.org ///
--
--
You received this message from the "vim_dev" maillist.
Do not top-post! Type your reply below the text you are replying to.
For more information, visit http://www.vim.org/maillist.php
---
You received this message because you are subscribed to the Google Groups
"vim_dev" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to [email protected].
To view this discussion on the web visit
https://groups.google.com/d/msgid/vim_dev/20220408122516.5EA061C0AF6%40moolenaar.net.
