blob: 7018ea5fbc27009cfe0cf18fadfd6106d96681c6 [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
Bram Moolenaara21df1d2020-03-17 20:57:09 +010020 sleep 1m
Bram Moolenaarc79745a2019-05-20 22:12:34 +020021 endfunc
22 func! Foo3()
23 endfunc
24 func! Bar()
25 endfunc
26 call Foo1()
27 call Foo1()
28 profile pause
29 call Foo1()
30 profile continue
31 call Foo2()
32 call Foo3()
33 call Bar()
34 if !v:profiling
35 delfunc Foo2
36 endif
37 delfunc Foo3
38 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +010039
40 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +020041 call system(GetVimCommand()
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +020042 \ . ' -es --clean'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010043 \ . ' -c "so Xprofile_func.vim"'
44 \ . ' -c "qall!"')
45 call assert_equal(0, v:shell_error)
46
Bram Moolenaar296b1f22017-01-15 15:22:33 +010047 let lines = readfile('Xprofile_func.log')
48
Bram Moolenaar296b1f22017-01-15 15:22:33 +010049 " - Foo1() is called 3 times but should be reported as called twice
50 " since one call is in between "profile pause" .. "profile continue".
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010051 " - Foo2() should come before Foo1() since Foo1() does much more work.
Bram Moolenaar296b1f22017-01-15 15:22:33 +010052 " - Foo3() is not reported because function is deleted.
53 " - Unlike Foo3(), Foo2() should not be deleted since there is a check
54 " for v:profiling.
55 " - Bar() is not reported since it does not match "profile func Foo*".
Bram Moolenaara21df1d2020-03-17 20:57:09 +010056 call assert_equal(31, len(lines))
Bram Moolenaarc011a3d2017-01-16 22:37:42 +010057
58 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar181d4f52019-09-18 22:04:56 +020059 call assert_match('Defined:.*Xprofile_func.vim:3', lines[1])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +020060 call assert_equal('Called 2 times', lines[2])
61 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
62 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
63 call assert_equal('', lines[5])
64 call assert_equal('count total (s) self (s)', lines[6])
65 call assert_equal('', lines[7])
66 call assert_equal('FUNCTION Foo2()', lines[8])
67 call assert_equal('Called 1 time', lines[10])
68 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11])
69 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12])
70 call assert_equal('', lines[13])
71 call assert_equal('count total (s) self (s)', lines[14])
72 call assert_match('^\s*1\s\+.*\slet l:count = 100$', lines[15])
73 call assert_match('^\s*101\s\+.*\swhile l:count > 0$', lines[16])
74 call assert_match('^\s*100\s\+.*\s let l:count = l:count - 1$', lines[17])
75 call assert_match('^\s*101\s\+.*\sendwhile$', lines[18])
Bram Moolenaara21df1d2020-03-17 20:57:09 +010076 call assert_match('^\s*1\s\+.\+sleep 1m$', lines[19])
77 call assert_equal('', lines[20])
78 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[21])
79 call assert_equal('count total (s) self (s) function', lines[22])
80 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[23])
81 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[24])
82 call assert_equal('', lines[25])
83 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[26])
84 call assert_equal('count total (s) self (s) function', lines[27])
85 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[28])
86 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[29])
87 call assert_equal('', lines[30])
Bram Moolenaar296b1f22017-01-15 15:22:33 +010088
89 call delete('Xprofile_func.vim')
90 call delete('Xprofile_func.log')
91endfunc
92
Bram Moolenaar7feb35e2018-08-21 17:49:54 +020093func Test_profile_func_with_ifelse()
Bram Moolenaarc79745a2019-05-20 22:12:34 +020094 let lines =<< trim [CODE]
95 func! Foo1()
96 if 1
97 let x = 0
98 elseif 1
99 let x = 1
100 else
101 let x = 2
102 endif
103 endfunc
104 func! Foo2()
105 if 0
106 let x = 0
107 elseif 1
108 let x = 1
109 else
110 let x = 2
111 endif
112 endfunc
113 func! Foo3()
114 if 0
115 let x = 0
116 elseif 0
117 let x = 1
118 else
119 let x = 2
120 endif
121 endfunc
122 call Foo1()
123 call Foo2()
124 call Foo3()
125 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200126
127 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200128 call system(GetVimCommand()
129 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200130 \ . ' -c "profile start Xprofile_func.log"'
131 \ . ' -c "profile func Foo*"'
132 \ . ' -c "so Xprofile_func.vim"'
133 \ . ' -c "qall!"')
134 call assert_equal(0, v:shell_error)
135
136 let lines = readfile('Xprofile_func.log')
137
138 " - Foo1() should pass 'if' block.
139 " - Foo2() should pass 'elseif' block.
140 " - Foo3() should pass 'else' block.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200141 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200142
143 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200144 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
145 call assert_equal('Called 1 time', lines[2])
146 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
147 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
148 call assert_equal('', lines[5])
149 call assert_equal('count total (s) self (s)', lines[6])
150 call assert_match('^\s*1\s\+.*\sif 1$', lines[7])
151 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
152 call assert_match( '^\s\+elseif 1$', lines[9])
153 call assert_match( '^\s\+let x = 1$', lines[10])
154 call assert_match( '^\s\+else$', lines[11])
155 call assert_match( '^\s\+let x = 2$', lines[12])
156 call assert_match('^\s*1\s\+.*\sendif$', lines[13])
157 call assert_equal('', lines[14])
158 call assert_equal('FUNCTION Foo2()', lines[15])
159 call assert_equal('Called 1 time', lines[17])
160 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
161 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
162 call assert_equal('', lines[20])
163 call assert_equal('count total (s) self (s)', lines[21])
164 call assert_match('^\s*1\s\+.*\sif 0$', lines[22])
165 call assert_match( '^\s\+let x = 0$', lines[23])
166 call assert_match('^\s*1\s\+.*\selseif 1$', lines[24])
167 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
168 call assert_match( '^\s\+else$', lines[26])
169 call assert_match( '^\s\+let x = 2$', lines[27])
170 call assert_match('^\s*1\s\+.*\sendif$', lines[28])
171 call assert_equal('', lines[29])
172 call assert_equal('FUNCTION Foo3()', lines[30])
173 call assert_equal('Called 1 time', lines[32])
174 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
175 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
176 call assert_equal('', lines[35])
177 call assert_equal('count total (s) self (s)', lines[36])
178 call assert_match('^\s*1\s\+.*\sif 0$', lines[37])
179 call assert_match( '^\s\+let x = 0$', lines[38])
180 call assert_match('^\s*1\s\+.*\selseif 0$', lines[39])
181 call assert_match( '^\s\+let x = 1$', lines[40])
182 call assert_match('^\s*1\s\+.*\selse$', lines[41])
183 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
184 call assert_match('^\s*1\s\+.*\sendif$', lines[43])
185 call assert_equal('', lines[44])
186 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
187 call assert_equal('count total (s) self (s) function', lines[46])
188 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
189 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
190 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
191 call assert_equal('', lines[50])
192 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
193 call assert_equal('count total (s) self (s) function', lines[52])
194 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
195 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
196 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
197 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200198
199 call delete('Xprofile_func.vim')
200 call delete('Xprofile_func.log')
201endfunc
202
203func Test_profile_func_with_trycatch()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200204 let lines =<< trim [CODE]
205 func! Foo1()
206 try
207 let x = 0
208 catch
209 let x = 1
210 finally
211 let x = 2
212 endtry
213 endfunc
214 func! Foo2()
215 try
216 throw 0
217 catch
218 let x = 1
219 finally
220 let x = 2
221 endtry
222 endfunc
223 func! Foo3()
224 try
225 throw 0
226 catch
227 throw 1
228 finally
229 let x = 2
230 endtry
231 endfunc
232 call Foo1()
233 call Foo2()
234 try
235 call Foo3()
236 catch
237 endtry
238 [CODE]
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200239
240 call writefile(lines, 'Xprofile_func.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200241 call system(GetVimCommand()
242 \ . ' -es -i NONE --noplugin'
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200243 \ . ' -c "profile start Xprofile_func.log"'
244 \ . ' -c "profile func Foo*"'
245 \ . ' -c "so Xprofile_func.vim"'
246 \ . ' -c "qall!"')
247 call assert_equal(0, v:shell_error)
248
249 let lines = readfile('Xprofile_func.log')
250
251 " - Foo1() should pass 'try' 'finally' blocks.
252 " - Foo2() should pass 'catch' 'finally' blocks.
253 " - Foo3() should not pass 'endtry'.
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200254 call assert_equal(57, len(lines))
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200255
256 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200257 call assert_match('Defined:.*Xprofile_func.vim', lines[1])
258 call assert_equal('Called 1 time', lines[2])
259 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3])
260 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4])
261 call assert_equal('', lines[5])
262 call assert_equal('count total (s) self (s)', lines[6])
263 call assert_match('^\s*1\s\+.*\stry$', lines[7])
264 call assert_match('^\s*1\s\+.*\s let x = 0$', lines[8])
265 call assert_match( '^\s\+catch$', lines[9])
266 call assert_match( '^\s\+let x = 1$', lines[10])
267 call assert_match('^\s*1\s\+.*\sfinally$', lines[11])
268 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[12])
269 call assert_match('^\s*1\s\+.*\sendtry$', lines[13])
270 call assert_equal('', lines[14])
271 call assert_equal('FUNCTION Foo2()', lines[15])
272 call assert_equal('Called 1 time', lines[17])
273 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18])
274 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19])
275 call assert_equal('', lines[20])
276 call assert_equal('count total (s) self (s)', lines[21])
277 call assert_match('^\s*1\s\+.*\stry$', lines[22])
278 call assert_match('^\s*1\s\+.*\s throw 0$', lines[23])
279 call assert_match('^\s*1\s\+.*\scatch$', lines[24])
280 call assert_match('^\s*1\s\+.*\s let x = 1$', lines[25])
281 call assert_match('^\s*1\s\+.*\sfinally$', lines[26])
282 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[27])
283 call assert_match('^\s*1\s\+.*\sendtry$', lines[28])
284 call assert_equal('', lines[29])
285 call assert_equal('FUNCTION Foo3()', lines[30])
286 call assert_equal('Called 1 time', lines[32])
287 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33])
288 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34])
289 call assert_equal('', lines[35])
290 call assert_equal('count total (s) self (s)', lines[36])
291 call assert_match('^\s*1\s\+.*\stry$', lines[37])
292 call assert_match('^\s*1\s\+.*\s throw 0$', lines[38])
293 call assert_match('^\s*1\s\+.*\scatch$', lines[39])
294 call assert_match('^\s*1\s\+.*\s throw 1$', lines[40])
295 call assert_match('^\s*1\s\+.*\sfinally$', lines[41])
296 call assert_match('^\s*1\s\+.*\s let x = 2$', lines[42])
297 call assert_match( '^\s\+endtry$', lines[43])
298 call assert_equal('', lines[44])
299 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45])
300 call assert_equal('count total (s) self (s) function', lines[46])
301 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47])
302 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48])
303 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49])
304 call assert_equal('', lines[50])
305 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51])
306 call assert_equal('count total (s) self (s) function', lines[52])
307 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53])
308 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54])
309 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55])
310 call assert_equal('', lines[56])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200311
312 call delete('Xprofile_func.vim')
313 call delete('Xprofile_func.log')
314endfunc
315
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100316func Test_profile_file()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200317 let lines =<< trim [CODE]
Bram Moolenaare7eb9272019-06-24 00:58:07 +0200318 func! Foo()
319 endfunc
320 for i in range(10)
321 " a comment
322 call Foo()
323 endfor
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200324 call Foo()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200325 [CODE]
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100326
327 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200328 call system(GetVimCommandClean()
329 \ . ' -es'
Bram Moolenaarc011a3d2017-01-16 22:37:42 +0100330 \ . ' -c "profile start Xprofile_file.log"'
331 \ . ' -c "profile file Xprofile_file.vim"'
332 \ . ' -c "so Xprofile_file.vim"'
333 \ . ' -c "so Xprofile_file.vim"'
334 \ . ' -c "qall!"')
335 call assert_equal(0, v:shell_error)
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100336
337 let lines = readfile('Xprofile_file.log')
338
339 call assert_equal(14, len(lines))
340
341 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
342 call assert_equal('Sourced 2 times', lines[1])
343 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
344 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
345 call assert_equal('', lines[4])
346 call assert_equal('count total (s) self (s)', lines[5])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200347 call assert_match(' 2 0.\d\+ func! Foo()', lines[6])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100348 call assert_equal(' endfunc', lines[7])
349 " Loop iterates 10 times. Since script runs twice, body executes 20 times.
350 " First line of loop executes one more time than body to detect end of loop.
351 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8])
352 call assert_equal(' " a comment', lines[9])
Bram Moolenaard21b16f2017-08-14 23:13:30 +0200353 " if self and total are equal we only get one number
354 call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10])
Bram Moolenaar7feb35e2018-08-21 17:49:54 +0200355 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11])
Bram Moolenaare32bbde2017-01-15 21:12:48 +0100356 " if self and total are equal we only get one number
357 call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12])
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100358 call assert_equal('', lines[13])
359
360 call delete('Xprofile_file.vim')
361 call delete('Xprofile_file.log')
362endfunc
363
Bram Moolenaar67435d92017-10-19 21:04:37 +0200364func Test_profile_file_with_cont()
365 let lines = [
366 \ 'echo "hello',
367 \ ' \ world"',
368 \ 'echo "foo ',
369 \ ' \bar"',
370 \ ]
371
372 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200373 call system(GetVimCommandClean()
374 \ . ' -es'
Bram Moolenaar67435d92017-10-19 21:04:37 +0200375 \ . ' -c "profile start Xprofile_file.log"'
376 \ . ' -c "profile file Xprofile_file.vim"'
377 \ . ' -c "so Xprofile_file.vim"'
378 \ . ' -c "qall!"')
379 call assert_equal(0, v:shell_error)
380
381 let lines = readfile('Xprofile_file.log')
382 call assert_equal(11, len(lines))
383
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200384 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0])
385 call assert_equal('Sourced 1 time', lines[1])
386 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2])
387 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3])
388 call assert_equal('', lines[4])
389 call assert_equal('count total (s) self (s)', lines[5])
390 call assert_match(' 1 0.\d\+ echo "hello', lines[6])
391 call assert_equal(' \ world"', lines[7])
392 call assert_match(' 1 0.\d\+ echo "foo ', lines[8])
393 call assert_equal(' \bar"', lines[9])
394 call assert_equal('', lines[10])
Bram Moolenaar67435d92017-10-19 21:04:37 +0200395
396 call delete('Xprofile_file.vim')
397 call delete('Xprofile_file.log')
398endfunc
399
Bram Moolenaar296b1f22017-01-15 15:22:33 +0100400func Test_profile_completion()
401 call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx')
402 call assert_equal('"profile continue file func pause start', @:)
403
404 call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx')
405 call assert_match('^"profile start.* test_profile\.vim', @:)
406endfunc
407
408func Test_profile_errors()
409 call assert_fails("profile func Foo", 'E750:')
410 call assert_fails("profile pause", 'E750:')
411 call assert_fails("profile continue", 'E750:')
412endfunc
Bram Moolenaarac112f02017-12-05 16:46:28 +0100413
414func Test_profile_truncate_mbyte()
Bram Moolenaar30276f22019-01-24 17:59:39 +0100415 if &enc !=# 'utf-8'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100416 return
417 endif
418
419 let lines = [
420 \ 'scriptencoding utf-8',
421 \ 'func! Foo()',
422 \ ' return [',
423 \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",',
424 \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",',
425 \ ' \ ]',
426 \ 'endfunc',
427 \ 'call Foo()',
428 \ ]
429
430 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200431 call system(GetVimCommandClean()
432 \ . ' -es --cmd "set enc=utf-8"'
Bram Moolenaarac112f02017-12-05 16:46:28 +0100433 \ . ' -c "profile start Xprofile_file.log"'
434 \ . ' -c "profile file Xprofile_file.vim"'
435 \ . ' -c "so Xprofile_file.vim"'
436 \ . ' -c "qall!"')
437 call assert_equal(0, v:shell_error)
438
439 split Xprofile_file.log
440 if &fenc != ''
441 call assert_equal('utf-8', &fenc)
442 endif
443 /func! Foo()
444 let lnum = line('.')
445 call assert_match('^\s*return \[$', getline(lnum + 1))
446 call assert_match("\u4F52$", getline(lnum + 2))
447 call assert_match("\u5052$", getline(lnum + 3))
448 call assert_match('^\s*\\ \]$', getline(lnum + 4))
449 bwipe!
450
451 call delete('Xprofile_file.vim')
452 call delete('Xprofile_file.log')
453endfunc
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200454
455func Test_profdel_func()
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200456 let lines =<< trim [CODE]
457 profile start Xprofile_file.log
458 func! Foo1()
459 endfunc
460 func! Foo2()
461 endfunc
462 func! Foo3()
463 endfunc
464
465 profile func Foo1
466 profile func Foo2
467 call Foo1()
468 call Foo2()
469
470 profile func Foo3
471 profdel func Foo2
472 profdel func Foo3
473 call Foo1()
474 call Foo2()
475 call Foo3()
476 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200477 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200478 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200479 call assert_equal(0, v:shell_error)
480
481 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200482 call assert_equal(26, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200483
484 " Check that:
485 " - Foo1() is called twice (profdel not invoked)
486 " - Foo2() is called once (profdel invoked after it was called)
487 " - Foo3() is not called (profdel invoked before it was called)
488 call assert_equal('FUNCTION Foo1()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200489 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
490 call assert_equal('Called 2 times', lines[2])
491 call assert_equal('FUNCTION Foo2()', lines[8])
492 call assert_equal('Called 1 time', lines[10])
493 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16])
494 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200495
496 call delete('Xprofile_file.vim')
497 call delete('Xprofile_file.log')
498endfunc
499
500func Test_profdel_star()
501 " Foo() is invoked once before and once after 'profdel *'.
502 " So profiling should report it only once.
Bram Moolenaarc79745a2019-05-20 22:12:34 +0200503 let lines =<< trim [CODE]
504 profile start Xprofile_file.log
505 func! Foo()
506 endfunc
507 profile func Foo
508 call Foo()
509 profdel *
510 call Foo()
511 [CODE]
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200512 call writefile(lines, 'Xprofile_file.vim')
Bram Moolenaar93344c22019-08-14 21:12:05 +0200513 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200514 call assert_equal(0, v:shell_error)
515
516 let lines = readfile('Xprofile_file.log')
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200517 call assert_equal(16, len(lines))
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200518
519 call assert_equal('FUNCTION Foo()', lines[0])
Bram Moolenaar4c7b08f2018-09-10 22:03:40 +0200520 call assert_match('Defined:.*Xprofile_file.vim', lines[1])
521 call assert_equal('Called 1 time', lines[2])
522 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8])
523 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12])
Bram Moolenaar1fbfe7c2018-06-30 21:18:13 +0200524
525 call delete('Xprofile_file.vim')
526 call delete('Xprofile_file.log')
527endfunc
Bram Moolenaar16358802019-08-30 18:37:26 +0200528
529" When typing the function it won't have a script ID, test that this works.
530func Test_profile_typed_func()
531 CheckScreendump
532
533 let lines =<< trim END
534 profile start XprofileTypedFunc
535 END
536 call writefile(lines, 'XtestProfile')
537 let buf = RunVimInTerminal('-S XtestProfile', #{})
538
539 call term_sendkeys(buf, ":func DoSomething()\<CR>"
540 \ .. "echo 'hello'\<CR>"
541 \ .. "endfunc\<CR>")
542 call term_sendkeys(buf, ":profile func DoSomething\<CR>")
543 call term_sendkeys(buf, ":call DoSomething()\<CR>")
Bram Moolenaar6a2c5a72020-04-08 21:50:25 +0200544 call TermWait(buf, 100)
Bram Moolenaar16358802019-08-30 18:37:26 +0200545 call StopVimInTerminal(buf)
546 let lines = readfile('XprofileTypedFunc')
547 call assert_equal("FUNCTION DoSomething()", lines[0])
548 call assert_equal("Called 1 time", lines[1])
549
550 " clean up
551 call delete('XprofileTypedFunc')
552 call delete('XtestProfile')
553endfunc