:prof[ile] start {fname} *:prof* *:profile* *E750*
- Start profiling, write the output in {fname} upon exit.
+ 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
+ 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".
+ Continue profiling after `:profile pause`.
:prof[ile] func {pattern}
Profile function that matches the pattern {pattern}.
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.
-
+ 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
static char_u *profile_fname = NULL;
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"
*/
if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL)
{
- vim_free(profile_fname);
+ VIM_CLEAR(profile_fname);
profile_fname = expand_env_save_opt(e, TRUE);
do_profiling = PROF_YES;
profile_zero(&prof_wait_time);
}
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)
}
do_profiling = PROF_YES;
}
+ else if (STRCMP(eap->arg, "dump") == 0)
+ profile_dump();
else
{
// The rest is similar to ":breakadd".
static char *pexpand_cmds[] = {
"start",
#define PROFCMD_START 0
+ "stop",
+#define PROFCMD_STOP 1
"pause",
-#define PROFCMD_PAUSE 1
+#define PROFCMD_PAUSE 2
"continue",
-#define PROFCMD_CONTINUE 2
+#define PROFCMD_CONTINUE 3
"func",
-#define PROFCMD_FUNC 3
+#define PROFCMD_FUNC 4
"file",
-#define PROFCMD_FILE 4
+#define PROFCMD_DUMP 5
+ "dump",
+#define PROFCMD_FILE 6
NULL
-#define PROFCMD_LAST 5
+#define PROFCMD_LAST 7
};
/*
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 file func pause start', @:)
+ 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', @:)
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()
projects / vim / commitdiff