blob: d6e9c03bd59d4a3e2f88db724a03b10f15c3abce [file] [log] [blame]
Bram Moolenaar296b1f22017-01-15 15:22:33 +01001" Test Vim profiler
2if !has('profile')
3 finish
4endif
5
6func Test_profile_func()
Bram Moolenaar296b1f22017-01-15 15:22:33 +01007 let lines = [
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +02008 \ 'profile start Xprofile_func.log',
9 \ 'profile func Foo*"',
Bram Moolenaar296b1f22017-01-15 15:22:33 +010010 \ "func! Foo1()",
11 \ "endfunc",
12 \ "func! Foo2()",
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010013 \ " let l:count = 100",
14 \ " while l:count > 0",
15 \ " let l:count = l:count - 1",
Bram Moolenaar296b1f22017-01-15 15:22:33 +010016 \ " endwhile",
17 \ "endfunc",
18 \ "func! Foo3()",
19 \ "endfunc",
20 \ "func! Bar()",
21 \ "endfunc",
22 \ "call Foo1()",
23 \ "call Foo1()",
24 \ "profile pause",
25 \ "call Foo1()",
26 \ "profile continue",
27 \ "call Foo2()",
28 \ "call Foo3()",
29 \ "call Bar()",
30 \ "if !v:profiling",
31 \ " delfunc Foo2",
32 \ "endif",
33 \ "delfunc Foo3",
34 \ ]
35
36 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010037 call system(v:progpath
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +020038 \ . ' -es --clean'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010039 \ . ' -c "so Xprofile_func.vim"'
40 \ . ' -c "qall!"')
41 call assert_equal(0, v:shell_error)
42
Bram Moolenaar296b1f22017-01-15 15:22:33 +010043 let lines = readfile('Xprofile_func.log')
44
Bram Moolenaar296b1f22017-01-15 15:22:33 +010045 " - Foo1() is called 3 times but should be reported as called twice
46 " since one call is in between "profile pause" .. "profile continue".
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010047 " - Foo2() should come before Foo1() since Foo1() does much more work.
Bram Moolenaar296b1f22017-01-15 15:22:33 +010048 " - Foo3() is not reported because function is deleted.
49 " - Unlike Foo3(), Foo2() should not be deleted since there is a check
50 " for v:profiling.
51 " - Bar() is not reported since it does not match "profile func Foo*".
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020052 call assert_equal(30, len(lines))
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010053
54 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020055 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
56 call assert_equal('Called 2 times', lines[2])
57 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
58 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
59 call assert_equal('', lines[5])
60 call assert_equal('count total (s) self (s)', lines[6])
61 call assert_equal('', lines[7])
62 call assert_equal('FUNCTION Foo2()', lines[8])
63 call assert_equal('Called 1 time', lines[10])
64 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11])
65 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12])
66 call assert_equal('', lines[13])
67 call assert_equal('count total (s) self (s)', lines[14])
68 call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[15])
69 call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[16])
70 call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[17])
71 call assert_match('^\s*101\s\+.*\sendwhile$', lines[18])
72 call assert_equal('', lines[19])
73 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[20])
74 call assert_equal('count total (s) self (s) function', lines[21])
75 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[22])
76 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[23])
77 call assert_equal('', lines[24])
78 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[25])
79 call assert_equal('count total (s) self (s) function', lines[26])
80 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[27])
81 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[28])
82 call assert_equal('', lines[29])
Bram Moolenaar296b1f22017-01-15 15:22:33 +010083
84 call delete('Xprofile_func.vim')
85 call delete('Xprofile_func.log')
86endfunc
87
Bram Moolenaar7feb35e2018-08-21 17:49:54 +020088func Test_profile_func_with_ifelse()
89 let lines = [
90 \ "func! Foo1()",
91 \ " if 1",
92 \ " let x = 0",
93 \ " elseif 1",
94 \ " let x = 1",
95 \ " else",
96 \ " let x = 2",
97 \ " endif",
98 \ "endfunc",
99 \ "func! Foo2()",
100 \ " if 0",
101 \ " let x = 0",
102 \ " elseif 1",
103 \ " let x = 1",
104 \ " else",
105 \ " let x = 2",
106 \ " endif",
107 \ "endfunc",
108 \ "func! Foo3()",
109 \ " if 0",
110 \ " let x = 0",
111 \ " elseif 0",
112 \ " let x = 1",
113 \ " else",
114 \ " let x = 2",
115 \ " endif",
116 \ "endfunc",
117 \ "call Foo1()",
118 \ "call Foo2()",
119 \ "call Foo3()",
120 \ ]
121
122 call writefile(lines, 'Xprofile_func.vim')
123 call system(v:progpath
124 \ . ' -es -u NONE -U NONE -i NONE --noplugin'
125 \ . ' -c "profile start Xprofile_func.log"'
126 \ . ' -c "profile func Foo*"'
127 \ . ' -c "so Xprofile_func.vim"'
128 \ . ' -c "qall!"')
129 call assert_equal(0, v:shell_error)
130
131 let lines = readfile('Xprofile_func.log')
132
133 " - Foo1() should pass 'if' block.
134 " - Foo2() should pass 'elseif' block.
135 " - Foo3() should pass 'else' block.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200136 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200137
138 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200139 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
140 call assert_equal('Called 1 time', lines[2])
141 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
142 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
143 call assert_equal('', lines[5])
144 call assert_equal('count total (s) self (s)', lines[6])
145 call assert_match('^\s*1\s\+.*\sif 1$', lines[7])
146 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
147 call assert_match( '^\s\+elseif 1$', lines[9])
148 call assert_match( '^\s\+let x = 1$', lines[10])
149 call assert_match( '^\s\+else$', lines[11])
150 call assert_match( '^\s\+let x = 2$', lines[12])
151 call assert_match('^\s*1\s\+.*\sendif$', lines[13])
152 call assert_equal('', lines[14])
153 call assert_equal('FUNCTION Foo2()', lines[15])
154 call assert_equal('Called 1 time', lines[17])
155 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
156 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
157 call assert_equal('', lines[20])
158 call assert_equal('count total (s) self (s)', lines[21])
159 call assert_match('^\s*1\s\+.*\sif 0$', lines[22])
160 call assert_match( '^\s\+let x = 0$', lines[23])
161 call assert_match('^\s*1\s\+.*\selseif 1$', lines[24])
162 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
163 call assert_match( '^\s\+else$', lines[26])
164 call assert_match( '^\s\+let x = 2$', lines[27])
165 call assert_match('^\s*1\s\+.*\sendif$', lines[28])
166 call assert_equal('', lines[29])
167 call assert_equal('FUNCTION Foo3()', lines[30])
168 call assert_equal('Called 1 time', lines[32])
169 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
170 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
171 call assert_equal('', lines[35])
172 call assert_equal('count total (s) self (s)', lines[36])
173 call assert_match('^\s*1\s\+.*\sif 0$', lines[37])
174 call assert_match( '^\s\+let x = 0$', lines[38])
175 call assert_match('^\s*1\s\+.*\selseif 0$', lines[39])
176 call assert_match( '^\s\+let x = 1$', lines[40])
177 call assert_match('^\s*1\s\+.*\selse$', lines[41])
178 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
179 call assert_match('^\s*1\s\+.*\sendif$', lines[43])
180 call assert_equal('', lines[44])
181 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
182 call assert_equal('count total (s) self (s) function', lines[46])
183 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
184 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
185 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
186 call assert_equal('', lines[50])
187 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
188 call assert_equal('count total (s) self (s) function', lines[52])
189 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
190 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
191 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
192 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200193
194 call delete('Xprofile_func.vim')
195 call delete('Xprofile_func.log')
196endfunc
197
198func Test_profile_func_with_trycatch()
199 let lines = [
200 \ "func! Foo1()",
201 \ " try",
202 \ " let x = 0",
203 \ " catch",
204 \ " let x = 1",
205 \ " finally",
206 \ " let x = 2",
207 \ " endtry",
208 \ "endfunc",
209 \ "func! Foo2()",
210 \ " try",
211 \ " throw 0",
212 \ " catch",
213 \ " let x = 1",
214 \ " finally",
215 \ " let x = 2",
216 \ " endtry",
217 \ "endfunc",
218 \ "func! Foo3()",
219 \ " try",
220 \ " throw 0",
221 \ " catch",
222 \ " throw 1",
223 \ " finally",
224 \ " let x = 2",
225 \ " endtry",
226 \ "endfunc",
227 \ "call Foo1()",
228 \ "call Foo2()",
229 \ "try",
230 \ " call Foo3()",
231 \ "catch",
232 \ "endtry",
233 \ ]
234
235 call writefile(lines, 'Xprofile_func.vim')
236 call system(v:progpath
237 \ . ' -es -u NONE -U NONE -i NONE --noplugin'
238 \ . ' -c "profile start Xprofile_func.log"'
239 \ . ' -c "profile func Foo*"'
240 \ . ' -c "so Xprofile_func.vim"'
241 \ . ' -c "qall!"')
242 call assert_equal(0, v:shell_error)
243
244 let lines = readfile('Xprofile_func.log')
245
246 " - Foo1() should pass 'try' 'finally' blocks.
247 " - Foo2() should pass 'catch' 'finally' blocks.
248 " - Foo3() should not pass 'endtry'.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200249 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200250
251 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200252 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
253 call assert_equal('Called 1 time', lines[2])
254 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
255 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
256 call assert_equal('', lines[5])
257 call assert_equal('count total (s) self (s)', lines[6])
258 call assert_match('^\s*1\s\+.*\stry$', lines[7])
259 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
260 call assert_match( '^\s\+catch$', lines[9])
261 call assert_match( '^\s\+let x = 1$', lines[10])
262 call assert_match('^\s*1\s\+.*\sfinally$', lines[11])
263 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12])
264 call assert_match('^\s*1\s\+.*\sendtry$', lines[13])
265 call assert_equal('', lines[14])
266 call assert_equal('FUNCTION Foo2()', lines[15])
267 call assert_equal('Called 1 time', lines[17])
268 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
269 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
270 call assert_equal('', lines[20])
271 call assert_equal('count total (s) self (s)', lines[21])
272 call assert_match('^\s*1\s\+.*\stry$', lines[22])
273 call assert_match('^\s*1\s\+.*\s throw 0$', lines[23])
274 call assert_match('^\s*1\s\+.*\scatch$', lines[24])
275 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
276 call assert_match('^\s*1\s\+.*\sfinally$', lines[26])
277 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27])
278 call assert_match('^\s*1\s\+.*\sendtry$', lines[28])
279 call assert_equal('', lines[29])
280 call assert_equal('FUNCTION Foo3()', lines[30])
281 call assert_equal('Called 1 time', lines[32])
282 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
283 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
284 call assert_equal('', lines[35])
285 call assert_equal('count total (s) self (s)', lines[36])
286 call assert_match('^\s*1\s\+.*\stry$', lines[37])
287 call assert_match('^\s*1\s\+.*\s throw 0$', lines[38])
288 call assert_match('^\s*1\s\+.*\scatch$', lines[39])
289 call assert_match('^\s*1\s\+.*\s throw 1$', lines[40])
290 call assert_match('^\s*1\s\+.*\sfinally$', lines[41])
291 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
292 call assert_match( '^\s\+endtry$', lines[43])
293 call assert_equal('', lines[44])
294 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
295 call assert_equal('count total (s) self (s) function', lines[46])
296 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
297 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
298 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
299 call assert_equal('', lines[50])
300 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
301 call assert_equal('count total (s) self (s) function', lines[52])
302 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
303 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
304 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
305 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200306
307 call delete('Xprofile_func.vim')
308 call delete('Xprofile_func.log')
309endfunc
310
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100311func Test_profile_file()
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100312 let lines = [
313 \ 'func! Foo()',
314 \ 'endfunc',
315 \ 'for i in range(10)',
316 \ ' " a comment',
317 \ ' call Foo()',
318 \ 'endfor',
319 \ 'call Foo()',
320 \ ]
321
322 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaarc011a3d2017-01-16 22:37:42 +0100323 call system(v:progpath
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200324 \ . ' -es --clean'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +0100325 \ . ' -c "profile start Xprofile_file.log"'
326 \ . ' -c "profile file Xprofile_file.vim"'
327 \ . ' -c "so Xprofile_file.vim"'
328 \ . ' -c "so Xprofile_file.vim"'
329 \ . ' -c "qall!"')
330 call assert_equal(0, v:shell_error)
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100331
332 let lines = readfile('Xprofile_file.log')
333
334 call assert_equal(14, len(lines))
335
336 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
337 call assert_equal('Sourced 2 times', lines[1])
338 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
339 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
340 call assert_equal('', lines[4])
341 call assert_equal('count total (s) self (s)', lines[5])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200342 call assert_match(' 2 0.\d\+ func! Foo()', lines[6])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100343 call assert_equal(' endfunc', lines[7])
344 " Loop iterates 10 times. Since script runs twice, body executes 20 times.
345 " First line of loop executes one more time than body to detect end of loop.
346 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8])
347 call assert_equal(' " a comment', lines[9])
Bram Moolenaard21b16f2017-08-14 23:13:30 +0200348 " if self and total are equal we only get one number
349 call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200350 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11])
Bram Moolenaare32bbde2017-01-15 21:12:48 +0100351 " if self and total are equal we only get one number
352 call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100353 call assert_equal('', lines[13])
354
355 call delete('Xprofile_file.vim')
356 call delete('Xprofile_file.log')
357endfunc
358
Bram Moolenaar67435d92017-10-19 21:04:37 +0200359func Test_profile_file_with_cont()
360 let lines = [
361 \ 'echo "hello',
362 \ ' \ world"',
363 \ 'echo "foo ',
364 \ ' \bar"',
365 \ ]
366
367 call writefile(lines, 'Xprofile_file.vim')
368 call system(v:progpath
369 \ . ' -es --clean'
370 \ . ' -c "profile start Xprofile_file.log"'
371 \ . ' -c "profile file Xprofile_file.vim"'
372 \ . ' -c "so Xprofile_file.vim"'
373 \ . ' -c "qall!"')
374 call assert_equal(0, v:shell_error)
375
376 let lines = readfile('Xprofile_file.log')
377 call assert_equal(11, len(lines))
378
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200379 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
380 call assert_equal('Sourced 1 time', lines[1])
381 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
382 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
383 call assert_equal('', lines[4])
384 call assert_equal('count total (s) self (s)', lines[5])
385 call assert_match(' 1 0.\d\+ echo "hello', lines[6])
386 call assert_equal(' \ world"', lines[7])
387 call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
388 call assert_equal(' \bar"', lines[9])
389 call assert_equal('', lines[10])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200390
391 call delete('Xprofile_file.vim')
392 call delete('Xprofile_file.log')
393endfunc
394
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100395func Test_profile_completion()
396 call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
397 call assert_equal('"profile continue file func pause start', @:)
398
399 call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
400 call assert_match('^"profile start.* test_profile\.vim', @:)
401endfunc
402
403func Test_profile_errors()
404 call assert_fails("profile func Foo", 'E750:')
405 call assert_fails("profile pause", 'E750:')
406 call assert_fails("profile continue", 'E750:')
407endfunc
Bram Moolenaarac112f02017-12-05 16:46:28 +0100408
409func Test_profile_truncate_mbyte()
Bram Moolenaar30276f22019-01-24 17:59:39 +0100410 if &enc !=# 'utf-8'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100411 return
412 endif
413
414 let lines = [
415 \ 'scriptencoding utf-8',
416 \ 'func! Foo()',
417 \ ' return [',
418 \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",',
419 \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",',
420 \ ' \ ]',
421 \ 'endfunc',
422 \ 'call Foo()',
423 \ ]
424
425 call writefile(lines, 'Xprofile_file.vim')
426 call system(v:progpath
427 \ . ' -es --clean --cmd "set enc=utf-8"'
428 \ . ' -c "profile start Xprofile_file.log"'
429 \ . ' -c "profile file Xprofile_file.vim"'
430 \ . ' -c "so Xprofile_file.vim"'
431 \ . ' -c "qall!"')
432 call assert_equal(0, v:shell_error)
433
434 split Xprofile_file.log
435 if &fenc != ''
436 call assert_equal('utf-8', &fenc)
437 endif
438 /func! Foo()
439 let lnum = line('.')
440 call assert_match('^\s*return \[$', getline(lnum + 1))
441 call assert_match("\u4F52$", getline(lnum + 2))
442 call assert_match("\u5052$", getline(lnum + 3))
443 call assert_match('^\s*\\ \]$', getline(lnum + 4))
444 bwipe!
445
446 call delete('Xprofile_file.vim')
447 call delete('Xprofile_file.log')
448endfunc
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200449
450func Test_profdel_func()
451 let lines = [
452 \ 'profile start Xprofile_file.log',
453 \ 'func! Foo1()',
454 \ 'endfunc',
455 \ 'func! Foo2()',
456 \ 'endfunc',
457 \ 'func! Foo3()',
458 \ 'endfunc',
459 \ '',
460 \ 'profile func Foo1',
461 \ 'profile func Foo2',
462 \ 'call Foo1()',
463 \ 'call Foo2()',
464 \ '',
465 \ 'profile func Foo3',
466 \ 'profdel func Foo2',
467 \ 'profdel func Foo3',
468 \ 'call Foo1()',
469 \ 'call Foo2()',
470 \ 'call Foo3()' ]
471 call writefile(lines, 'Xprofile_file.vim')
472 call system(v:progpath . ' -es --clean -c "so Xprofile_file.vim" -c q')
473 call assert_equal(0, v:shell_error)
474
475 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200476 call assert_equal(26, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200477
478 " Check that:
479 " - Foo1() is called twice (profdel not invoked)
480 " - Foo2() is called once (profdel invoked after it was called)
481 " - Foo3() is not called (profdel invoked before it was called)
482 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200483 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
484 call assert_equal('Called 2 times', lines[2])
485 call assert_equal('FUNCTION Foo2()', lines[8])
486 call assert_equal('Called 1 time', lines[10])
487 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16])
488 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200489
490 call delete('Xprofile_file.vim')
491 call delete('Xprofile_file.log')
492endfunc
493
494func Test_profdel_star()
495 " Foo() is invoked once before and once after 'profdel *'.
496 " So profiling should report it only once.
497 let lines = [
498 \ 'profile start Xprofile_file.log',
499 \ 'func! Foo()',
500 \ 'endfunc',
501 \ 'profile func Foo',
502 \ 'call Foo()',
503 \ 'profdel *',
504 \ 'call Foo()' ]
505 call writefile(lines, 'Xprofile_file.vim')
506 call system(v:progpath . ' -es --clean -c "so Xprofile_file.vim" -c q')
507 call assert_equal(0, v:shell_error)
508
509 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200510 call assert_equal(16, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200511
512 call assert_equal('FUNCTION Foo()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200513 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
514 call assert_equal('Called 1 time', lines[2])
515 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8])
516 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200517
518 call delete('Xprofile_file.vim')
519 call delete('Xprofile_file.log')
520endfunc