mirror of
https://github.com/vim/vim
synced 2025-03-15 22:37:52 +01:00
Problem: qsort() comparison functions should be transitive Solution: Do not subtract values, but rather use explicit comparisons Improve qsort() comparison functions There has been a recent report on qsort() causing out-of-bounds read & write in glibc for non transitive comparison functions https://www.qualys.com/2024/01/30/qsort.txt Even so the bug is in glibc's implementation of the qsort() algorithm, it's bad style to just use substraction for the comparison functions, which may cause overflow issues and as hinted at in OpenBSD's manual page for qsort(): "It is almost always an error to use subtraction to compute the return value of the comparison function." So check the qsort() comparison functions and change them to be safe. closes: #13980 Signed-off-by: Christian Brabandt <cb@256bit.org>
1107 lines
25 KiB
C
1107 lines
25 KiB
C
/* 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 tm2->QuadPart == tm1->QuadPart ? 0 :
|
|
tm2->QuadPart > tm1->QuadPart ? 1 : -1;
|
|
# else
|
|
if (tm1->tv_sec == tm2->tv_sec)
|
|
return tm2->tv_fsec == tm1->tv_fsec ? 0 :
|
|
tm2->tv_fsec > tm1->tv_fsec ? 1 : -1;
|
|
return tm2->tv_sec > tm1->tv_sec ? 1 : -1;
|
|
# 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
|