blob: c7f515a8939ffde2526433a4238ae1670b972db4 [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
7
Bram Moolenaar296b1f22017-01-15 15:22:33 +01008func Test_profile_func()
Bram Moolenaarc79745a2019-05-20 22:12:34 +02009 let lines =<< trim [CODE]
10 profile start Xprofile_func.log
11 profile func Foo*
12 func! Foo1()
13 endfunc
14 func! Foo2()
15 let l:count = 100
16 while l:count > 0
17 let l:count = l:count - 1
18 endwhile
19 endfunc
20 func! Foo3()
21 endfunc
22 func! Bar()
23 endfunc
24 call Foo1()
25 call Foo1()
26 profile pause
27 call Foo1()
28 profile continue
29 call Foo2()
30 call Foo3()
31 call Bar()
32 if !v:profiling
33 delfunc Foo2
34 endif
35 delfunc Foo3
36 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +010037
38 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +020039 call system(GetVimCommand()
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +020040 \ . ' -es --clean'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010041 \ . ' -c "so Xprofile_func.vim"'
42 \ . ' -c "qall!"')
43 call assert_equal(0, v:shell_error)
44
Bram Moolenaar296b1f22017-01-15 15:22:33 +010045 let lines = readfile('Xprofile_func.log')
46
Bram Moolenaar296b1f22017-01-15 15:22:33 +010047 " - Foo1() is called 3 times but should be reported as called twice
48 " since one call is in between "profile pause" .. "profile continue".
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010049 " - Foo2() should come before Foo1() since Foo1() does much more work.
Bram Moolenaar296b1f22017-01-15 15:22:33 +010050 " - Foo3() is not reported because function is deleted.
51 " - Unlike Foo3(), Foo2() should not be deleted since there is a check
52 " for v:profiling.
53 " - Bar() is not reported since it does not match "profile func Foo*".
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020054 call assert_equal(30, len(lines))
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010055
56 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020057 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
58 call assert_equal('Called 2 times', lines[2])
59 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
60 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
61 call assert_equal('', lines[5])
62 call assert_equal('count total (s) self (s)', lines[6])
63 call assert_equal('', lines[7])
64 call assert_equal('FUNCTION Foo2()', lines[8])
65 call assert_equal('Called 1 time', lines[10])
66 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11])
67 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12])
68 call assert_equal('', lines[13])
69 call assert_equal('count total (s) self (s)', lines[14])
70 call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[15])
71 call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[16])
72 call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[17])
73 call assert_match('^\s*101\s\+.*\sendwhile$', lines[18])
74 call assert_equal('', lines[19])
75 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[20])
76 call assert_equal('count total (s) self (s) function', lines[21])
77 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[22])
78 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[23])
79 call assert_equal('', lines[24])
80 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[25])
81 call assert_equal('count total (s) self (s) function', lines[26])
82 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[27])
83 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[28])
84 call assert_equal('', lines[29])
Bram Moolenaar296b1f22017-01-15 15:22:33 +010085
86 call delete('Xprofile_func.vim')
87 call delete('Xprofile_func.log')
88endfunc
89
Bram Moolenaar7feb35e2018-08-21 17:49:54 +020090func Test_profile_func_with_ifelse()
Bram Moolenaarc79745a2019-05-20 22:12:34 +020091 let lines =<< trim [CODE]
92 func! Foo1()
93 if 1
94 let x = 0
95 elseif 1
96 let x = 1
97 else
98 let x = 2
99 endif
100 endfunc
101 func! Foo2()
102 if 0
103 let x = 0
104 elseif 1
105 let x = 1
106 else
107 let x = 2
108 endif
109 endfunc
110 func! Foo3()
111 if 0
112 let x = 0
113 elseif 0
114 let x = 1
115 else
116 let x = 2
117 endif
118 endfunc
119 call Foo1()
120 call Foo2()
121 call Foo3()
122 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200123
124 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200125 call system(GetVimCommand()
126 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200127 \ . ' -c "profile start Xprofile_func.log"'
128 \ . ' -c "profile func Foo*"'
129 \ . ' -c "so Xprofile_func.vim"'
130 \ . ' -c "qall!"')
131 call assert_equal(0, v:shell_error)
132
133 let lines = readfile('Xprofile_func.log')
134
135 " - Foo1() should pass 'if' block.
136 " - Foo2() should pass 'elseif' block.
137 " - Foo3() should pass 'else' block.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200138 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200139
140 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200141 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
142 call assert_equal('Called 1 time', lines[2])
143 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
144 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
145 call assert_equal('', lines[5])
146 call assert_equal('count total (s) self (s)', lines[6])
147 call assert_match('^\s*1\s\+.*\sif 1$', lines[7])
148 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
149 call assert_match( '^\s\+elseif 1$', lines[9])
150 call assert_match( '^\s\+let x = 1$', lines[10])
151 call assert_match( '^\s\+else$', lines[11])
152 call assert_match( '^\s\+let x = 2$', lines[12])
153 call assert_match('^\s*1\s\+.*\sendif$', lines[13])
154 call assert_equal('', lines[14])
155 call assert_equal('FUNCTION Foo2()', lines[15])
156 call assert_equal('Called 1 time', lines[17])
157 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
158 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
159 call assert_equal('', lines[20])
160 call assert_equal('count total (s) self (s)', lines[21])
161 call assert_match('^\s*1\s\+.*\sif 0$', lines[22])
162 call assert_match( '^\s\+let x = 0$', lines[23])
163 call assert_match('^\s*1\s\+.*\selseif 1$', lines[24])
164 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
165 call assert_match( '^\s\+else$', lines[26])
166 call assert_match( '^\s\+let x = 2$', lines[27])
167 call assert_match('^\s*1\s\+.*\sendif$', lines[28])
168 call assert_equal('', lines[29])
169 call assert_equal('FUNCTION Foo3()', lines[30])
170 call assert_equal('Called 1 time', lines[32])
171 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
172 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
173 call assert_equal('', lines[35])
174 call assert_equal('count total (s) self (s)', lines[36])
175 call assert_match('^\s*1\s\+.*\sif 0$', lines[37])
176 call assert_match( '^\s\+let x = 0$', lines[38])
177 call assert_match('^\s*1\s\+.*\selseif 0$', lines[39])
178 call assert_match( '^\s\+let x = 1$', lines[40])
179 call assert_match('^\s*1\s\+.*\selse$', lines[41])
180 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
181 call assert_match('^\s*1\s\+.*\sendif$', lines[43])
182 call assert_equal('', lines[44])
183 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
184 call assert_equal('count total (s) self (s) function', lines[46])
185 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
186 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
187 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
188 call assert_equal('', lines[50])
189 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
190 call assert_equal('count total (s) self (s) function', lines[52])
191 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
192 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
193 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
194 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200195
196 call delete('Xprofile_func.vim')
197 call delete('Xprofile_func.log')
198endfunc
199
200func Test_profile_func_with_trycatch()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200201 let lines =<< trim [CODE]
202 func! Foo1()
203 try
204 let x = 0
205 catch
206 let x = 1
207 finally
208 let x = 2
209 endtry
210 endfunc
211 func! Foo2()
212 try
213 throw 0
214 catch
215 let x = 1
216 finally
217 let x = 2
218 endtry
219 endfunc
220 func! Foo3()
221 try
222 throw 0
223 catch
224 throw 1
225 finally
226 let x = 2
227 endtry
228 endfunc
229 call Foo1()
230 call Foo2()
231 try
232 call Foo3()
233 catch
234 endtry
235 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200236
237 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200238 call system(GetVimCommand()
239 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200240 \ . ' -c "profile start Xprofile_func.log"'
241 \ . ' -c "profile func Foo*"'
242 \ . ' -c "so Xprofile_func.vim"'
243 \ . ' -c "qall!"')
244 call assert_equal(0, v:shell_error)
245
246 let lines = readfile('Xprofile_func.log')
247
248 " - Foo1() should pass 'try' 'finally' blocks.
249 " - Foo2() should pass 'catch' 'finally' blocks.
250 " - Foo3() should not pass 'endtry'.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200251 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200252
253 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200254 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
255 call assert_equal('Called 1 time', lines[2])
256 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
257 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
258 call assert_equal('', lines[5])
259 call assert_equal('count total (s) self (s)', lines[6])
260 call assert_match('^\s*1\s\+.*\stry$', lines[7])
261 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
262 call assert_match( '^\s\+catch$', lines[9])
263 call assert_match( '^\s\+let x = 1$', lines[10])
264 call assert_match('^\s*1\s\+.*\sfinally$', lines[11])
265 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12])
266 call assert_match('^\s*1\s\+.*\sendtry$', lines[13])
267 call assert_equal('', lines[14])
268 call assert_equal('FUNCTION Foo2()', lines[15])
269 call assert_equal('Called 1 time', lines[17])
270 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
271 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
272 call assert_equal('', lines[20])
273 call assert_equal('count total (s) self (s)', lines[21])
274 call assert_match('^\s*1\s\+.*\stry$', lines[22])
275 call assert_match('^\s*1\s\+.*\s throw 0$', lines[23])
276 call assert_match('^\s*1\s\+.*\scatch$', lines[24])
277 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
278 call assert_match('^\s*1\s\+.*\sfinally$', lines[26])
279 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27])
280 call assert_match('^\s*1\s\+.*\sendtry$', lines[28])
281 call assert_equal('', lines[29])
282 call assert_equal('FUNCTION Foo3()', lines[30])
283 call assert_equal('Called 1 time', lines[32])
284 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
285 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
286 call assert_equal('', lines[35])
287 call assert_equal('count total (s) self (s)', lines[36])
288 call assert_match('^\s*1\s\+.*\stry$', lines[37])
289 call assert_match('^\s*1\s\+.*\s throw 0$', lines[38])
290 call assert_match('^\s*1\s\+.*\scatch$', lines[39])
291 call assert_match('^\s*1\s\+.*\s throw 1$', lines[40])
292 call assert_match('^\s*1\s\+.*\sfinally$', lines[41])
293 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
294 call assert_match( '^\s\+endtry$', lines[43])
295 call assert_equal('', lines[44])
296 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
297 call assert_equal('count total (s) self (s) function', lines[46])
298 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
299 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
300 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
301 call assert_equal('', lines[50])
302 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
303 call assert_equal('count total (s) self (s) function', lines[52])
304 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
305 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
306 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
307 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200308
309 call delete('Xprofile_func.vim')
310 call delete('Xprofile_func.log')
311endfunc
312
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100313func Test_profile_file()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200314 let lines =<< trim [CODE]
Bram Moolenaare7eb9272019-06-24 00:58:07 +0200315 func! Foo()
316 endfunc
317 for i in range(10)
318 " a comment
319 call Foo()
320 endfor
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200321 call Foo()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200322 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100323
324 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200325 call system(GetVimCommandClean()
326 \ . ' -es'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +0100327 \ . ' -c "profile start Xprofile_file.log"'
328 \ . ' -c "profile file Xprofile_file.vim"'
329 \ . ' -c "so Xprofile_file.vim"'
330 \ . ' -c "so Xprofile_file.vim"'
331 \ . ' -c "qall!"')
332 call assert_equal(0, v:shell_error)
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100333
334 let lines = readfile('Xprofile_file.log')
335
336 call assert_equal(14, len(lines))
337
338 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
339 call assert_equal('Sourced 2 times', lines[1])
340 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
341 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
342 call assert_equal('', lines[4])
343 call assert_equal('count total (s) self (s)', lines[5])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200344 call assert_match(' 2 0.\d\+ func! Foo()', lines[6])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100345 call assert_equal(' endfunc', lines[7])
346 " Loop iterates 10 times. Since script runs twice, body executes 20 times.
347 " First line of loop executes one more time than body to detect end of loop.
348 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8])
349 call assert_equal(' " a comment', lines[9])
Bram Moolenaard21b16f2017-08-14 23:13:30 +0200350 " if self and total are equal we only get one number
351 call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200352 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11])
Bram Moolenaare32bbde2017-01-15 21:12:48 +0100353 " if self and total are equal we only get one number
354 call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100355 call assert_equal('', lines[13])
356
357 call delete('Xprofile_file.vim')
358 call delete('Xprofile_file.log')
359endfunc
360
Bram Moolenaar67435d92017-10-19 21:04:37 +0200361func Test_profile_file_with_cont()
362 let lines = [
363 \ 'echo "hello',
364 \ ' \ world"',
365 \ 'echo "foo ',
366 \ ' \bar"',
367 \ ]
368
369 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200370 call system(GetVimCommandClean()
371 \ . ' -es'
Bram Moolenaar67435d92017-10-19 21:04:37 +0200372 \ . ' -c "profile start Xprofile_file.log"'
373 \ . ' -c "profile file Xprofile_file.vim"'
374 \ . ' -c "so Xprofile_file.vim"'
375 \ . ' -c "qall!"')
376 call assert_equal(0, v:shell_error)
377
378 let lines = readfile('Xprofile_file.log')
379 call assert_equal(11, len(lines))
380
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200381 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
382 call assert_equal('Sourced 1 time', lines[1])
383 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
384 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
385 call assert_equal('', lines[4])
386 call assert_equal('count total (s) self (s)', lines[5])
387 call assert_match(' 1 0.\d\+ echo "hello', lines[6])
388 call assert_equal(' \ world"', lines[7])
389 call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
390 call assert_equal(' \bar"', lines[9])
391 call assert_equal('', lines[10])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200392
393 call delete('Xprofile_file.vim')
394 call delete('Xprofile_file.log')
395endfunc
396
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100397func Test_profile_completion()
398 call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
399 call assert_equal('"profile continue file func pause start', @:)
400
401 call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
402 call assert_match('^"profile start.* test_profile\.vim', @:)
403endfunc
404
405func Test_profile_errors()
406 call assert_fails("profile func Foo", 'E750:')
407 call assert_fails("profile pause", 'E750:')
408 call assert_fails("profile continue", 'E750:')
409endfunc
Bram Moolenaarac112f02017-12-05 16:46:28 +0100410
411func Test_profile_truncate_mbyte()
Bram Moolenaar30276f22019-01-24 17:59:39 +0100412 if &enc !=# 'utf-8'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100413 return
414 endif
415
416 let lines = [
417 \ 'scriptencoding utf-8',
418 \ 'func! Foo()',
419 \ ' return [',
420 \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",',
421 \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",',
422 \ ' \ ]',
423 \ 'endfunc',
424 \ 'call Foo()',
425 \ ]
426
427 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200428 call system(GetVimCommandClean()
429 \ . ' -es --cmd "set enc=utf-8"'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100430 \ . ' -c "profile start Xprofile_file.log"'
431 \ . ' -c "profile file Xprofile_file.vim"'
432 \ . ' -c "so Xprofile_file.vim"'
433 \ . ' -c "qall!"')
434 call assert_equal(0, v:shell_error)
435
436 split Xprofile_file.log
437 if &fenc != ''
438 call assert_equal('utf-8', &fenc)
439 endif
440 /func! Foo()
441 let lnum = line('.')
442 call assert_match('^\s*return \[$', getline(lnum + 1))
443 call assert_match("\u4F52$", getline(lnum + 2))
444 call assert_match("\u5052$", getline(lnum + 3))
445 call assert_match('^\s*\\ \]$', getline(lnum + 4))
446 bwipe!
447
448 call delete('Xprofile_file.vim')
449 call delete('Xprofile_file.log')
450endfunc
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200451
452func Test_profdel_func()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200453 let lines =<< trim [CODE]
454 profile start Xprofile_file.log
455 func! Foo1()
456 endfunc
457 func! Foo2()
458 endfunc
459 func! Foo3()
460 endfunc
461
462 profile func Foo1
463 profile func Foo2
464 call Foo1()
465 call Foo2()
466
467 profile func Foo3
468 profdel func Foo2
469 profdel func Foo3
470 call Foo1()
471 call Foo2()
472 call Foo3()
473 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200474 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200475 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200476 call assert_equal(0, v:shell_error)
477
478 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200479 call assert_equal(26, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200480
481 " Check that:
482 " - Foo1() is called twice (profdel not invoked)
483 " - Foo2() is called once (profdel invoked after it was called)
484 " - Foo3() is not called (profdel invoked before it was called)
485 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200486 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
487 call assert_equal('Called 2 times', lines[2])
488 call assert_equal('FUNCTION Foo2()', lines[8])
489 call assert_equal('Called 1 time', lines[10])
490 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16])
491 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200492
493 call delete('Xprofile_file.vim')
494 call delete('Xprofile_file.log')
495endfunc
496
497func Test_profdel_star()
498 " Foo() is invoked once before and once after 'profdel *'.
499 " So profiling should report it only once.
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200500 let lines =<< trim [CODE]
501 profile start Xprofile_file.log
502 func! Foo()
503 endfunc
504 profile func Foo
505 call Foo()
506 profdel *
507 call Foo()
508 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200509 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200510 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200511 call assert_equal(0, v:shell_error)
512
513 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200514 call assert_equal(16, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200515
516 call assert_equal('FUNCTION Foo()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200517 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
518 call assert_equal('Called 1 time', lines[2])
519 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8])
520 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200521
522 call delete('Xprofile_file.vim')
523 call delete('Xprofile_file.log')
524endfunc