Mercurial > vim
changeset 14706:2c0f454fcdc9 v8.1.0365
patch 8.1.0365: function profile doesn't specify where it was defined
commit https://github.com/vim/vim/commit/4c7b08f6409349cf5324a26f7523c438590550ef
Author: Bram Moolenaar <Bram@vim.org>
Date: Mon Sep 10 22:03:40 2018 +0200
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.
| author | Christian Brabandt <cb@256bit.org> |
|---|---|
| date | Mon, 10 Sep 2018 22:15:05 +0200 |
| parents | 2e3693fee018 |
| children | 5cb5b079ad90 |
| files | src/testdir/test_profile.vim src/userfunc.c src/version.c |
| diffstat | 3 files changed, 162 insertions(+), 146 deletions(-) [+] |
line wrap: on
line diff
--- a/src/testdir/test_profile.vim +++ b/src/testdir/test_profile.vim @@ -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')
--- a/src/userfunc.c +++ b/src/userfunc.c @@ -2587,6 +2587,7 @@ func_dump_profile(FILE *fd) int i; ufunc_T **sorttab; int st_len = 0; + char_u *p; todo = (int)func_hashtab.ht_used; if (todo == 0) @@ -2609,6 +2610,14 @@ func_dump_profile(FILE *fd) fprintf(fd, "FUNCTION <SNR>%s()\n", fp->uf_name + 3); else fprintf(fd, "FUNCTION %s()\n", fp->uf_name); + p = home_replace_save(NULL, + get_scriptname(fp->uf_script_ctx.sc_sid)); + if (p != NULL) + { + fprintf(fd, " Defined: %s line %ld\n", + p, (long)fp->uf_script_ctx.sc_lnum); + vim_free(p); + } if (fp->uf_tm_count == 1) fprintf(fd, "Called 1 time\n"); else