xref: /vim-8.2.3635/src/testdir/test_profile.vim (revision ced68a00)
1" Test Vim profiler
2
3source check.vim
4CheckFeature profile
5
6source shared.vim
7source screendump.vim
8
9func Test_profile_func()
10  call RunProfileFunc('func', 'let', 'let')
11  call RunProfileFunc('def', 'var', '')
12endfunc
13
14func RunProfileFunc(command, declare, assign)
15  let lines =<< trim [CODE]
16    profile start Xprofile_func.log
17    profile func Foo*
18    XXX Foo1()
19    endXXX
20    XXX Foo2()
21      DDD counter = 100
22      while counter > 0
23        AAA counter = counter - 1
24      endwhile
25      sleep 1m
26    endXXX
27    XXX Foo3()
28    endXXX
29    XXX Bar()
30    endXXX
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]
44
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
49  call writefile(lines, 'Xprofile_func.vim')
50  call system(GetVimCommand()
51    \ . ' -es --clean'
52    \ . ' -c "so Xprofile_func.vim"'
53    \ . ' -c "qall!"')
54  call assert_equal(0, v:shell_error)
55
56  let lines = readfile('Xprofile_func.log')
57
58  " - Foo1() is called 3 times but should be reported as called twice
59  "   since one call is in between "profile pause" .. "profile continue".
60  " - Foo2() should come before Foo1() since Foo1() does much more work.
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*".
65  call assert_equal(31, len(lines))
66
67  call assert_equal('FUNCTION  Foo1()',                            lines[0])
68  call assert_match('Defined:.*Xprofile_func.vim:3',               lines[1])
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])
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])
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])
97
98  call delete('Xprofile_func.vim')
99  call delete('Xprofile_func.log')
100endfunc
101
102func Test_profile_func_with_ifelse()
103  call Run_profile_func_with_ifelse('func', 'let', 'let')
104  call Run_profile_func_with_ifelse('def', 'var', '')
105endfunc
106
107func Run_profile_func_with_ifelse(command, declare, assign)
108  let lines =<< trim [CODE]
109    XXX Foo1()
110      if 1
111        DDD x = 0
112      elseif 1
113        DDD x = 1
114      else
115        DDD x = 2
116      endif
117    endXXX
118    XXX Foo2()
119      if 0
120        DDD x = 0
121      elseif 1
122        DDD x = 1
123      else
124        DDD x = 2
125      endif
126    endXXX
127    XXX Foo3()
128      if 0
129        DDD x = 0
130      elseif 0
131        DDD x = 1
132      else
133        DDD x = 2
134      endif
135    endXXX
136    call Foo1()
137    call Foo2()
138    call Foo3()
139  [CODE]
140
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
145  call writefile(lines, 'Xprofile_func.vim')
146  call system(GetVimCommand()
147    \ . ' -es -i NONE --noplugin'
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.
159  call assert_equal(57, len(lines))
160
161  call assert_equal('FUNCTION  Foo1()',                            lines[0])
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])
169  call assert_match('^\s*1\s\+.*\s  \(let\|var\) x = 0$',          lines[8])
170  call assert_match(        '^\s\+elseif 1$',                      lines[9])
171  call assert_match(          '^\s\+\(let\|var\) x = 1$',          lines[10])
172  call assert_match(        '^\s\+else$',                          lines[11])
173  call assert_match(          '^\s\+\(let\|var\) x = 2$',          lines[12])
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])
183  call assert_match(          '^\s\+\(let\|var\) x = 0$',          lines[23])
184  call assert_match('^\s*1\s\+.*\selseif 1$',                      lines[24])
185  call assert_match('^\s*1\s\+.*\s  \(let\|var\) x = 1$',          lines[25])
186  call assert_match(        '^\s\+else$',                          lines[26])
187  call assert_match(          '^\s\+\(let\|var\) x = 2$',          lines[27])
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])
197  call assert_match(          '^\s\+\(let\|var\) x = 0$',          lines[38])
198  call assert_match('^\s*1\s\+.*\selseif 0$',                      lines[39])
199  call assert_match(          '^\s\+\(let\|var\) x = 1$',          lines[40])
200  call assert_match('^\s*1\s\+.*\selse$',                          lines[41])
201  call assert_match('^\s*1\s\+.*\s  \(let\|var\) x = 2$',          lines[42])
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])
216
217  call delete('Xprofile_func.vim')
218  call delete('Xprofile_func.log')
219endfunc
220
221func Test_profile_func_with_trycatch()
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]
257
258  call writefile(lines, 'Xprofile_func.vim')
259  call system(GetVimCommand()
260    \ . ' -es -i NONE --noplugin'
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'.
272  call assert_equal(57, len(lines))
273
274  call assert_equal('FUNCTION  Foo1()',                            lines[0])
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])
329
330  call delete('Xprofile_func.vim')
331  call delete('Xprofile_func.log')
332endfunc
333
334func Test_profile_file()
335  let lines =<< trim [CODE]
336    func! Foo()
337    endfunc
338    for i in range(10)
339      " a comment
340      call Foo()
341    endfor
342    call Foo()
343  [CODE]
344
345  call writefile(lines, 'Xprofile_file.vim')
346  call system(GetVimCommandClean()
347    \ . ' -es'
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)
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])
365  call assert_match('    2              0.\d\+ func! Foo()',          lines[6])
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])
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])
373  call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$',                lines[11])
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])
376  call assert_equal('',                                               lines[13])
377
378  call delete('Xprofile_file.vim')
379  call delete('Xprofile_file.log')
380endfunc
381
382func 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')
391  call system(GetVimCommandClean()
392    \ . ' -es'
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
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])
413
414  call delete('Xprofile_file.vim')
415  call delete('Xprofile_file.log')
416endfunc
417
418func 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', @:)
424endfunc
425
426func 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:')
430endfunc
431
432func Test_profile_truncate_mbyte()
433  if &enc !=# 'utf-8'
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')
449  call system(GetVimCommandClean()
450    \ . ' -es --cmd "set enc=utf-8"'
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')
471endfunc
472
473func Test_profdel_func()
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]
495  call writefile(lines, 'Xprofile_file.vim')
496  call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
497  call assert_equal(0, v:shell_error)
498
499  let lines = readfile('Xprofile_file.log')
500  call assert_equal(26, len(lines))
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])
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])
513
514  call delete('Xprofile_file.vim')
515  call delete('Xprofile_file.log')
516endfunc
517
518func Test_profdel_star()
519  " Foo() is invoked once before and once after 'profdel *'.
520  " So profiling should report it only once.
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]
530  call writefile(lines, 'Xprofile_file.vim')
531  call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q')
532  call assert_equal(0, v:shell_error)
533
534  let lines = readfile('Xprofile_file.log')
535  call assert_equal(16, len(lines))
536
537  call assert_equal('FUNCTION  Foo()',                lines[0])
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])
542
543  call delete('Xprofile_file.vim')
544  call delete('Xprofile_file.log')
545endfunc
546
547" When typing the function it won't have a script ID, test that this works.
548func 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>")
562  call TermWait(buf, 100)
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')
571endfunc
572
573" vim: shiftwidth=2 sts=2 expandtab
574