Mercurial > vim
view src/profiler.c @ 33591:288da62613ba v9.0.2040
patch 9.0.2040: trim(): hard to use default mask
Commit: https://github.com/vim/vim/commit/6e6386716f9494ae86027c6d34f657fd03dfec42
Author: Illia Bobyr <illia.bobyr@gmail.com>
Date: Tue Oct 17 11:09:45 2023 +0200
patch 9.0.2040: trim(): hard to use default mask
Problem: trim(): hard to use default mask
Solution: Use default 'mask' when it is v:none
The default 'mask' value is pretty complex, as it includes many
characters. Yet, if one needs to specify the trimming direction, the
third argument, 'trim()' currently requires the 'mask' value to be
provided explicitly.
'v:none' is already used to mean "use the default argument value" in
user defined functions. See |none-function_argument| in help.
closes: #13363
Signed-off-by: Christian Brabandt <cb@256bit.org>
Co-authored-by: Illia Bobyr <illia.bobyr@gmail.com>
author | Christian Brabandt <cb@256bit.org> |
---|---|
date | Tue, 17 Oct 2023 11:15:09 +0200 |
parents | bede81965821 |
children | d7cfd8fb1d75 |
line wrap: on
line source
/* vi:set ts=8 sts=4 sw=4 noet: * * VIM - Vi IMproved by Bram Moolenaar * * Do ":help uganda" in Vim to read copying and usage conditions. * Do ":help credits" in Vim to see a list of people who contributed. * See README.txt for an overview of the Vim source code. */ /* * profiler.c: vim script profiler */ #include "vim.h" #if defined(FEAT_EVAL) || defined(PROTO) # if defined(FEAT_PROFILE) || defined(FEAT_RELTIME) || defined(PROTO) /* * Store the current time in "tm". */ void profile_start(proftime_T *tm) { # ifdef MSWIN QueryPerformanceCounter(tm); # else PROF_GET_TIME(tm); # endif } /* * Compute the elapsed time from "tm" till now and store in "tm". */ void profile_end(proftime_T *tm) { proftime_T now; # ifdef MSWIN QueryPerformanceCounter(&now); tm->QuadPart = now.QuadPart - tm->QuadPart; # else PROF_GET_TIME(&now); tm->tv_fsec = now.tv_fsec - tm->tv_fsec; tm->tv_sec = now.tv_sec - tm->tv_sec; if (tm->tv_fsec < 0) { tm->tv_fsec += TV_FSEC_SEC; --tm->tv_sec; } # endif } /* * Subtract the time "tm2" from "tm". */ void profile_sub(proftime_T *tm, proftime_T *tm2) { # ifdef MSWIN tm->QuadPart -= tm2->QuadPart; # else tm->tv_fsec -= tm2->tv_fsec; tm->tv_sec -= tm2->tv_sec; if (tm->tv_fsec < 0) { tm->tv_fsec += TV_FSEC_SEC; --tm->tv_sec; } # endif } /* * Return a string that represents the time in "tm". * Uses a static buffer! */ char * profile_msg(proftime_T *tm) { static char buf[50]; # ifdef MSWIN LARGE_INTEGER fr; QueryPerformanceFrequency(&fr); sprintf(buf, "%10.6lf", (double)tm->QuadPart / (double)fr.QuadPart); # else sprintf(buf, PROF_TIME_FORMAT, (long)tm->tv_sec, (long)tm->tv_fsec); # endif return buf; } /* * Return a float that represents the time in "tm". */ float_T profile_float(proftime_T *tm) { # ifdef MSWIN LARGE_INTEGER fr; QueryPerformanceFrequency(&fr); return (float_T)tm->QuadPart / (float_T)fr.QuadPart; # else return (float_T)tm->tv_sec + (float_T)tm->tv_fsec / (float_T)TV_FSEC_SEC; # endif } /* * Put the time "msec" past now in "tm". */ void profile_setlimit(long msec, proftime_T *tm) { if (msec <= 0) // no limit profile_zero(tm); else { # ifdef MSWIN LARGE_INTEGER fr; QueryPerformanceCounter(tm); QueryPerformanceFrequency(&fr); tm->QuadPart += (LONGLONG)((double)msec / 1000.0 * (double)fr.QuadPart); # else varnumber_T fsec; // this should be 64 bit if possible PROF_GET_TIME(tm); fsec = (varnumber_T)tm->tv_fsec + (varnumber_T)msec * (varnumber_T)(TV_FSEC_SEC / 1000); tm->tv_fsec = fsec % (long)TV_FSEC_SEC; tm->tv_sec += fsec / (long)TV_FSEC_SEC; # endif } } /* * Return TRUE if the current time is past "tm". */ int profile_passed_limit(proftime_T *tm) { 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; PROF_GET_TIME(&now); return (now.tv_sec > tm->tv_sec || (now.tv_sec == tm->tv_sec && now.tv_fsec > tm->tv_fsec)); # endif } /* * Set the time in "tm" to zero. */ void profile_zero(proftime_T *tm) { # ifdef MSWIN tm->QuadPart = 0; # else tm->tv_fsec = 0; tm->tv_sec = 0; # endif } # endif // FEAT_PROFILE || FEAT_RELTIME #if defined(FEAT_SYN_HL) && defined(FEAT_RELTIME) && defined(FEAT_PROFILE) # if defined(HAVE_MATH_H) # include <math.h> # endif /* * Divide the time "tm" by "count" and store in "tm2". */ void profile_divide(proftime_T *tm, int count, proftime_T *tm2) { if (count == 0) profile_zero(tm2); else { # ifdef MSWIN tm2->QuadPart = tm->QuadPart / count; # else double fsec = (tm->tv_sec * (float_T)TV_FSEC_SEC + tm->tv_fsec) / count; tm2->tv_sec = floor(fsec / (float_T)TV_FSEC_SEC); tm2->tv_fsec = vim_round(fsec - (tm2->tv_sec * (float_T)TV_FSEC_SEC)); # endif } } #endif # if defined(FEAT_PROFILE) || defined(PROTO) /* * Functions for profiling. */ static proftime_T prof_wait_time; /* * Add the time "tm2" to "tm". */ void profile_add(proftime_T *tm, proftime_T *tm2) { # ifdef MSWIN tm->QuadPart += tm2->QuadPart; # else tm->tv_fsec += tm2->tv_fsec; tm->tv_sec += tm2->tv_sec; if (tm->tv_fsec >= TV_FSEC_SEC) { tm->tv_fsec -= TV_FSEC_SEC; ++tm->tv_sec; } # endif } /* * Add the "self" time from the total time and the children's time. */ 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; #else if (total->tv_sec < children->tv_sec || (total->tv_sec == children->tv_sec && total->tv_fsec <= children->tv_fsec)) return; #endif profile_add(self, total); profile_sub(self, children); } /* * Get the current waittime. */ static void profile_get_wait(proftime_T *tm) { *tm = prof_wait_time; } /* * Subtract the passed waittime since "tm" from "tma". */ void profile_sub_wait(proftime_T *tm, proftime_T *tma) { proftime_T tm3 = prof_wait_time; profile_sub(&tm3, tm); profile_sub(tma, &tm3); } /* * Return TRUE if "tm1" and "tm2" are equal. */ static int profile_equal(proftime_T *tm1, proftime_T *tm2) { # ifdef MSWIN return (tm1->QuadPart == tm2->QuadPart); # else return (tm1->tv_fsec == tm2->tv_fsec && tm1->tv_sec == tm2->tv_sec); # endif } /* * Return <0, 0 or >0 if "tm1" < "tm2", "tm1" == "tm2" or "tm1" > "tm2" */ int profile_cmp(const proftime_T *tm1, const proftime_T *tm2) { # ifdef MSWIN return (int)(tm2->QuadPart - tm1->QuadPart); # else if (tm1->tv_sec == tm2->tv_sec) return tm2->tv_fsec - tm1->tv_fsec; return tm2->tv_sec - tm1->tv_sec; # endif } static char_u *profile_fname = NULL; static proftime_T pause_time; /* * Reset all profiling information. */ static void profile_reset(void) { int id; int todo; hashtab_T *functbl; hashitem_T *hi; // Reset sourced files. for (id = 1; id <= script_items.ga_len; id++) { scriptitem_T *si = SCRIPT_ITEM(id); if (si->sn_prof_on) { si->sn_prof_on = FALSE; si->sn_pr_force = FALSE; profile_zero(&si->sn_pr_child); si->sn_pr_nest = 0; si->sn_pr_count = 0; profile_zero(&si->sn_pr_total); profile_zero(&si->sn_pr_self); profile_zero(&si->sn_pr_start); profile_zero(&si->sn_pr_children); ga_clear(&si->sn_prl_ga); profile_zero(&si->sn_prl_start); profile_zero(&si->sn_prl_children); profile_zero(&si->sn_prl_wait); si->sn_prl_idx = -1; si->sn_prl_execed = 0; } } // Reset functions. functbl = func_tbl_get(); todo = (int)functbl->ht_used; FOR_ALL_HASHTAB_ITEMS(functbl, hi, todo) { ufunc_T *fp; int i; if (HASHITEM_EMPTY(hi)) continue; todo--; fp = HI2UF(hi); if (fp->uf_prof_initialized) { fp->uf_profiling = 0; fp->uf_prof_initialized = FALSE; fp->uf_tm_count = 0; profile_zero(&fp->uf_tm_total); profile_zero(&fp->uf_tm_self); profile_zero(&fp->uf_tm_children); for (i = 0; i < fp->uf_lines.ga_len; i++) { fp->uf_tml_count[i] = 0; profile_zero(&fp->uf_tml_total[i]); profile_zero(&fp->uf_tml_self[i]); } profile_zero(&fp->uf_tml_start); profile_zero(&fp->uf_tml_children); profile_zero(&fp->uf_tml_wait); fp->uf_tml_idx = -1; fp->uf_tml_execed = 0; } } VIM_CLEAR(profile_fname); } /* * ":profile cmd args" */ void ex_profile(exarg_T *eap) { char_u *e; int len; e = skiptowhite(eap->arg); len = (int)(e - eap->arg); e = skipwhite(e); if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL) { VIM_CLEAR(profile_fname); profile_fname = expand_env_save_opt(e, TRUE); do_profiling = PROF_YES; profile_zero(&prof_wait_time); set_vim_var_nr(VV_PROFILING, 1L); } else if (do_profiling == PROF_NONE) emsg(_(e_first_use_profile_start_fname)); else if (STRCMP(eap->arg, "stop") == 0) { profile_dump(); do_profiling = PROF_NONE; set_vim_var_nr(VV_PROFILING, 0L); profile_reset(); } else if (STRCMP(eap->arg, "pause") == 0) { if (do_profiling == PROF_YES) profile_start(&pause_time); do_profiling = PROF_PAUSED; } else if (STRCMP(eap->arg, "continue") == 0) { if (do_profiling == PROF_PAUSED) { profile_end(&pause_time); profile_add(&prof_wait_time, &pause_time); } do_profiling = PROF_YES; } else if (STRCMP(eap->arg, "dump") == 0) profile_dump(); 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[] = { "start", "stop", "pause", "continue", "func", "file", "dump", NULL }; /* * Function given to ExpandGeneric() to obtain the profile command * specific expansion. */ char_u * get_profile_name(expand_T *xp UNUSED, int idx) { switch (pexpand_what) { case PEXP_SUBCMD: return (char_u *)pexpand_cmds[idx]; default: return NULL; } } /* * Handle command line completion for :profile command. */ void set_context_in_profile_cmd(expand_T *xp, char_u *arg) { char_u *end_subcmd; // Default: expand subcommands. xp->xp_context = EXPAND_PROFILE; pexpand_what = PEXP_SUBCMD; xp->xp_pattern = arg; end_subcmd = skiptowhite(arg); if (*end_subcmd == NUL) return; if ((end_subcmd - arg == 5 && STRNCMP(arg, "start", 5) == 0) || (end_subcmd - arg == 4 && STRNCMP(arg, "file", 4) == 0)) { xp->xp_context = EXPAND_FILES; xp->xp_pattern = skipwhite(end_subcmd); return; } else if (end_subcmd - arg == 4 && STRNCMP(arg, "func", 4) == 0) { xp->xp_context = EXPAND_USER_FUNC; xp->xp_pattern = skipwhite(end_subcmd); return; } xp->xp_context = EXPAND_NOTHING; } static proftime_T inchar_time; /* * Called when starting to wait for the user to type a character. */ void prof_inchar_enter(void) { profile_start(&inchar_time); } /* * Called when finished waiting for the user to type a character. */ void prof_inchar_exit(void) { profile_end(&inchar_time); profile_add(&prof_wait_time, &inchar_time); } /* * Return TRUE when a function defined in the current script should be * profiled. */ int prof_def_func(void) { if (current_sctx.sc_sid > 0) return SCRIPT_ITEM(current_sctx.sc_sid)->sn_pr_force; 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) { fprintf(fd, "%5d ", count); if (prefer_self && profile_equal(total, self)) fprintf(fd, PROF_TIME_BLANK); else fprintf(fd, "%s ", profile_msg(total)); if (!prefer_self && profile_equal(total, self)) fprintf(fd, PROF_TIME_BLANK); else fprintf(fd, "%s ", profile_msg(self)); } else fprintf(fd, " %s%s", PROF_TIME_BLANK, PROF_TIME_BLANK); } 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, "%s function\n", PROF_TOTALS_HEADER); 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, " <SNR>%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; p1 = *(ufunc_T **)s1; p2 = *(ufunc_T **)s2; return profile_cmp(&p1->uf_tm_total, &p2->uf_tm_total); } /* * Compare function for self time sorting. */ static int prof_self_cmp(const void *s1, const void *s2) { ufunc_T *p1, *p2; p1 = *(ufunc_T **)s1; p2 = *(ufunc_T **)s2; return profile_cmp(&p1->uf_tm_self, &p2->uf_tm_self); } /* * Start profiling function "fp". */ void func_do_profile(ufunc_T *fp) { int len = fp->uf_lines.ga_len; 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); if (fp->uf_tml_count == NULL) fp->uf_tml_count = ALLOC_CLEAR_MULT(int, len); if (fp->uf_tml_total == NULL) fp->uf_tml_total = ALLOC_CLEAR_MULT(proftime_T, len); if (fp->uf_tml_self == NULL) fp->uf_tml_self = ALLOC_CLEAR_MULT(proftime_T, len); 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; } fp->uf_profiling = TRUE; } /* * Save time when starting to invoke another script or function. */ static void script_prof_save( proftime_T *tm) // place to store wait time { scriptitem_T *si; if (SCRIPT_ID_VALID(current_sctx.sc_sid)) { 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); } /* * When calling a function: may initialize for profiling. */ void profile_may_start_func(profinfo_T *info, ufunc_T *fp, ufunc_T *caller) { if (!fp->uf_profiling && has_profiling(FALSE, fp->uf_name, NULL, &fp->uf_hash)) { info->pi_started_profiling = TRUE; func_do_profile(fp); } if (fp->uf_profiling || (caller != NULL && caller->uf_profiling)) { ++fp->uf_tm_count; profile_start(&info->pi_call_start); profile_zero(&fp->uf_tm_children); } script_prof_save(&info->pi_wait_start); } /* * After calling a function: may handle profiling. profile_may_start_func() * must have been called previously. */ void profile_may_end_func(profinfo_T *info, ufunc_T *fp, ufunc_T *caller) { profile_end(&info->pi_call_start); profile_sub_wait(&info->pi_wait_start, &info->pi_call_start); profile_add(&fp->uf_tm_total, &info->pi_call_start); profile_self(&fp->uf_tm_self, &info->pi_call_start, &fp->uf_tm_children); if (caller != NULL && caller->uf_profiling) { profile_add(&caller->uf_tm_children, &info->pi_call_start); profile_add(&caller->uf_tml_children, &info->pi_call_start); } if (info->pi_started_profiling) // make a ":profdel func" stop profiling the function fp->uf_profiling = FALSE; } /* * Prepare profiling for entering a child or something else that is not * counted for the script/function itself. * Should always be called in pair with prof_child_exit(). */ void prof_child_enter( proftime_T *tm) // place to store waittime { funccall_T *fc = get_current_funccal(); if (fc != NULL && fc->fc_func->uf_profiling) profile_start(&fc->fc_prof_child); script_prof_save(tm); } /* * Take care of time spent in a child. * Should always be called after prof_child_enter(). */ void prof_child_exit( proftime_T *tm) // where waittime was stored { funccall_T *fc = get_current_funccal(); if (fc != NULL && fc->fc_func->uf_profiling) { profile_end(&fc->fc_prof_child); profile_sub_wait(tm, &fc->fc_prof_child); // don't count waiting time profile_add(&fc->fc_func->uf_tm_children, &fc->fc_prof_child); profile_add(&fc->fc_func->uf_tml_children, &fc->fc_prof_child); } script_prof_restore(tm); } /* * Called when starting to read a function 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 func_line_start(void *cookie, long lnum) { funccall_T *fcp = (funccall_T *)cookie; ufunc_T *fp = fcp->fc_func; if (fp->uf_profiling && lnum >= 1 && lnum <= fp->uf_lines.ga_len) { fp->uf_tml_idx = 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; profile_start(&fp->uf_tml_start); profile_zero(&fp->uf_tml_children); profile_get_wait(&fp->uf_tml_wait); } } /* * Called when actually executing a function line. */ void func_line_exec(void *cookie) { funccall_T *fcp = (funccall_T *)cookie; ufunc_T *fp = fcp->fc_func; if (fp->uf_profiling && fp->uf_tml_idx >= 0) fp->uf_tml_execed = TRUE; } /* * Called when done with a function line. */ void func_line_end(void *cookie) { funccall_T *fcp = (funccall_T *)cookie; ufunc_T *fp = fcp->fc_func; if (fp->uf_profiling && fp->uf_tml_idx >= 0) { if (fp->uf_tml_execed) { ++fp->uf_tml_count[fp->uf_tml_idx]; profile_end(&fp->uf_tml_start); profile_sub_wait(&fp->uf_tml_wait, &fp->uf_tml_start); profile_add(&fp->uf_tml_total[fp->uf_tml_idx], &fp->uf_tml_start); profile_self(&fp->uf_tml_self[fp->uf_tml_idx], &fp->uf_tml_start, &fp->uf_tml_children); } 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_ALL_HASHTAB_ITEMS(functbl, hi, todo) { 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 <SNR>%s()\n", fp->uf_name + 3); else fprintf(fd, "FUNCTION %s()\n", fp->uf_name); if (fp->uf_script_ctx.sc_sid > 0) { p = home_replace_save(NULL, get_scriptname(fp->uf_script_ctx.sc_sid)); if (p != NULL) { fprintf(fd, " Defined: %s:%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, "%s\n", PROF_TOTALS_HEADER); 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; } /* * Count time spent in children after invoking another script or function. */ void script_prof_restore(proftime_T *tm) { scriptitem_T *si; if (!SCRIPT_ID_VALID(current_sctx.sc_sid)) return; 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, "%s\n", PROF_TOTALS_HEADER); 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) return; fd = mch_fopen((char *)profile_fname, "w"); if (fd == NULL) semsg(_(e_cant_open_file_str), 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 (!SCRIPT_ID_VALID(current_sctx.sc_sid)) 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 (!SCRIPT_ID_VALID(current_sctx.sc_sid)) 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 (!SCRIPT_ID_VALID(current_sctx.sc_sid)) 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