blob: d0546df865d9e5081b5716045c248a9b91343b20 [file] [log] [blame]
Bram Moolenaar296b1f22017-01-15 15:22:33 +01001" Test Vim profiler
Bram Moolenaarb0f94c12019-06-13 22:19:53 +02002
Bram Moolenaarb46fecd2019-06-15 17:58:09 +02003source check.vim
4CheckFeature profile
Bram Moolenaar296b1f22017-01-15 15:22:33 +01005
Bram Moolenaar93344c22019-08-14 21:12:05 +02006source shared.vim
Bram Moolenaar16358802019-08-30 18:37:26 +02007source screendump.vim
Bram Moolenaar93344c22019-08-14 21:12:05 +02008
Bram Moolenaar296b1f22017-01-15 15:22:33 +01009func Test_profile_func()
Bram Moolenaarc79745a2019-05-20 22:12:34 +020010 let lines =<< trim [CODE]
11 profile start Xprofile_func.log
12 profile func Foo*
13 func! Foo1()
14 endfunc
15 func! Foo2()
16 let l:count = 100
17 while l:count > 0
18 let l:count = l:count - 1
19 endwhile
20 endfunc
21 func! Foo3()
22 endfunc
23 func! Bar()
24 endfunc
25 call Foo1()
26 call Foo1()
27 profile pause
28 call Foo1()
29 profile continue
30 call Foo2()
31 call Foo3()
32 call Bar()
33 if !v:profiling
34 delfunc Foo2
35 endif
36 delfunc Foo3
37 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +010038
39 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +020040 call system(GetVimCommand()
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +020041 \ . ' -es --clean'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010042 \ . ' -c "so Xprofile_func.vim"'
43 \ . ' -c "qall!"')
44 call assert_equal(0, v:shell_error)
45
Bram Moolenaar296b1f22017-01-15 15:22:33 +010046 let lines = readfile('Xprofile_func.log')
47
Bram Moolenaar296b1f22017-01-15 15:22:33 +010048 " - Foo1() is called 3 times but should be reported as called twice
49 " since one call is in between "profile pause" .. "profile continue".
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010050 " - Foo2() should come before Foo1() since Foo1() does much more work.
Bram Moolenaar296b1f22017-01-15 15:22:33 +010051 " - Foo3() is not reported because function is deleted.
52 " - Unlike Foo3(), Foo2() should not be deleted since there is a check
53 " for v:profiling.
54 " - Bar() is not reported since it does not match "profile func Foo*".
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020055 call assert_equal(30, len(lines))
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010056
57 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020058 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
59 call assert_equal('Called 2 times', lines[2])
60 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
61 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
62 call assert_equal('', lines[5])
63 call assert_equal('count total (s) self (s)', lines[6])
64 call assert_equal('', lines[7])
65 call assert_equal('FUNCTION Foo2()', lines[8])
66 call assert_equal('Called 1 time', lines[10])
67 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11])
68 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12])
69 call assert_equal('', lines[13])
70 call assert_equal('count total (s) self (s)', lines[14])
71 call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[15])
72 call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[16])
73 call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[17])
74 call assert_match('^\s*101\s\+.*\sendwhile$', lines[18])
75 call assert_equal('', lines[19])
76 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[20])
77 call assert_equal('count total (s) self (s) function', lines[21])
78 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[22])
79 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[23])
80 call assert_equal('', lines[24])
81 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[25])
82 call assert_equal('count total (s) self (s) function', lines[26])
83 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[27])
84 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[28])
85 call assert_equal('', lines[29])
Bram Moolenaar296b1f22017-01-15 15:22:33 +010086
87 call delete('Xprofile_func.vim')
88 call delete('Xprofile_func.log')
89endfunc
90
Bram Moolenaar7feb35e2018-08-21 17:49:54 +020091func Test_profile_func_with_ifelse()
Bram Moolenaarc79745a2019-05-20 22:12:34 +020092 let lines =<< trim [CODE]
93 func! Foo1()
94 if 1
95 let x = 0
96 elseif 1
97 let x = 1
98 else
99 let x = 2
100 endif
101 endfunc
102 func! Foo2()
103 if 0
104 let x = 0
105 elseif 1
106 let x = 1
107 else
108 let x = 2
109 endif
110 endfunc
111 func! Foo3()
112 if 0
113 let x = 0
114 elseif 0
115 let x = 1
116 else
117 let x = 2
118 endif
119 endfunc
120 call Foo1()
121 call Foo2()
122 call Foo3()
123 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200124
125 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200126 call system(GetVimCommand()
127 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200128 \ . ' -c "profile start Xprofile_func.log"'
129 \ . ' -c "profile func Foo*"'
130 \ . ' -c "so Xprofile_func.vim"'
131 \ . ' -c "qall!"')
132 call assert_equal(0, v:shell_error)
133
134 let lines = readfile('Xprofile_func.log')
135
136 " - Foo1() should pass 'if' block.
137 " - Foo2() should pass 'elseif' block.
138 " - Foo3() should pass 'else' block.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200139 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200140
141 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200142 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
143 call assert_equal('Called 1 time', lines[2])
144 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
145 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
146 call assert_equal('', lines[5])
147 call assert_equal('count total (s) self (s)', lines[6])
148 call assert_match('^\s*1\s\+.*\sif 1$', lines[7])
149 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
150 call assert_match( '^\s\+elseif 1$', lines[9])
151 call assert_match( '^\s\+let x = 1$', lines[10])
152 call assert_match( '^\s\+else$', lines[11])
153 call assert_match( '^\s\+let x = 2$', lines[12])
154 call assert_match('^\s*1\s\+.*\sendif$', lines[13])
155 call assert_equal('', lines[14])
156 call assert_equal('FUNCTION Foo2()', lines[15])
157 call assert_equal('Called 1 time', lines[17])
158 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
159 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
160 call assert_equal('', lines[20])
161 call assert_equal('count total (s) self (s)', lines[21])
162 call assert_match('^\s*1\s\+.*\sif 0$', lines[22])
163 call assert_match( '^\s\+let x = 0$', lines[23])
164 call assert_match('^\s*1\s\+.*\selseif 1$', lines[24])
165 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
166 call assert_match( '^\s\+else$', lines[26])
167 call assert_match( '^\s\+let x = 2$', lines[27])
168 call assert_match('^\s*1\s\+.*\sendif$', lines[28])
169 call assert_equal('', lines[29])
170 call assert_equal('FUNCTION Foo3()', lines[30])
171 call assert_equal('Called 1 time', lines[32])
172 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
173 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
174 call assert_equal('', lines[35])
175 call assert_equal('count total (s) self (s)', lines[36])
176 call assert_match('^\s*1\s\+.*\sif 0$', lines[37])
177 call assert_match( '^\s\+let x = 0$', lines[38])
178 call assert_match('^\s*1\s\+.*\selseif 0$', lines[39])
179 call assert_match( '^\s\+let x = 1$', lines[40])
180 call assert_match('^\s*1\s\+.*\selse$', lines[41])
181 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
182 call assert_match('^\s*1\s\+.*\sendif$', lines[43])
183 call assert_equal('', lines[44])
184 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
185 call assert_equal('count total (s) self (s) function', lines[46])
186 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
187 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
188 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
189 call assert_equal('', lines[50])
190 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
191 call assert_equal('count total (s) self (s) function', lines[52])
192 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
193 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
194 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
195 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200196
197 call delete('Xprofile_func.vim')
198 call delete('Xprofile_func.log')
199endfunc
200
201func Test_profile_func_with_trycatch()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200202 let lines =<< trim [CODE]
203 func! Foo1()
204 try
205 let x = 0
206 catch
207 let x = 1
208 finally
209 let x = 2
210 endtry
211 endfunc
212 func! Foo2()
213 try
214 throw 0
215 catch
216 let x = 1
217 finally
218 let x = 2
219 endtry
220 endfunc
221 func! Foo3()
222 try
223 throw 0
224 catch
225 throw 1
226 finally
227 let x = 2
228 endtry
229 endfunc
230 call Foo1()
231 call Foo2()
232 try
233 call Foo3()
234 catch
235 endtry
236 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200237
238 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200239 call system(GetVimCommand()
240 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200241 \ . ' -c "profile start Xprofile_func.log"'
242 \ . ' -c "profile func Foo*"'
243 \ . ' -c "so Xprofile_func.vim"'
244 \ . ' -c "qall!"')
245 call assert_equal(0, v:shell_error)
246
247 let lines = readfile('Xprofile_func.log')
248
249 " - Foo1() should pass 'try' 'finally' blocks.
250 " - Foo2() should pass 'catch' 'finally' blocks.
251 " - Foo3() should not pass 'endtry'.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200252 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200253
254 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200255 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
256 call assert_equal('Called 1 time', lines[2])
257 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
258 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
259 call assert_equal('', lines[5])
260 call assert_equal('count total (s) self (s)', lines[6])
261 call assert_match('^\s*1\s\+.*\stry$', lines[7])
262 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
263 call assert_match( '^\s\+catch$', lines[9])
264 call assert_match( '^\s\+let x = 1$', lines[10])
265 call assert_match('^\s*1\s\+.*\sfinally$', lines[11])
266 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12])
267 call assert_match('^\s*1\s\+.*\sendtry$', lines[13])
268 call assert_equal('', lines[14])
269 call assert_equal('FUNCTION Foo2()', lines[15])
270 call assert_equal('Called 1 time', lines[17])
271 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
272 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
273 call assert_equal('', lines[20])
274 call assert_equal('count total (s) self (s)', lines[21])
275 call assert_match('^\s*1\s\+.*\stry$', lines[22])
276 call assert_match('^\s*1\s\+.*\s throw 0$', lines[23])
277 call assert_match('^\s*1\s\+.*\scatch$', lines[24])
278 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
279 call assert_match('^\s*1\s\+.*\sfinally$', lines[26])
280 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27])
281 call assert_match('^\s*1\s\+.*\sendtry$', lines[28])
282 call assert_equal('', lines[29])
283 call assert_equal('FUNCTION Foo3()', lines[30])
284 call assert_equal('Called 1 time', lines[32])
285 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
286 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
287 call assert_equal('', lines[35])
288 call assert_equal('count total (s) self (s)', lines[36])
289 call assert_match('^\s*1\s\+.*\stry$', lines[37])
290 call assert_match('^\s*1\s\+.*\s throw 0$', lines[38])
291 call assert_match('^\s*1\s\+.*\scatch$', lines[39])
292 call assert_match('^\s*1\s\+.*\s throw 1$', lines[40])
293 call assert_match('^\s*1\s\+.*\sfinally$', lines[41])
294 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
295 call assert_match( '^\s\+endtry$', lines[43])
296 call assert_equal('', lines[44])
297 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
298 call assert_equal('count total (s) self (s) function', lines[46])
299 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
300 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
301 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
302 call assert_equal('', lines[50])
303 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
304 call assert_equal('count total (s) self (s) function', lines[52])
305 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
306 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
307 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
308 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200309
310 call delete('Xprofile_func.vim')
311 call delete('Xprofile_func.log')
312endfunc
313
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100314func Test_profile_file()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200315 let lines =<< trim [CODE]
Bram Moolenaare7eb9272019-06-24 00:58:07 +0200316 func! Foo()
317 endfunc
318 for i in range(10)
319 " a comment
320 call Foo()
321 endfor
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200322 call Foo()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200323 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100324
325 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200326 call system(GetVimCommandClean()
327 \ . ' -es'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +0100328 \ . ' -c "profile start Xprofile_file.log"'
329 \ . ' -c "profile file Xprofile_file.vim"'
330 \ . ' -c "so Xprofile_file.vim"'
331 \ . ' -c "so Xprofile_file.vim"'
332 \ . ' -c "qall!"')
333 call assert_equal(0, v:shell_error)
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100334
335 let lines = readfile('Xprofile_file.log')
336
337 call assert_equal(14, len(lines))
338
339 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
340 call assert_equal('Sourced 2 times', lines[1])
341 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
342 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
343 call assert_equal('', lines[4])
344 call assert_equal('count total (s) self (s)', lines[5])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200345 call assert_match(' 2 0.\d\+ func! Foo()', lines[6])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100346 call assert_equal(' endfunc', lines[7])
347 " Loop iterates 10 times. Since script runs twice, body executes 20 times.
348 " First line of loop executes one more time than body to detect end of loop.
349 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8])
350 call assert_equal(' " a comment', lines[9])
Bram Moolenaard21b16f2017-08-14 23:13:30 +0200351 " if self and total are equal we only get one number
352 call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200353 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11])
Bram Moolenaare32bbde2017-01-15 21:12:48 +0100354 " if self and total are equal we only get one number
355 call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100356 call assert_equal('', lines[13])
357
358 call delete('Xprofile_file.vim')
359 call delete('Xprofile_file.log')
360endfunc
361
Bram Moolenaar67435d92017-10-19 21:04:37 +0200362func Test_profile_file_with_cont()
363 let lines = [
364 \ 'echo "hello',
365 \ ' \ world"',
366 \ 'echo "foo ',
367 \ ' \bar"',
368 \ ]
369
370 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200371 call system(GetVimCommandClean()
372 \ . ' -es'
Bram Moolenaar67435d92017-10-19 21:04:37 +0200373 \ . ' -c "profile start Xprofile_file.log"'
374 \ . ' -c "profile file Xprofile_file.vim"'
375 \ . ' -c "so Xprofile_file.vim"'
376 \ . ' -c "qall!"')
377 call assert_equal(0, v:shell_error)
378
379 let lines = readfile('Xprofile_file.log')
380 call assert_equal(11, len(lines))
381
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200382 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
383 call assert_equal('Sourced 1 time', lines[1])
384 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
385 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
386 call assert_equal('', lines[4])
387 call assert_equal('count total (s) self (s)', lines[5])
388 call assert_match(' 1 0.\d\+ echo "hello', lines[6])
389 call assert_equal(' \ world"', lines[7])
390 call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
391 call assert_equal(' \bar"', lines[9])
392 call assert_equal('', lines[10])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200393
394 call delete('Xprofile_file.vim')
395 call delete('Xprofile_file.log')
396endfunc
397
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100398func Test_profile_completion()
399 call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
400 call assert_equal('"profile continue file func pause start', @:)
401
402 call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
403 call assert_match('^"profile start.* test_profile\.vim', @:)
404endfunc
405
406func Test_profile_errors()
407 call assert_fails("profile func Foo", 'E750:')
408 call assert_fails("profile pause", 'E750:')
409 call assert_fails("profile continue", 'E750:')
410endfunc
Bram Moolenaarac112f02017-12-05 16:46:28 +0100411
412func Test_profile_truncate_mbyte()
Bram Moolenaar30276f22019-01-24 17:59:39 +0100413 if &enc !=# 'utf-8'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100414 return
415 endif
416
417 let lines = [
418 \ 'scriptencoding utf-8',
419 \ 'func! Foo()',
420 \ ' return [',
421 \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",',
422 \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",',
423 \ ' \ ]',
424 \ 'endfunc',
425 \ 'call Foo()',
426 \ ]
427
428 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200429 call system(GetVimCommandClean()
430 \ . ' -es --cmd "set enc=utf-8"'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100431 \ . ' -c "profile start Xprofile_file.log"'
432 \ . ' -c "profile file Xprofile_file.vim"'
433 \ . ' -c "so Xprofile_file.vim"'
434 \ . ' -c "qall!"')
435 call assert_equal(0, v:shell_error)
436
437 split Xprofile_file.log
438 if &fenc != ''
439 call assert_equal('utf-8', &fenc)
440 endif
441 /func! Foo()
442 let lnum = line('.')
443 call assert_match('^\s*return \[$', getline(lnum + 1))
444 call assert_match("\u4F52$", getline(lnum + 2))
445 call assert_match("\u5052$", getline(lnum + 3))
446 call assert_match('^\s*\\ \]$', getline(lnum + 4))
447 bwipe!
448
449 call delete('Xprofile_file.vim')
450 call delete('Xprofile_file.log')
451endfunc
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200452
453func Test_profdel_func()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200454 let lines =<< trim [CODE]
455 profile start Xprofile_file.log
456 func! Foo1()
457 endfunc
458 func! Foo2()
459 endfunc
460 func! Foo3()
461 endfunc
462
463 profile func Foo1
464 profile func Foo2
465 call Foo1()
466 call Foo2()
467
468 profile func Foo3
469 profdel func Foo2
470 profdel func Foo3
471 call Foo1()
472 call Foo2()
473 call Foo3()
474 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200475 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200476 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200477 call assert_equal(0, v:shell_error)
478
479 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200480 call assert_equal(26, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200481
482 " Check that:
483 " - Foo1() is called twice (profdel not invoked)
484 " - Foo2() is called once (profdel invoked after it was called)
485 " - Foo3() is not called (profdel invoked before it was called)
486 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200487 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
488 call assert_equal('Called 2 times', lines[2])
489 call assert_equal('FUNCTION Foo2()', lines[8])
490 call assert_equal('Called 1 time', lines[10])
491 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16])
492 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200493
494 call delete('Xprofile_file.vim')
495 call delete('Xprofile_file.log')
496endfunc
497
498func Test_profdel_star()
499 " Foo() is invoked once before and once after 'profdel *'.
500 " So profiling should report it only once.
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200501 let lines =<< trim [CODE]
502 profile start Xprofile_file.log
503 func! Foo()
504 endfunc
505 profile func Foo
506 call Foo()
507 profdel *
508 call Foo()
509 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200510 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200511 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200512 call assert_equal(0, v:shell_error)
513
514 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200515 call assert_equal(16, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200516
517 call assert_equal('FUNCTION Foo()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200518 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
519 call assert_equal('Called 1 time', lines[2])
520 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8])
521 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200522
523 call delete('Xprofile_file.vim')
524 call delete('Xprofile_file.log')
525endfunc
Bram Moolenaar16358802019-08-30 18:37:26 +0200526
527" When typing the function it won't have a script ID, test that this works.
528func Test_profile_typed_func()
529 CheckScreendump
530
531 let lines =<< trim END
532 profile start XprofileTypedFunc
533 END
534 call writefile(lines, 'XtestProfile')
535 let buf = RunVimInTerminal('-S XtestProfile', #{})
536
537 call term_sendkeys(buf, ":func DoSomething()\<CR>"
538 \ .. "echo 'hello'\<CR>"
539 \ .. "endfunc\<CR>")
540 call term_sendkeys(buf, ":profile func DoSomething\<CR>")
541 call term_sendkeys(buf, ":call DoSomething()\<CR>")
542 call term_wait(buf, 200)
543 call StopVimInTerminal(buf)
544 let lines = readfile('XprofileTypedFunc')
545 call assert_equal("FUNCTION DoSomething()", lines[0])
546 call assert_equal("Called 1 time", lines[1])
547
548 " clean up
549 call delete('XprofileTypedFunc')
550 call delete('XtestProfile')
551endfunc