Re: [Tarantool-patches] [PATCH luajit] Fix interaction between profiler hooks and finalizers.

[sergos via Tarantool-patches <tarantool-patches@dev.tarantool.org>]

Hi!

Thanks for the patch!
LGTM with minor updates to the message.

Sergos

> On 6 Jun 2022, at 16:35, Sergey Kaplun <skaplun@tarantool.org> wrote:
> 
> From: Mike Pall <mike>
> 
> Thanks to Julien Desgats.
> 
> (cherry picked from commit 92fa45f9eb5d9aa732c6b972a85c26120d7612b4)
> 
> Embedded LuaJIT profiler uses the following approach:
> * Create trigger on timer signals, which set `HOOK_PROFILE` flag on
>  `g->hookmask` (if not set already) and update all BC instructions
>  dispatch.
         ??? plural, perhaps dispatch places?
> * When any of instruction is executed, callback set by user on profiler
                                        a
>  initialize is called. After the dispatch table updated again to
>  the old static values, and flags are reset.
> * `HOOK_PROFILE` flag will set again and dispatch will updated at the next
>  tick of the timer.
> 
> Before call to __gc finalizer the old hookmask is saved to be restored
               a                                         for the future use.
> later. When the second step is happening on call of __gc metamethod
                                             a      a
> `HOOK_PROFILE` flag is reset. But right after that the old hook
 the
> disposition (with `HOOK_PROFILE`) is restored, when we leaving
> `gc_call_finalizer()` without updating the dispatch table, so the
> profiler callback is never called again.
> 
> This patch updates dispatch table right after hooks manipulation in
> `gc_call_finalizer()` and prevent ticks influence inside finalizer
> calls.
> 
> Sergey Kaplun:
> * added the description and the test for the problem
> 
> Part of tarantool/tarantool#6548
> ---
> 
> Side note: PR has 2 extra commits because the tarantool/luajit master
> (tarantool branch) isn't bumped in the tarantool yet.
> 
> Branch: https://github.com/tarantool/luajit/tree/skaplun/lj-512-profiler-hook-finalizers-full-ci
> Tarantool PR: https://github.com/tarantool/tarantool/pull/7237
> Related issues:
> * https://github.com/LuaJIT/LuaJIT/issues/512
> * https://github.com/tarantool/tarantool/issues/6548
> 
> 
> src/lj_gc.c                                   |  2 ++
> src/lj_obj.h                                  |  3 +-
> src/lj_profile.c                              |  2 +-
> .../lj-512-profiler-hook-finalizers.test.lua  | 31 +++++++++++++++++++
> 4 files changed, 36 insertions(+), 2 deletions(-)
> create mode 100644 test/tarantool-tests/lj-512-profiler-hook-finalizers.test.lua
> 
> diff --git a/src/lj_gc.c b/src/lj_gc.c
> index 7f0ec896..29387a48 100644
> --- a/src/lj_gc.c
> +++ b/src/lj_gc.c
> @@ -493,6 +493,7 @@ static void gc_call_finalizer(global_State *g, lua_State *L,
>   TValue *top;
>   lj_trace_abort(g);
>   hook_entergc(g);  /* Disable hooks and new traces during __gc. */
> +  if (LJ_HASPROFILE && (oldh & HOOK_PROFILE)) lj_dispatch_update(g);
>   g->gc.threshold = LJ_MAX_MEM;  /* Prevent GC steps. */
>   top = L->top;
>   copyTV(L, top++, mo);
> @@ -501,6 +502,7 @@ static void gc_call_finalizer(global_State *g, lua_State *L,
>   L->top = top+1;
>   errcode = lj_vm_pcall(L, top, 1+0, -1);  /* Stack: |mo|o| -> | */
>   hook_restore(g, oldh);
> +  if (LJ_HASPROFILE && (oldh & HOOK_PROFILE)) lj_dispatch_update(g);
>   g->gc.threshold = oldt;  /* Restore GC threshold. */
>   if (errcode)
>     lj_err_throw(L, errcode);  /* Propagate errors. */
> diff --git a/src/lj_obj.h b/src/lj_obj.h
> index 197d735a..d1451c3a 100644
> --- a/src/lj_obj.h
> +++ b/src/lj_obj.h
> @@ -692,7 +692,8 @@ typedef struct global_State {
> #define HOOK_PROFILE		0x80
> #define hook_active(g)		((g)->hookmask & HOOK_ACTIVE)
> #define hook_enter(g)		((g)->hookmask |= HOOK_ACTIVE)
> -#define hook_entergc(g)		((g)->hookmask |= (HOOK_ACTIVE|HOOK_GC))
> +#define hook_entergc(g) \
> +  ((g)->hookmask = ((g)->hookmask | (HOOK_ACTIVE|HOOK_GC)) & ~HOOK_PROFILE)
> #define hook_vmevent(g)		((g)->hookmask |= (HOOK_ACTIVE|HOOK_VMEVENT))
> #define hook_leave(g)		((g)->hookmask &= ~HOOK_ACTIVE)
> #define hook_save(g)		((g)->hookmask & ~HOOK_EVENTMASK)
> diff --git a/src/lj_profile.c b/src/lj_profile.c
> index 4412d68b..896d8f46 100644
> --- a/src/lj_profile.c
> +++ b/src/lj_profile.c
> @@ -106,7 +106,7 @@ static void profile_trigger(ProfileState *ps)
>   profile_lock(ps);
>   ps->samples++;  /* Always increment number of samples. */
>   mask = g->hookmask;
> -  if (!(mask & (HOOK_PROFILE|HOOK_VMEVENT))) {  /* Set profile hook. */
> +  if (!(mask & (HOOK_PROFILE|HOOK_VMEVENT|HOOK_GC))) {  /* Set profile hook. */
>     int st = g->vmstate;
>     ps->vmstate = st >= 0 ? 'N' :
> 		  st == ~LJ_VMST_INTERP ? 'I' :
> diff --git a/test/tarantool-tests/lj-512-profiler-hook-finalizers.test.lua b/test/tarantool-tests/lj-512-profiler-hook-finalizers.test.lua
> new file mode 100644
> index 00000000..4b6aabb7
> --- /dev/null
> +++ b/test/tarantool-tests/lj-512-profiler-hook-finalizers.test.lua
> @@ -0,0 +1,31 @@
> +local tap = require('tap')
> +local profile = require('jit.profile')
> +
> +local test = tap.test('lj-512-profiler-hook-finalizers')
> +test:plan(1)
> +
> +-- Sampling interval in ms.
> +local INTERVAL = 10
> +
> +local nsamples = 0
> +profile.start('li' .. tostring(INTERVAL), function()

> +  nsamples = nsamples + 1
> +end)
> +
> +local start = os.clock()
> +for _ = 1, 1e6 do
> +   getmetatable(newproxy(true)).__gc = function() end
> +end
> +local finish = os.clock()
> +
> +profile.stop()
> +
> +-- XXX: The bug is occured as stopping of callbacks invocation,
> +-- when a new tick strikes inside `gc_call_finalizer()`.
> +-- The amount of successfull callbacks isn't stable (2-15).
> +-- So, assume that amount of profiling samples should be at least
> +-- more than 0.5 intervals of time during sampling.
> +test:ok(nsamples >= 0.5 * (finish - start) * 1e3 / INTERVAL,
> +        'profiler sampling')
> +
> +os.exit(test:check() and 0 or 1)
> -- 
> 2.34.1
>