1" Test Vim profiler 2 3source check.vim 4CheckFeature profile 5 6source shared.vim 7source screendump.vim 8source vim9.vim 9 10func Test_profile_func() 11 call RunProfileFunc('func', 'let', 'let') 12 call RunProfileFunc('def', 'var', '') 13endfunc 14 15func RunProfileFunc(command, declare, assign) 16 let lines =<< trim [CODE] 17 profile start Xprofile_func.log 18 profile func Foo* 19 XXX Foo1() 20 endXXX 21 XXX Foo2() 22 DDD counter = 100 23 while counter > 0 24 AAA counter = counter - 1 25 endwhile 26 sleep 1m 27 endXXX 28 XXX Foo3() 29 endXXX 30 XXX Bar() 31 endXXX 32 call Foo1() 33 call Foo1() 34 profile pause 35 call Foo1() 36 profile continue 37 call Foo2() 38 call Foo3() 39 call Bar() 40 if !v:profiling 41 delfunc Foo2 42 endif 43 delfunc Foo3 44 [CODE] 45 46 call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) 47 call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) 48 call map(lines, {k, v -> substitute(v, 'AAA', a:assign, '') }) 49 50 call writefile(lines, 'Xprofile_func.vim') 51 call system(GetVimCommand() 52 \ . ' -es --clean' 53 \ . ' -c "so Xprofile_func.vim"' 54 \ . ' -c "qall!"') 55 call assert_equal(0, v:shell_error) 56 57 let lines = readfile('Xprofile_func.log') 58 59 " - Foo1() is called 3 times but should be reported as called twice 60 " since one call is in between "profile pause" .. "profile continue". 61 " - Foo2() should come before Foo1() since Foo1() does much more work. 62 " - Foo3() is not reported because function is deleted. 63 " - Unlike Foo3(), Foo2() should not be deleted since there is a check 64 " for v:profiling. 65 " - Bar() is not reported since it does not match "profile func Foo*". 66 call assert_equal(31, len(lines)) 67 68 call assert_equal('FUNCTION Foo1()', lines[0]) 69 call assert_match('Defined:.*Xprofile_func.vim:3', lines[1]) 70 call assert_equal('Called 2 times', lines[2]) 71 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) 72 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) 73 call assert_equal('', lines[5]) 74 call assert_equal('count total (s) self (s)', lines[6]) 75 call assert_equal('', lines[7]) 76 call assert_equal('FUNCTION Foo2()', lines[8]) 77 call assert_equal('Called 1 time', lines[10]) 78 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[11]) 79 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[12]) 80 call assert_equal('', lines[13]) 81 call assert_equal('count total (s) self (s)', lines[14]) 82 call assert_match('^\s*1\s\+.*\s\(let\|var\) counter = 100$', lines[15]) 83 call assert_match('^\s*101\s\+.*\swhile counter > 0$', lines[16]) 84 call assert_match('^\s*100\s\+.*\s \(let\)\= counter = counter - 1$', lines[17]) 85 call assert_match('^\s*10[01]\s\+.*\sendwhile$', lines[18]) 86 call assert_match('^\s*1\s\+.\+sleep 1m$', lines[19]) 87 call assert_equal('', lines[20]) 88 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[21]) 89 call assert_equal('count total (s) self (s) function', lines[22]) 90 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[23]) 91 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[24]) 92 call assert_equal('', lines[25]) 93 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[26]) 94 call assert_equal('count total (s) self (s) function', lines[27]) 95 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo2()$', lines[28]) 96 call assert_match('^\s*2\s\+\d\+\.\d\+\s\+Foo1()$', lines[29]) 97 call assert_equal('', lines[30]) 98 99 call delete('Xprofile_func.vim') 100 call delete('Xprofile_func.log') 101endfunc 102 103func Test_profile_func_with_ifelse() 104 call Run_profile_func_with_ifelse('func', 'let') 105 call Run_profile_func_with_ifelse('def', 'var') 106endfunc 107 108func Run_profile_func_with_ifelse(command, declare) 109 let lines =<< trim [CODE] 110 XXX Foo1() 111 if 1 112 DDD x = 0 113 elseif 1 114 DDD x = 1 115 else 116 DDD x = 2 117 endif 118 endXXX 119 XXX Foo2() 120 if 0 121 DDD x = 0 122 elseif 1 123 DDD x = 1 124 else 125 DDD x = 2 126 endif 127 endXXX 128 XXX Foo3() 129 if 0 130 DDD x = 0 131 elseif 0 132 DDD x = 1 133 else 134 DDD x = 2 135 endif 136 endXXX 137 call Foo1() 138 call Foo2() 139 call Foo3() 140 [CODE] 141 142 call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) 143 call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) 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 call Run_profile_func_with_trycatch('func', 'let') 223 call Run_profile_func_with_trycatch('def', 'var') 224endfunc 225 226func Run_profile_func_with_trycatch(command, declare) 227 let lines =<< trim [CODE] 228 XXX Foo1() 229 try 230 DDD x = 0 231 catch 232 DDD x = 1 233 finally 234 DDD x = 2 235 endtry 236 endXXX 237 XXX Foo2() 238 try 239 throw 0 240 catch 241 DDD x = 1 242 finally 243 DDD x = 2 244 endtry 245 endXXX 246 XXX Foo3() 247 try 248 throw 0 249 catch 250 throw 1 251 finally 252 DDD x = 2 253 endtry 254 endXXX 255 call Foo1() 256 call Foo2() 257 let rethrown = 0 258 try 259 call Foo3() 260 catch 261 let rethrown = 1 262 endtry 263 if rethrown != 1 264 " call Foo1 again so that the test fails 265 call Foo1() 266 endif 267 [CODE] 268 269 call map(lines, {k, v -> substitute(v, 'XXX', a:command, '') }) 270 call map(lines, {k, v -> substitute(v, 'DDD', a:declare, '') }) 271 272 call writefile(lines, 'Xprofile_func.vim') 273 call system(GetVimCommand() 274 \ . ' -es -i NONE --noplugin' 275 \ . ' -c "profile start Xprofile_func.log"' 276 \ . ' -c "profile func Foo*"' 277 \ . ' -c "so Xprofile_func.vim"' 278 \ . ' -c "qall!"') 279 call assert_equal(0, v:shell_error) 280 281 let lines = readfile('Xprofile_func.log') 282 283 " - Foo1() should pass 'try' 'finally' blocks. 284 " - Foo2() should pass 'catch' 'finally' blocks. 285 " - Foo3() should not pass 'endtry'. 286 call assert_equal(57, len(lines)) 287 288 call assert_equal('FUNCTION Foo1()', lines[0]) 289 call assert_match('Defined:.*Xprofile_func.vim', lines[1]) 290 call assert_equal('Called 1 time', lines[2]) 291 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[3]) 292 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[4]) 293 call assert_equal('', lines[5]) 294 call assert_equal('count total (s) self (s)', lines[6]) 295 call assert_match('^\s*1\s\+.*\stry$', lines[7]) 296 call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 0$', lines[8]) 297 call assert_match( '^\s\+catch$', lines[9]) 298 call assert_match( '^\s\+\(let\|var\) x = 1$', lines[10]) 299 call assert_match('^\s*1\s\+.*\sfinally$', lines[11]) 300 call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[12]) 301 call assert_match('^\s*1\s\+.*\sendtry$', lines[13]) 302 call assert_equal('', lines[14]) 303 call assert_equal('FUNCTION Foo2()', lines[15]) 304 call assert_equal('Called 1 time', lines[17]) 305 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[18]) 306 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[19]) 307 call assert_equal('', lines[20]) 308 call assert_equal('count total (s) self (s)', lines[21]) 309 call assert_match('^\s*1\s\+.*\stry$', lines[22]) 310 call assert_match('^\s*1\s\+.*\s throw 0$', lines[23]) 311 call assert_match('^\s*1\s\+.*\scatch$', lines[24]) 312 call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 1$', lines[25]) 313 call assert_match('^\s*1\s\+.*\sfinally$', lines[26]) 314 call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[27]) 315 call assert_match('^\s*1\s\+.*\sendtry$', lines[28]) 316 call assert_equal('', lines[29]) 317 call assert_equal('FUNCTION Foo3()', lines[30]) 318 call assert_equal('Called 1 time', lines[32]) 319 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[33]) 320 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[34]) 321 call assert_equal('', lines[35]) 322 call assert_equal('count total (s) self (s)', lines[36]) 323 call assert_match('^\s*1\s\+.*\stry$', lines[37]) 324 call assert_match('^\s*1\s\+.*\s throw 0$', lines[38]) 325 call assert_match('^\s*1\s\+.*\scatch$', lines[39]) 326 call assert_match('^\s*1\s\+.*\s throw 1$', lines[40]) 327 call assert_match('^\s*1\s\+.*\sfinally$', lines[41]) 328 call assert_match('^\s*1\s\+.*\s \(let\|var\) x = 2$', lines[42]) 329 call assert_match( '^\s\+endtry$', lines[43]) 330 call assert_equal('', lines[44]) 331 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[45]) 332 call assert_equal('count total (s) self (s) function', lines[46]) 333 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[47]) 334 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[48]) 335 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[49]) 336 call assert_equal('', lines[50]) 337 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[51]) 338 call assert_equal('count total (s) self (s) function', lines[52]) 339 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[53]) 340 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[54]) 341 call assert_match('^\s*1\s\+\d\+\.\d\+\s\+Foo.()$', lines[55]) 342 call assert_equal('', lines[56]) 343 344 call delete('Xprofile_func.vim') 345 call delete('Xprofile_func.log') 346endfunc 347 348func Test_profile_file() 349 let lines =<< trim [CODE] 350 func! Foo() 351 endfunc 352 for i in range(10) 353 " a comment 354 call Foo() 355 endfor 356 call Foo() 357 [CODE] 358 359 call writefile(lines, 'Xprofile_file.vim') 360 call system(GetVimCommandClean() 361 \ . ' -es' 362 \ . ' -c "profile start Xprofile_file.log"' 363 \ . ' -c "profile file Xprofile_file.vim"' 364 \ . ' -c "so Xprofile_file.vim"' 365 \ . ' -c "so Xprofile_file.vim"' 366 \ . ' -c "qall!"') 367 call assert_equal(0, v:shell_error) 368 369 let lines = readfile('Xprofile_file.log') 370 371 call assert_equal(14, len(lines)) 372 373 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) 374 call assert_equal('Sourced 2 times', lines[1]) 375 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) 376 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) 377 call assert_equal('', lines[4]) 378 call assert_equal('count total (s) self (s)', lines[5]) 379 call assert_match(' 2 0.\d\+ func! Foo()', lines[6]) 380 call assert_equal(' endfunc', lines[7]) 381 " Loop iterates 10 times. Since script runs twice, body executes 20 times. 382 " First line of loop executes one more time than body to detect end of loop. 383 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+for i in range(10)$', lines[8]) 384 call assert_equal(' " a comment', lines[9]) 385 " if self and total are equal we only get one number 386 call assert_match('^\s*20\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[10]) 387 call assert_match('^\s*22\s\+\d\+\.\d\+\s\+endfor$', lines[11]) 388 " if self and total are equal we only get one number 389 call assert_match('^\s*2\s\+\(\d\+\.\d\+\s\+\)\=\d\+\.\d\+\s\+call Foo()$', lines[12]) 390 call assert_equal('', lines[13]) 391 392 call delete('Xprofile_file.vim') 393 call delete('Xprofile_file.log') 394endfunc 395 396func Test_profile_file_with_cont() 397 let lines = [ 398 \ 'echo "hello', 399 \ ' \ world"', 400 \ 'echo "foo ', 401 \ ' \bar"', 402 \ ] 403 404 call writefile(lines, 'Xprofile_file.vim') 405 call system(GetVimCommandClean() 406 \ . ' -es' 407 \ . ' -c "profile start Xprofile_file.log"' 408 \ . ' -c "profile file Xprofile_file.vim"' 409 \ . ' -c "so Xprofile_file.vim"' 410 \ . ' -c "qall!"') 411 call assert_equal(0, v:shell_error) 412 413 let lines = readfile('Xprofile_file.log') 414 call assert_equal(11, len(lines)) 415 416 call assert_match('^SCRIPT .*Xprofile_file.vim$', lines[0]) 417 call assert_equal('Sourced 1 time', lines[1]) 418 call assert_match('^Total time:\s\+\d\+\.\d\+$', lines[2]) 419 call assert_match('^ Self time:\s\+\d\+\.\d\+$', lines[3]) 420 call assert_equal('', lines[4]) 421 call assert_equal('count total (s) self (s)', lines[5]) 422 call assert_match(' 1 0.\d\+ echo "hello', lines[6]) 423 call assert_equal(' \ world"', lines[7]) 424 call assert_match(' 1 0.\d\+ echo "foo ', lines[8]) 425 call assert_equal(' \bar"', lines[9]) 426 call assert_equal('', lines[10]) 427 428 call delete('Xprofile_file.vim') 429 call delete('Xprofile_file.log') 430endfunc 431 432func Test_profile_completion() 433 call feedkeys(":profile \<C-A>\<C-B>\"\<CR>", 'tx') 434 call assert_equal('"profile continue file func pause start', @:) 435 436 call feedkeys(":profile start test_prof\<C-A>\<C-B>\"\<CR>", 'tx') 437 call assert_match('^"profile start.* test_profile\.vim', @:) 438endfunc 439 440func Test_profile_errors() 441 call assert_fails("profile func Foo", 'E750:') 442 call assert_fails("profile pause", 'E750:') 443 call assert_fails("profile continue", 'E750:') 444endfunc 445 446func Test_profile_truncate_mbyte() 447 if &enc !=# 'utf-8' 448 return 449 endif 450 451 let lines = [ 452 \ 'scriptencoding utf-8', 453 \ 'func! Foo()', 454 \ ' return [', 455 \ ' \ "' . join(map(range(0x4E00, 0x4E00 + 340), 'nr2char(v:val)'), '') . '",', 456 \ ' \ "' . join(map(range(0x4F00, 0x4F00 + 340), 'nr2char(v:val)'), '') . '",', 457 \ ' \ ]', 458 \ 'endfunc', 459 \ 'call Foo()', 460 \ ] 461 462 call writefile(lines, 'Xprofile_file.vim') 463 call system(GetVimCommandClean() 464 \ . ' -es --cmd "set enc=utf-8"' 465 \ . ' -c "profile start Xprofile_file.log"' 466 \ . ' -c "profile file Xprofile_file.vim"' 467 \ . ' -c "so Xprofile_file.vim"' 468 \ . ' -c "qall!"') 469 call assert_equal(0, v:shell_error) 470 471 split Xprofile_file.log 472 if &fenc != '' 473 call assert_equal('utf-8', &fenc) 474 endif 475 /func! Foo() 476 let lnum = line('.') 477 call assert_match('^\s*return \[$', getline(lnum + 1)) 478 call assert_match("\u4F52$", getline(lnum + 2)) 479 call assert_match("\u5052$", getline(lnum + 3)) 480 call assert_match('^\s*\\ \]$', getline(lnum + 4)) 481 bwipe! 482 483 call delete('Xprofile_file.vim') 484 call delete('Xprofile_file.log') 485endfunc 486 487func Test_profdel_func() 488 let lines =<< trim [CODE] 489 profile start Xprofile_file.log 490 func! Foo1() 491 endfunc 492 func! Foo2() 493 endfunc 494 func! Foo3() 495 endfunc 496 497 profile func Foo1 498 profile func Foo2 499 call Foo1() 500 call Foo2() 501 502 profile func Foo3 503 profdel func Foo2 504 profdel func Foo3 505 call Foo1() 506 call Foo2() 507 call Foo3() 508 [CODE] 509 call writefile(lines, 'Xprofile_file.vim') 510 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') 511 call assert_equal(0, v:shell_error) 512 513 let lines = readfile('Xprofile_file.log') 514 call assert_equal(26, len(lines)) 515 516 " Check that: 517 " - Foo1() is called twice (profdel not invoked) 518 " - Foo2() is called once (profdel invoked after it was called) 519 " - Foo3() is not called (profdel invoked before it was called) 520 call assert_equal('FUNCTION Foo1()', lines[0]) 521 call assert_match('Defined:.*Xprofile_file.vim', lines[1]) 522 call assert_equal('Called 2 times', lines[2]) 523 call assert_equal('FUNCTION Foo2()', lines[8]) 524 call assert_equal('Called 1 time', lines[10]) 525 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[16]) 526 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[21]) 527 528 call delete('Xprofile_file.vim') 529 call delete('Xprofile_file.log') 530endfunc 531 532func Test_profdel_star() 533 " Foo() is invoked once before and once after 'profdel *'. 534 " So profiling should report it only once. 535 let lines =<< trim [CODE] 536 profile start Xprofile_file.log 537 func! Foo() 538 endfunc 539 profile func Foo 540 call Foo() 541 profdel * 542 call Foo() 543 [CODE] 544 call writefile(lines, 'Xprofile_file.vim') 545 call system(GetVimCommandClean() . ' -es -c "so Xprofile_file.vim" -c q') 546 call assert_equal(0, v:shell_error) 547 548 let lines = readfile('Xprofile_file.log') 549 call assert_equal(16, len(lines)) 550 551 call assert_equal('FUNCTION Foo()', lines[0]) 552 call assert_match('Defined:.*Xprofile_file.vim', lines[1]) 553 call assert_equal('Called 1 time', lines[2]) 554 call assert_equal('FUNCTIONS SORTED ON TOTAL TIME', lines[8]) 555 call assert_equal('FUNCTIONS SORTED ON SELF TIME', lines[12]) 556 557 call delete('Xprofile_file.vim') 558 call delete('Xprofile_file.log') 559endfunc 560 561" When typing the function it won't have a script ID, test that this works. 562func Test_profile_typed_func() 563 CheckScreendump 564 565 let lines =<< trim END 566 profile start XprofileTypedFunc 567 END 568 call writefile(lines, 'XtestProfile') 569 let buf = RunVimInTerminal('-S XtestProfile', #{}) 570 571 call term_sendkeys(buf, ":func DoSomething()\<CR>" 572 \ .. "echo 'hello'\<CR>" 573 \ .. "endfunc\<CR>") 574 call term_sendkeys(buf, ":profile func DoSomething\<CR>") 575 call term_sendkeys(buf, ":call DoSomething()\<CR>") 576 call TermWait(buf, 100) 577 call StopVimInTerminal(buf) 578 let lines = readfile('XprofileTypedFunc') 579 call assert_equal("FUNCTION DoSomething()", lines[0]) 580 call assert_equal("Called 1 time", lines[1]) 581 582 " clean up 583 call delete('XprofileTypedFunc') 584 call delete('XtestProfile') 585endfunc 586 587func Test_vim9_profiling() 588 " only tests that compiling and calling functions doesn't crash 589 let lines =<< trim END 590 vim9script 591 def Func() 592 Crash() 593 enddef 594 def Crash() 595 enddef 596 prof start Xprofile_crash.log 597 prof func Func 598 Func() 599 END 600 call writefile(lines, 'Xprofile_crash.vim') 601 call system(GetVimCommandClean() . ' -es -c "so Xprofile_crash.vim" -c q') 602 call assert_equal(0, v:shell_error) 603 call assert_true(readfile('Xprofile_crash.log')->len() > 10) 604 call delete('Xprofile_crash.vim') 605 call delete('Xprofile_crash.log') 606endfunc 607 608func Test_vim9_nested_call() 609 let lines =<< trim END 610 vim9script 611 var total = 0 612 def One(Ref: func(number)) 613 for i in range(3) 614 Ref(i) 615 endfor 616 enddef 617 def Two(nr: number) 618 total += nr 619 enddef 620 prof start Xprofile_nested.log 621 prof func One 622 prof func Two 623 One((nr) => Two(nr)) 624 assert_equal(3, total) 625 END 626 call writefile(lines, 'Xprofile_nested.vim') 627 call system(GetVimCommandClean() . ' -es -c "so Xprofile_nested.vim" -c q') 628 call assert_equal(0, v:shell_error) 629 630 let prof_lines = readfile('Xprofile_nested.log')->join('#') 631 call assert_match('FUNCTION <SNR>\d\+_One().*' 632 \ .. '#Called 1 time.*' 633 \ .. '# 1 \s*[0-9.]\+ for i in range(3)' 634 \ .. '# 3 \s*[0-9.]\+ \s*[0-9.]\+ Ref(i)' 635 \ .. '# 3 \s*[0-9.]\+ endfor', prof_lines) 636 call assert_match('FUNCTION <SNR>\d\+_Two().*' 637 \ .. '#Called 3 times.*' 638 \ .. '# 3 \s*[0-9.]\+ total += nr', prof_lines) 639 call delete('Xprofile_nested.vim') 640 call delete('Xprofile_nested.log') 641endfunc 642 643 644" vim: shiftwidth=2 sts=2 expandtab 645