diff options
| -rwxr-xr-x | scripts/vim-patch.sh | 4 | ||||
| -rw-r--r-- | src/nvim/autocmd.c | 1 | ||||
| -rw-r--r-- | src/nvim/buffer_defs.h | 2 | ||||
| -rw-r--r-- | src/nvim/eval.c | 184 | ||||
| -rw-r--r-- | src/nvim/eval/funcs.c | 1 | ||||
| -rw-r--r-- | src/nvim/eval/typval.h | 1 | ||||
| -rw-r--r-- | src/nvim/eval/userfunc.c | 1 | ||||
| -rw-r--r-- | src/nvim/ex_cmds.c | 1 | ||||
| -rw-r--r-- | src/nvim/ex_cmds2.c | 213 | ||||
| -rw-r--r-- | src/nvim/ex_cmds2.h | 21 | ||||
| -rw-r--r-- | src/nvim/ex_docmd.c | 1 | ||||
| -rw-r--r-- | src/nvim/ex_getln.c | 1 | ||||
| -rw-r--r-- | src/nvim/match.c | 1 | ||||
| -rw-r--r-- | src/nvim/normal.c | 1 | ||||
| -rw-r--r-- | src/nvim/os/input.c | 1 | ||||
| -rw-r--r-- | src/nvim/os/shell.c | 1 | ||||
| -rw-r--r-- | src/nvim/profile.c | 391 | ||||
| -rw-r--r-- | src/nvim/profile.h | 2 | ||||
| -rw-r--r-- | src/nvim/regexp.c | 1 | ||||
| -rw-r--r-- | src/nvim/regexp_defs.h | 1 | ||||
| -rw-r--r-- | src/nvim/runtime.c | 3 | ||||
| -rw-r--r-- | src/nvim/runtime.h | 32 | ||||
| -rw-r--r-- | src/nvim/screen.c | 1 | ||||
| -rw-r--r-- | src/nvim/search.c | 1 | ||||
| -rw-r--r-- | src/nvim/spell.c | 1 | ||||
| -rw-r--r-- | src/nvim/syntax.c | 1 | ||||
| -rw-r--r-- | src/nvim/types.h | 2 |
27 files changed, 449 insertions, 422 deletions
diff --git a/scripts/vim-patch.sh b/scripts/vim-patch.sh index 3825d9f0ea..505a88c55c 100755 --- a/scripts/vim-patch.sh +++ b/scripts/vim-patch.sh @@ -241,6 +241,10 @@ preprocess_patch() { LC_ALL=C sed -e 's/\( [ab]\/src\/nvim\)\/map\(\.[ch]\)/\1\/mapping\2/g' \ "$file" > "$file".tmp && mv "$file".tmp "$file" + # Rename profiler.c to profile.c + LC_ALL=C sed -e 's/\( [ab]\/src\/nvim\)\/profiler\(\.[ch]\)/\1\/profile\2/g' \ + "$file" > "$file".tmp && mv "$file".tmp "$file" + # Rename session.c to ex_session.c LC_ALL=C sed -e 's/\( [ab]\/src\/nvim\)\/session\(\.[ch]\)/\1\/ex_session\2/g' \ "$file" > "$file".tmp && mv "$file".tmp "$file" diff --git a/src/nvim/autocmd.c b/src/nvim/autocmd.c index bbb044fba3..1186eea62c 100644 --- a/src/nvim/autocmd.c +++ b/src/nvim/autocmd.c @@ -24,6 +24,7 @@ #include "nvim/map.h" #include "nvim/option.h" #include "nvim/os/input.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/search.h" #include "nvim/state.h" diff --git a/src/nvim/buffer_defs.h b/src/nvim/buffer_defs.h index 3ef5ea7e02..38f701ea7d 100644 --- a/src/nvim/buffer_defs.h +++ b/src/nvim/buffer_defs.h @@ -36,8 +36,6 @@ typedef struct { #include "nvim/hashtab.h" // for dict_T #include "nvim/eval/typval.h" -// for proftime_T -#include "nvim/profile.h" // for String #include "nvim/api/private/defs.h" // for Map(K, V) diff --git a/src/nvim/eval.c b/src/nvim/eval.c index 5abaf88e60..613a1cf99f 100644 --- a/src/nvim/eval.c +++ b/src/nvim/eval.c @@ -44,6 +44,7 @@ #include "nvim/os/input.h" #include "nvim/os/shell.h" #include "nvim/path.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/regexp.h" #include "nvim/screen.h" @@ -1192,42 +1193,6 @@ void *call_func_retlist(const char *func, int argc, typval_T *argv) return rettv.vval.v_list; } -/// 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(). -/// -/// @param tm place to store waittime -void prof_child_enter(proftime_T *tm) -{ - funccall_T *fc = get_current_funccal(); - - if (fc != NULL && fc->func->uf_profiling) { - fc->prof_child = profile_start(); - } - - script_prof_save(tm); -} - -/// Take care of time spent in a child. -/// Should always be called after prof_child_enter(). -/// -/// @param tm where waittime was stored -void prof_child_exit(proftime_T *tm) -{ - funccall_T *fc = get_current_funccal(); - - if (fc != NULL && fc->func->uf_profiling) { - fc->prof_child = profile_end(fc->prof_child); - // don't count waiting time - fc->prof_child = profile_sub_wait(*tm, fc->prof_child); - fc->func->uf_tm_children = - profile_add(fc->func->uf_tm_children, fc->prof_child); - fc->func->uf_tml_children = - profile_add(fc->func->uf_tml_children, fc->prof_child); - } - script_prof_restore(tm); -} - /// Evaluate 'foldexpr'. Returns the foldlevel, and any character preceding /// it in "*cp". Doesn't give error messages. int eval_foldexpr(char *arg, int *cp) @@ -7941,38 +7906,6 @@ const char *find_option_end(const char **const arg, int *const opt_flags) return p; } -/// 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; - fp->uf_tm_self = profile_zero(); - fp->uf_tm_total = profile_zero(); - - if (fp->uf_tml_count == NULL) { - fp->uf_tml_count = xcalloc((size_t)len, sizeof(int)); - } - - if (fp->uf_tml_total == NULL) { - fp->uf_tml_total = xcalloc((size_t)len, sizeof(proftime_T)); - } - - if (fp->uf_tml_self == NULL) { - fp->uf_tml_self = xcalloc((size_t)len, sizeof(proftime_T)); - } - - fp->uf_tml_idx = -1; - fp->uf_prof_initialized = true; - } - - fp->uf_profiling = TRUE; -} - /// Dump the profiling results for all functions in file "fd". void func_dump_profile(FILE *fd) { @@ -8049,66 +7982,6 @@ void func_dump_profile(FILE *fd) xfree(sorttab); } -/// @param prefer_self when equal print only self time -static void prof_sort_list(FILE *fd, ufunc_T **sorttab, int st_len, char *title, int prefer_self) -{ - 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, " <SNR>%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. -/// -/// @param prefer_self when equal print only self time -static void prof_func_line(FILE *fd, int count, proftime_T *total, proftime_T *self, - int prefer_self) -{ - if (count > 0) { - fprintf(fd, "%5d ", count); - if (prefer_self && profile_equal(*total, *self)) { - fprintf(fd, " "); - } else { - fprintf(fd, "%s ", profile_msg(*total)); - } - if (!prefer_self && profile_equal(*total, *self)) { - fprintf(fd, " "); - } else { - fprintf(fd, "%s ", profile_msg(*self)); - } - } else { - fprintf(fd, " "); - } -} - -/// Compare function for total time sorting. -static int prof_total_cmp(const void *s1, const void *s2) -{ - ufunc_T *p1 = *(ufunc_T **)s1; - ufunc_T *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 = *(ufunc_T **)s1; - ufunc_T *p2 = *(ufunc_T **)s2; - return profile_cmp(p1->uf_tm_self, p2->uf_tm_self); -} - /// Return the autoload script name for a function or variable name /// Caller must make sure that "name" contains AUTOLOAD_CHAR. /// @@ -8183,61 +8056,6 @@ bool script_autoload(const char *const name, const size_t name_len, const bool r return ret; } -/// 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) -{ - funccall_T *fcp = (funccall_T *)cookie; - ufunc_T *fp = fcp->func; - - if (fp->uf_profiling && sourcing_lnum >= 1 - && 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; - fp->uf_tml_start = profile_start(); - fp->uf_tml_children = profile_zero(); - fp->uf_tml_wait = profile_get_wait(); - } -} - -/// Called when actually executing a function line. -void func_line_exec(void *cookie) -{ - funccall_T *fcp = (funccall_T *)cookie; - ufunc_T *fp = fcp->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->func; - - if (fp->uf_profiling && fp->uf_tml_idx >= 0) { - if (fp->uf_tml_execed) { - ++fp->uf_tml_count[fp->uf_tml_idx]; - fp->uf_tml_start = profile_end(fp->uf_tml_start); - fp->uf_tml_start = profile_sub_wait(fp->uf_tml_wait, fp->uf_tml_start); - fp->uf_tml_total[fp->uf_tml_idx] = - profile_add(fp->uf_tml_total[fp->uf_tml_idx], fp->uf_tml_start); - fp->uf_tml_self[fp->uf_tml_idx] = - profile_self(fp->uf_tml_self[fp->uf_tml_idx], fp->uf_tml_start, - fp->uf_tml_children); - } - fp->uf_tml_idx = -1; - } -} - static var_flavour_T var_flavour(char *varname) FUNC_ATTR_PURE { diff --git a/src/nvim/eval/funcs.c b/src/nvim/eval/funcs.c index 4a44c08457..5c21825897 100644 --- a/src/nvim/eval/funcs.c +++ b/src/nvim/eval/funcs.c @@ -58,6 +58,7 @@ #include "nvim/path.h" #include "nvim/plines.h" #include "nvim/popupmnu.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/regexp.h" #include "nvim/screen.h" diff --git a/src/nvim/eval/typval.h b/src/nvim/eval/typval.h index 2a4dd7b146..e411419a07 100644 --- a/src/nvim/eval/typval.h +++ b/src/nvim/eval/typval.h @@ -16,7 +16,6 @@ #include "nvim/mbyte_defs.h" #include "nvim/message.h" #include "nvim/pos.h" // for linenr_T -#include "nvim/profile.h" // for proftime_T #include "nvim/types.h" #ifdef LOG_LIST_ACTIONS # include "nvim/memory.h" diff --git a/src/nvim/eval/userfunc.c b/src/nvim/eval/userfunc.c index 38a00099bc..f31b86fc14 100644 --- a/src/nvim/eval/userfunc.c +++ b/src/nvim/eval/userfunc.c @@ -21,6 +21,7 @@ #include "nvim/insexpand.h" #include "nvim/lua/executor.h" #include "nvim/os/input.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/search.h" #include "nvim/ui.h" diff --git a/src/nvim/ex_cmds.c b/src/nvim/ex_cmds.c index 9ad65500e9..8f22fe6178 100644 --- a/src/nvim/ex_cmds.c +++ b/src/nvim/ex_cmds.c @@ -60,6 +60,7 @@ #include "nvim/os_unix.h" #include "nvim/path.h" #include "nvim/plines.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/regexp.h" #include "nvim/screen.h" diff --git a/src/nvim/ex_cmds2.c b/src/nvim/ex_cmds2.c index 730a2f1b69..c8bb8aa38f 100644 --- a/src/nvim/ex_cmds2.c +++ b/src/nvim/ex_cmds2.c @@ -54,17 +54,6 @@ #include "nvim/version.h" #include "nvim/window.h" -/// Growarray to store info about already sourced scripts. -static garray_T script_items = { 0, 0, sizeof(scriptitem_T), 4, NULL }; -#define SCRIPT_ITEM(id) (((scriptitem_T *)script_items.ga_data)[(id) - 1]) - -// Struct used in sn_prl_ga for every line of a script. -typedef struct sn_prl_S { - int snp_count; ///< nr of times line was executed - proftime_T sn_prl_total; ///< time spent in a line + children - proftime_T sn_prl_self; ///< time spent in a line itself -} sn_prl_T; - /// Structure used to store info for each sourced file. /// It is shared between do_source() and getsourceline(). /// This is required, because it needs to be handed to do_cmdline() and @@ -91,52 +80,6 @@ struct source_cookie { # include "ex_cmds2.c.generated.h" #endif -static char *profile_fname = NULL; - -/// ":profile cmd args" -void ex_profile(exarg_T *eap) -{ - static proftime_T pause_time; - - char *e; - int len; - - e = (char *)skiptowhite((char_u *)eap->arg); - len = (int)(e - eap->arg); - e = skipwhite(e); - - if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL) { - xfree(profile_fname); - profile_fname = (char *)expand_env_save_opt((char_u *)e, true); - do_profiling = PROF_YES; - profile_set_wait(profile_zero()); - set_vim_var_nr(VV_PROFILING, 1L); - } else if (do_profiling == PROF_NONE) { - emsg(_("E750: 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) { - pause_time = profile_start(); - } - do_profiling = PROF_PAUSED; - } else if (STRCMP(eap->arg, "continue") == 0) { - if (do_profiling == PROF_PAUSED) { - pause_time = profile_end(pause_time); - profile_set_wait(profile_add(profile_get_wait(), 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); - } -} - void ex_ruby(exarg_T *eap) { script_host_execute("ruby", eap); @@ -182,134 +125,6 @@ void ex_perldo(exarg_T *eap) script_host_do_range("perl", 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[] = { - "continue", - "dump", - "file", - "func", - "pause", - "start", - "stop", - NULL -}; - -/// Function given to ExpandGeneric() to obtain the profile command -/// specific expansion. -char *get_profile_name(expand_T *xp, int idx) - FUNC_ATTR_PURE -{ - switch (pexpand_what) { - case PEXP_SUBCMD: - return pexpand_cmds[idx]; - // case PEXP_FUNC: TODO - default: - return NULL; - } -} - -/// Handle command line completion for :profile command. -void set_context_in_profile_cmd(expand_T *xp, const char *arg) -{ - // Default: expand subcommands. - xp->xp_context = EXPAND_PROFILE; - pexpand_what = PEXP_SUBCMD; - xp->xp_pattern = (char *)arg; - - char_u *const end_subcmd = skiptowhite((const char_u *)arg); - if (*end_subcmd == NUL) { - return; - } - - if ((const char *)end_subcmd - arg == 5 && strncmp(arg, "start", 5) == 0) { - xp->xp_context = EXPAND_FILES; - xp->xp_pattern = skipwhite((char *)end_subcmd); - return; - } - - // TODO(tarruda): 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 = os_fopen(profile_fname, "w"); - if (fd == NULL) { - semsg(_(e_notopen), profile_fname); - } else { - script_dump_profile(fd); - func_dump_profile(fd); - fclose(fd); - } - } -} - -/// Reset all profiling information. -static void profile_reset(void) -{ - // Reset sourced files. - for (int 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; - si->sn_pr_child = profile_zero(); - si->sn_pr_nest = 0; - si->sn_pr_count = 0; - si->sn_pr_total = profile_zero(); - si->sn_pr_self = profile_zero(); - si->sn_pr_start = profile_zero(); - si->sn_pr_children = profile_zero(); - ga_clear(&si->sn_prl_ga); - si->sn_prl_start = profile_zero(); - si->sn_prl_children = profile_zero(); - si->sn_prl_wait = profile_zero(); - si->sn_prl_idx = -1; - si->sn_prl_execed = 0; - } - } - - // Reset functions. - size_t n = func_hashtab.ht_used; - hashitem_T *hi = func_hashtab.ht_array; - - for (; n > (size_t)0; hi++) { - if (!HASHITEM_EMPTY(hi)) { - n--; - ufunc_T *uf = HI2UF(hi); - if (uf->uf_prof_initialized) { - uf->uf_profiling = 0; - uf->uf_tm_count = 0; - uf->uf_tm_total = profile_zero(); - uf->uf_tm_self = profile_zero(); - uf->uf_tm_children = profile_zero(); - - for (int i = 0; i < uf->uf_lines.ga_len; i++) { - uf->uf_tml_count[i] = 0; - uf->uf_tml_total[i] = uf->uf_tml_self[i] = 0; - } - - uf->uf_tml_start = profile_zero(); - uf->uf_tml_children = profile_zero(); - uf->uf_tml_wait = profile_zero(); - uf->uf_tml_idx = -1; - uf->uf_tml_execed = 0; - } - } - } - - XFREE_CLEAR(profile_fname); -} - /// Start profiling a script. static void profile_init(scriptitem_T *si) { @@ -356,23 +171,8 @@ void script_prof_restore(proftime_T *tm) } } -static proftime_T inchar_time; - -/// Called when starting to wait for the user to type a character. -void prof_inchar_enter(void) -{ - inchar_time = profile_start(); -} - -/// Called when finished waiting for the user to type a character. -void prof_inchar_exit(void) -{ - inchar_time = profile_end(inchar_time); - profile_set_wait(profile_add(profile_get_wait(), inchar_time)); -} - /// Dump the profiling results for all scripts in file "fd". -static void script_dump_profile(FILE *fd) +void script_dump_profile(FILE *fd) { scriptitem_T *si; FILE *sfd; @@ -438,17 +238,6 @@ static void script_dump_profile(FILE *fd) } } -/// @return true when a function defined in the current script should be -/// profiled. -bool prof_def_func(void) - FUNC_ATTR_PURE -{ - if (current_sctx.sc_sid > 0) { - return SCRIPT_ITEM(current_sctx.sc_sid).sn_pr_force; - } - return false; -} - /// If 'autowrite' option set, try to write the file. /// Careful: autocommands may make "buf" invalid! /// diff --git a/src/nvim/ex_cmds2.h b/src/nvim/ex_cmds2.h index c463bfa5ab..95433fde90 100644 --- a/src/nvim/ex_cmds2.h +++ b/src/nvim/ex_cmds2.h @@ -15,27 +15,6 @@ #define CCGD_ALLBUF 8 // may write all buffers #define CCGD_EXCMD 16 // may suggest using ! -typedef struct scriptitem_S { - char_u *sn_name; - bool sn_prof_on; ///< true when script is/was profiled - bool sn_pr_force; ///< forceit: profile functions in this script - proftime_T sn_pr_child; ///< time set when going into first child - int sn_pr_nest; ///< nesting for sn_pr_child - // profiling the script as a whole - int sn_pr_count; ///< nr of times sourced - proftime_T sn_pr_total; ///< time spent in script + children - proftime_T sn_pr_self; ///< time spent in script itself - proftime_T sn_pr_start; ///< time at script start - proftime_T sn_pr_children; ///< time in children after script start - // profiling the script per line - garray_T sn_prl_ga; ///< things stored for every line - proftime_T sn_prl_start; ///< start time for current line - proftime_T sn_prl_children; ///< time spent in children for this line - proftime_T sn_prl_wait; ///< wait start time for current line - linenr_T sn_prl_idx; ///< index of line being timed; -1 if none - int sn_prl_execed; ///< line being timed was executed -} scriptitem_T; - #ifdef INCLUDE_GENERATED_DECLARATIONS # include "ex_cmds2.h.generated.h" #endif diff --git a/src/nvim/ex_docmd.c b/src/nvim/ex_docmd.c index e8dc0b8e86..e482c9e9cf 100644 --- a/src/nvim/ex_docmd.c +++ b/src/nvim/ex_docmd.c @@ -64,6 +64,7 @@ #include "nvim/os_unix.h" #include "nvim/path.h" #include "nvim/popupmnu.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/regexp.h" #include "nvim/screen.h" diff --git a/src/nvim/ex_getln.c b/src/nvim/ex_getln.c index 22bbefe827..bba8aa5343 100644 --- a/src/nvim/ex_getln.c +++ b/src/nvim/ex_getln.c @@ -65,6 +65,7 @@ #include "nvim/os_unix.h" #include "nvim/path.h" #include "nvim/popupmnu.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/screen.h" #include "nvim/search.h" diff --git a/src/nvim/match.c b/src/nvim/match.c index ba587c4141..291f7ab696 100644 --- a/src/nvim/match.c +++ b/src/nvim/match.c @@ -12,6 +12,7 @@ #include "nvim/highlight_group.h" #include "nvim/match.h" #include "nvim/memline.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/runtime.h" #include "nvim/screen.h" diff --git a/src/nvim/normal.c b/src/nvim/normal.c index 1657b391d0..5ff35d4922 100644 --- a/src/nvim/normal.c +++ b/src/nvim/normal.c @@ -51,6 +51,7 @@ #include "nvim/os/input.h" #include "nvim/os/time.h" #include "nvim/plines.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/screen.h" #include "nvim/search.h" diff --git a/src/nvim/os/input.c b/src/nvim/os/input.c index c47a891c18..da3f68edc7 100644 --- a/src/nvim/os/input.c +++ b/src/nvim/os/input.c @@ -19,6 +19,7 @@ #include "nvim/memory.h" #include "nvim/msgpack_rpc/channel.h" #include "nvim/os/input.h" +#include "nvim/profile.h" #include "nvim/screen.h" #include "nvim/state.h" #include "nvim/ui.h" diff --git a/src/nvim/os/shell.c b/src/nvim/os/shell.c index 8f2018c1f4..dd44cb1ce7 100644 --- a/src/nvim/os/shell.c +++ b/src/nvim/os/shell.c @@ -25,6 +25,7 @@ #include "nvim/os/shell.h" #include "nvim/os/signal.h" #include "nvim/path.h" +#include "nvim/profile.h" #include "nvim/screen.h" #include "nvim/strings.h" #include "nvim/tag.h" diff --git a/src/nvim/profile.c b/src/nvim/profile.c index fe7bd2e912..c426fec9b1 100644 --- a/src/nvim/profile.c +++ b/src/nvim/profile.c @@ -6,11 +6,18 @@ #include <stdio.h> #include "nvim/assert.h" +#include "nvim/charset.h" +#include "nvim/debugger.h" +#include "nvim/eval.h" +#include "nvim/eval/userfunc.h" +#include "nvim/ex_cmds2.h" #include "nvim/func_attr.h" #include "nvim/globals.h" // for the global `time_fd` (startuptime) -#include "nvim/os/os_defs.h" +#include "nvim/os/os.h" #include "nvim/os/time.h" #include "nvim/profile.h" +#include "nvim/runtime.h" +#include "nvim/vim.h" #ifdef INCLUDE_GENERATED_DECLARATIONS # include "profile.c.generated.h" @@ -195,6 +202,388 @@ int profile_cmp(proftime_T tm1, proftime_T tm2) FUNC_ATTR_CONST return profile_signed(tm2 - tm1) < 0 ? -1 : 1; } +static char *profile_fname = NULL; + +/// Reset all profiling information. +void profile_reset(void) +{ + // Reset sourced files. + for (int 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; + si->sn_pr_child = profile_zero(); + si->sn_pr_nest = 0; + si->sn_pr_count = 0; + si->sn_pr_total = profile_zero(); + si->sn_pr_self = profile_zero(); + si->sn_pr_start = profile_zero(); + si->sn_pr_children = profile_zero(); + ga_clear(&si->sn_prl_ga); + si->sn_prl_start = profile_zero(); + si->sn_prl_children = profile_zero(); + si->sn_prl_wait = profile_zero(); + si->sn_prl_idx = -1; + si->sn_prl_execed = 0; + } + } + + // Reset functions. + size_t n = func_hashtab.ht_used; + hashitem_T *hi = func_hashtab.ht_array; + + for (; n > (size_t)0; hi++) { + if (!HASHITEM_EMPTY(hi)) { + n--; + ufunc_T *uf = HI2UF(hi); + if (uf->uf_prof_initialized) { + uf->uf_profiling = 0; + uf->uf_tm_count = 0; + uf->uf_tm_total = profile_zero(); + uf->uf_tm_self = profile_zero(); + uf->uf_tm_children = profile_zero(); + + for (int i = 0; i < uf->uf_lines.ga_len; i++) { + uf->uf_tml_count[i] = 0; + uf->uf_tml_total[i] = uf->uf_tml_self[i] = 0; + } + + uf->uf_tml_start = profile_zero(); + uf->uf_tml_children = profile_zero(); + uf->uf_tml_wait = profile_zero(); + uf->uf_tml_idx = -1; + uf->uf_tml_execed = 0; + } + } + } + + XFREE_CLEAR(profile_fname); +} + +/// ":profile cmd args" +void ex_profile(exarg_T *eap) +{ + static proftime_T pause_time; + + char *e; + int len; + + e = (char *)skiptowhite((char_u *)eap->arg); + len = (int)(e - eap->arg); + e = skipwhite(e); + + if (len == 5 && STRNCMP(eap->arg, "start", 5) == 0 && *e != NUL) { + xfree(profile_fname); + profile_fname = (char *)expand_env_save_opt((char_u *)e, true); + do_profiling = PROF_YES; + profile_set_wait(profile_zero()); + set_vim_var_nr(VV_PROFILING, 1L); + } else if (do_profiling == PROF_NONE) { + emsg(_("E750: 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) { + pause_time = profile_start(); + } + do_profiling = PROF_PAUSED; + } else if (STRCMP(eap->arg, "continue") == 0) { + if (do_profiling == PROF_PAUSED) { + pause_time = profile_end(pause_time); + profile_set_wait(profile_add(profile_get_wait(), 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[] = { + "continue", + "dump", + "file", + "func", + "pause", + "start", + "stop", + NULL +}; + +/// Function given to ExpandGeneric() to obtain the profile command +/// specific expansion. +char *get_profile_name(expand_T *xp, int idx) + FUNC_ATTR_PURE +{ + switch (pexpand_what) { + case PEXP_SUBCMD: + return pexpand_cmds[idx]; + // case PEXP_FUNC: TODO + default: + return NULL; + } +} + +/// Handle command line completion for :profile command. +void set_context_in_profile_cmd(expand_T *xp, const char *arg) +{ + // Default: expand subcommands. + xp->xp_context = EXPAND_PROFILE; + pexpand_what = PEXP_SUBCMD; + xp->xp_pattern = (char *)arg; + + char_u *const end_subcmd = skiptowhite((const char_u *)arg); + if (*end_subcmd == NUL) { + return; + } + + if ((const char *)end_subcmd - arg == 5 && strncmp(arg, "start", 5) == 0) { + xp->xp_context = EXPAND_FILES; + xp->xp_pattern = skipwhite((char *)end_subcmd); + return; + } + + // TODO(tarruda): 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 = os_fopen(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; + +/// Called when starting to wait for the user to type a character. +void prof_inchar_enter(void) +{ + inchar_time = profile_start(); +} + +/// Called when finished waiting for the user to type a character. +void prof_inchar_exit(void) +{ + inchar_time = profile_end(inchar_time); + profile_set_wait(profile_add(profile_get_wait(), inchar_time)); +} + +/// @return true when a function defined in the current script should be +/// profiled. +bool prof_def_func(void) + FUNC_ATTR_PURE +{ + if (current_sctx.sc_sid > 0) { + return SCRIPT_ITEM(current_sctx.sc_sid).sn_pr_force; + } + return false; +} + +/// @param prefer_self when equal print only self time +void prof_sort_list(FILE *fd, ufunc_T **sorttab, int st_len, char *title, int prefer_self) +{ + 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, " <SNR>%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. +/// +/// @param prefer_self when equal print only self time +void prof_func_line(FILE *fd, int count, proftime_T *total, proftime_T *self, int prefer_self) +{ + if (count > 0) { + fprintf(fd, "%5d ", count); + if (prefer_self && profile_equal(*total, *self)) { + fprintf(fd, " "); + } else { + fprintf(fd, "%s ", profile_msg(*total)); + } + if (!prefer_self && profile_equal(*total, *self)) { + fprintf(fd, " "); + } else { + fprintf(fd, "%s ", profile_msg(*self)); + } + } else { + fprintf(fd, " "); + } +} + +/// Compare function for total time sorting. +int prof_total_cmp(const void *s1, const void *s2) +{ + ufunc_T *p1 = *(ufunc_T **)s1; + ufunc_T *p2 = *(ufunc_T **)s2; + return profile_cmp(p1->uf_tm_total, p2->uf_tm_total); +} + +/// Compare function for self time sorting. +int prof_self_cmp(const void *s1, const void *s2) +{ + ufunc_T *p1 = *(ufunc_T **)s1; + ufunc_T *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; + fp->uf_tm_self = profile_zero(); + fp->uf_tm_total = profile_zero(); + + if (fp->uf_tml_count == NULL) { + fp->uf_tml_count = xcalloc((size_t)len, sizeof(int)); + } + + if (fp->uf_tml_total == NULL) { + fp->uf_tml_total = xcalloc((size_t)len, sizeof(proftime_T)); + } + + if (fp->uf_tml_self == NULL) { + fp->uf_tml_self = xcalloc((size_t)len, sizeof(proftime_T)); + } + + fp->uf_tml_idx = -1; + fp->uf_prof_initialized = true; + } + + fp->uf_profiling = true; +} + +/// 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(). +/// +/// @param tm place to store waittime +void prof_child_enter(proftime_T *tm) +{ + funccall_T *fc = get_current_funccal(); + + if (fc != NULL && fc->func->uf_profiling) { + fc->prof_child = profile_start(); + } + + script_prof_save(tm); +} + +/// Take care of time spent in a child. +/// Should always be called after prof_child_enter(). +/// +/// @param tm where waittime was stored +void prof_child_exit(proftime_T *tm) +{ + funccall_T *fc = get_current_funccal(); + + if (fc != NULL && fc->func->uf_profiling) { + fc->prof_child = profile_end(fc->prof_child); + // don't count waiting time + fc->prof_child = profile_sub_wait(*tm, fc->prof_child); + fc->func->uf_tm_children = + profile_add(fc->func->uf_tm_children, fc->prof_child); + fc->func->uf_tml_children = + profile_add(fc->func->uf_tml_children, 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) +{ + funccall_T *fcp = (funccall_T *)cookie; + ufunc_T *fp = fcp->func; + + if (fp->uf_profiling && sourcing_lnum >= 1 + && 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; + fp->uf_tml_start = profile_start(); + fp->uf_tml_children = profile_zero(); + fp->uf_tml_wait = profile_get_wait(); + } +} + +/// Called when actually executing a function line. +void func_line_exec(void *cookie) +{ + funccall_T *fcp = (funccall_T *)cookie; + ufunc_T *fp = fcp->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->func; + + if (fp->uf_profiling && fp->uf_tml_idx >= 0) { + if (fp->uf_tml_execed) { + fp->uf_tml_count[fp->uf_tml_idx]++; + fp->uf_tml_start = profile_end(fp->uf_tml_start); + fp->uf_tml_start = profile_sub_wait(fp->uf_tml_wait, fp->uf_tml_start); + fp->uf_tml_total[fp->uf_tml_idx] = + profile_add(fp->uf_tml_total[fp->uf_tml_idx], fp->uf_tml_start); + fp->uf_tml_self[fp->uf_tml_idx] = + profile_self(fp->uf_tml_self[fp->uf_tml_idx], fp->uf_tml_start, + fp->uf_tml_children); + } + fp->uf_tml_idx = -1; + } +} + /// globals for use in the startuptime related functionality (time_*). static proftime_T g_start_time; static proftime_T g_prev_time; diff --git a/src/nvim/profile.h b/src/nvim/profile.h index 17c35c5eb7..63f4e72027 100644 --- a/src/nvim/profile.h +++ b/src/nvim/profile.h @@ -4,7 +4,7 @@ #include <stdint.h> #include <time.h> -typedef uint64_t proftime_T; +#include "nvim/ex_cmds_defs.h" #define TIME_MSG(s) do { \ if (time_fd != NULL) time_msg(s, NULL); \ diff --git a/src/nvim/regexp.c b/src/nvim/regexp.c index fbbf904f8b..4f0911af6c 100644 --- a/src/nvim/regexp.c +++ b/src/nvim/regexp.c @@ -28,6 +28,7 @@ #include "nvim/message.h" #include "nvim/os/input.h" #include "nvim/plines.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/strings.h" #include "nvim/vim.h" diff --git a/src/nvim/regexp_defs.h b/src/nvim/regexp_defs.h index 09f244c2f6..b313dfe877 100644 --- a/src/nvim/regexp_defs.h +++ b/src/nvim/regexp_defs.h @@ -15,7 +15,6 @@ #include <stdbool.h> #include "nvim/pos.h" -#include "nvim/profile.h" #include "nvim/types.h" /* diff --git a/src/nvim/runtime.c b/src/nvim/runtime.c index 5d28d624fe..4038e9f78a 100644 --- a/src/nvim/runtime.c +++ b/src/nvim/runtime.c @@ -14,6 +14,7 @@ #include "nvim/lua/executor.h" #include "nvim/option.h" #include "nvim/os/os.h" +#include "nvim/profile.h" #include "nvim/runtime.h" #include "nvim/vim.h" @@ -21,6 +22,8 @@ # include "runtime.c.generated.h" #endif +garray_T script_items = { 0, 0, sizeof(scriptitem_T), 4, NULL }; + static bool runtime_search_path_valid = false; static int *runtime_search_path_ref = NULL; static RuntimeSearchPath runtime_search_path; diff --git a/src/nvim/runtime.h b/src/nvim/runtime.h index d83ec00185..dae3850e3d 100644 --- a/src/nvim/runtime.h +++ b/src/nvim/runtime.h @@ -5,6 +5,38 @@ #include "nvim/ex_docmd.h" +typedef struct scriptitem_S { + char_u *sn_name; + bool sn_prof_on; ///< true when script is/was profiled + bool sn_pr_force; ///< forceit: profile functions in this script + proftime_T sn_pr_child; ///< time set when going into first child + int sn_pr_nest; ///< nesting for sn_pr_child + // profiling the script as a whole + int sn_pr_count; ///< nr of times sourced + proftime_T sn_pr_total; ///< time spent in script + children + proftime_T sn_pr_self; ///< time spent in script itself + proftime_T sn_pr_start; ///< time at script start + proftime_T sn_pr_children; ///< time in children after script start + // profiling the script per line + garray_T sn_prl_ga; ///< things stored for every line + proftime_T sn_prl_start; ///< start time for current line + proftime_T sn_prl_children; ///< time spent in children for this line + proftime_T sn_prl_wait; ///< wait start time for current line + linenr_T sn_prl_idx; ///< index of line being timed; -1 if none + int sn_prl_execed; ///< line being timed was executed +} scriptitem_T; + +/// Growarray to store info about already sourced scripts. +extern garray_T script_items; +#define SCRIPT_ITEM(id) (((scriptitem_T *)script_items.ga_data)[(id) - 1]) + +/// Struct used in sn_prl_ga for every line of a script. +typedef struct sn_prl_S { + int snp_count; ///< nr of times line was executed + proftime_T sn_prl_total; ///< time spent in a line + children + proftime_T sn_prl_self; ///< time spent in a line itself +} sn_prl_T; + typedef void (*DoInRuntimepathCB)(char *, void *); typedef struct { diff --git a/src/nvim/screen.c b/src/nvim/screen.c index 50bab38f64..0805a11d9f 100644 --- a/src/nvim/screen.c +++ b/src/nvim/screen.c @@ -112,6 +112,7 @@ #include "nvim/path.h" #include "nvim/plines.h" #include "nvim/popupmnu.h" +#include "nvim/profile.h" #include "nvim/quickfix.h" #include "nvim/regexp.h" #include "nvim/screen.h" diff --git a/src/nvim/search.c b/src/nvim/search.c index 4f396505e3..0c557052ed 100644 --- a/src/nvim/search.c +++ b/src/nvim/search.c @@ -43,6 +43,7 @@ #include "nvim/os/input.h" #include "nvim/os/time.h" #include "nvim/path.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/screen.h" #include "nvim/search.h" diff --git a/src/nvim/spell.c b/src/nvim/spell.c index 64139df689..8ae8121e07 100644 --- a/src/nvim/spell.c +++ b/src/nvim/spell.c @@ -107,6 +107,7 @@ #include "nvim/os/os.h" #include "nvim/os_unix.h" #include "nvim/path.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/screen.h" #include "nvim/search.h" diff --git a/src/nvim/syntax.c b/src/nvim/syntax.c index dd3087dd31..10fed63329 100644 --- a/src/nvim/syntax.c +++ b/src/nvim/syntax.c @@ -41,6 +41,7 @@ #include "nvim/os/time.h" #include "nvim/os_unix.h" #include "nvim/path.h" +#include "nvim/profile.h" #include "nvim/regexp.h" #include "nvim/screen.h" #include "nvim/sign.h" diff --git a/src/nvim/types.h b/src/nvim/types.h index 00b9e6fc09..477102276c 100644 --- a/src/nvim/types.h +++ b/src/nvim/types.h @@ -28,6 +28,8 @@ typedef handle_T NS; typedef struct expand expand_T; +typedef uint64_t proftime_T; + typedef enum { kNone = -1, kFalse = 0, |