Mercurial > vim
comparison src/profiler.c @ 17381:8f44c630c366 v8.1.1689
patch 8.1.1689: profiling code is spread out
commit https://github.com/vim/vim/commit/660a10ad41c14363326f83451c3c425201923119
Author: Bram Moolenaar <Bram@vim.org>
Date: Sun Jul 14 15:48:38 2019 +0200
patch 8.1.1689: profiling code is spread out
Problem: Profiling code is spread out.
Solution: Move more profiling code to profiler.c. (Yegappan Lakshmanan,
closes #4668)
author | Bram Moolenaar <Bram@vim.org> |
---|---|
date | Sun, 14 Jul 2019 16:00:06 +0200 |
parents | ba06a1c42274 |
children | 0f7ae8010787 |
comparison
equal
deleted
inserted
replaced
17380:9edf684600d7 | 17381:8f44c630c366 |
---|---|
112 * Put the time "msec" past now in "tm". | 112 * Put the time "msec" past now in "tm". |
113 */ | 113 */ |
114 void | 114 void |
115 profile_setlimit(long msec, proftime_T *tm) | 115 profile_setlimit(long msec, proftime_T *tm) |
116 { | 116 { |
117 if (msec <= 0) /* no limit */ | 117 if (msec <= 0) // no limit |
118 profile_zero(tm); | 118 profile_zero(tm); |
119 else | 119 else |
120 { | 120 { |
121 # ifdef MSWIN | 121 # ifdef MSWIN |
122 LARGE_INTEGER fr; | 122 LARGE_INTEGER fr; |
142 profile_passed_limit(proftime_T *tm) | 142 profile_passed_limit(proftime_T *tm) |
143 { | 143 { |
144 proftime_T now; | 144 proftime_T now; |
145 | 145 |
146 # ifdef MSWIN | 146 # ifdef MSWIN |
147 if (tm->QuadPart == 0) /* timer was not set */ | 147 if (tm->QuadPart == 0) // timer was not set |
148 return FALSE; | 148 return FALSE; |
149 QueryPerformanceCounter(&now); | 149 QueryPerformanceCounter(&now); |
150 return (now.QuadPart > tm->QuadPart); | 150 return (now.QuadPart > tm->QuadPart); |
151 # else | 151 # else |
152 if (tm->tv_sec == 0) /* timer was not set */ | 152 if (tm->tv_sec == 0) // timer was not set |
153 return FALSE; | 153 return FALSE; |
154 gettimeofday(&now, NULL); | 154 gettimeofday(&now, NULL); |
155 return (now.tv_sec > tm->tv_sec | 155 return (now.tv_sec > tm->tv_sec |
156 || (now.tv_sec == tm->tv_sec && now.tv_usec > tm->tv_usec)); | 156 || (now.tv_sec == tm->tv_sec && now.tv_usec > tm->tv_usec)); |
157 # endif | 157 # endif |
169 tm->tv_usec = 0; | 169 tm->tv_usec = 0; |
170 tm->tv_sec = 0; | 170 tm->tv_sec = 0; |
171 # endif | 171 # endif |
172 } | 172 } |
173 | 173 |
174 # endif /* FEAT_PROFILE || FEAT_RELTIME */ | 174 # endif // FEAT_PROFILE || FEAT_RELTIME |
175 | 175 |
176 #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT) && defined(FEAT_PROFILE) | 176 #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT) && defined(FEAT_PROFILE) |
177 # if defined(HAVE_MATH_H) | 177 # if defined(HAVE_MATH_H) |
178 # include <math.h> | 178 # include <math.h> |
179 # endif | 179 # endif |
229 * Add the "self" time from the total time and the children's time. | 229 * Add the "self" time from the total time and the children's time. |
230 */ | 230 */ |
231 void | 231 void |
232 profile_self(proftime_T *self, proftime_T *total, proftime_T *children) | 232 profile_self(proftime_T *self, proftime_T *total, proftime_T *children) |
233 { | 233 { |
234 /* Check that the result won't be negative. Can happen with recursive | 234 // Check that the result won't be negative. Can happen with recursive |
235 * calls. */ | 235 // calls. |
236 #ifdef MSWIN | 236 #ifdef MSWIN |
237 if (total->QuadPart <= children->QuadPart) | 237 if (total->QuadPart <= children->QuadPart) |
238 return; | 238 return; |
239 #else | 239 #else |
240 if (total->tv_sec < children->tv_sec | 240 if (total->tv_sec < children->tv_sec |
336 } | 336 } |
337 do_profiling = PROF_YES; | 337 do_profiling = PROF_YES; |
338 } | 338 } |
339 else | 339 else |
340 { | 340 { |
341 /* The rest is similar to ":breakadd". */ | 341 // The rest is similar to ":breakadd". |
342 ex_breakadd(eap); | 342 ex_breakadd(eap); |
343 } | 343 } |
344 } | 344 } |
345 | 345 |
346 /* Command line expansion for :profile. */ | 346 // Command line expansion for :profile. |
347 static enum | 347 static enum |
348 { | 348 { |
349 PEXP_SUBCMD, /* expand :profile sub-commands */ | 349 PEXP_SUBCMD, // expand :profile sub-commands |
350 PEXP_FUNC /* expand :profile func {funcname} */ | 350 PEXP_FUNC // expand :profile func {funcname} |
351 } pexpand_what; | 351 } pexpand_what; |
352 | 352 |
353 static char *pexpand_cmds[] = { | 353 static char *pexpand_cmds[] = { |
354 "start", | 354 "start", |
355 #define PROFCMD_START 0 | 355 #define PROFCMD_START 0 |
374 { | 374 { |
375 switch (pexpand_what) | 375 switch (pexpand_what) |
376 { | 376 { |
377 case PEXP_SUBCMD: | 377 case PEXP_SUBCMD: |
378 return (char_u *)pexpand_cmds[idx]; | 378 return (char_u *)pexpand_cmds[idx]; |
379 /* case PEXP_FUNC: TODO */ | 379 // case PEXP_FUNC: TODO |
380 default: | 380 default: |
381 return NULL; | 381 return NULL; |
382 } | 382 } |
383 } | 383 } |
384 | 384 |
388 void | 388 void |
389 set_context_in_profile_cmd(expand_T *xp, char_u *arg) | 389 set_context_in_profile_cmd(expand_T *xp, char_u *arg) |
390 { | 390 { |
391 char_u *end_subcmd; | 391 char_u *end_subcmd; |
392 | 392 |
393 /* Default: expand subcommands. */ | 393 // Default: expand subcommands. |
394 xp->xp_context = EXPAND_PROFILE; | 394 xp->xp_context = EXPAND_PROFILE; |
395 pexpand_what = PEXP_SUBCMD; | 395 pexpand_what = PEXP_SUBCMD; |
396 xp->xp_pattern = arg; | 396 xp->xp_pattern = arg; |
397 | 397 |
398 end_subcmd = skiptowhite(arg); | 398 end_subcmd = skiptowhite(arg); |
404 xp->xp_context = EXPAND_FILES; | 404 xp->xp_context = EXPAND_FILES; |
405 xp->xp_pattern = skipwhite(end_subcmd); | 405 xp->xp_pattern = skipwhite(end_subcmd); |
406 return; | 406 return; |
407 } | 407 } |
408 | 408 |
409 /* TODO: expand function names after "func" */ | 409 // TODO: expand function names after "func" |
410 xp->xp_context = EXPAND_NOTHING; | 410 xp->xp_context = EXPAND_NOTHING; |
411 } | |
412 | |
413 /* | |
414 * Dump the profiling info. | |
415 */ | |
416 void | |
417 profile_dump(void) | |
418 { | |
419 FILE *fd; | |
420 | |
421 if (profile_fname != NULL) | |
422 { | |
423 fd = mch_fopen((char *)profile_fname, "w"); | |
424 if (fd == NULL) | |
425 semsg(_(e_notopen), profile_fname); | |
426 else | |
427 { | |
428 script_dump_profile(fd); | |
429 func_dump_profile(fd); | |
430 fclose(fd); | |
431 } | |
432 } | |
433 } | 411 } |
434 | 412 |
435 static proftime_T inchar_time; | 413 static proftime_T inchar_time; |
436 | 414 |
437 /* | 415 /* |
464 if (current_sctx.sc_sid > 0) | 442 if (current_sctx.sc_sid > 0) |
465 return SCRIPT_ITEM(current_sctx.sc_sid).sn_pr_force; | 443 return SCRIPT_ITEM(current_sctx.sc_sid).sn_pr_force; |
466 return FALSE; | 444 return FALSE; |
467 } | 445 } |
468 | 446 |
469 void | |
470 prof_sort_list( | |
471 FILE *fd, | |
472 ufunc_T **sorttab, | |
473 int st_len, | |
474 char *title, | |
475 int prefer_self) /* when equal print only self time */ | |
476 { | |
477 int i; | |
478 ufunc_T *fp; | |
479 | |
480 fprintf(fd, "FUNCTIONS SORTED ON %s TIME\n", title); | |
481 fprintf(fd, "count total (s) self (s) function\n"); | |
482 for (i = 0; i < 20 && i < st_len; ++i) | |
483 { | |
484 fp = sorttab[i]; | |
485 prof_func_line(fd, fp->uf_tm_count, &fp->uf_tm_total, &fp->uf_tm_self, | |
486 prefer_self); | |
487 if (fp->uf_name[0] == K_SPECIAL) | |
488 fprintf(fd, " <SNR>%s()\n", fp->uf_name + 3); | |
489 else | |
490 fprintf(fd, " %s()\n", fp->uf_name); | |
491 } | |
492 fprintf(fd, "\n"); | |
493 } | |
494 | |
495 /* | 447 /* |
496 * Print the count and times for one function or function line. | 448 * Print the count and times for one function or function line. |
497 */ | 449 */ |
498 void | 450 static void |
499 prof_func_line( | 451 prof_func_line( |
500 FILE *fd, | 452 FILE *fd, |
501 int count, | 453 int count, |
502 proftime_T *total, | 454 proftime_T *total, |
503 proftime_T *self, | 455 proftime_T *self, |
504 int prefer_self) /* when equal print only self time */ | 456 int prefer_self) // when equal print only self time |
505 { | 457 { |
506 if (count > 0) | 458 if (count > 0) |
507 { | 459 { |
508 fprintf(fd, "%5d ", count); | 460 fprintf(fd, "%5d ", count); |
509 if (prefer_self && profile_equal(total, self)) | 461 if (prefer_self && profile_equal(total, self)) |
517 } | 469 } |
518 else | 470 else |
519 fprintf(fd, " "); | 471 fprintf(fd, " "); |
520 } | 472 } |
521 | 473 |
474 static void | |
475 prof_sort_list( | |
476 FILE *fd, | |
477 ufunc_T **sorttab, | |
478 int st_len, | |
479 char *title, | |
480 int prefer_self) // when equal print only self time | |
481 { | |
482 int i; | |
483 ufunc_T *fp; | |
484 | |
485 fprintf(fd, "FUNCTIONS SORTED ON %s TIME\n", title); | |
486 fprintf(fd, "count total (s) self (s) function\n"); | |
487 for (i = 0; i < 20 && i < st_len; ++i) | |
488 { | |
489 fp = sorttab[i]; | |
490 prof_func_line(fd, fp->uf_tm_count, &fp->uf_tm_total, &fp->uf_tm_self, | |
491 prefer_self); | |
492 if (fp->uf_name[0] == K_SPECIAL) | |
493 fprintf(fd, " <SNR>%s()\n", fp->uf_name + 3); | |
494 else | |
495 fprintf(fd, " %s()\n", fp->uf_name); | |
496 } | |
497 fprintf(fd, "\n"); | |
498 } | |
499 | |
522 /* | 500 /* |
523 * Compare function for total time sorting. | 501 * Compare function for total time sorting. |
524 */ | 502 */ |
525 int | 503 static int |
526 prof_total_cmp(const void *s1, const void *s2) | 504 prof_total_cmp(const void *s1, const void *s2) |
527 { | 505 { |
528 ufunc_T *p1, *p2; | 506 ufunc_T *p1, *p2; |
529 | 507 |
530 p1 = *(ufunc_T **)s1; | 508 p1 = *(ufunc_T **)s1; |
533 } | 511 } |
534 | 512 |
535 /* | 513 /* |
536 * Compare function for self time sorting. | 514 * Compare function for self time sorting. |
537 */ | 515 */ |
538 int | 516 static int |
539 prof_self_cmp(const void *s1, const void *s2) | 517 prof_self_cmp(const void *s1, const void *s2) |
540 { | 518 { |
541 ufunc_T *p1, *p2; | 519 ufunc_T *p1, *p2; |
542 | 520 |
543 p1 = *(ufunc_T **)s1; | 521 p1 = *(ufunc_T **)s1; |
554 int len = fp->uf_lines.ga_len; | 532 int len = fp->uf_lines.ga_len; |
555 | 533 |
556 if (!fp->uf_prof_initialized) | 534 if (!fp->uf_prof_initialized) |
557 { | 535 { |
558 if (len == 0) | 536 if (len == 0) |
559 len = 1; /* avoid getting error for allocating zero bytes */ | 537 len = 1; // avoid getting error for allocating zero bytes |
560 fp->uf_tm_count = 0; | 538 fp->uf_tm_count = 0; |
561 profile_zero(&fp->uf_tm_self); | 539 profile_zero(&fp->uf_tm_self); |
562 profile_zero(&fp->uf_tm_total); | 540 profile_zero(&fp->uf_tm_total); |
563 if (fp->uf_tml_count == NULL) | 541 if (fp->uf_tml_count == NULL) |
564 fp->uf_tml_count = ALLOC_CLEAR_MULT(int, len); | 542 fp->uf_tml_count = ALLOC_CLEAR_MULT(int, len); |
567 if (fp->uf_tml_self == NULL) | 545 if (fp->uf_tml_self == NULL) |
568 fp->uf_tml_self = ALLOC_CLEAR_MULT(proftime_T, len); | 546 fp->uf_tml_self = ALLOC_CLEAR_MULT(proftime_T, len); |
569 fp->uf_tml_idx = -1; | 547 fp->uf_tml_idx = -1; |
570 if (fp->uf_tml_count == NULL || fp->uf_tml_total == NULL | 548 if (fp->uf_tml_count == NULL || fp->uf_tml_total == NULL |
571 || fp->uf_tml_self == NULL) | 549 || fp->uf_tml_self == NULL) |
572 return; /* out of memory */ | 550 return; // out of memory |
573 fp->uf_prof_initialized = TRUE; | 551 fp->uf_prof_initialized = TRUE; |
574 } | 552 } |
575 | 553 |
576 fp->uf_profiling = TRUE; | 554 fp->uf_profiling = TRUE; |
577 } | 555 } |
581 * counted for the script/function itself. | 559 * counted for the script/function itself. |
582 * Should always be called in pair with prof_child_exit(). | 560 * Should always be called in pair with prof_child_exit(). |
583 */ | 561 */ |
584 void | 562 void |
585 prof_child_enter( | 563 prof_child_enter( |
586 proftime_T *tm) /* place to store waittime */ | 564 proftime_T *tm) // place to store waittime |
587 { | 565 { |
588 funccall_T *fc = get_current_funccal(); | 566 funccall_T *fc = get_current_funccal(); |
589 | 567 |
590 if (fc != NULL && fc->func->uf_profiling) | 568 if (fc != NULL && fc->func->uf_profiling) |
591 profile_start(&fc->prof_child); | 569 profile_start(&fc->prof_child); |
596 * Take care of time spent in a child. | 574 * Take care of time spent in a child. |
597 * Should always be called after prof_child_enter(). | 575 * Should always be called after prof_child_enter(). |
598 */ | 576 */ |
599 void | 577 void |
600 prof_child_exit( | 578 prof_child_exit( |
601 proftime_T *tm) /* where waittime was stored */ | 579 proftime_T *tm) // where waittime was stored |
602 { | 580 { |
603 funccall_T *fc = get_current_funccal(); | 581 funccall_T *fc = get_current_funccal(); |
604 | 582 |
605 if (fc != NULL && fc->func->uf_profiling) | 583 if (fc != NULL && fc->func->uf_profiling) |
606 { | 584 { |
607 profile_end(&fc->prof_child); | 585 profile_end(&fc->prof_child); |
608 profile_sub_wait(tm, &fc->prof_child); /* don't count waiting time */ | 586 profile_sub_wait(tm, &fc->prof_child); // don't count waiting time |
609 profile_add(&fc->func->uf_tm_children, &fc->prof_child); | 587 profile_add(&fc->func->uf_tm_children, &fc->prof_child); |
610 profile_add(&fc->func->uf_tml_children, &fc->prof_child); | 588 profile_add(&fc->func->uf_tml_children, &fc->prof_child); |
611 } | 589 } |
612 script_prof_restore(tm); | 590 script_prof_restore(tm); |
613 } | 591 } |
626 | 604 |
627 if (fp->uf_profiling && sourcing_lnum >= 1 | 605 if (fp->uf_profiling && sourcing_lnum >= 1 |
628 && sourcing_lnum <= fp->uf_lines.ga_len) | 606 && sourcing_lnum <= fp->uf_lines.ga_len) |
629 { | 607 { |
630 fp->uf_tml_idx = sourcing_lnum - 1; | 608 fp->uf_tml_idx = sourcing_lnum - 1; |
631 /* Skip continuation lines. */ | 609 // Skip continuation lines. |
632 while (fp->uf_tml_idx > 0 && FUNCLINE(fp, fp->uf_tml_idx) == NULL) | 610 while (fp->uf_tml_idx > 0 && FUNCLINE(fp, fp->uf_tml_idx) == NULL) |
633 --fp->uf_tml_idx; | 611 --fp->uf_tml_idx; |
634 fp->uf_tml_execed = FALSE; | 612 fp->uf_tml_execed = FALSE; |
635 profile_start(&fp->uf_tml_start); | 613 profile_start(&fp->uf_tml_start); |
636 profile_zero(&fp->uf_tml_children); | 614 profile_zero(&fp->uf_tml_children); |
672 &fp->uf_tml_children); | 650 &fp->uf_tml_children); |
673 } | 651 } |
674 fp->uf_tml_idx = -1; | 652 fp->uf_tml_idx = -1; |
675 } | 653 } |
676 } | 654 } |
677 # endif /* FEAT_PROFILE */ | 655 |
656 /* | |
657 * Dump the profiling results for all functions in file "fd". | |
658 */ | |
659 static void | |
660 func_dump_profile(FILE *fd) | |
661 { | |
662 hashtab_T *functbl; | |
663 hashitem_T *hi; | |
664 int todo; | |
665 ufunc_T *fp; | |
666 int i; | |
667 ufunc_T **sorttab; | |
668 int st_len = 0; | |
669 char_u *p; | |
670 | |
671 functbl = func_tbl_get(); | |
672 todo = (int)functbl->ht_used; | |
673 if (todo == 0) | |
674 return; // nothing to dump | |
675 | |
676 sorttab = ALLOC_MULT(ufunc_T *, todo); | |
677 | |
678 for (hi = functbl->ht_array; todo > 0; ++hi) | |
679 { | |
680 if (!HASHITEM_EMPTY(hi)) | |
681 { | |
682 --todo; | |
683 fp = HI2UF(hi); | |
684 if (fp->uf_prof_initialized) | |
685 { | |
686 if (sorttab != NULL) | |
687 sorttab[st_len++] = fp; | |
688 | |
689 if (fp->uf_name[0] == K_SPECIAL) | |
690 fprintf(fd, "FUNCTION <SNR>%s()\n", fp->uf_name + 3); | |
691 else | |
692 fprintf(fd, "FUNCTION %s()\n", fp->uf_name); | |
693 p = home_replace_save(NULL, | |
694 get_scriptname(fp->uf_script_ctx.sc_sid)); | |
695 if (p != NULL) | |
696 { | |
697 fprintf(fd, " Defined: %s line %ld\n", | |
698 p, (long)fp->uf_script_ctx.sc_lnum); | |
699 vim_free(p); | |
700 } | |
701 if (fp->uf_tm_count == 1) | |
702 fprintf(fd, "Called 1 time\n"); | |
703 else | |
704 fprintf(fd, "Called %d times\n", fp->uf_tm_count); | |
705 fprintf(fd, "Total time: %s\n", profile_msg(&fp->uf_tm_total)); | |
706 fprintf(fd, " Self time: %s\n", profile_msg(&fp->uf_tm_self)); | |
707 fprintf(fd, "\n"); | |
708 fprintf(fd, "count total (s) self (s)\n"); | |
709 | |
710 for (i = 0; i < fp->uf_lines.ga_len; ++i) | |
711 { | |
712 if (FUNCLINE(fp, i) == NULL) | |
713 continue; | |
714 prof_func_line(fd, fp->uf_tml_count[i], | |
715 &fp->uf_tml_total[i], &fp->uf_tml_self[i], TRUE); | |
716 fprintf(fd, "%s\n", FUNCLINE(fp, i)); | |
717 } | |
718 fprintf(fd, "\n"); | |
719 } | |
720 } | |
721 } | |
722 | |
723 if (sorttab != NULL && st_len > 0) | |
724 { | |
725 qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), | |
726 prof_total_cmp); | |
727 prof_sort_list(fd, sorttab, st_len, "TOTAL", FALSE); | |
728 qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), | |
729 prof_self_cmp); | |
730 prof_sort_list(fd, sorttab, st_len, "SELF", TRUE); | |
731 } | |
732 | |
733 vim_free(sorttab); | |
734 } | |
735 | |
736 /* | |
737 * Start profiling script "fp". | |
738 */ | |
739 void | |
740 script_do_profile(scriptitem_T *si) | |
741 { | |
742 si->sn_pr_count = 0; | |
743 profile_zero(&si->sn_pr_total); | |
744 profile_zero(&si->sn_pr_self); | |
745 | |
746 ga_init2(&si->sn_prl_ga, sizeof(sn_prl_T), 100); | |
747 si->sn_prl_idx = -1; | |
748 si->sn_prof_on = TRUE; | |
749 si->sn_pr_nest = 0; | |
750 } | |
751 | |
752 /* | |
753 * Save time when starting to invoke another script or function. | |
754 */ | |
755 void | |
756 script_prof_save( | |
757 proftime_T *tm) // place to store wait time | |
758 { | |
759 scriptitem_T *si; | |
760 | |
761 if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) | |
762 { | |
763 si = &SCRIPT_ITEM(current_sctx.sc_sid); | |
764 if (si->sn_prof_on && si->sn_pr_nest++ == 0) | |
765 profile_start(&si->sn_pr_child); | |
766 } | |
767 profile_get_wait(tm); | |
768 } | |
769 | |
770 /* | |
771 * Count time spent in children after invoking another script or function. | |
772 */ | |
773 void | |
774 script_prof_restore(proftime_T *tm) | |
775 { | |
776 scriptitem_T *si; | |
777 | |
778 if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) | |
779 { | |
780 si = &SCRIPT_ITEM(current_sctx.sc_sid); | |
781 if (si->sn_prof_on && --si->sn_pr_nest == 0) | |
782 { | |
783 profile_end(&si->sn_pr_child); | |
784 profile_sub_wait(tm, &si->sn_pr_child); // don't count wait time | |
785 profile_add(&si->sn_pr_children, &si->sn_pr_child); | |
786 profile_add(&si->sn_prl_children, &si->sn_pr_child); | |
787 } | |
788 } | |
789 } | |
790 | |
791 /* | |
792 * Dump the profiling results for all scripts in file "fd". | |
793 */ | |
794 static void | |
795 script_dump_profile(FILE *fd) | |
796 { | |
797 int id; | |
798 scriptitem_T *si; | |
799 int i; | |
800 FILE *sfd; | |
801 sn_prl_T *pp; | |
802 | |
803 for (id = 1; id <= script_items.ga_len; ++id) | |
804 { | |
805 si = &SCRIPT_ITEM(id); | |
806 if (si->sn_prof_on) | |
807 { | |
808 fprintf(fd, "SCRIPT %s\n", si->sn_name); | |
809 if (si->sn_pr_count == 1) | |
810 fprintf(fd, "Sourced 1 time\n"); | |
811 else | |
812 fprintf(fd, "Sourced %d times\n", si->sn_pr_count); | |
813 fprintf(fd, "Total time: %s\n", profile_msg(&si->sn_pr_total)); | |
814 fprintf(fd, " Self time: %s\n", profile_msg(&si->sn_pr_self)); | |
815 fprintf(fd, "\n"); | |
816 fprintf(fd, "count total (s) self (s)\n"); | |
817 | |
818 sfd = mch_fopen((char *)si->sn_name, "r"); | |
819 if (sfd == NULL) | |
820 fprintf(fd, "Cannot open file!\n"); | |
821 else | |
822 { | |
823 // Keep going till the end of file, so that trailing | |
824 // continuation lines are listed. | |
825 for (i = 0; ; ++i) | |
826 { | |
827 if (vim_fgets(IObuff, IOSIZE, sfd)) | |
828 break; | |
829 // When a line has been truncated, append NL, taking care | |
830 // of multi-byte characters . | |
831 if (IObuff[IOSIZE - 2] != NUL && IObuff[IOSIZE - 2] != NL) | |
832 { | |
833 int n = IOSIZE - 2; | |
834 | |
835 if (enc_utf8) | |
836 { | |
837 // Move to the first byte of this char. | |
838 // utf_head_off() doesn't work, because it checks | |
839 // for a truncated character. | |
840 while (n > 0 && (IObuff[n] & 0xc0) == 0x80) | |
841 --n; | |
842 } | |
843 else if (has_mbyte) | |
844 n -= mb_head_off(IObuff, IObuff + n); | |
845 IObuff[n] = NL; | |
846 IObuff[n + 1] = NUL; | |
847 } | |
848 if (i < si->sn_prl_ga.ga_len | |
849 && (pp = &PRL_ITEM(si, i))->snp_count > 0) | |
850 { | |
851 fprintf(fd, "%5d ", pp->snp_count); | |
852 if (profile_equal(&pp->sn_prl_total, &pp->sn_prl_self)) | |
853 fprintf(fd, " "); | |
854 else | |
855 fprintf(fd, "%s ", profile_msg(&pp->sn_prl_total)); | |
856 fprintf(fd, "%s ", profile_msg(&pp->sn_prl_self)); | |
857 } | |
858 else | |
859 fprintf(fd, " "); | |
860 fprintf(fd, "%s", IObuff); | |
861 } | |
862 fclose(sfd); | |
863 } | |
864 fprintf(fd, "\n"); | |
865 } | |
866 } | |
867 } | |
868 | |
869 /* | |
870 * Dump the profiling info. | |
871 */ | |
872 void | |
873 profile_dump(void) | |
874 { | |
875 FILE *fd; | |
876 | |
877 if (profile_fname != NULL) | |
878 { | |
879 fd = mch_fopen((char *)profile_fname, "w"); | |
880 if (fd == NULL) | |
881 semsg(_(e_notopen), profile_fname); | |
882 else | |
883 { | |
884 script_dump_profile(fd); | |
885 func_dump_profile(fd); | |
886 fclose(fd); | |
887 } | |
888 } | |
889 } | |
890 | |
891 /* | |
892 * Called when starting to read a script line. | |
893 * "sourcing_lnum" must be correct! | |
894 * When skipping lines it may not actually be executed, but we won't find out | |
895 * until later and we need to store the time now. | |
896 */ | |
897 void | |
898 script_line_start(void) | |
899 { | |
900 scriptitem_T *si; | |
901 sn_prl_T *pp; | |
902 | |
903 if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) | |
904 return; | |
905 si = &SCRIPT_ITEM(current_sctx.sc_sid); | |
906 if (si->sn_prof_on && sourcing_lnum >= 1) | |
907 { | |
908 // Grow the array before starting the timer, so that the time spent | |
909 // here isn't counted. | |
910 (void)ga_grow(&si->sn_prl_ga, | |
911 (int)(sourcing_lnum - si->sn_prl_ga.ga_len)); | |
912 si->sn_prl_idx = sourcing_lnum - 1; | |
913 while (si->sn_prl_ga.ga_len <= si->sn_prl_idx | |
914 && si->sn_prl_ga.ga_len < si->sn_prl_ga.ga_maxlen) | |
915 { | |
916 // Zero counters for a line that was not used before. | |
917 pp = &PRL_ITEM(si, si->sn_prl_ga.ga_len); | |
918 pp->snp_count = 0; | |
919 profile_zero(&pp->sn_prl_total); | |
920 profile_zero(&pp->sn_prl_self); | |
921 ++si->sn_prl_ga.ga_len; | |
922 } | |
923 si->sn_prl_execed = FALSE; | |
924 profile_start(&si->sn_prl_start); | |
925 profile_zero(&si->sn_prl_children); | |
926 profile_get_wait(&si->sn_prl_wait); | |
927 } | |
928 } | |
929 | |
930 /* | |
931 * Called when actually executing a function line. | |
932 */ | |
933 void | |
934 script_line_exec(void) | |
935 { | |
936 scriptitem_T *si; | |
937 | |
938 if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) | |
939 return; | |
940 si = &SCRIPT_ITEM(current_sctx.sc_sid); | |
941 if (si->sn_prof_on && si->sn_prl_idx >= 0) | |
942 si->sn_prl_execed = TRUE; | |
943 } | |
944 | |
945 /* | |
946 * Called when done with a script line. | |
947 */ | |
948 void | |
949 script_line_end(void) | |
950 { | |
951 scriptitem_T *si; | |
952 sn_prl_T *pp; | |
953 | |
954 if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) | |
955 return; | |
956 si = &SCRIPT_ITEM(current_sctx.sc_sid); | |
957 if (si->sn_prof_on && si->sn_prl_idx >= 0 | |
958 && si->sn_prl_idx < si->sn_prl_ga.ga_len) | |
959 { | |
960 if (si->sn_prl_execed) | |
961 { | |
962 pp = &PRL_ITEM(si, si->sn_prl_idx); | |
963 ++pp->snp_count; | |
964 profile_end(&si->sn_prl_start); | |
965 profile_sub_wait(&si->sn_prl_wait, &si->sn_prl_start); | |
966 profile_add(&pp->sn_prl_total, &si->sn_prl_start); | |
967 profile_self(&pp->sn_prl_self, &si->sn_prl_start, | |
968 &si->sn_prl_children); | |
969 } | |
970 si->sn_prl_idx = -1; | |
971 } | |
972 } | |
973 # endif // FEAT_PROFILE | |
678 | 974 |
679 #endif | 975 #endif |