vim-patch:8.1.0365: function profile doesn't specify where it was defined

Problem:    Function profile doesn't specify where it was defined.
Solution:   Show the script name and line number.
4c7b08f640
This commit is contained in:
erw7 2019-08-29 12:06:59 +09:00
parent 0e11a106c5
commit e4a4786241
2 changed files with 168 additions and 150 deletions

View File

@ -22138,14 +22138,27 @@ void func_dump_profile(FILE *fd)
if (fp->uf_prof_initialized) {
sorttab[st_len++] = fp;
if (fp->uf_name[0] == K_SPECIAL)
if (fp->uf_name[0] == K_SPECIAL) {
fprintf(fd, "FUNCTION <SNR>%s()\n", fp->uf_name + 3);
else
} else {
fprintf(fd, "FUNCTION %s()\n", fp->uf_name);
if (fp->uf_tm_count == 1)
}
bool should_free;
const LastSet last_set = (LastSet){
.script_ctx = fp->uf_script_ctx,
.channel_id = 0,
};
char_u *p = get_scriptname(last_set, &should_free);
fprintf(fd, " Defined: %s line %" PRIdLINENR "\n",
p, fp->uf_script_ctx.sc_lnum);
if (should_free) {
xfree(p);
}
if (fp->uf_tm_count == 1) {
fprintf(fd, "Called 1 time\n");
else
} else {
fprintf(fd, "Called %d times\n", fp->uf_tm_count);
}
fprintf(fd, "Total time: %s\n", profile_msg(fp->uf_tm_total));
fprintf(fd, " Self time: %s\n", profile_msg(fp->uf_tm_self));
fprintf(fd, "\n");

View File

@ -49,36 +49,37 @@ func Test_profile_func()
" - Unlike Foo3(), Foo2() should not be deleted since there is a check
" for v:profiling.
" - Bar() is not reported since it does not match "profile func Foo*".
call assert_equal(28, len(lines))
call assert_equal(30, len(lines))
call assert_equal('FUNCTION Foo1()', lines[0])
call assert_equal('Called 2 times', 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_equal('', lines[6])
call assert_equal('FUNCTION Foo2()', lines[7])
call assert_equal('Called 1 time', lines[8])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[9])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[10])
call assert_equal('', lines[11])
call assert_equal('count total (s) self (s)', lines[12])
call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[13])
call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[14])
call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[15])
call assert_match('^\s*101\s\+.*\sendwhile$', lines[16])
call assert_equal('', lines[17])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[18])
call assert_equal('count total (s) self (s) function', lines[19])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[20])
call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[21])
call assert_equal('', lines[22])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[23])
call assert_equal('count total (s) self (s) function', lines[24])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[25])
call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[26])
call assert_equal('', lines[27])
call assert_match('Defined:.*Xprofile_func.vim', lines[1])
call assert_equal('Called 2 times', 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_equal('', lines[7])
call assert_equal('FUNCTION Foo2()', lines[8])
call assert_equal('Called 1 time', lines[10])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12])
call assert_equal('', lines[13])
call assert_equal('count total (s) self (s)', lines[14])
call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[15])
call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[16])
call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[17])
call assert_match('^\s*101\s\+.*\sendwhile$', lines[18])
call assert_equal('', lines[19])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[20])
call assert_equal('count total (s) self (s) function', lines[21])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[22])
call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[23])
call assert_equal('', lines[24])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[25])
call assert_equal('count total (s) self (s) function', lines[26])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[27])
call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[28])
call assert_equal('', lines[29])
call delete('Xprofile_func.vim')
call delete('Xprofile_func.log')
@ -132,62 +133,63 @@ func Test_profile_func_with_ifelse()
" - Foo1() should pass 'if' block.
" - Foo2() should pass 'elseif' block.
" - Foo3() should pass 'else' block.
call assert_equal(54, len(lines))
call assert_equal(57, len(lines))
call assert_equal('FUNCTION Foo1()', lines[0])
call assert_equal('Called 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('^\s*1\s\+.*\sif 1$', lines[6])
call assert_match('^\s*1\s\+.*\s let x = 0$', lines[7])
call assert_match( '^\s\+elseif 1$', lines[8])
call assert_match( '^\s\+let x = 1$', lines[9])
call assert_match( '^\s\+else$', lines[10])
call assert_match( '^\s\+let x = 2$', lines[11])
call assert_match('^\s*1\s\+.*\sendif$', lines[12])
call assert_equal('', lines[13])
call assert_equal('FUNCTION Foo2()', lines[14])
call assert_equal('Called 1 time', lines[15])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[16])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[17])
call assert_equal('', lines[18])
call assert_equal('count total (s) self (s)', lines[19])
call assert_match('^\s*1\s\+.*\sif 0$', lines[20])
call assert_match( '^\s\+let x = 0$', lines[21])
call assert_match('^\s*1\s\+.*\selseif 1$', lines[22])
call assert_match('^\s*1\s\+.*\s let x = 1$', lines[23])
call assert_match( '^\s\+else$', lines[24])
call assert_match( '^\s\+let x = 2$', lines[25])
call assert_match('^\s*1\s\+.*\sendif$', lines[26])
call assert_equal('', lines[27])
call assert_equal('FUNCTION Foo3()', lines[28])
call assert_equal('Called 1 time', lines[29])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[30])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[31])
call assert_equal('', lines[32])
call assert_equal('count total (s) self (s)', lines[33])
call assert_match('^\s*1\s\+.*\sif 0$', lines[34])
call assert_match( '^\s\+let x = 0$', lines[35])
call assert_match('^\s*1\s\+.*\selseif 0$', lines[36])
call assert_match( '^\s\+let x = 1$', lines[37])
call assert_match('^\s*1\s\+.*\selse$', lines[38])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[39])
call assert_match('^\s*1\s\+.*\sendif$', lines[40])
call assert_equal('', lines[41])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[42])
call assert_equal('count total (s) self (s) function', lines[43])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[44])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[45])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[46])
call assert_equal('', lines[47])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[48])
call assert_equal('count total (s) self (s) function', lines[49])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[50])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[51])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[52])
call assert_equal('', lines[53])
call assert_match('Defined:.*Xprofile_func.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\+.*\sif 1$', lines[7])
call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
call assert_match( '^\s\+elseif 1$', lines[9])
call assert_match( '^\s\+let x = 1$', lines[10])
call assert_match( '^\s\+else$', lines[11])
call assert_match( '^\s\+let x = 2$', lines[12])
call assert_match('^\s*1\s\+.*\sendif$', lines[13])
call assert_equal('', lines[14])
call assert_equal('FUNCTION Foo2()', lines[15])
call assert_equal('Called 1 time', lines[17])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
call assert_equal('', lines[20])
call assert_equal('count total (s) self (s)', lines[21])
call assert_match('^\s*1\s\+.*\sif 0$', lines[22])
call assert_match( '^\s\+let x = 0$', lines[23])
call assert_match('^\s*1\s\+.*\selseif 1$', lines[24])
call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
call assert_match( '^\s\+else$', lines[26])
call assert_match( '^\s\+let x = 2$', lines[27])
call assert_match('^\s*1\s\+.*\sendif$', lines[28])
call assert_equal('', lines[29])
call assert_equal('FUNCTION Foo3()', lines[30])
call assert_equal('Called 1 time', lines[32])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
call assert_equal('', lines[35])
call assert_equal('count total (s) self (s)', lines[36])
call assert_match('^\s*1\s\+.*\sif 0$', lines[37])
call assert_match( '^\s\+let x = 0$', lines[38])
call assert_match('^\s*1\s\+.*\selseif 0$', lines[39])
call assert_match( '^\s\+let x = 1$', lines[40])
call assert_match('^\s*1\s\+.*\selse$', lines[41])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
call assert_match('^\s*1\s\+.*\sendif$', lines[43])
call assert_equal('', lines[44])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
call assert_equal('count total (s) self (s) function', lines[46])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
call assert_equal('', lines[50])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
call assert_equal('count total (s) self (s) function', lines[52])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
call assert_equal('', lines[56])
call delete('Xprofile_func.vim')
call delete('Xprofile_func.log')
@ -244,62 +246,63 @@ func Test_profile_func_with_trycatch()
" - Foo1() should pass 'try' 'finally' blocks.
" - Foo2() should pass 'catch' 'finally' blocks.
" - Foo3() should not pass 'endtry'.
call assert_equal(54, len(lines))
call assert_equal(57, len(lines))
call assert_equal('FUNCTION Foo1()', lines[0])
call assert_equal('Called 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('^\s*1\s\+.*\stry$', lines[6])
call assert_match('^\s*1\s\+.*\s let x = 0$', lines[7])
call assert_match( '^\s\+catch$', lines[8])
call assert_match( '^\s\+let x = 1$', lines[9])
call assert_match('^\s*1\s\+.*\sfinally$', lines[10])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[11])
call assert_match('^\s*1\s\+.*\sendtry$', lines[12])
call assert_equal('', lines[13])
call assert_equal('FUNCTION Foo2()', lines[14])
call assert_equal('Called 1 time', lines[15])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[16])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[17])
call assert_equal('', lines[18])
call assert_equal('count total (s) self (s)', lines[19])
call assert_match('^\s*1\s\+.*\stry$', lines[20])
call assert_match('^\s*1\s\+.*\s throw 0$', lines[21])
call assert_match('^\s*1\s\+.*\scatch$', lines[22])
call assert_match('^\s*1\s\+.*\s let x = 1$', lines[23])
call assert_match('^\s*1\s\+.*\sfinally$', lines[24])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[25])
call assert_match('^\s*1\s\+.*\sendtry$', lines[26])
call assert_equal('', lines[27])
call assert_equal('FUNCTION Foo3()', lines[28])
call assert_equal('Called 1 time', lines[29])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[30])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[31])
call assert_equal('', lines[32])
call assert_equal('count total (s) self (s)', lines[33])
call assert_match('^\s*1\s\+.*\stry$', lines[34])
call assert_match('^\s*1\s\+.*\s throw 0$', lines[35])
call assert_match('^\s*1\s\+.*\scatch$', lines[36])
call assert_match('^\s*1\s\+.*\s throw 1$', lines[37])
call assert_match('^\s*1\s\+.*\sfinally$', lines[38])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[39])
call assert_match( '^\s\+endtry$', lines[40])
call assert_equal('', lines[41])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[42])
call assert_equal('count total (s) self (s) function', lines[43])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[44])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[45])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[46])
call assert_equal('', lines[47])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[48])
call assert_equal('count total (s) self (s) function', lines[49])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[50])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[51])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[52])
call assert_equal('', lines[53])
call assert_match('Defined:.*Xprofile_func.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\+.*\stry$', lines[7])
call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
call assert_match( '^\s\+catch$', lines[9])
call assert_match( '^\s\+let x = 1$', lines[10])
call assert_match('^\s*1\s\+.*\sfinally$', lines[11])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12])
call assert_match('^\s*1\s\+.*\sendtry$', lines[13])
call assert_equal('', lines[14])
call assert_equal('FUNCTION Foo2()', lines[15])
call assert_equal('Called 1 time', lines[17])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
call assert_equal('', lines[20])
call assert_equal('count total (s) self (s)', lines[21])
call assert_match('^\s*1\s\+.*\stry$', lines[22])
call assert_match('^\s*1\s\+.*\s throw 0$', lines[23])
call assert_match('^\s*1\s\+.*\scatch$', lines[24])
call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
call assert_match('^\s*1\s\+.*\sfinally$', lines[26])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27])
call assert_match('^\s*1\s\+.*\sendtry$', lines[28])
call assert_equal('', lines[29])
call assert_equal('FUNCTION Foo3()', lines[30])
call assert_equal('Called 1 time', lines[32])
call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
call assert_equal('', lines[35])
call assert_equal('count total (s) self (s)', lines[36])
call assert_match('^\s*1\s\+.*\stry$', lines[37])
call assert_match('^\s*1\s\+.*\s throw 0$', lines[38])
call assert_match('^\s*1\s\+.*\scatch$', lines[39])
call assert_match('^\s*1\s\+.*\s throw 1$', lines[40])
call assert_match('^\s*1\s\+.*\sfinally$', lines[41])
call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
call assert_match( '^\s\+endtry$', lines[43])
call assert_equal('', lines[44])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
call assert_equal('count total (s) self (s) function', lines[46])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
call assert_equal('', lines[50])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
call assert_equal('count total (s) self (s) function', lines[52])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
call assert_equal('', lines[56])
call delete('Xprofile_func.vim')
call delete('Xprofile_func.log')
@ -470,18 +473,19 @@ func Test_profdel_func()
call assert_equal(0, v:shell_error)
let lines = readfile('Xprofile_file.log')
call assert_equal(24, len(lines))
call assert_equal(26, 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 assert_match('Defined:.*Xprofile_file.vim', lines[1])
call assert_equal('Called 2 times', lines[2])
call assert_equal('FUNCTION Foo2()', lines[8])
call assert_equal('Called 1 time', lines[10])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21])
call delete('Xprofile_file.vim')
call delete('Xprofile_file.log')
@ -503,12 +507,13 @@ func Test_profdel_star()
call assert_equal(0, v:shell_error)
let lines = readfile('Xprofile_file.log')
call assert_equal(15, len(lines))
call assert_equal(16, 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 assert_match('Defined:.*Xprofile_file.vim', lines[1])
call assert_equal('Called 1 time', lines[2])
call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8])
call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12])
call delete('Xprofile_file.vim')
call delete('Xprofile_file.log')