To: vim_dev@googlegroups.com Subject: Patch 8.1.1689 Fcc: outbox From: Bram Moolenaar Mime-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ------------ Patch 8.1.1689 Problem: Profiling code is spread out. Solution: Move more profiling code to profiler.c. (Yegappan Lakshmanan, closes #4668) Files: src/ex_cmds2.c, src/profiler.c, src/proto/ex_cmds2.pro, src/proto/profiler.pro, src/proto/userfunc.pro, src/structs.h, src/userfunc.c *** ../vim-8.1.1688/src/ex_cmds2.c 2019-07-13 22:59:06.922076875 +0200 --- src/ex_cmds2.c 2019-07-14 15:32:30.332418702 +0200 *************** *** 395,534 **** # endif # endif - # if defined(FEAT_PROFILE) || defined(PROTO) - /* - * Start profiling script "fp". - */ - void - script_do_profile(scriptitem_T *si) - { - si->sn_pr_count = 0; - profile_zero(&si->sn_pr_total); - profile_zero(&si->sn_pr_self); - - ga_init2(&si->sn_prl_ga, sizeof(sn_prl_T), 100); - si->sn_prl_idx = -1; - si->sn_prof_on = TRUE; - si->sn_pr_nest = 0; - } - - /* - * Save time when starting to invoke another script or function. - */ - void - script_prof_save( - proftime_T *tm) /* place to store wait time */ - { - scriptitem_T *si; - - if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) - { - si = &SCRIPT_ITEM(current_sctx.sc_sid); - if (si->sn_prof_on && si->sn_pr_nest++ == 0) - profile_start(&si->sn_pr_child); - } - profile_get_wait(tm); - } - - /* - * Count time spent in children after invoking another script or function. - */ - void - script_prof_restore(proftime_T *tm) - { - scriptitem_T *si; - - if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) - { - si = &SCRIPT_ITEM(current_sctx.sc_sid); - if (si->sn_prof_on && --si->sn_pr_nest == 0) - { - profile_end(&si->sn_pr_child); - profile_sub_wait(tm, &si->sn_pr_child); /* don't count wait time */ - profile_add(&si->sn_pr_children, &si->sn_pr_child); - profile_add(&si->sn_prl_children, &si->sn_pr_child); - } - } - } - - /* - * Dump the profiling results for all scripts in file "fd". - */ - void - script_dump_profile(FILE *fd) - { - int id; - scriptitem_T *si; - int i; - FILE *sfd; - sn_prl_T *pp; - - for (id = 1; id <= script_items.ga_len; ++id) - { - si = &SCRIPT_ITEM(id); - if (si->sn_prof_on) - { - fprintf(fd, "SCRIPT %s\n", si->sn_name); - if (si->sn_pr_count == 1) - fprintf(fd, "Sourced 1 time\n"); - else - fprintf(fd, "Sourced %d times\n", si->sn_pr_count); - fprintf(fd, "Total time: %s\n", profile_msg(&si->sn_pr_total)); - fprintf(fd, " Self time: %s\n", profile_msg(&si->sn_pr_self)); - fprintf(fd, "\n"); - fprintf(fd, "count total (s) self (s)\n"); - - sfd = mch_fopen((char *)si->sn_name, "r"); - if (sfd == NULL) - fprintf(fd, "Cannot open file!\n"); - else - { - /* Keep going till the end of file, so that trailing - * continuation lines are listed. */ - for (i = 0; ; ++i) - { - if (vim_fgets(IObuff, IOSIZE, sfd)) - break; - /* When a line has been truncated, append NL, taking care - * of multi-byte characters . */ - if (IObuff[IOSIZE - 2] != NUL && IObuff[IOSIZE - 2] != NL) - { - int n = IOSIZE - 2; - - if (enc_utf8) - { - /* Move to the first byte of this char. - * utf_head_off() doesn't work, because it checks - * for a truncated character. */ - while (n > 0 && (IObuff[n] & 0xc0) == 0x80) - --n; - } - else if (has_mbyte) - n -= mb_head_off(IObuff, IObuff + n); - IObuff[n] = NL; - IObuff[n + 1] = NUL; - } - if (i < si->sn_prl_ga.ga_len - && (pp = &PRL_ITEM(si, i))->snp_count > 0) - { - fprintf(fd, "%5d ", pp->snp_count); - if (profile_equal(&pp->sn_prl_total, &pp->sn_prl_self)) - fprintf(fd, " "); - else - fprintf(fd, "%s ", profile_msg(&pp->sn_prl_total)); - fprintf(fd, "%s ", profile_msg(&pp->sn_prl_self)); - } - else - fprintf(fd, " "); - fprintf(fd, "%s", IObuff); - } - fclose(sfd); - } - fprintf(fd, "\n"); - } - } - } - # endif #endif /* --- 395,400 ---- *************** *** 3534,3624 **** return NULL; } - #if defined(FEAT_PROFILE) || defined(PROTO) - /* - * Called when starting to read a script line. - * "sourcing_lnum" must be correct! - * When skipping lines it may not actually be executed, but we won't find out - * until later and we need to store the time now. - */ - void - script_line_start(void) - { - scriptitem_T *si; - sn_prl_T *pp; - - if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) - return; - si = &SCRIPT_ITEM(current_sctx.sc_sid); - if (si->sn_prof_on && sourcing_lnum >= 1) - { - /* Grow the array before starting the timer, so that the time spent - * here isn't counted. */ - (void)ga_grow(&si->sn_prl_ga, - (int)(sourcing_lnum - si->sn_prl_ga.ga_len)); - si->sn_prl_idx = sourcing_lnum - 1; - while (si->sn_prl_ga.ga_len <= si->sn_prl_idx - && si->sn_prl_ga.ga_len < si->sn_prl_ga.ga_maxlen) - { - /* Zero counters for a line that was not used before. */ - pp = &PRL_ITEM(si, si->sn_prl_ga.ga_len); - pp->snp_count = 0; - profile_zero(&pp->sn_prl_total); - profile_zero(&pp->sn_prl_self); - ++si->sn_prl_ga.ga_len; - } - si->sn_prl_execed = FALSE; - profile_start(&si->sn_prl_start); - profile_zero(&si->sn_prl_children); - profile_get_wait(&si->sn_prl_wait); - } - } - - /* - * Called when actually executing a function line. - */ - void - script_line_exec(void) - { - scriptitem_T *si; - - if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) - return; - si = &SCRIPT_ITEM(current_sctx.sc_sid); - if (si->sn_prof_on && si->sn_prl_idx >= 0) - si->sn_prl_execed = TRUE; - } - - /* - * Called when done with a script line. - */ - void - script_line_end(void) - { - scriptitem_T *si; - sn_prl_T *pp; - - if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) - return; - si = &SCRIPT_ITEM(current_sctx.sc_sid); - if (si->sn_prof_on && si->sn_prl_idx >= 0 - && si->sn_prl_idx < si->sn_prl_ga.ga_len) - { - if (si->sn_prl_execed) - { - pp = &PRL_ITEM(si, si->sn_prl_idx); - ++pp->snp_count; - profile_end(&si->sn_prl_start); - profile_sub_wait(&si->sn_prl_wait, &si->sn_prl_start); - profile_add(&pp->sn_prl_total, &si->sn_prl_start); - profile_self(&pp->sn_prl_self, &si->sn_prl_start, - &si->sn_prl_children); - } - si->sn_prl_idx = -1; - } - } - #endif - /* * ":scriptencoding": Set encoding conversion for a sourced script. */ --- 3400,3405 ---- *** ../vim-8.1.1688/src/profiler.c 2019-07-13 22:59:06.922076875 +0200 --- src/profiler.c 2019-07-14 15:46:55.510643006 +0200 *************** *** 114,120 **** void profile_setlimit(long msec, proftime_T *tm) { ! if (msec <= 0) /* no limit */ profile_zero(tm); else { --- 114,120 ---- void profile_setlimit(long msec, proftime_T *tm) { ! if (msec <= 0) // no limit profile_zero(tm); else { *************** *** 144,155 **** proftime_T now; # ifdef MSWIN ! if (tm->QuadPart == 0) /* timer was not set */ return FALSE; QueryPerformanceCounter(&now); return (now.QuadPart > tm->QuadPart); # else ! if (tm->tv_sec == 0) /* timer was not set */ return FALSE; gettimeofday(&now, NULL); return (now.tv_sec > tm->tv_sec --- 144,155 ---- proftime_T now; # ifdef MSWIN ! if (tm->QuadPart == 0) // timer was not set return FALSE; QueryPerformanceCounter(&now); return (now.QuadPart > tm->QuadPart); # else ! if (tm->tv_sec == 0) // timer was not set return FALSE; gettimeofday(&now, NULL); return (now.tv_sec > tm->tv_sec *************** *** 171,177 **** # endif } ! # endif /* FEAT_PROFILE || FEAT_RELTIME */ #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT) && defined(FEAT_PROFILE) # if defined(HAVE_MATH_H) --- 171,177 ---- # endif } ! # endif // FEAT_PROFILE || FEAT_RELTIME #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_FLOAT) && defined(FEAT_PROFILE) # if defined(HAVE_MATH_H) *************** *** 231,238 **** void profile_self(proftime_T *self, proftime_T *total, proftime_T *children) { ! /* Check that the result won't be negative. Can happen with recursive ! * calls. */ #ifdef MSWIN if (total->QuadPart <= children->QuadPart) return; --- 231,238 ---- void profile_self(proftime_T *self, proftime_T *total, proftime_T *children) { ! // Check that the result won't be negative. Can happen with recursive ! // calls. #ifdef MSWIN if (total->QuadPart <= children->QuadPart) return; *************** *** 338,353 **** } else { ! /* The rest is similar to ":breakadd". */ ex_breakadd(eap); } } ! /* Command line expansion for :profile. */ static enum { ! PEXP_SUBCMD, /* expand :profile sub-commands */ ! PEXP_FUNC /* expand :profile func {funcname} */ } pexpand_what; static char *pexpand_cmds[] = { --- 338,353 ---- } else { ! // The rest is similar to ":breakadd". ex_breakadd(eap); } } ! // Command line expansion for :profile. static enum { ! PEXP_SUBCMD, // expand :profile sub-commands ! PEXP_FUNC // expand :profile func {funcname} } pexpand_what; static char *pexpand_cmds[] = { *************** *** 376,382 **** { case PEXP_SUBCMD: return (char_u *)pexpand_cmds[idx]; ! /* case PEXP_FUNC: TODO */ default: return NULL; } --- 376,382 ---- { case PEXP_SUBCMD: return (char_u *)pexpand_cmds[idx]; ! // case PEXP_FUNC: TODO default: return NULL; } *************** *** 390,396 **** { char_u *end_subcmd; ! /* Default: expand subcommands. */ xp->xp_context = EXPAND_PROFILE; pexpand_what = PEXP_SUBCMD; xp->xp_pattern = arg; --- 390,396 ---- { char_u *end_subcmd; ! // Default: expand subcommands. xp->xp_context = EXPAND_PROFILE; pexpand_what = PEXP_SUBCMD; xp->xp_pattern = arg; *************** *** 406,437 **** return; } ! /* TODO: expand function names after "func" */ xp->xp_context = EXPAND_NOTHING; } - /* - * Dump the profiling info. - */ - void - profile_dump(void) - { - FILE *fd; - - if (profile_fname != NULL) - { - fd = mch_fopen((char *)profile_fname, "w"); - if (fd == NULL) - semsg(_(e_notopen), profile_fname); - else - { - script_dump_profile(fd); - func_dump_profile(fd); - fclose(fd); - } - } - } - static proftime_T inchar_time; /* --- 406,415 ---- return; } ! // TODO: expand function names after "func" xp->xp_context = EXPAND_NOTHING; } static proftime_T inchar_time; /* *************** *** 466,507 **** return FALSE; } - void - prof_sort_list( - FILE *fd, - ufunc_T **sorttab, - int st_len, - char *title, - int prefer_self) /* when equal print only self time */ - { - int i; - ufunc_T *fp; - - fprintf(fd, "FUNCTIONS SORTED ON %s TIME\n", title); - fprintf(fd, "count total (s) self (s) function\n"); - for (i = 0; i < 20 && i < st_len; ++i) - { - fp = sorttab[i]; - prof_func_line(fd, fp->uf_tm_count, &fp->uf_tm_total, &fp->uf_tm_self, - prefer_self); - if (fp->uf_name[0] == K_SPECIAL) - fprintf(fd, " %s()\n", fp->uf_name + 3); - else - fprintf(fd, " %s()\n", fp->uf_name); - } - fprintf(fd, "\n"); - } - /* * Print the count and times for one function or function line. */ ! void prof_func_line( FILE *fd, int count, proftime_T *total, proftime_T *self, ! int prefer_self) /* when equal print only self time */ { if (count > 0) { --- 444,459 ---- return FALSE; } /* * Print the count and times for one function or function line. */ ! static void prof_func_line( FILE *fd, int count, proftime_T *total, proftime_T *self, ! int prefer_self) // when equal print only self time { if (count > 0) { *************** *** 519,528 **** fprintf(fd, " "); } /* * Compare function for total time sorting. */ ! int prof_total_cmp(const void *s1, const void *s2) { ufunc_T *p1, *p2; --- 471,506 ---- fprintf(fd, " "); } + static void + prof_sort_list( + FILE *fd, + ufunc_T **sorttab, + int st_len, + char *title, + int prefer_self) // when equal print only self time + { + int i; + ufunc_T *fp; + + fprintf(fd, "FUNCTIONS SORTED ON %s TIME\n", title); + fprintf(fd, "count total (s) self (s) function\n"); + for (i = 0; i < 20 && i < st_len; ++i) + { + fp = sorttab[i]; + prof_func_line(fd, fp->uf_tm_count, &fp->uf_tm_total, &fp->uf_tm_self, + prefer_self); + if (fp->uf_name[0] == K_SPECIAL) + fprintf(fd, " %s()\n", fp->uf_name + 3); + else + fprintf(fd, " %s()\n", fp->uf_name); + } + fprintf(fd, "\n"); + } + /* * Compare function for total time sorting. */ ! static int prof_total_cmp(const void *s1, const void *s2) { ufunc_T *p1, *p2; *************** *** 535,541 **** /* * Compare function for self time sorting. */ ! int prof_self_cmp(const void *s1, const void *s2) { ufunc_T *p1, *p2; --- 513,519 ---- /* * Compare function for self time sorting. */ ! static int prof_self_cmp(const void *s1, const void *s2) { ufunc_T *p1, *p2; *************** *** 556,562 **** if (!fp->uf_prof_initialized) { if (len == 0) ! len = 1; /* avoid getting error for allocating zero bytes */ fp->uf_tm_count = 0; profile_zero(&fp->uf_tm_self); profile_zero(&fp->uf_tm_total); --- 534,540 ---- if (!fp->uf_prof_initialized) { if (len == 0) ! len = 1; // avoid getting error for allocating zero bytes fp->uf_tm_count = 0; profile_zero(&fp->uf_tm_self); profile_zero(&fp->uf_tm_total); *************** *** 569,575 **** fp->uf_tml_idx = -1; if (fp->uf_tml_count == NULL || fp->uf_tml_total == NULL || fp->uf_tml_self == NULL) ! return; /* out of memory */ fp->uf_prof_initialized = TRUE; } --- 547,553 ---- fp->uf_tml_idx = -1; if (fp->uf_tml_count == NULL || fp->uf_tml_total == NULL || fp->uf_tml_self == NULL) ! return; // out of memory fp->uf_prof_initialized = TRUE; } *************** *** 583,589 **** */ void prof_child_enter( ! proftime_T *tm) /* place to store waittime */ { funccall_T *fc = get_current_funccal(); --- 561,567 ---- */ void prof_child_enter( ! proftime_T *tm) // place to store waittime { funccall_T *fc = get_current_funccal(); *************** *** 598,611 **** */ void prof_child_exit( ! proftime_T *tm) /* where waittime was stored */ { funccall_T *fc = get_current_funccal(); if (fc != NULL && fc->func->uf_profiling) { profile_end(&fc->prof_child); ! profile_sub_wait(tm, &fc->prof_child); /* don't count waiting time */ profile_add(&fc->func->uf_tm_children, &fc->prof_child); profile_add(&fc->func->uf_tml_children, &fc->prof_child); } --- 576,589 ---- */ void prof_child_exit( ! proftime_T *tm) // where waittime was stored { funccall_T *fc = get_current_funccal(); if (fc != NULL && fc->func->uf_profiling) { profile_end(&fc->prof_child); ! profile_sub_wait(tm, &fc->prof_child); // don't count waiting time profile_add(&fc->func->uf_tm_children, &fc->prof_child); profile_add(&fc->func->uf_tml_children, &fc->prof_child); } *************** *** 628,634 **** && sourcing_lnum <= fp->uf_lines.ga_len) { fp->uf_tml_idx = sourcing_lnum - 1; ! /* Skip continuation lines. */ while (fp->uf_tml_idx > 0 && FUNCLINE(fp, fp->uf_tml_idx) == NULL) --fp->uf_tml_idx; fp->uf_tml_execed = FALSE; --- 606,612 ---- && sourcing_lnum <= fp->uf_lines.ga_len) { fp->uf_tml_idx = sourcing_lnum - 1; ! // Skip continuation lines. while (fp->uf_tml_idx > 0 && FUNCLINE(fp, fp->uf_tml_idx) == NULL) --fp->uf_tml_idx; fp->uf_tml_execed = FALSE; *************** *** 674,679 **** fp->uf_tml_idx = -1; } } ! # endif /* FEAT_PROFILE */ #endif --- 652,975 ---- fp->uf_tml_idx = -1; } } ! ! /* ! * Dump the profiling results for all functions in file "fd". ! */ ! static void ! func_dump_profile(FILE *fd) ! { ! hashtab_T *functbl; ! hashitem_T *hi; ! int todo; ! ufunc_T *fp; ! int i; ! ufunc_T **sorttab; ! int st_len = 0; ! char_u *p; ! ! functbl = func_tbl_get(); ! todo = (int)functbl->ht_used; ! if (todo == 0) ! return; // nothing to dump ! ! sorttab = ALLOC_MULT(ufunc_T *, todo); ! ! for (hi = functbl->ht_array; todo > 0; ++hi) ! { ! if (!HASHITEM_EMPTY(hi)) ! { ! --todo; ! fp = HI2UF(hi); ! if (fp->uf_prof_initialized) ! { ! if (sorttab != NULL) ! sorttab[st_len++] = fp; ! ! if (fp->uf_name[0] == K_SPECIAL) ! fprintf(fd, "FUNCTION %s()\n", fp->uf_name + 3); ! else ! fprintf(fd, "FUNCTION %s()\n", fp->uf_name); ! p = home_replace_save(NULL, ! get_scriptname(fp->uf_script_ctx.sc_sid)); ! if (p != NULL) ! { ! fprintf(fd, " Defined: %s line %ld\n", ! p, (long)fp->uf_script_ctx.sc_lnum); ! vim_free(p); ! } ! if (fp->uf_tm_count == 1) ! fprintf(fd, "Called 1 time\n"); ! else ! fprintf(fd, "Called %d times\n", fp->uf_tm_count); ! fprintf(fd, "Total time: %s\n", profile_msg(&fp->uf_tm_total)); ! fprintf(fd, " Self time: %s\n", profile_msg(&fp->uf_tm_self)); ! fprintf(fd, "\n"); ! fprintf(fd, "count total (s) self (s)\n"); ! ! for (i = 0; i < fp->uf_lines.ga_len; ++i) ! { ! if (FUNCLINE(fp, i) == NULL) ! continue; ! prof_func_line(fd, fp->uf_tml_count[i], ! &fp->uf_tml_total[i], &fp->uf_tml_self[i], TRUE); ! fprintf(fd, "%s\n", FUNCLINE(fp, i)); ! } ! fprintf(fd, "\n"); ! } ! } ! } ! ! if (sorttab != NULL && st_len > 0) ! { ! qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), ! prof_total_cmp); ! prof_sort_list(fd, sorttab, st_len, "TOTAL", FALSE); ! qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), ! prof_self_cmp); ! prof_sort_list(fd, sorttab, st_len, "SELF", TRUE); ! } ! ! vim_free(sorttab); ! } ! ! /* ! * Start profiling script "fp". ! */ ! void ! script_do_profile(scriptitem_T *si) ! { ! si->sn_pr_count = 0; ! profile_zero(&si->sn_pr_total); ! profile_zero(&si->sn_pr_self); ! ! ga_init2(&si->sn_prl_ga, sizeof(sn_prl_T), 100); ! si->sn_prl_idx = -1; ! si->sn_prof_on = TRUE; ! si->sn_pr_nest = 0; ! } ! ! /* ! * Save time when starting to invoke another script or function. ! */ ! void ! script_prof_save( ! proftime_T *tm) // place to store wait time ! { ! scriptitem_T *si; ! ! if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) ! { ! si = &SCRIPT_ITEM(current_sctx.sc_sid); ! if (si->sn_prof_on && si->sn_pr_nest++ == 0) ! profile_start(&si->sn_pr_child); ! } ! profile_get_wait(tm); ! } ! ! /* ! * Count time spent in children after invoking another script or function. ! */ ! void ! script_prof_restore(proftime_T *tm) ! { ! scriptitem_T *si; ! ! if (current_sctx.sc_sid > 0 && current_sctx.sc_sid <= script_items.ga_len) ! { ! si = &SCRIPT_ITEM(current_sctx.sc_sid); ! if (si->sn_prof_on && --si->sn_pr_nest == 0) ! { ! profile_end(&si->sn_pr_child); ! profile_sub_wait(tm, &si->sn_pr_child); // don't count wait time ! profile_add(&si->sn_pr_children, &si->sn_pr_child); ! profile_add(&si->sn_prl_children, &si->sn_pr_child); ! } ! } ! } ! ! /* ! * Dump the profiling results for all scripts in file "fd". ! */ ! static void ! script_dump_profile(FILE *fd) ! { ! int id; ! scriptitem_T *si; ! int i; ! FILE *sfd; ! sn_prl_T *pp; ! ! for (id = 1; id <= script_items.ga_len; ++id) ! { ! si = &SCRIPT_ITEM(id); ! if (si->sn_prof_on) ! { ! fprintf(fd, "SCRIPT %s\n", si->sn_name); ! if (si->sn_pr_count == 1) ! fprintf(fd, "Sourced 1 time\n"); ! else ! fprintf(fd, "Sourced %d times\n", si->sn_pr_count); ! fprintf(fd, "Total time: %s\n", profile_msg(&si->sn_pr_total)); ! fprintf(fd, " Self time: %s\n", profile_msg(&si->sn_pr_self)); ! fprintf(fd, "\n"); ! fprintf(fd, "count total (s) self (s)\n"); ! ! sfd = mch_fopen((char *)si->sn_name, "r"); ! if (sfd == NULL) ! fprintf(fd, "Cannot open file!\n"); ! else ! { ! // Keep going till the end of file, so that trailing ! // continuation lines are listed. ! for (i = 0; ; ++i) ! { ! if (vim_fgets(IObuff, IOSIZE, sfd)) ! break; ! // When a line has been truncated, append NL, taking care ! // of multi-byte characters . ! if (IObuff[IOSIZE - 2] != NUL && IObuff[IOSIZE - 2] != NL) ! { ! int n = IOSIZE - 2; ! ! if (enc_utf8) ! { ! // Move to the first byte of this char. ! // utf_head_off() doesn't work, because it checks ! // for a truncated character. ! while (n > 0 && (IObuff[n] & 0xc0) == 0x80) ! --n; ! } ! else if (has_mbyte) ! n -= mb_head_off(IObuff, IObuff + n); ! IObuff[n] = NL; ! IObuff[n + 1] = NUL; ! } ! if (i < si->sn_prl_ga.ga_len ! && (pp = &PRL_ITEM(si, i))->snp_count > 0) ! { ! fprintf(fd, "%5d ", pp->snp_count); ! if (profile_equal(&pp->sn_prl_total, &pp->sn_prl_self)) ! fprintf(fd, " "); ! else ! fprintf(fd, "%s ", profile_msg(&pp->sn_prl_total)); ! fprintf(fd, "%s ", profile_msg(&pp->sn_prl_self)); ! } ! else ! fprintf(fd, " "); ! fprintf(fd, "%s", IObuff); ! } ! fclose(sfd); ! } ! fprintf(fd, "\n"); ! } ! } ! } ! ! /* ! * Dump the profiling info. ! */ ! void ! profile_dump(void) ! { ! FILE *fd; ! ! if (profile_fname != NULL) ! { ! fd = mch_fopen((char *)profile_fname, "w"); ! if (fd == NULL) ! semsg(_(e_notopen), profile_fname); ! else ! { ! script_dump_profile(fd); ! func_dump_profile(fd); ! fclose(fd); ! } ! } ! } ! ! /* ! * Called when starting to read a script line. ! * "sourcing_lnum" must be correct! ! * When skipping lines it may not actually be executed, but we won't find out ! * until later and we need to store the time now. ! */ ! void ! script_line_start(void) ! { ! scriptitem_T *si; ! sn_prl_T *pp; ! ! if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) ! return; ! si = &SCRIPT_ITEM(current_sctx.sc_sid); ! if (si->sn_prof_on && sourcing_lnum >= 1) ! { ! // Grow the array before starting the timer, so that the time spent ! // here isn't counted. ! (void)ga_grow(&si->sn_prl_ga, ! (int)(sourcing_lnum - si->sn_prl_ga.ga_len)); ! si->sn_prl_idx = sourcing_lnum - 1; ! while (si->sn_prl_ga.ga_len <= si->sn_prl_idx ! && si->sn_prl_ga.ga_len < si->sn_prl_ga.ga_maxlen) ! { ! // Zero counters for a line that was not used before. ! pp = &PRL_ITEM(si, si->sn_prl_ga.ga_len); ! pp->snp_count = 0; ! profile_zero(&pp->sn_prl_total); ! profile_zero(&pp->sn_prl_self); ! ++si->sn_prl_ga.ga_len; ! } ! si->sn_prl_execed = FALSE; ! profile_start(&si->sn_prl_start); ! profile_zero(&si->sn_prl_children); ! profile_get_wait(&si->sn_prl_wait); ! } ! } ! ! /* ! * Called when actually executing a function line. ! */ ! void ! script_line_exec(void) ! { ! scriptitem_T *si; ! ! if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) ! return; ! si = &SCRIPT_ITEM(current_sctx.sc_sid); ! if (si->sn_prof_on && si->sn_prl_idx >= 0) ! si->sn_prl_execed = TRUE; ! } ! ! /* ! * Called when done with a script line. ! */ ! void ! script_line_end(void) ! { ! scriptitem_T *si; ! sn_prl_T *pp; ! ! if (current_sctx.sc_sid <= 0 || current_sctx.sc_sid > script_items.ga_len) ! return; ! si = &SCRIPT_ITEM(current_sctx.sc_sid); ! if (si->sn_prof_on && si->sn_prl_idx >= 0 ! && si->sn_prl_idx < si->sn_prl_ga.ga_len) ! { ! if (si->sn_prl_execed) ! { ! pp = &PRL_ITEM(si, si->sn_prl_idx); ! ++pp->snp_count; ! profile_end(&si->sn_prl_start); ! profile_sub_wait(&si->sn_prl_wait, &si->sn_prl_start); ! profile_add(&pp->sn_prl_total, &si->sn_prl_start); ! profile_self(&pp->sn_prl_self, &si->sn_prl_start, ! &si->sn_prl_children); ! } ! si->sn_prl_idx = -1; ! } ! } ! # endif // FEAT_PROFILE #endif *** ../vim-8.1.1688/src/proto/ex_cmds2.pro 2019-07-13 22:59:06.922076875 +0200 --- src/proto/ex_cmds2.pro 2019-07-14 15:32:30.332418702 +0200 *************** *** 9,18 **** void add_timer_info_all(typval_T *rettv); int set_ref_in_timer(int copyID); void timer_free_all(void); - void script_do_profile(scriptitem_T *si); - void script_prof_save(proftime_T *tm); - void script_prof_restore(proftime_T *tm); - void script_dump_profile(FILE *fd); int autowrite(buf_T *buf, int forceit); void autowrite_all(void); int check_changed(buf_T *buf, int flags); --- 9,14 ---- *************** *** 63,71 **** void free_scriptnames(void); linenr_T get_sourced_lnum(char_u *(*fgetline)(int, void *, int, int), void *cookie); char_u *getsourceline(int c, void *cookie, int indent, int do_concat); - void script_line_start(void); - void script_line_exec(void); - void script_line_end(void); void ex_scriptencoding(exarg_T *eap); void ex_scriptversion(exarg_T *eap); void ex_finish(exarg_T *eap); --- 59,64 ---- *** ../vim-8.1.1688/src/proto/profiler.pro 2019-07-13 22:59:06.922076875 +0200 --- src/proto/profiler.pro 2019-07-14 15:47:38.546358772 +0200 *************** *** 17,34 **** void ex_profile(exarg_T *eap); char_u *get_profile_name(expand_T *xp, int idx); void set_context_in_profile_cmd(expand_T *xp, char_u *arg); - void profile_dump(void); void prof_inchar_enter(void); void prof_inchar_exit(void); int prof_def_func(void); - void prof_sort_list(FILE *fd, ufunc_T **sorttab, int st_len, char *title, int prefer_self); - void prof_func_line(FILE *fd, int count, proftime_T *total, proftime_T *self, int prefer_self); - int prof_total_cmp(const void *s1, const void *s2); - int prof_self_cmp(const void *s1, const void *s2); void func_do_profile(ufunc_T *fp); void prof_child_enter(proftime_T *tm); void prof_child_exit(proftime_T *tm); void func_line_start(void *cookie); void func_line_exec(void *cookie); void func_line_end(void *cookie); /* vim: set ft=c : */ --- 17,36 ---- void ex_profile(exarg_T *eap); char_u *get_profile_name(expand_T *xp, int idx); void set_context_in_profile_cmd(expand_T *xp, char_u *arg); void prof_inchar_enter(void); void prof_inchar_exit(void); int prof_def_func(void); void func_do_profile(ufunc_T *fp); void prof_child_enter(proftime_T *tm); void prof_child_exit(proftime_T *tm); void func_line_start(void *cookie); void func_line_exec(void *cookie); void func_line_end(void *cookie); + void script_do_profile(scriptitem_T *si); + void script_prof_save(proftime_T *tm); + void script_prof_restore(proftime_T *tm); + void profile_dump(void); + void script_line_start(void); + void script_line_exec(void); + void script_line_end(void); /* vim: set ft=c : */ *** ../vim-8.1.1688/src/proto/userfunc.pro 2019-07-13 22:59:06.922076875 +0200 --- src/proto/userfunc.pro 2019-07-14 15:32:30.332418702 +0200 *************** *** 1,12 **** /* userfunc.c */ void func_init(void); int get_lambda_tv(char_u **arg, typval_T *rettv, int evaluate); char_u *deref_func_name(char_u *name, int *lenp, partial_T **partialp, int no_autoload); int get_func_tv(char_u *name, int len, typval_T *rettv, char_u **arg, linenr_T firstline, linenr_T lastline, int *doesrange, int evaluate, partial_T *partial, dict_T *selfdict); ufunc_T *find_func(char_u *name); void save_funccal(funccal_entry_T *entry); void restore_funccal(void); ! funccall_T * get_current_funccal(void); void free_all_functions(void); int func_call(char_u *name, typval_T *args, partial_T *partial, dict_T *selfdict, typval_T *rettv); int call_callback(callback_T *callback, int len, typval_T *rettv, int argcount, typval_T *argvars, int (*argv_func)(int, typval_T *, int), linenr_T firstline, linenr_T lastline, int *doesrange, int evaluate, dict_T *selfdict); --- 1,13 ---- /* userfunc.c */ void func_init(void); + hashtab_T *func_tbl_get(void); int get_lambda_tv(char_u **arg, typval_T *rettv, int evaluate); char_u *deref_func_name(char_u *name, int *lenp, partial_T **partialp, int no_autoload); int get_func_tv(char_u *name, int len, typval_T *rettv, char_u **arg, linenr_T firstline, linenr_T lastline, int *doesrange, int evaluate, partial_T *partial, dict_T *selfdict); ufunc_T *find_func(char_u *name); void save_funccal(funccal_entry_T *entry); void restore_funccal(void); ! funccall_T *get_current_funccal(void); void free_all_functions(void); int func_call(char_u *name, typval_T *args, partial_T *partial, dict_T *selfdict, typval_T *rettv); int call_callback(callback_T *callback, int len, typval_T *rettv, int argcount, typval_T *argvars, int (*argv_func)(int, typval_T *, int), linenr_T firstline, linenr_T lastline, int *doesrange, int evaluate, dict_T *selfdict); *************** *** 17,23 **** int translated_function_exists(char_u *name); int function_exists(char_u *name, int no_deref); char_u *get_expanded_name(char_u *name, int check); - void func_dump_profile(FILE *fd); char_u *get_user_func_name(expand_T *xp, int idx); void ex_delfunction(exarg_T *eap); void func_unref(char_u *name); --- 18,23 ---- *************** *** 30,38 **** void discard_pending_return(void *rettv); char_u *get_return_cmd(void *rettv); char_u *get_func_line(int c, void *cookie, int indent, int do_concat); - void func_line_start(void *cookie); - void func_line_exec(void *cookie); - void func_line_end(void *cookie); int func_has_ended(void *cookie); int func_has_abort(void *cookie); dict_T *make_partial(dict_T *selfdict_in, typval_T *rettv); --- 30,35 ---- *** ../vim-8.1.1688/src/structs.h 2019-07-13 22:59:06.926076855 +0200 --- src/structs.h 2019-07-14 15:32:30.332418702 +0200 *************** *** 1518,1523 **** --- 1518,1528 ---- funccal_entry_T *next; }; + /* From user function to hashitem and back. */ + #define UF2HIKEY(fp) ((fp)->uf_name) + #define HIKEY2UF(p) ((ufunc_T *)((p) - offsetof(ufunc_T, uf_name))) + #define HI2UF(hi) HIKEY2UF((hi)->hi_key) + /* Growarray to store info about already sourced scripts. * For Unix also store the dev/ino, so that we don't have to stat() each * script when going through the list. */ *** ../vim-8.1.1688/src/userfunc.c 2019-07-13 22:59:06.926076855 +0200 --- src/userfunc.c 2019-07-14 15:32:30.332418702 +0200 *************** *** 23,33 **** #define FC_REMOVED 0x20 // function redefined while uf_refcount > 0 #define FC_SANDBOX 0x40 // function defined in the sandbox - /* From user function to hashitem and back. */ - #define UF2HIKEY(fp) ((fp)->uf_name) - #define HIKEY2UF(p) ((ufunc_T *)((p) - offsetof(ufunc_T, uf_name))) - #define HI2UF(hi) HIKEY2UF((hi)->hi_key) - #define FUNCARG(fp, j) ((char_u **)(fp->uf_args.ga_data))[j] /* --- 23,28 ---- *************** *** 59,64 **** --- 54,68 ---- } /* + * Return the function hash table + */ + hashtab_T * + func_tbl_get(void) + { + return &func_hashtab; + } + + /* * Get function arguments. */ static int *************** *** 2759,2846 **** } #endif - #if defined(FEAT_PROFILE) || defined(PROTO) - - /* - * Dump the profiling results for all functions in file "fd". - */ - void - func_dump_profile(FILE *fd) - { - hashitem_T *hi; - int todo; - ufunc_T *fp; - int i; - ufunc_T **sorttab; - int st_len = 0; - char_u *p; - - todo = (int)func_hashtab.ht_used; - if (todo == 0) - return; /* nothing to dump */ - - sorttab = ALLOC_MULT(ufunc_T *, todo); - - for (hi = func_hashtab.ht_array; todo > 0; ++hi) - { - if (!HASHITEM_EMPTY(hi)) - { - --todo; - fp = HI2UF(hi); - if (fp->uf_prof_initialized) - { - if (sorttab != NULL) - sorttab[st_len++] = fp; - - if (fp->uf_name[0] == K_SPECIAL) - fprintf(fd, "FUNCTION %s()\n", fp->uf_name + 3); - else - fprintf(fd, "FUNCTION %s()\n", fp->uf_name); - p = home_replace_save(NULL, - get_scriptname(fp->uf_script_ctx.sc_sid)); - if (p != NULL) - { - fprintf(fd, " Defined: %s line %ld\n", - p, (long)fp->uf_script_ctx.sc_lnum); - vim_free(p); - } - if (fp->uf_tm_count == 1) - fprintf(fd, "Called 1 time\n"); - else - fprintf(fd, "Called %d times\n", fp->uf_tm_count); - fprintf(fd, "Total time: %s\n", profile_msg(&fp->uf_tm_total)); - fprintf(fd, " Self time: %s\n", profile_msg(&fp->uf_tm_self)); - fprintf(fd, "\n"); - fprintf(fd, "count total (s) self (s)\n"); - - for (i = 0; i < fp->uf_lines.ga_len; ++i) - { - if (FUNCLINE(fp, i) == NULL) - continue; - prof_func_line(fd, fp->uf_tml_count[i], - &fp->uf_tml_total[i], &fp->uf_tml_self[i], TRUE); - fprintf(fd, "%s\n", FUNCLINE(fp, i)); - } - fprintf(fd, "\n"); - } - } - } - - if (sorttab != NULL && st_len > 0) - { - qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), - prof_total_cmp); - prof_sort_list(fd, sorttab, st_len, "TOTAL", FALSE); - qsort((void *)sorttab, (size_t)st_len, sizeof(ufunc_T *), - prof_self_cmp); - prof_sort_list(fd, sorttab, st_len, "SELF", TRUE); - } - - vim_free(sorttab); - } - - #endif /* FEAT_PROFILE */ - #if defined(FEAT_CMDL_COMPL) || defined(PROTO) /* --- 2763,2768 ---- *** ../vim-8.1.1688/src/version.c 2019-07-14 15:09:52.302899006 +0200 --- src/version.c 2019-07-14 15:33:41.363937119 +0200 *************** *** 779,780 **** --- 779,782 ---- { /* Add new patch number below this line */ + /**/ + 1689, /**/ -- Why isn't there mouse-flavored cat food? /// Bram Moolenaar -- Bram@Moolenaar.net -- http://www.Moolenaar.net \\\ /// sponsor Vim, vote for features -- http://www.Vim.org/sponsor/ \\\ \\\ an exciting new programming language -- http://www.Zimbu.org /// \\\ help me help AIDS victims -- http://ICCF-Holland.org ///