aboutsummaryrefslogtreecommitdiff
diff options
context:
space:
mode:
-rw-r--r--src/nvim/eval.c49
-rw-r--r--src/nvim/eval/typval.h1
-rw-r--r--src/nvim/testdir/test_profile.vim100
3 files changed, 114 insertions, 36 deletions
diff --git a/src/nvim/eval.c b/src/nvim/eval.c
index 988435fd19..54c469fabf 100644
--- a/src/nvim/eval.c
+++ b/src/nvim/eval.c
@@ -5871,10 +5871,6 @@ static int get_lambda_tv(char_u **arg, typval_T *rettv, bool evaluate)
fp->uf_scoped = NULL;
}
- fp->uf_tml_count = NULL;
- fp->uf_tml_total = NULL;
- fp->uf_tml_self = NULL;
- fp->uf_profiling = false;
if (prof_def_func()) {
func_do_profile(fp);
}
@@ -21628,25 +21624,29 @@ static void func_do_profile(ufunc_T *fp)
{
int len = fp->uf_lines.ga_len;
- if (len == 0)
- len = 1; /* avoid getting error for allocating zero bytes */
- fp->uf_tm_count = 0;
- fp->uf_tm_self = profile_zero();
- fp->uf_tm_total = profile_zero();
+ if (!fp->uf_prof_initialized) {
+ if (len == 0) {
+ len = 1; // avoid getting error for allocating zero bytes
+ }
+ fp->uf_tm_count = 0;
+ fp->uf_tm_self = profile_zero();
+ fp->uf_tm_total = profile_zero();
- if (fp->uf_tml_count == NULL) {
- fp->uf_tml_count = xcalloc(len, sizeof(int));
- }
+ if (fp->uf_tml_count == NULL) {
+ fp->uf_tml_count = xcalloc(len, sizeof(int));
+ }
- if (fp->uf_tml_total == NULL) {
- fp->uf_tml_total = xcalloc(len, sizeof(proftime_T));
- }
+ if (fp->uf_tml_total == NULL) {
+ fp->uf_tml_total = xcalloc(len, sizeof(proftime_T));
+ }
- if (fp->uf_tml_self == NULL) {
- fp->uf_tml_self = xcalloc(len, sizeof(proftime_T));
- }
+ if (fp->uf_tml_self == NULL) {
+ fp->uf_tml_self = xcalloc(len, sizeof(proftime_T));
+ }
- fp->uf_tml_idx = -1;
+ fp->uf_tml_idx = -1;
+ fp->uf_prof_initialized = true;
+ }
fp->uf_profiling = TRUE;
}
@@ -21672,7 +21672,7 @@ void func_dump_profile(FILE *fd)
if (!HASHITEM_EMPTY(hi)) {
--todo;
fp = HI2UF(hi);
- if (fp->uf_profiling) {
+ if (fp->uf_prof_initialized) {
sorttab[st_len++] = fp;
if (fp->uf_name[0] == K_SPECIAL)
@@ -22174,6 +22174,7 @@ void call_user_func(ufunc_T *fp, int argcount, typval_T *argvars,
char_u *name;
proftime_T wait_start;
proftime_T call_start;
+ int started_profiling = false;
bool did_save_redo = false;
save_redo_T save_redo;
@@ -22393,8 +22394,10 @@ void call_user_func(ufunc_T *fp, int argcount, typval_T *argvars,
do_profiling_yes
&& !fp->uf_profiling && has_profiling(false, fp->uf_name, NULL);
- if (func_not_yet_profiling_but_should)
+ if (func_not_yet_profiling_but_should) {
+ started_profiling = true;
func_do_profile(fp);
+ }
bool func_or_func_caller_profiling =
do_profiling_yes
@@ -22442,6 +22445,10 @@ void call_user_func(ufunc_T *fp, int argcount, typval_T *argvars,
fc->caller->func->uf_tml_children =
profile_add(fc->caller->func->uf_tml_children, call_start);
}
+ if (started_profiling) {
+ // make a ":profdel func" stop profiling the function
+ fp->uf_profiling = false;
+ }
}
/* when being verbose, mention the return value */
diff --git a/src/nvim/eval/typval.h b/src/nvim/eval/typval.h
index e99289c430..5c0f872b38 100644
--- a/src/nvim/eval/typval.h
+++ b/src/nvim/eval/typval.h
@@ -260,6 +260,7 @@ struct ufunc {
garray_T uf_args; ///< arguments
garray_T uf_lines; ///< function lines
int uf_profiling; ///< true when func is being profiled
+ int uf_prof_initialized;
// Profiling the function as a whole.
int uf_tm_count; ///< nr of calls
proftime_T uf_tm_total; ///< time spent in function + children
diff --git a/src/nvim/testdir/test_profile.vim b/src/nvim/testdir/test_profile.vim
index 8996e86b43..1aa4d5eaf8 100644
--- a/src/nvim/testdir/test_profile.vim
+++ b/src/nvim/testdir/test_profile.vim
@@ -5,6 +5,8 @@ endif
func Test_profile_func()
let lines = [
+ \ 'profile start Xprofile_func.log',
+ \ 'profile func Foo*"',
\ "func! Foo1()",
\ "endfunc",
\ "func! Foo2()",
@@ -33,9 +35,7 @@ func Test_profile_func()
call writefile(lines, 'Xprofile_func.vim')
call system(v:progpath
- \ . ' -es -u NONE -U NONE -i NONE --noplugin'
- \ . ' -c "profile start Xprofile_func.log"'
- \ . ' -c "profile func Foo*"'
+ \ . ' -es --clean'
\ . ' -c "so Xprofile_func.vim"'
\ . ' -c "qall!"')
call assert_equal(0, v:shell_error)
@@ -97,7 +97,7 @@ func Test_profile_file()
call writefile(lines, 'Xprofile_file.vim')
call system(v:progpath
- \ . ' -es -u NONE -U NONE -i NONE --noplugin'
+ \ . ' -es --clean'
\ . ' -c "profile start Xprofile_file.log"'
\ . ' -c "profile file Xprofile_file.vim"'
\ . ' -c "so Xprofile_file.vim"'
@@ -152,17 +152,17 @@ func Test_profile_file_with_cont()
let lines = readfile('Xprofile_file.log')
call assert_equal(11, len(lines))
- call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
- call assert_equal('Sourced 1 time', lines[1])
- call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
- call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
- call assert_equal('', lines[4])
- call assert_equal('count total (s) self (s)', lines[5])
- call assert_match(' 1 0.\d\+ echo "hello', lines[6])
- call assert_equal(' \ world"', lines[7])
- call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
- call assert_equal(' \bar"', lines[9])
- call assert_equal('', lines[10])
+ call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
+ call assert_equal('Sourced 1 time', lines[1])
+ call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
+ call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
+ call assert_equal('', lines[4])
+ call assert_equal('count total (s) self (s)', lines[5])
+ call assert_match(' 1 0.\d\+ echo "hello', lines[6])
+ call assert_equal(' \ world"', lines[7])
+ call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
+ call assert_equal(' \bar"', lines[9])
+ call assert_equal('', lines[10])
call delete('Xprofile_file.vim')
call delete('Xprofile_file.log')
@@ -222,3 +222,73 @@ func Test_profile_truncate_mbyte()
call delete('Xprofile_file.vim')
call delete('Xprofile_file.log')
endfunc
+
+func Test_profdel_func()
+ let lines = [
+ \ 'profile start Xprofile_file.log',
+ \ 'func! Foo1()',
+ \ 'endfunc',
+ \ 'func! Foo2()',
+ \ 'endfunc',
+ \ 'func! Foo3()',
+ \ 'endfunc',
+ \ '',
+ \ 'profile func Foo1',
+ \ 'profile func Foo2',
+ \ 'call Foo1()',
+ \ 'call Foo2()',
+ \ '',
+ \ 'profile func Foo3',
+ \ 'profdel func Foo2',
+ \ 'profdel func Foo3',
+ \ 'call Foo1()',
+ \ 'call Foo2()',
+ \ 'call Foo3()' ]
+ call writefile(lines, 'Xprofile_file.vim')
+ call system(v:progpath . ' -es --clean -c "so Xprofile_file.vim" -c q')
+ call assert_equal(0, v:shell_error)
+
+ let lines = readfile('Xprofile_file.log')
+ call assert_equal(24, len(lines))
+
+ " Check that:
+ " - Foo1() is called twice (profdel not invoked)
+ " - Foo2() is called once (profdel invoked after it was called)
+ " - Foo3() is not called (profdel invoked before it was called)
+ call assert_equal('FUNCTION Foo1()', lines[0])
+ call assert_equal('Called 2 times', lines[1])
+ call assert_equal('FUNCTION Foo2()', lines[7])
+ call assert_equal('Called 1 time', lines[8])
+ call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[14])
+ call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[19])
+
+ call delete('Xprofile_file.vim')
+ call delete('Xprofile_file.log')
+endfunc
+
+func Test_profdel_star()
+ " Foo() is invoked once before and once after 'profdel *'.
+ " So profiling should report it only once.
+ let lines = [
+ \ 'profile start Xprofile_file.log',
+ \ 'func! Foo()',
+ \ 'endfunc',
+ \ 'profile func Foo',
+ \ 'call Foo()',
+ \ 'profdel *',
+ \ 'call Foo()' ]
+ call writefile(lines, 'Xprofile_file.vim')
+ call system(v:progpath . ' -es --clean -c "so Xprofile_file.vim" -c q')
+ call assert_equal(0, v:shell_error)
+
+ let lines = readfile('Xprofile_file.log')
+ call assert_equal(15, len(lines))
+
+ call assert_equal('FUNCTION Foo()', lines[0])
+ call assert_equal('Called 1 time', lines[1])
+ call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[7])
+ call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[11])
+
+ call delete('Xprofile_file.vim')
+ call delete('Xprofile_file.log')
+endfunc