Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 1 | " Test Vim profiler |
Bram Moolenaar | b0f94c1 | 2019-06-13 22:19:53 +0200 | [diff] [blame] | 2 | |
Bram Moolenaar | b46fecd | 2019-06-15 17:58:09 +0200 | [diff] [blame] | 3 | source check.vim |
| 4 | CheckFeature profile |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 5 | |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 6 | source shared.vim |
Bram Moolenaar | 1635880 | 2019-08-30 18:37:26 +0200 | [diff] [blame] | 7 | source screendump.vim |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 8 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 9 | func Test_profile_func() |
Bram Moolenaar | b204990 | 2021-01-24 12:53:53 +0100 | [diff] [blame] | 10 | call RunProfileFunc('func', 'let', 'let') |
| 11 | call RunProfileFunc('def', 'var', '') |
| 12 | endfunc |
| 13 | |
| 14 | func RunProfileFunc(command, declare, assign) |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 15 | let lines =<< trim [CODE] |
| 16 | profile start Xprofile_func.log |
| 17 | profile func Foo* |
Bram Moolenaar | b204990 | 2021-01-24 12:53:53 +0100 | [diff] [blame] | 18 | XXX Foo1() |
| 19 | endXXX |
| 20 | XXX Foo2() |
| 21 | DDD counter = 100 |
| 22 | while counter > 0 |
| 23 | AAA counter = counter - 1 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 24 | endwhile |
Bram Moolenaar | a21df1d | 2020-03-17 20:57:09 +0100 | [diff] [blame] | 25 | sleep 1m |
Bram Moolenaar | b204990 | 2021-01-24 12:53:53 +0100 | [diff] [blame] | 26 | endXXX |
| 27 | XXX Foo3() |
| 28 | endXXX |
| 29 | XXX Bar() |
| 30 | endXXX |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 31 | call Foo1() |
| 32 | call Foo1() |
| 33 | profile pause |
| 34 | call Foo1() |
| 35 | profile continue |
| 36 | call Foo2() |
| 37 | call Foo3() |
| 38 | call Bar() |
| 39 | if !v:profiling |
| 40 | delfunc Foo2 |
| 41 | endif |
| 42 | delfunc Foo3 |
| 43 | [CODE] |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 44 | |
Bram Moolenaar | b204990 | 2021-01-24 12:53:53 +0100 | [diff] [blame] | 45 | call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) |
| 46 | call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) |
| 47 | call map(lines, {k, v -> substitute(v, 'AAA', a:assign, '') }) |
| 48 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 49 | call writefile(lines, 'Xprofile_func.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 50 | call system(GetVimCommand() |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 51 | \ . ' -es --clean' |
Bram Moolenaar | c011a3d | 2017-01-16 22:37:42 +0100 | [diff] [blame] | 52 | \ . ' -c "so Xprofile_func.vim"' |
| 53 | \ . ' -c "qall!"') |
| 54 | call assert_equal(0, v:shell_error) |
| 55 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 56 | let lines = readfile('Xprofile_func.log') |
| 57 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 58 | " - Foo1() is called 3 times but should be reported as called twice |
| 59 | " since one call is in between "profile pause" .. "profile continue". |
Bram Moolenaar | c011a3d | 2017-01-16 22:37:42 +0100 | [diff] [blame] | 60 | " - Foo2() should come before Foo1() since Foo1() does much more work. |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 61 | " - Foo3() is not reported because function is deleted. |
| 62 | " - Unlike Foo3(), Foo2() should not be deleted since there is a check |
| 63 | " for v:profiling. |
| 64 | " - Bar() is not reported since it does not match "profile func Foo*". |
Bram Moolenaar | a21df1d | 2020-03-17 20:57:09 +0100 | [diff] [blame] | 65 | call assert_equal(31, len(lines)) |
Bram Moolenaar | c011a3d | 2017-01-16 22:37:42 +0100 | [diff] [blame] | 66 | |
| 67 | call assert_equal('FUNCTION Foo1()', lines[0]) |
Bram Moolenaar | 181d4f5 | 2019-09-18 22:04:56 +0200 | [diff] [blame] | 68 | call assert_match('Defined:.*Xprofile_func.vim:3', lines[1]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 69 | call assert_equal('Called 2 times', lines[2]) |
| 70 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) |
| 71 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) |
| 72 | call assert_equal('', lines[5]) |
| 73 | call assert_equal('count total (s) self (s)', lines[6]) |
| 74 | call assert_equal('', lines[7]) |
| 75 | call assert_equal('FUNCTION Foo2()', lines[8]) |
| 76 | call assert_equal('Called 1 time', lines[10]) |
| 77 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11]) |
| 78 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12]) |
| 79 | call assert_equal('', lines[13]) |
| 80 | call assert_equal('count total (s) self (s)', lines[14]) |
Bram Moolenaar | b204990 | 2021-01-24 12:53:53 +0100 | [diff] [blame] | 81 | call assert_match('^\s*1\s\+.*\s\(let\|var\) counter = 100$', lines[15]) |
| 82 | call assert_match('^\s*101\s\+.*\swhile counter > 0$', lines[16]) |
| 83 | call assert_match('^\s*100\s\+.*\s \(let\)\= counter = counter - 1$', lines[17]) |
| 84 | call assert_match('^\s*10[01]\s\+.*\sendwhile$', lines[18]) |
Bram Moolenaar | a21df1d | 2020-03-17 20:57:09 +0100 | [diff] [blame] | 85 | call assert_match('^\s*1\s\+.\+sleep 1m$', lines[19]) |
| 86 | call assert_equal('', lines[20]) |
| 87 | call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[21]) |
| 88 | call assert_equal('count total (s) self (s) function', lines[22]) |
| 89 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[23]) |
| 90 | call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[24]) |
| 91 | call assert_equal('', lines[25]) |
| 92 | call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[26]) |
| 93 | call assert_equal('count total (s) self (s) function', lines[27]) |
| 94 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[28]) |
| 95 | call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[29]) |
| 96 | call assert_equal('', lines[30]) |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 97 | |
| 98 | call delete('Xprofile_func.vim') |
| 99 | call delete('Xprofile_func.log') |
| 100 | endfunc |
| 101 | |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 102 | func Test_profile_func_with_ifelse() |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 103 | call Run_profile_func_with_ifelse('func', 'let', 'let') |
| 104 | call Run_profile_func_with_ifelse('def', 'var', '') |
| 105 | endfunc |
| 106 | |
| 107 | func Run_profile_func_with_ifelse(command, declare, assign) |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 108 | let lines =<< trim [CODE] |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 109 | XXX Foo1() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 110 | if 1 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 111 | DDD x = 0 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 112 | elseif 1 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 113 | DDD x = 1 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 114 | else |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 115 | DDD x = 2 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 116 | endif |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 117 | endXXX |
| 118 | XXX Foo2() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 119 | if 0 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 120 | DDD x = 0 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 121 | elseif 1 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 122 | DDD x = 1 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 123 | else |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 124 | DDD x = 2 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 125 | endif |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 126 | endXXX |
| 127 | XXX Foo3() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 128 | if 0 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 129 | DDD x = 0 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 130 | elseif 0 |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 131 | DDD x = 1 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 132 | else |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 133 | DDD x = 2 |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 134 | endif |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 135 | endXXX |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 136 | call Foo1() |
| 137 | call Foo2() |
| 138 | call Foo3() |
| 139 | [CODE] |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 140 | |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 141 | call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) |
| 142 | call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) |
| 143 | call map(lines, {k, v -> substitute(v, 'AAA', a:assign, '') }) |
| 144 | |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 145 | call writefile(lines, 'Xprofile_func.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 146 | call system(GetVimCommand() |
| 147 | \ . ' -es -i NONE --noplugin' |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 148 | \ . ' -c "profile start Xprofile_func.log"' |
| 149 | \ . ' -c "profile func Foo*"' |
| 150 | \ . ' -c "so Xprofile_func.vim"' |
| 151 | \ . ' -c "qall!"') |
| 152 | call assert_equal(0, v:shell_error) |
| 153 | |
| 154 | let lines = readfile('Xprofile_func.log') |
| 155 | |
| 156 | " - Foo1() should pass 'if' block. |
| 157 | " - Foo2() should pass 'elseif' block. |
| 158 | " - Foo3() should pass 'else' block. |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 159 | call assert_equal(57, len(lines)) |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 160 | |
| 161 | call assert_equal('FUNCTION Foo1()', lines[0]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 162 | call assert_match('Defined:.*Xprofile_func.vim', lines[1]) |
| 163 | call assert_equal('Called 1 time', lines[2]) |
| 164 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) |
| 165 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) |
| 166 | call assert_equal('', lines[5]) |
| 167 | call assert_equal('count total (s) self (s)', lines[6]) |
| 168 | call assert_match('^\s*1\s\+.*\sif 1$', lines[7]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 169 | call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 0$', lines[8]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 170 | call assert_match( '^\s\+elseif 1$', lines[9]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 171 | call assert_match( '^\s\+\(let\|var\) x = 1$', lines[10]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 172 | call assert_match( '^\s\+else$', lines[11]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 173 | call assert_match( '^\s\+\(let\|var\) x = 2$', lines[12]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 174 | call assert_match('^\s*1\s\+.*\sendif$', lines[13]) |
| 175 | call assert_equal('', lines[14]) |
| 176 | call assert_equal('FUNCTION Foo2()', lines[15]) |
| 177 | call assert_equal('Called 1 time', lines[17]) |
| 178 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18]) |
| 179 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19]) |
| 180 | call assert_equal('', lines[20]) |
| 181 | call assert_equal('count total (s) self (s)', lines[21]) |
| 182 | call assert_match('^\s*1\s\+.*\sif 0$', lines[22]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 183 | call assert_match( '^\s\+\(let\|var\) x = 0$', lines[23]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 184 | call assert_match('^\s*1\s\+.*\selseif 1$', lines[24]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 185 | call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 1$', lines[25]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 186 | call assert_match( '^\s\+else$', lines[26]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 187 | call assert_match( '^\s\+\(let\|var\) x = 2$', lines[27]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 188 | call assert_match('^\s*1\s\+.*\sendif$', lines[28]) |
| 189 | call assert_equal('', lines[29]) |
| 190 | call assert_equal('FUNCTION Foo3()', lines[30]) |
| 191 | call assert_equal('Called 1 time', lines[32]) |
| 192 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33]) |
| 193 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34]) |
| 194 | call assert_equal('', lines[35]) |
| 195 | call assert_equal('count total (s) self (s)', lines[36]) |
| 196 | call assert_match('^\s*1\s\+.*\sif 0$', lines[37]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 197 | call assert_match( '^\s\+\(let\|var\) x = 0$', lines[38]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 198 | call assert_match('^\s*1\s\+.*\selseif 0$', lines[39]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 199 | call assert_match( '^\s\+\(let\|var\) x = 1$', lines[40]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 200 | call assert_match('^\s*1\s\+.*\selse$', lines[41]) |
Bram Moolenaar | ced68a0 | 2021-01-24 17:53:47 +0100 | [diff] [blame^] | 201 | call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[42]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 202 | call assert_match('^\s*1\s\+.*\sendif$', lines[43]) |
| 203 | call assert_equal('', lines[44]) |
| 204 | call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45]) |
| 205 | call assert_equal('count total (s) self (s) function', lines[46]) |
| 206 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47]) |
| 207 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48]) |
| 208 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49]) |
| 209 | call assert_equal('', lines[50]) |
| 210 | call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51]) |
| 211 | call assert_equal('count total (s) self (s) function', lines[52]) |
| 212 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53]) |
| 213 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54]) |
| 214 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55]) |
| 215 | call assert_equal('', lines[56]) |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 216 | |
| 217 | call delete('Xprofile_func.vim') |
| 218 | call delete('Xprofile_func.log') |
| 219 | endfunc |
| 220 | |
| 221 | func Test_profile_func_with_trycatch() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 222 | let lines =<< trim [CODE] |
| 223 | func! Foo1() |
| 224 | try |
| 225 | let x = 0 |
| 226 | catch |
| 227 | let x = 1 |
| 228 | finally |
| 229 | let x = 2 |
| 230 | endtry |
| 231 | endfunc |
| 232 | func! Foo2() |
| 233 | try |
| 234 | throw 0 |
| 235 | catch |
| 236 | let x = 1 |
| 237 | finally |
| 238 | let x = 2 |
| 239 | endtry |
| 240 | endfunc |
| 241 | func! Foo3() |
| 242 | try |
| 243 | throw 0 |
| 244 | catch |
| 245 | throw 1 |
| 246 | finally |
| 247 | let x = 2 |
| 248 | endtry |
| 249 | endfunc |
| 250 | call Foo1() |
| 251 | call Foo2() |
| 252 | try |
| 253 | call Foo3() |
| 254 | catch |
| 255 | endtry |
| 256 | [CODE] |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 257 | |
| 258 | call writefile(lines, 'Xprofile_func.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 259 | call system(GetVimCommand() |
| 260 | \ . ' -es -i NONE --noplugin' |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 261 | \ . ' -c "profile start Xprofile_func.log"' |
| 262 | \ . ' -c "profile func Foo*"' |
| 263 | \ . ' -c "so Xprofile_func.vim"' |
| 264 | \ . ' -c "qall!"') |
| 265 | call assert_equal(0, v:shell_error) |
| 266 | |
| 267 | let lines = readfile('Xprofile_func.log') |
| 268 | |
| 269 | " - Foo1() should pass 'try' 'finally' blocks. |
| 270 | " - Foo2() should pass 'catch' 'finally' blocks. |
| 271 | " - Foo3() should not pass 'endtry'. |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 272 | call assert_equal(57, len(lines)) |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 273 | |
| 274 | call assert_equal('FUNCTION Foo1()', lines[0]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 275 | call assert_match('Defined:.*Xprofile_func.vim', lines[1]) |
| 276 | call assert_equal('Called 1 time', lines[2]) |
| 277 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) |
| 278 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) |
| 279 | call assert_equal('', lines[5]) |
| 280 | call assert_equal('count total (s) self (s)', lines[6]) |
| 281 | call assert_match('^\s*1\s\+.*\stry$', lines[7]) |
| 282 | call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8]) |
| 283 | call assert_match( '^\s\+catch$', lines[9]) |
| 284 | call assert_match( '^\s\+let x = 1$', lines[10]) |
| 285 | call assert_match('^\s*1\s\+.*\sfinally$', lines[11]) |
| 286 | call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12]) |
| 287 | call assert_match('^\s*1\s\+.*\sendtry$', lines[13]) |
| 288 | call assert_equal('', lines[14]) |
| 289 | call assert_equal('FUNCTION Foo2()', lines[15]) |
| 290 | call assert_equal('Called 1 time', lines[17]) |
| 291 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18]) |
| 292 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19]) |
| 293 | call assert_equal('', lines[20]) |
| 294 | call assert_equal('count total (s) self (s)', lines[21]) |
| 295 | call assert_match('^\s*1\s\+.*\stry$', lines[22]) |
| 296 | call assert_match('^\s*1\s\+.*\s throw 0$', lines[23]) |
| 297 | call assert_match('^\s*1\s\+.*\scatch$', lines[24]) |
| 298 | call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25]) |
| 299 | call assert_match('^\s*1\s\+.*\sfinally$', lines[26]) |
| 300 | call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27]) |
| 301 | call assert_match('^\s*1\s\+.*\sendtry$', lines[28]) |
| 302 | call assert_equal('', lines[29]) |
| 303 | call assert_equal('FUNCTION Foo3()', lines[30]) |
| 304 | call assert_equal('Called 1 time', lines[32]) |
| 305 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33]) |
| 306 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34]) |
| 307 | call assert_equal('', lines[35]) |
| 308 | call assert_equal('count total (s) self (s)', lines[36]) |
| 309 | call assert_match('^\s*1\s\+.*\stry$', lines[37]) |
| 310 | call assert_match('^\s*1\s\+.*\s throw 0$', lines[38]) |
| 311 | call assert_match('^\s*1\s\+.*\scatch$', lines[39]) |
| 312 | call assert_match('^\s*1\s\+.*\s throw 1$', lines[40]) |
| 313 | call assert_match('^\s*1\s\+.*\sfinally$', lines[41]) |
| 314 | call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42]) |
| 315 | call assert_match( '^\s\+endtry$', lines[43]) |
| 316 | call assert_equal('', lines[44]) |
| 317 | call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45]) |
| 318 | call assert_equal('count total (s) self (s) function', lines[46]) |
| 319 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47]) |
| 320 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48]) |
| 321 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49]) |
| 322 | call assert_equal('', lines[50]) |
| 323 | call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51]) |
| 324 | call assert_equal('count total (s) self (s) function', lines[52]) |
| 325 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53]) |
| 326 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54]) |
| 327 | call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55]) |
| 328 | call assert_equal('', lines[56]) |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 329 | |
| 330 | call delete('Xprofile_func.vim') |
| 331 | call delete('Xprofile_func.log') |
| 332 | endfunc |
| 333 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 334 | func Test_profile_file() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 335 | let lines =<< trim [CODE] |
Bram Moolenaar | e7eb927 | 2019-06-24 00:58:07 +0200 | [diff] [blame] | 336 | func! Foo() |
| 337 | endfunc |
| 338 | for i in range(10) |
| 339 | " a comment |
| 340 | call Foo() |
| 341 | endfor |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 342 | call Foo() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 343 | [CODE] |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 344 | |
| 345 | call writefile(lines, 'Xprofile_file.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 346 | call system(GetVimCommandClean() |
| 347 | \ . ' -es' |
Bram Moolenaar | c011a3d | 2017-01-16 22:37:42 +0100 | [diff] [blame] | 348 | \ . ' -c "profile start Xprofile_file.log"' |
| 349 | \ . ' -c "profile file Xprofile_file.vim"' |
| 350 | \ . ' -c "so Xprofile_file.vim"' |
| 351 | \ . ' -c "so Xprofile_file.vim"' |
| 352 | \ . ' -c "qall!"') |
| 353 | call assert_equal(0, v:shell_error) |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 354 | |
| 355 | let lines = readfile('Xprofile_file.log') |
| 356 | |
| 357 | call assert_equal(14, len(lines)) |
| 358 | |
| 359 | call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) |
| 360 | call assert_equal('Sourced 2 times', lines[1]) |
| 361 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) |
| 362 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) |
| 363 | call assert_equal('', lines[4]) |
| 364 | call assert_equal('count total (s) self (s)', lines[5]) |
Bram Moolenaar | 67435d9 | 2017-10-19 21:04:37 +0200 | [diff] [blame] | 365 | call assert_match(' 2 0.\d\+ func! Foo()', lines[6]) |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 366 | call assert_equal(' endfunc', lines[7]) |
| 367 | " Loop iterates 10 times. Since script runs twice, body executes 20 times. |
| 368 | " First line of loop executes one more time than body to detect end of loop. |
| 369 | call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8]) |
| 370 | call assert_equal(' " a comment', lines[9]) |
Bram Moolenaar | d21b16f | 2017-08-14 23:13:30 +0200 | [diff] [blame] | 371 | " if self and total are equal we only get one number |
| 372 | call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10]) |
Bram Moolenaar | 7feb35e | 2018-08-21 17:49:54 +0200 | [diff] [blame] | 373 | call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11]) |
Bram Moolenaar | e32bbde | 2017-01-15 21:12:48 +0100 | [diff] [blame] | 374 | " if self and total are equal we only get one number |
| 375 | call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12]) |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 376 | call assert_equal('', lines[13]) |
| 377 | |
| 378 | call delete('Xprofile_file.vim') |
| 379 | call delete('Xprofile_file.log') |
| 380 | endfunc |
| 381 | |
Bram Moolenaar | 67435d9 | 2017-10-19 21:04:37 +0200 | [diff] [blame] | 382 | func Test_profile_file_with_cont() |
| 383 | let lines = [ |
| 384 | \ 'echo "hello', |
| 385 | \ ' \ world"', |
| 386 | \ 'echo "foo ', |
| 387 | \ ' \bar"', |
| 388 | \ ] |
| 389 | |
| 390 | call writefile(lines, 'Xprofile_file.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 391 | call system(GetVimCommandClean() |
| 392 | \ . ' -es' |
Bram Moolenaar | 67435d9 | 2017-10-19 21:04:37 +0200 | [diff] [blame] | 393 | \ . ' -c "profile start Xprofile_file.log"' |
| 394 | \ . ' -c "profile file Xprofile_file.vim"' |
| 395 | \ . ' -c "so Xprofile_file.vim"' |
| 396 | \ . ' -c "qall!"') |
| 397 | call assert_equal(0, v:shell_error) |
| 398 | |
| 399 | let lines = readfile('Xprofile_file.log') |
| 400 | call assert_equal(11, len(lines)) |
| 401 | |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 402 | call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) |
| 403 | call assert_equal('Sourced 1 time', lines[1]) |
| 404 | call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) |
| 405 | call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) |
| 406 | call assert_equal('', lines[4]) |
| 407 | call assert_equal('count total (s) self (s)', lines[5]) |
| 408 | call assert_match(' 1 0.\d\+ echo "hello', lines[6]) |
| 409 | call assert_equal(' \ world"', lines[7]) |
| 410 | call assert_match(' 1 0.\d\+ echo "foo ', lines[8]) |
| 411 | call assert_equal(' \bar"', lines[9]) |
| 412 | call assert_equal('', lines[10]) |
Bram Moolenaar | 67435d9 | 2017-10-19 21:04:37 +0200 | [diff] [blame] | 413 | |
| 414 | call delete('Xprofile_file.vim') |
| 415 | call delete('Xprofile_file.log') |
| 416 | endfunc |
| 417 | |
Bram Moolenaar | 296b1f2 | 2017-01-15 15:22:33 +0100 | [diff] [blame] | 418 | func Test_profile_completion() |
| 419 | call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx') |
| 420 | call assert_equal('"profile continue file func pause start', @:) |
| 421 | |
| 422 | call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx') |
| 423 | call assert_match('^"profile start.* test_profile\.vim', @:) |
| 424 | endfunc |
| 425 | |
| 426 | func Test_profile_errors() |
| 427 | call assert_fails("profile func Foo", 'E750:') |
| 428 | call assert_fails("profile pause", 'E750:') |
| 429 | call assert_fails("profile continue", 'E750:') |
| 430 | endfunc |
Bram Moolenaar | ac112f0 | 2017-12-05 16:46:28 +0100 | [diff] [blame] | 431 | |
| 432 | func Test_profile_truncate_mbyte() |
Bram Moolenaar | 30276f2 | 2019-01-24 17:59:39 +0100 | [diff] [blame] | 433 | if &enc !=# 'utf-8' |
Bram Moolenaar | ac112f0 | 2017-12-05 16:46:28 +0100 | [diff] [blame] | 434 | return |
| 435 | endif |
| 436 | |
| 437 | let lines = [ |
| 438 | \ 'scriptencoding utf-8', |
| 439 | \ 'func! Foo()', |
| 440 | \ ' return [', |
| 441 | \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",', |
| 442 | \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",', |
| 443 | \ ' \ ]', |
| 444 | \ 'endfunc', |
| 445 | \ 'call Foo()', |
| 446 | \ ] |
| 447 | |
| 448 | call writefile(lines, 'Xprofile_file.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 449 | call system(GetVimCommandClean() |
| 450 | \ . ' -es --cmd "set enc=utf-8"' |
Bram Moolenaar | ac112f0 | 2017-12-05 16:46:28 +0100 | [diff] [blame] | 451 | \ . ' -c "profile start Xprofile_file.log"' |
| 452 | \ . ' -c "profile file Xprofile_file.vim"' |
| 453 | \ . ' -c "so Xprofile_file.vim"' |
| 454 | \ . ' -c "qall!"') |
| 455 | call assert_equal(0, v:shell_error) |
| 456 | |
| 457 | split Xprofile_file.log |
| 458 | if &fenc != '' |
| 459 | call assert_equal('utf-8', &fenc) |
| 460 | endif |
| 461 | /func! Foo() |
| 462 | let lnum = line('.') |
| 463 | call assert_match('^\s*return \[$', getline(lnum + 1)) |
| 464 | call assert_match("\u4F52$", getline(lnum + 2)) |
| 465 | call assert_match("\u5052$", getline(lnum + 3)) |
| 466 | call assert_match('^\s*\\ \]$', getline(lnum + 4)) |
| 467 | bwipe! |
| 468 | |
| 469 | call delete('Xprofile_file.vim') |
| 470 | call delete('Xprofile_file.log') |
| 471 | endfunc |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 472 | |
| 473 | func Test_profdel_func() |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 474 | let lines =<< trim [CODE] |
| 475 | profile start Xprofile_file.log |
| 476 | func! Foo1() |
| 477 | endfunc |
| 478 | func! Foo2() |
| 479 | endfunc |
| 480 | func! Foo3() |
| 481 | endfunc |
| 482 | |
| 483 | profile func Foo1 |
| 484 | profile func Foo2 |
| 485 | call Foo1() |
| 486 | call Foo2() |
| 487 | |
| 488 | profile func Foo3 |
| 489 | profdel func Foo2 |
| 490 | profdel func Foo3 |
| 491 | call Foo1() |
| 492 | call Foo2() |
| 493 | call Foo3() |
| 494 | [CODE] |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 495 | call writefile(lines, 'Xprofile_file.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 496 | call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 497 | call assert_equal(0, v:shell_error) |
| 498 | |
| 499 | let lines = readfile('Xprofile_file.log') |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 500 | call assert_equal(26, len(lines)) |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 501 | |
| 502 | " Check that: |
| 503 | " - Foo1() is called twice (profdel not invoked) |
| 504 | " - Foo2() is called once (profdel invoked after it was called) |
| 505 | " - Foo3() is not called (profdel invoked before it was called) |
| 506 | call assert_equal('FUNCTION Foo1()', lines[0]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 507 | call assert_match('Defined:.*Xprofile_file.vim', lines[1]) |
| 508 | call assert_equal('Called 2 times', lines[2]) |
| 509 | call assert_equal('FUNCTION Foo2()', lines[8]) |
| 510 | call assert_equal('Called 1 time', lines[10]) |
| 511 | call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16]) |
| 512 | call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21]) |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 513 | |
| 514 | call delete('Xprofile_file.vim') |
| 515 | call delete('Xprofile_file.log') |
| 516 | endfunc |
| 517 | |
| 518 | func Test_profdel_star() |
| 519 | " Foo() is invoked once before and once after 'profdel *'. |
| 520 | " So profiling should report it only once. |
Bram Moolenaar | c79745a | 2019-05-20 22:12:34 +0200 | [diff] [blame] | 521 | let lines =<< trim [CODE] |
| 522 | profile start Xprofile_file.log |
| 523 | func! Foo() |
| 524 | endfunc |
| 525 | profile func Foo |
| 526 | call Foo() |
| 527 | profdel * |
| 528 | call Foo() |
| 529 | [CODE] |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 530 | call writefile(lines, 'Xprofile_file.vim') |
Bram Moolenaar | 93344c2 | 2019-08-14 21:12:05 +0200 | [diff] [blame] | 531 | call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 532 | call assert_equal(0, v:shell_error) |
| 533 | |
| 534 | let lines = readfile('Xprofile_file.log') |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 535 | call assert_equal(16, len(lines)) |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 536 | |
| 537 | call assert_equal('FUNCTION Foo()', lines[0]) |
Bram Moolenaar | 4c7b08f | 2018-09-10 22:03:40 +0200 | [diff] [blame] | 538 | call assert_match('Defined:.*Xprofile_file.vim', lines[1]) |
| 539 | call assert_equal('Called 1 time', lines[2]) |
| 540 | call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8]) |
| 541 | call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12]) |
Bram Moolenaar | 1fbfe7c | 2018-06-30 21:18:13 +0200 | [diff] [blame] | 542 | |
| 543 | call delete('Xprofile_file.vim') |
| 544 | call delete('Xprofile_file.log') |
| 545 | endfunc |
Bram Moolenaar | 1635880 | 2019-08-30 18:37:26 +0200 | [diff] [blame] | 546 | |
| 547 | " When typing the function it won't have a script ID, test that this works. |
| 548 | func Test_profile_typed_func() |
| 549 | CheckScreendump |
| 550 | |
| 551 | let lines =<< trim END |
| 552 | profile start XprofileTypedFunc |
| 553 | END |
| 554 | call writefile(lines, 'XtestProfile') |
| 555 | let buf = RunVimInTerminal('-S XtestProfile', #{}) |
| 556 | |
| 557 | call term_sendkeys(buf, ":func DoSomething()\<CR>" |
| 558 | \ .. "echo 'hello'\<CR>" |
| 559 | \ .. "endfunc\<CR>") |
| 560 | call term_sendkeys(buf, ":profile func DoSomething\<CR>") |
| 561 | call term_sendkeys(buf, ":call DoSomething()\<CR>") |
Bram Moolenaar | 6a2c5a7 | 2020-04-08 21:50:25 +0200 | [diff] [blame] | 562 | call TermWait(buf, 100) |
Bram Moolenaar | 1635880 | 2019-08-30 18:37:26 +0200 | [diff] [blame] | 563 | call StopVimInTerminal(buf) |
| 564 | let lines = readfile('XprofileTypedFunc') |
| 565 | call assert_equal("FUNCTION DoSomething()", lines[0]) |
| 566 | call assert_equal("Called 1 time", lines[1]) |
| 567 | |
| 568 | " clean up |
| 569 | call delete('XprofileTypedFunc') |
| 570 | call delete('XtestProfile') |
| 571 | endfunc |
Bram Moolenaar | 6d91bcb | 2020-08-12 18:50:36 +0200 | [diff] [blame] | 572 | |
| 573 | " vim: shiftwidth=2 sts=2 expandtab |