thac0/vim
1
0
Fork 0
forked from aniani/vim
Code

patch 8.2.2530: Vim9: not enough testing for profiling

Browse Source 
Problem:    Vim9: not enough testing for profiling.
Solution:   Add a test with nested functions and a lambda.  Fix profiling
            for calling a compiled function.
This commit is contained in:
Bram Moolenaar 2021-02-19 19:13:21 +01:00
parent d3f8a9ee65
commit 12d265315f
6 changed files with 114 additions and 38 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

34
src/profiler.c
View File

@ -558,24 +558,20 @@ func_do_profile(ufunc_T *fp)
* When calling a function: may initialize for profiling.
*/
void
profile_may_start_func(profinfo_T *info, ufunc_T *fp, funccall_T *fc)
profile_may_start_func(profinfo_T *info, ufunc_T *fp, ufunc_T *caller)
{
if (do_profiling == PROF_YES)
if (!fp->uf_profiling && has_profiling(FALSE, fp->uf_name, NULL))
{
if (!fp->uf_profiling && has_profiling(FALSE, fp->uf_name, NULL))
{
info->pi_started_profiling = TRUE;
func_do_profile(fp);
}
if (fp->uf_profiling
|| (fc->caller != NULL && fc->caller->func->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);
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);
}
/*
@ -583,16 +579,16 @@ profile_may_start_func(profinfo_T *info, ufunc_T *fp, funccall_T *fc)
* must have been called previously.
*/
void
profile_may_end_func(profinfo_T *info, ufunc_T *fp, funccall_T *fc)
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 (fc->caller != NULL && fc->caller->func->uf_profiling)
if (caller != NULL && caller->uf_profiling)
{
profile_add(&fc->caller->func->uf_tm_children, &info->pi_call_start);
profile_add(&fc->caller->func->uf_tml_children, &info->pi_call_start);
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

4
src/proto/profiler.pro
View File

@ -19,8 +19,8 @@ void prof_inchar_enter(void);
void prof_inchar_exit(void);
int prof_def_func(void);
void func_do_profile(ufunc_T *fp);
void profile_may_start_func(profinfo_T *info, ufunc_T *fp, funccall_T *fc);
void profile_may_end_func(profinfo_T *info, ufunc_T *fp, funccall_T *fc);
void profile_may_start_func(profinfo_T *info, ufunc_T *fp, ufunc_T *caller);
void profile_may_end_func(profinfo_T *info, ufunc_T *fp, ufunc_T *caller);
void prof_child_enter(proftime_T *tm);
void prof_child_exit(proftime_T *tm);
void func_line_start(void *cookie, long lnum);

33
src/testdir/test_profile.vim
View File

@ -605,5 +605,38 @@ func Test_vim9_profiling()
call delete('Xprofile_crash.log')
endfunc
func Test_vim9_nested_call()
let lines =<< trim END
vim9script
var total = 0
def One(Ref: func(number))
for i in range(3)
Ref(i)
endfor
enddef
def Two(nr: number)
total += nr
enddef
prof start Xprofile_nested.log
prof func One
prof func Two
One((nr) => Two(nr))
assert_equal(3, total)
END
call writefile(lines, 'Xprofile_nested.vim')
call system(GetVimCommandClean() . ' -es -c "so Xprofile_nested.vim" -c q')
call assert_equal(0, v:shell_error)
let prof_lines = readfile('Xprofile_nested.log')->join('#')
call assert_match('FUNCTION <SNR>\d\+_One().*'
\ .. '#Called 1 time.*'
\ .. '# 1 \s*[0-9.]\+ for i in range(3)'
\ .. '# 3 \s*[0-9.]\+ \s*[0-9.]\+ Ref(i)'
\ .. '# 3 \s*[0-9.]\+ endfor', prof_lines)
call assert_match('FUNCTION <SNR>\d\+_Two().*'
\ .. '#Called 3 times.*'
\ .. '# 3 \s*[0-9.]\+ total += nr', prof_lines)
endfunc
" vim: shiftwidth=2 sts=2 expandtab

24
src/userfunc.c
View File

@ -1649,16 +1649,20 @@ call_user_func(
if (fp->uf_def_status != UF_NOT_COMPILED)
{
#ifdef FEAT_PROFILE
ufunc_T *caller = fc->caller == NULL ? NULL : fc->caller->func;
#endif
// Execute the function, possibly compiling it first.
#ifdef FEAT_PROFILE
profile_may_start_func(&profile_info, fp, fc);
if (do_profiling == PROF_YES)
profile_may_start_func(&profile_info, fp, caller);
#endif
call_def_function(fp, argcount, argvars, funcexe->partial, rettv);
funcdepth_decrement();
#ifdef FEAT_PROFILE
if (do_profiling == PROF_YES && (fp->uf_profiling
|| (fc->caller != NULL && fc->caller->func->uf_profiling)))
profile_may_end_func(&profile_info, fp, fc);
|| (caller != NULL && caller->uf_profiling)))
profile_may_end_func(&profile_info, fp, caller);
#endif
current_funccal = fc->caller;
free_funccal(fc);
@ -1872,7 +1876,9 @@ call_user_func(
--no_wait_return;
}
#ifdef FEAT_PROFILE
profile_may_start_func(&profile_info, fp, fc);
if (do_profiling == PROF_YES)
profile_may_start_func(&profile_info, fp,
fc->caller == NULL ? NULL : fc->caller->func);
#endif
save_current_sctx = current_sctx;
@ -1908,9 +1914,13 @@ call_user_func(
}
#ifdef FEAT_PROFILE
if (do_profiling == PROF_YES && (fp->uf_profiling
|| (fc->caller != NULL && fc->caller->func->uf_profiling)))
profile_may_end_func(&profile_info, fp, fc);
if (do_profiling == PROF_YES)
{
ufunc_T *caller = fc->caller == NULL ? NULL : fc->caller->func;
if (fp->uf_profiling || (caller != NULL && caller->uf_profiling))
profile_may_end_func(&profile_info, fp, caller);
}
#endif
// when being verbose, mention the return value

2
src/version.c
View File

@ -750,6 +750,8 @@ static char *(features[]) =
static int included_patches[] =
{ /* Add new patch number below this line */
/**/
2530,
/**/
2529,
/**/

55
src/vim9execute.c
View File

@ -72,6 +72,11 @@ struct ectx_S {
garray_T ec_funcrefs; // partials that might be a closure
};
#ifdef FEAT_PROFILE
// stack of profinfo_T used when profiling.
static garray_T profile_info_ga = {0, 0, sizeof(profinfo_T), 20, NULL};
#endif
// Get pointer to item relative to the bottom of the stack, -1 is the last one.
#define STACK_TV_BOT(idx) (((typval_T *)ectx->ec_stack.ga_data) + ectx->ec_stack.ga_len + (idx))
@ -184,13 +189,27 @@ call_dfunc(int cdf_idx, partial_T *pt, int argcount_arg, ectx_T *ectx)
}
#ifdef FEAT_PROFILE
// Profiling might be enabled/disabled along the way. This should not
// fail, since the function was compiled before and toggling profiling
// doesn't change any errors.
if (func_needs_compiling(ufunc, PROFILING(ufunc))
&& compile_def_function(ufunc, FALSE, PROFILING(ufunc), NULL)
if (do_profiling == PROF_YES)
{
if (ga_grow(&profile_info_ga, 1) == OK)
{
profinfo_T *info = ((profinfo_T *)profile_info_ga.ga_data)
+ profile_info_ga.ga_len;
++profile_info_ga.ga_len;
CLEAR_POINTER(info);
profile_may_start_func(info, ufunc,
(((dfunc_T *)def_functions.ga_data)
+ ectx->ec_dfunc_idx)->df_ufunc);
}
// Profiling might be enabled/disabled along the way. This should not
// fail, since the function was compiled before and toggling profiling
// doesn't change any errors.
if (func_needs_compiling(ufunc, PROFILING(ufunc))
&& compile_def_function(ufunc, FALSE, PROFILING(ufunc), NULL)
== FAIL)
return FAIL;
return FAIL;
}
#endif
if (ufunc->uf_va_name != NULL)
@ -517,7 +536,25 @@ func_return(ectx_T *ectx)
int argcount = ufunc_argcount(dfunc->df_ufunc);
int top = ectx->ec_frame_idx - argcount;
estack_T *entry;
int prev_dfunc_idx = STACK_TV(ectx->ec_frame_idx
+ STACK_FRAME_FUNC_OFF)->vval.v_number;
dfunc_T *prev_dfunc = ((dfunc_T *)def_functions.ga_data)
+ prev_dfunc_idx;
#ifdef FEAT_PROFILE
if (do_profiling == PROF_YES)
{
ufunc_T *caller = prev_dfunc->df_ufunc;
if (dfunc->df_ufunc->uf_profiling
|| (caller != NULL && caller->uf_profiling))
{
profile_may_end_func(((profinfo_T *)profile_info_ga.ga_data)
+ profile_info_ga.ga_len - 1, dfunc->df_ufunc, caller);
--profile_info_ga.ga_len;
}
}
#endif
// execution context goes one level up
entry = estack_pop();
if (entry != NULL)
@ -544,8 +581,7 @@ func_return(ectx_T *ectx)
vim_free(ectx->ec_outer);
// Restore the previous frame.
ectx->ec_dfunc_idx = STACK_TV(ectx->ec_frame_idx
+ STACK_FRAME_FUNC_OFF)->vval.v_number;
ectx->ec_dfunc_idx = prev_dfunc_idx;
ectx->ec_iidx = STACK_TV(ectx->ec_frame_idx
+ STACK_FRAME_IIDX_OFF)->vval.v_number;
ectx->ec_outer = (void *)STACK_TV(ectx->ec_frame_idx
@ -553,8 +589,7 @@ func_return(ectx_T *ectx)
// restoring ec_frame_idx must be last
ectx->ec_frame_idx = STACK_TV(ectx->ec_frame_idx
+ STACK_FRAME_IDX_OFF)->vval.v_number;
dfunc = ((dfunc_T *)def_functions.ga_data) + ectx->ec_dfunc_idx;
ectx->ec_instr = INSTRUCTIONS(dfunc);
ectx->ec_instr = INSTRUCTIONS(prev_dfunc);
if (ret_idx > 0)
{