Mercurial > vim

comparison src/profiler.c @ 17381:8f44c630c366 v8.1.1689

Find changesets by keywords (author, files, the commit message), revision number or hash, or revset expression.
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