From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from [87.239.111.99] (localhost [127.0.0.1]) by dev.tarantool.org (Postfix) with ESMTP id 688996ECE6; Mon, 6 Jun 2022 16:37:46 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org 688996ECE6 DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=tarantool.org; s=dev; t=1654522666; bh=kKPJXp6M80IctD+lE1pXcE4zrcJ0E+J423MIARiK5jc=; h=To:Date:Subject:List-Id:List-Unsubscribe:List-Archive:List-Post: List-Help:List-Subscribe:From:Reply-To:Cc:From; b=maIf8QIi90qfz0A+hMqIxf00k5sB30Xph8IrUJSum1BsMMsYEP/4l6S0I+rDivgrc bwvRJx2R1QSybzX6x3o4jSUBB9h4DCrpqMGoRk0ZxsLLoqD+GovDHqnahzY6RmnYS8 /wjI8hWSsV+mOLLM9q0/gJlQVZXWfS7CdWI7dYK4= Received: from smtp3.mail.ru (smtp3.mail.ru [94.100.179.58]) (using TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)) (No client certificate requested) by dev.tarantool.org (Postfix) with ESMTPS id D0EDF6ECE6 for ; Mon, 6 Jun 2022 16:37:45 +0300 (MSK) DKIM-Filter: OpenDKIM Filter v2.11.0 dev.tarantool.org D0EDF6ECE6 Received: by smtp3.mail.ru with esmtpa (envelope-from ) id 1nyCvQ-00073c-Ko; Mon, 06 Jun 2022 16:37:45 +0300 To: Sergey Ostanevich , Igor Munkin Date: Mon, 6 Jun 2022 16:35:28 +0300 Message-Id: <20220606133528.13355-1-skaplun@tarantool.org> X-Mailer: git-send-email 2.34.1 MIME-Version: 1.0 Content-Transfer-Encoding: 8bit X-7564579A: 646B95376F6C166E X-77F55803: 4F1203BC0FB41BD9A866A199C4CD7E1071F787FD1D87DD886398D2FD36F3E881182A05F5380850401B9F5CCEC7D4CFA18D83880BF0AEB22AB9FBFE9980271C6C9C6715247054DBAA X-7FA49CB5: FF5795518A3D127A4AD6D5ED66289B5278DA827A17800CE74D0D2DEF2EB846B0EA1F7E6F0F101C67BD4B6F7A4D31EC0BCC500DACC3FED6E28638F802B75D45FF8AA50765F7900637AA32F0A5ADCF96E68638F802B75D45FF36EB9D2243A4F8B5A6FCA7DBDB1FC311F39EFFDF887939037866D6147AF826D80DFFE98DD57784C02FEF7CBA1FAEB104117882F4460429724CE54428C33FAD305F5C1EE8F4F765FC2EE5AD8F952D28FBA471835C12D1D9774AD6D5ED66289B52BA9C0B312567BB23117882F446042972877693876707352033AC447995A7AD18CB629EEF1311BF91D2E47CDBA5A96583BA9C0B312567BB2376E601842F6C81A19E625A9149C048EE9647ADFADE5905B103F1AB874ED890284AD6D5ED66289B52698AB9A7B718F8C46E0066C2D8992A16725E5C173C3A84C33C47BDC0B0347B17BA3038C0950A5D36B5C8C57E37DE458B0BC6067A898B09E46D1867E19FE14079C09775C1D3CA48CF3D321E7403792E342EB15956EA79C166A417C69337E82CC275ECD9A6C639B01B78DA827A17800CE7BEE702378D8A34C7731C566533BA786AA5CC5B56E945C8DA X-8FC586DF: 6EFBBC1D9D64D975 X-C1DE0DAB: C20DE7B7AB408E4181F030C43753B8186998911F362727C414F749A5E30D975C401E41E28D1833AC57B91DA4D09E3ED28CD563DBB02EC0AD9C2B6934AE262D3EE7EAB7254005DCED695F253C9721EF04F36E2E0160E5C55395B8A2A0B6518DF68C46860778A80D548DA55E71E02F9FC08E8E86DC7131B365E7726E8460B7C23C X-C8649E89: 4E36BF7865823D7055A7F0CF078B5EC49A30900B95165D34951738D4D62E58A4C474F68539F0937980547C31F5791B473A6AA5D86FB56A1E15E1D34DE4D815271D7E09C32AA3244CB12AA6AF97AF71906820F36FBF2F3567C3B3ADDA61883BB5927AC6DF5659F194 X-D57D3AED: 3ZO7eAau8CL7WIMRKs4sN3D3tLDjz0dLbV79QFUyzQ2Ujvy7cMT6pYYqY16iZVKkSc3dCLJ7zSJH7+u4VD18S7Vl4ZUrpaVfd2+vE6kuoey4m4VkSEu530nj6fImhcD4MUrOEAnl0W826KZ9Q+tr5ycPtXkTV4k65bRjmOUUP8cvGozZ33TWg5HZplvhhXbhDGzqmQDTd6OAevLeAnq3Ra9uf7zvY2zzsIhlcp/Y7m53TZgf2aB4JOg4gkr2biojbL9S8ysBdXg+KRhGkuasgTR0kTkwInbu X-Mailru-Sender: 11C2EC085EDE56FAC07928AF2646A76973476E7305FBA97F8D83880BF0AEB22A38066306E4938E9FDEDBA653FF35249392D99EB8CC7091A70E183A470755BFD208F19895AA18418972D6B4FCE48DF648AE208404248635DF X-Mras: Ok Subject: [Tarantool-patches] [PATCH luajit] Fix interaction between profiler hooks and finalizers. X-BeenThere: tarantool-patches@dev.tarantool.org X-Mailman-Version: 2.1.34 Precedence: list List-Id: Tarantool development patches List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , From: Sergey Kaplun via Tarantool-patches Reply-To: Sergey Kaplun Cc: tarantool-patches@dev.tarantool.org Errors-To: tarantool-patches-bounces@dev.tarantool.org Sender: "Tarantool-patches" From: Mike Pall 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. * When any of instruction is executed, callback set by user on profiler 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 later. When the second step is happening on call of __gc metamethod `HOOK_PROFILE` flag is reset. But right after that the old hook 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