diff options
| -rw-r--r-- | src/nvim/context.c | 3 | ||||
| -rw-r--r-- | src/nvim/eval.c | 76 | ||||
| -rw-r--r-- | src/nvim/eval.h | 9 | ||||
| -rw-r--r-- | src/nvim/eval/userfunc.c | 8 | ||||
| -rw-r--r-- | src/nvim/eval/userfunc.h | 5 | ||||
| -rw-r--r-- | src/nvim/ex_cmds2.c | 188 | ||||
| -rw-r--r-- | src/nvim/profile.c | 365 | ||||
| -rw-r--r-- | src/nvim/profile.h | 1 | ||||
| -rw-r--r-- | src/nvim/runtime.h | 7 |
9 files changed, 335 insertions, 327 deletions
diff --git a/src/nvim/context.c b/src/nvim/context.c index db26667009..e3ae9355bf 100644 --- a/src/nvim/context.c +++ b/src/nvim/context.c @@ -9,6 +9,7 @@ #include "nvim/api/vimscript.h" #include "nvim/context.h" #include "nvim/eval/encode.h" +#include "nvim/eval/userfunc.h" #include "nvim/ex_docmd.h" #include "nvim/option.h" #include "nvim/shada.h" @@ -249,7 +250,7 @@ static inline void ctx_save_funcs(Context *ctx, bool scriptonly) ctx->funcs = (Array)ARRAY_DICT_INIT; Error err = ERROR_INIT; - HASHTAB_ITER(&func_hashtab, hi, { + HASHTAB_ITER(func_tbl_get(), hi, { const char_u *const name = hi->hi_key; bool islambda = (STRNCMP(name, "<lambda>", 8) == 0); bool isscript = (name[0] == K_SPECIAL); diff --git a/src/nvim/eval.c b/src/nvim/eval.c index 613a1cf99f..42a3c7df80 100644 --- a/src/nvim/eval.c +++ b/src/nvim/eval.c @@ -7906,82 +7906,6 @@ const char *find_option_end(const char **const arg, int *const opt_flags) return p; } -/// Dump the profiling results for all functions in file "fd". -void func_dump_profile(FILE *fd) -{ - hashitem_T *hi; - int todo; - ufunc_T *fp; - ufunc_T **sorttab; - int st_len = 0; - - todo = (int)func_hashtab.ht_used; - if (todo == 0) { - return; // nothing to dump - } - - sorttab = xmalloc(sizeof(ufunc_T *) * (size_t)todo); - - for (hi = func_hashtab.ht_array; todo > 0; ++hi) { - if (!HASHITEM_EMPTY(hi)) { - --todo; - fp = HI2UF(hi); - if (fp->uf_prof_initialized) { - 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) { - bool should_free; - const LastSet last_set = (LastSet){ - .script_ctx = fp->uf_script_ctx, - .channel_id = 0, - }; - char *p = (char *)get_scriptname(last_set, &should_free); - fprintf(fd, " Defined: %s:%" PRIdLINENR "\n", - p, fp->uf_script_ctx.sc_lnum); - if (should_free) { - xfree(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 (int 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 (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); - } - - xfree(sorttab); -} - /// Return the autoload script name for a function or variable name /// Caller must make sure that "name" contains AUTOLOAD_CHAR. /// diff --git a/src/nvim/eval.h b/src/nvim/eval.h index 7dbd18737a..b0cb5fd8c1 100644 --- a/src/nvim/eval.h +++ b/src/nvim/eval.h @@ -11,15 +11,6 @@ #define COPYID_INC 2 #define COPYID_MASK (~0x1) -// All user-defined functions are found in this hashtable. -extern hashtab_T func_hashtab; - -// From user function to hashitem and back. -EXTERN ufunc_T dumuf; -#define UF2HIKEY(fp) ((fp)->uf_name) -#define HIKEY2UF(p) ((ufunc_T *)(p - offsetof(ufunc_T, uf_name))) -#define HI2UF(hi) HIKEY2UF((hi)->hi_key) - /* * Structure returned by get_lval() and used by set_var_lval(). * For a plain name: diff --git a/src/nvim/eval/userfunc.c b/src/nvim/eval/userfunc.c index f31b86fc14..72a8c45326 100644 --- a/src/nvim/eval/userfunc.c +++ b/src/nvim/eval/userfunc.c @@ -45,7 +45,7 @@ # include "eval/userfunc.c.generated.h" #endif -hashtab_T func_hashtab; +static hashtab_T func_hashtab; // Used by get_func_tv() static garray_T funcargs = GA_EMPTY_INIT_VALUE; @@ -67,6 +67,12 @@ void func_init(void) hash_init(&func_hashtab); } +/// Return the function hash table +hashtab_T *func_tbl_get(void) +{ + return &func_hashtab; +} + /// Get function arguments. static int get_function_args(char_u **argp, char_u endchar, garray_T *newargs, int *varargs, garray_T *default_args, bool skip) diff --git a/src/nvim/eval/userfunc.h b/src/nvim/eval/userfunc.h index ed86aaad4a..7edf69d13b 100644 --- a/src/nvim/eval/userfunc.h +++ b/src/nvim/eval/userfunc.h @@ -4,6 +4,11 @@ #include "nvim/eval/typval.h" #include "nvim/ex_cmds_defs.h" +// 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) + ///< Structure used by trans_function_name() typedef struct { dict_T *fd_dict; ///< Dictionary used. diff --git a/src/nvim/ex_cmds2.c b/src/nvim/ex_cmds2.c index c8bb8aa38f..382780adec 100644 --- a/src/nvim/ex_cmds2.c +++ b/src/nvim/ex_cmds2.c @@ -74,8 +74,6 @@ struct source_cookie { vimconv_T conv; ///< type of conversion }; -#define PRL_ITEM(si, idx) (((sn_prl_T *)(si)->sn_prl_ga.ga_data)[(idx)]) - #ifdef INCLUDE_GENERATED_DECLARATIONS # include "ex_cmds2.c.generated.h" #endif @@ -125,119 +123,6 @@ void ex_perldo(exarg_T *eap) script_host_do_range("perl", eap); } -/// Start profiling a script. -static void profile_init(scriptitem_T *si) -{ - si->sn_pr_count = 0; - si->sn_pr_total = profile_zero(); - si->sn_pr_self = profile_zero(); - - ga_init(&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. -/// -/// @param tm place to store wait time -void script_prof_save(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) { - si->sn_pr_child = profile_start(); - } - } - *tm = profile_get_wait(); -} - -/// 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) { - si->sn_pr_child = profile_end(si->sn_pr_child); - // don't count wait time - si->sn_pr_child = profile_sub_wait(*tm, si->sn_pr_child); - si->sn_pr_children = profile_add(si->sn_pr_children, si->sn_pr_child); - si->sn_prl_children = 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) -{ - scriptitem_T *si; - FILE *sfd; - sn_prl_T *pp; - - for (int 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 = os_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 (int 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; - - // 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--; - } - - 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"); - } - } -} - /// If 'autowrite' option set, try to write the file. /// Careful: autocommands may make "buf" invalid! /// @@ -2257,79 +2142,6 @@ retry: return NULL; } -/// 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, 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; - pp->sn_prl_total = profile_zero(); - pp->sn_prl_self = profile_zero(); - si->sn_prl_ga.ga_len++; - } - si->sn_prl_execed = false; - si->sn_prl_start = profile_start(); - si->sn_prl_children = profile_zero(); - si->sn_prl_wait = profile_get_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 function 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++; - si->sn_prl_start = profile_end(si->sn_prl_start); - si->sn_prl_start = profile_sub_wait(si->sn_prl_wait, si->sn_prl_start); - pp->sn_prl_total = profile_add(pp->sn_prl_total, si->sn_prl_start); - pp->sn_prl_self = profile_self(pp->sn_prl_self, si->sn_prl_start, - si->sn_prl_children); - } - si->sn_prl_idx = -1; - } -} - /// ":scriptencoding": Set encoding conversion for a sourced script. /// Without the multi-byte feature it's simply ignored. void ex_scriptencoding(exarg_T *eap) diff --git a/src/nvim/profile.c b/src/nvim/profile.c index c426fec9b1..a77680c9f2 100644 --- a/src/nvim/profile.c +++ b/src/nvim/profile.c @@ -11,6 +11,7 @@ #include "nvim/eval.h" #include "nvim/eval/userfunc.h" #include "nvim/ex_cmds2.h" +#include "nvim/fileio.h" #include "nvim/func_attr.h" #include "nvim/globals.h" // for the global `time_fd` (startuptime) #include "nvim/os/os.h" @@ -23,6 +24,15 @@ # include "profile.c.generated.h" #endif +/// 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; + +#define PRL_ITEM(si, idx) (((sn_prl_T *)(si)->sn_prl_ga.ga_data)[(idx)]) + static proftime_T prof_wait_time; /// Gets the current time. @@ -230,12 +240,13 @@ void profile_reset(void) } // Reset functions. - size_t n = func_hashtab.ht_used; - hashitem_T *hi = func_hashtab.ht_array; + hashtab_T *const functbl = func_tbl_get(); + size_t todo = functbl->ht_used; + hashitem_T *hi = functbl->ht_array; - for (; n > (size_t)0; hi++) { + for (; todo > (size_t)0; hi++) { if (!HASHITEM_EMPTY(hi)) { - n--; + todo--; ufunc_T *uf = HI2UF(hi); if (uf->uf_prof_initialized) { uf->uf_profiling = 0; @@ -359,23 +370,6 @@ void set_context_in_profile_cmd(expand_T *xp, const char *arg) 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. @@ -402,31 +396,11 @@ bool prof_def_func(void) 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) +static void prof_func_line(FILE *fd, int count, proftime_T *total, proftime_T *self, + bool prefer_self) { if (count > 0) { fprintf(fd, "%5d ", count); @@ -445,8 +419,29 @@ void prof_func_line(FILE *fd, int count, proftime_T *total, proftime_T *self, in } } +/// @param prefer_self when equal print only self time +static void prof_sort_list(FILE *fd, ufunc_T **sorttab, int st_len, char *title, bool 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"); +} + /// Compare function for total time sorting. -int prof_total_cmp(const void *s1, const void *s2) +static int prof_total_cmp(const void *s1, const void *s2) { ufunc_T *p1 = *(ufunc_T **)s1; ufunc_T *p2 = *(ufunc_T **)s2; @@ -454,7 +449,7 @@ int prof_total_cmp(const void *s1, const void *s2) } /// Compare function for self time sorting. -int prof_self_cmp(const void *s1, const void *s2) +static int prof_self_cmp(const void *s1, const void *s2) { ufunc_T *p1 = *(ufunc_T **)s1; ufunc_T *p2 = *(ufunc_T **)s2; @@ -584,6 +579,286 @@ void func_line_end(void *cookie) } } +/// Dump the profiling results for all functions in file "fd". +static void func_dump_profile(FILE *fd) +{ + hashtab_T *const functbl = func_tbl_get(); + hashitem_T *hi; + int todo; + ufunc_T *fp; + ufunc_T **sorttab; + int st_len = 0; + + todo = (int)functbl->ht_used; + if (todo == 0) { + return; // nothing to dump + } + + sorttab = xmalloc(sizeof(ufunc_T *) * (size_t)todo); + + for (hi = functbl->ht_array; todo > 0; hi++) { + if (!HASHITEM_EMPTY(hi)) { + todo--; + fp = HI2UF(hi); + if (fp->uf_prof_initialized) { + 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) { + bool should_free; + const LastSet last_set = (LastSet){ + .script_ctx = fp->uf_script_ctx, + .channel_id = 0, + }; + char *p = (char *)get_scriptname(last_set, &should_free); + fprintf(fd, " Defined: %s:%" PRIdLINENR "\n", + p, fp->uf_script_ctx.sc_lnum); + if (should_free) { + xfree(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 (int 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 (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); + } + + xfree(sorttab); +} + +/// Start profiling a script. +void profile_init(scriptitem_T *si) +{ + si->sn_pr_count = 0; + si->sn_pr_total = profile_zero(); + si->sn_pr_self = profile_zero(); + + ga_init(&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. +/// +/// @param tm place to store wait time +void script_prof_save(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) { + si->sn_pr_child = profile_start(); + } + } + *tm = profile_get_wait(); +} + +/// 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) { + si->sn_pr_child = profile_end(si->sn_pr_child); + // don't count wait time + si->sn_pr_child = profile_sub_wait(*tm, si->sn_pr_child); + si->sn_pr_children = profile_add(si->sn_pr_children, si->sn_pr_child); + si->sn_prl_children = 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) +{ + scriptitem_T *si; + FILE *sfd; + sn_prl_T *pp; + + for (int 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 = os_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 (int 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; + + // 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--; + } + + 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 = os_fopen(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, 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; + pp->sn_prl_total = profile_zero(); + pp->sn_prl_self = profile_zero(); + si->sn_prl_ga.ga_len++; + } + si->sn_prl_execed = false; + si->sn_prl_start = profile_start(); + si->sn_prl_children = profile_zero(); + si->sn_prl_wait = profile_get_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 function 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++; + si->sn_prl_start = profile_end(si->sn_prl_start); + si->sn_prl_start = profile_sub_wait(si->sn_prl_wait, si->sn_prl_start); + pp->sn_prl_total = profile_add(pp->sn_prl_total, si->sn_prl_start); + pp->sn_prl_self = profile_self(pp->sn_prl_self, si->sn_prl_start, + si->sn_prl_children); + } + si->sn_prl_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 63f4e72027..547d11185f 100644 --- a/src/nvim/profile.h +++ b/src/nvim/profile.h @@ -5,6 +5,7 @@ #include <time.h> #include "nvim/ex_cmds_defs.h" +#include "nvim/runtime.h" #define TIME_MSG(s) do { \ if (time_fd != NULL) time_msg(s, NULL); \ diff --git a/src/nvim/runtime.h b/src/nvim/runtime.h index dae3850e3d..d715dcdf30 100644 --- a/src/nvim/runtime.h +++ b/src/nvim/runtime.h @@ -30,13 +30,6 @@ typedef struct scriptitem_S { 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 { |