<HTML><BODY><div>Hi, Igor!</div><div>Thanks for the fixes!</div><div>LGTM</div><div data-signature-widget="container"><div data-signature-widget="content"><div>--<br>Best regards,</div><div>Maxim Kokryashkin</div></div></div><div> </div><div> </div><blockquote style="border-left:1px solid #0857A6; margin:10px; padding:0 0 0 10px;"><div> <blockquote style="border-left:1px solid #0857A6; margin:10px; padding:0 0 0 10px;"><div id=""><div class="js-helper js-readmsg-msg"><div><div id="style_17017761270311541127_BODY">Max,<br><br>Thanks for your review!<br><br>On 03.12.23, Maxim Kokryashkin wrote:<br>> Hi, Igor!<br>> Thanks for the patch!<br>> Please consider my comments below.<br>><br>> Side note: This new testing approach is amazing, thanks a lot!<br>><br>> On Tue, Nov 28, 2023 at 02:53:17PM +0000, Igor Munkin wrote:<br>> > Often tests for sampling profiler require long running loops to be<br>> Typo: s/Often/Often,/<br>> > executed, so a certain situation is likely to occur. Thus the test added<br>> Typo: s/Thus/Thus,/<br>> > in the commit 285a1b0a16c1c3224ab93f7cf1fef17ab29e4ab4 ("sysprof: fix<br>> Typo: s/in the/in/<br>> > crash during FFUNC stream") expects FFUNC VM state (and even the<br>> Typo: s/expects FFUNC/expects the FFUNC/<br>> > particular instruction to be executed) at the moment when stacktrace is<br>> > being collected. Unfortunately, it leads to test routine hang for<br>> Typo: s/to test routine hang/to the test routine hanging/<br>> > several environments and if it does not we cannot guarantee that the<br>> Typo: s/environments/environments,/<br>> Typo: s/and if it does not/and even if it does not,/<br>> > desired scenario is tested (only rely on statistics). As a result the<br>> Typo: s/As a result/As a result,/<br>> > test for the aforementioned patch was disabled for Tarantool CI in the<br>> > commit fef60a1052b8444be61e9a9932ab4875aff0b2ed ("test: prevent hanging<br>> > Tarantool CI by sysprof test") until the issue is not resolved.<br>> ><br>> > This patch introduces the new approach for testing our sampling profiler<br>> > via <ptrace> implementing precise managed execution of the profiled<br>> Typo: s/<ptrace>/<ptrace>,/<br>> > instance mentioned in tarantool/tarantool#9387.<br>> ><br>> > Instead of running around <tostring> gazillion times we accurately step<br>> Typo: s/times/times,/<br>> > to the exact place where the issue reproduces and manually emit SIGPROF<br>> > to the Lua VM being profiled. The particular approach implemented in<br>> > this patch is described below.<br>> ><br>> > As it was mentioned, the test makes sysprof to collect the particular<br>> Typo: s/to collect/collect/<br>> > event (FFUNC) at the certain instruction in Lua VM (<lj_fff_res1>) to<br>> > reproduce the issue from tarantool/tarantool#8594. Hence it's enough to<br>> Typo: s/Hence/Hence,/<br>> > call <tostring> fast function in the profiled instance (i.e. "tracee").<br>> Typo: s/i.e./i.e.,/<br>> > To emit SIGPROF right at <lj_fff_res1> in scope of <tostring> builtin,<br>> Typo: s/in scope/in the scope/<br>> > the manager (i.e. "tracer") is implemented.<br>> Typo: s/i.e./i.e.,/<br>> ><br>> > Here are the main steps (see comments and `man 2 ptrace' for more info):<br>> > 1. Poison <int 3> instruction as the first instruction at<br>> > <lj_ff_tostring> to stop at the beginning of the fast function;<br>> > 2. Resume the "tracee" from the "tracer";<br>> > 3. Hit the emitted interruption, restore the original instruction and<br>> > "rewind" the RIP to "replay" the instruction at <lj_ff_tostring>;<br>> > 4. Do the hack 1-3 for <lj_fff_res1>;<br>> > 5. Emit SIGPROF while resumimg the "tracee";<br>> Typo: s/resumimg/resuming/<br>> ><br>> > As a result sysprof collects the full backtrace with <tostring> fast<br>> Typo: s/a result/a result,/<br>> > function as the topmost frame.<br>> ><br>> > Resolves tarantool/tarantool#9387<br>> > Follows up tarantool/tarantool#8594<br>> ><br>> > Signed-off-by: Igor Munkin <<a href="/compose?To=imun@tarantool.org">imun@tarantool.org</a>><br><br>Here is the updated commit message:<br><br>================================================================================<br><br>test: rewrite sysprof test using managed execution<br><br>Often, tests for sampling profiler require long running loops to be<br>executed, so a certain situation is likely to occur. Thus, the test<br>added in commit 285a1b0a16c1c3224ab93f7cf1fef17ab29e4ab4 ("sysprof: fix<br>crash during FFUNC stream") expects the FFUNC VM state (and even the<br>particular instruction to be executed) at the moment when stacktrace is<br>being collected. Unfortunately, it leads to the test routine hang for<br>several environments, and even if it does not, we cannot guarantee that<br>the desired scenario is tested (only rely on statistics). As a result,<br>the test for the aforementioned patch was disabled for Tarantool CI in<br>the commit fef60a1052b8444be61e9a9932ab4875aff0b2ed ("test: prevent<br>hanging Tarantool CI by sysprof test") until the issue is not resolved.<br><br>This patch introduces the new approach for testing our sampling profiler<br>via <ptrace>, implementing precise managed execution of the profiled<br>instance mentioned in tarantool/tarantool#9387.<br><br>Instead of running around <tostring> gazillion times, we accurately step<br>to the exact place where the issue reproduces and manually emit SIGPROF<br>to the Lua VM being profiled. The particular approach implemented in<br>this patch is described below.<br><br>As it was mentioned, the test makes sysprof collect the particular event<br>type (FFUNC) at the certain instruction in Lua VM (<lj_fff_res1>) to<br>reproduce the issue from tarantool/tarantool#8594. Hence, it's enough to<br>call <tostring> fast function in the profiled instance (i.e., "tracee").<br>To emit SIGPROF right at <lj_fff_res1> in the scope of <tostring><br>builtin, the manager (i.e., "tracer") is implemented.<br><br>Here are the main steps (see comments and `man 2 ptrace' for more info):<br> 1. Poison <int 3> instruction as the first instruction at<br> <lj_ff_tostring> to stop at the beginning of the fast function;<br> 2. Resume the "tracee" from the "tracer";<br> 3. Hit the emitted interruption, restore the original instruction and<br> "rewind" the RIP to "replay" the instruction at <lj_ff_tostring>;<br> 4. Do the hack 1-3 for <lj_fff_res1>;<br> 5. Emit SIGPROF while resuming the "tracee";<br><br>As a result, sysprof collects the full backtrace with <tostring> fast<br>function as the topmost frame.<br><br>Resolves tarantool/tarantool#9387<br>Follows up tarantool/tarantool#8594<br><br>================================================================================<br><br>> > ---<br>> > .../gh-8594-sysprof-ffunc-crash.test.c | 269 ++++++++++++++++++<br>> > .../gh-8594-sysprof-ffunc-crash.test.lua | 55 ----<br>> > 2 files changed, 269 insertions(+), 55 deletions(-)<br>> > create mode 100644 test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>> > delete mode 100644 test/tarantool-tests/gh-8594-sysprof-ffunc-crash.test.lua<br>> ><br>> > diff --git a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>> > new file mode 100644<br>> > index 00000000..4caed8cb<br>> > --- /dev/null<br>> > +++ b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>> > @@ -0,0 +1,269 @@<br>> > +#include "lauxlib.h"<br>> > +#include "lmisclib.h"<br>> > +#include "lua.h"<br>> > +<br>> > +#include "test.h"<br>> > +#include "utils.h"<br>> > +<br>> > +#include <signal.h><br>> > +#include <sys/ptrace.h><br>> > +#include <sys/user.h><br>> > +#include <sys/wait.h><br>> > +#include <unistd.h><br>> > +<br>> > +/* XXX: Still need normal assert inside <tracee> and helpers. */<br>> > +#undef NDEBUG<br>> > +#include <assert.h><br>> > +<br>> > +/*<br>> > + * XXX: The test is *very* Linux/x86_64 specific. Fortunately, so<br>> > + * does the sampling profiler. <lj_arch.> is needed for LUAJIT_OS<br>> > + * and LUAJIT_TARGET.<br>> > + */<br>> > +#include "lj_arch.h"<br>> > +<br>> > +#if LUAJIT_OS == LUAJIT_OS_LINUX && LUAJIT_TARGET == LUAJIT_ARCH_X64<br>> Why not use the `LJ_HASSYSPROF` flag?<br><br>Since the test per se is Linux/x86_64 specific (consider the particular<br>register name used below). E.g. sysprof is implemented for x86 either,<br>but the test is not. If somebody (Sergey Kaplun) finally decided to<br>introduce x86 testing environment, the test would crash. I prefer more<br>developer-friendly approach here (considering <ptrace> peculiarities).<br><br>> > +<br>> > +/*<br>> > + * XXX: The test makes sysprof to collect the particular event<br>> Typo: s/sysprof to/sysprof/<br>> > + * (FFUNC) at the particular instruction (<lj_fff_res1>) to<br>> > + * reproduce the issue #8594. Hence it's enough to call <tostring><br>> Typo: s/Hence/Hence,/<br>> > + * fast function (this is done in <tracee> function). To emit<br>> > + * SIGPROF right at <lj_fff_res1> in scope of <tostring> fast<br>> > + * function, the managed execution is implemented in the function<br>> > + * <tracer>: <int 3> instruction is poisoned as the first<br>> > + * instruction at <lj_ff_tostring> to stop <tracee> at the<br>> > + * beginning of the fast function; <tracer> resumes the <tracee>;<br>> > + * the same hack is done for <lj_fff_res1>. When the <tracee> hits<br>> > + * the interruption at <lj_fff_res1>, SIGPROF is emitted while<br>> > + * resuming the <tracee>. As a result sysprof collects the full<br>> Typo: s/a result/a result,/<br>> > + * backtrace with <tostring> fast function as the topmost frame.<br>> > + *<br>> > + * See more info here:<br>> > + * * <a href="https://man7.org/linux/man-pages/man2/ptrace.2.html" target="_blank">https://man7.org/linux/man-pages/man2/ptrace.2.html</a><br>> > + * * <a href="https://github.com/tarantool/tarantool/issues/8594" target="_blank">https://github.com/tarantool/tarantool/issues/8594</a><br>> > + * * <a href="https://github.com/tarantool/tarantool/issues/9387" target="_blank">https://github.com/tarantool/tarantool/issues/9387</a><br>> > + */<br><br>Fixed. The diff is below:<br><br>================================================================================<br><br>diff --git a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>index 4caed8cb..f060760b 100644<br>--- a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>+++ b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>@@ -25,18 +25,18 @@<br> #if LUAJIT_OS == LUAJIT_OS_LINUX && LUAJIT_TARGET == LUAJIT_ARCH_X64<br> <br> /*<br>- * XXX: The test makes sysprof to collect the particular event<br>+ * XXX: The test makes sysprof collect the particular event<br> * (FFUNC) at the particular instruction (<lj_fff_res1>) to<br>- * reproduce the issue #8594. Hence it's enough to call <tostring><br>- * fast function (this is done in <tracee> function). To emit<br>- * SIGPROF right at <lj_fff_res1> in scope of <tostring> fast<br>- * function, the managed execution is implemented in the function<br>- * <tracer>: <int 3> instruction is poisoned as the first<br>+ * reproduce the issue #8594. Hence, it's enough to call<br>+ * <tostring> fast function (this is done in <tracee> function).<br>+ * To emit SIGPROF right at <lj_fff_res1> in scope of <tostring><br>+ * fast function, the managed execution is implemented in the<br>+ * function <tracer>: <int 3> instruction is poisoned as the first<br> * instruction at <lj_ff_tostring> to stop <tracee> at the<br> * beginning of the fast function; <tracer> resumes the <tracee>;<br> * the same hack is done for <lj_fff_res1>. When the <tracee> hits<br> * the interruption at <lj_fff_res1>, SIGPROF is emitted while<br>- * resuming the <tracee>. As a result sysprof collects the full<br>+ * resuming the <tracee>. As a result, sysprof collects the full<br> * backtrace with <tostring> fast function as the topmost frame.<br> *<br> * See more info here:<br><br>================================================================================<br><br>> > +<br><br><snipped><br><br>> > +<br>> > + /* Allow tracing for this process */<br>> > + if (ptrace(PTRACE_TRACEME, 0, 0, 0) < 0) {<br>> > + perror("Failed to turn the calling thread into a tracee");<br>> Typo?: s/thread/process/<br><br>Yeah, copy-pasted from the <ptrace> recipe. Fixed.<br><br>> > + return EXIT_FAILURE;<br>> > + }<br><br><snipped><br><br>> > + /* Terminate profiler and Lua universe. */<br>> > + assert(luaM_sysprof_stop(L) == PROFILE_SUCCESS);<br>> > + utils_lua_close(L);<br>> It doesn't seem to be semantically correct to terminate Lua universe<br>> before obtaining the counters, even though there is no obstacles to do<br>> so in the API implementation itself.<br><br>To[MAH]to vs.To[MAY]to: fixed. The diff is below.<br><br>================================================================================<br><br>diff --git a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>index c0f9d1ca..5a2523ef 100644<br>--- a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>+++ b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>@@ -142,9 +142,8 @@ static int tracee(const char *luacode) {<br> assert(luaL_dostring(L, luacode) == LUA_OK);<br> assert(strcmp(lua_tostring(L, -1), MESSAGE) == 0);<br> <br>- /* Terminate profiler and Lua universe. */<br>+ /* Terminate profiler. */<br> assert(luaM_sysprof_stop(L) == PROFILE_SUCCESS);<br>- utils_lua_close(L);<br> <br> /*<br> * XXX: The only event to be streamed must be FFUNC at<br>@@ -155,6 +154,9 @@ static int tracee(const char *luacode) {<br> assert(counters.samples == 1);<br> assert(counters.vmst_ffunc == 1);<br> <br>+ /* Terminate Lua universe. */<br>+ utils_lua_close(L);<br>+<br> return EXIT_SUCCESS;<br> }<br> <br><br>================================================================================<br><br>> > +<br><br><snipped><br><br>> > + /* Resume <chpid> tracee until SIGTRAP occurs. */<br>> > + ptrace(PTRACE_CONT, chpid, 0, 0);<br>> > + /* Wait <chpid> tracee signal-delivery-stop. */<br>> > + waitpid(chpid, &wstatus, 0);<br>> Should we check the `wstatus` here too?<br><br>Implemented via <wait_alive> helper (see the details below).<br><br>> > +<br><br><snipped><br><br>> > +<br>> > +static int tracer(pid_t chpid) {<br>> > + int wstatus;<br>> > +<br>> > + /* Wait until <chpid> tracee is ready. */<br>> > + waitpid(chpid, &wstatus, 0);<br>> Should we check the process status here too?<br><br>Implemented via <wait_alive> helper (see the implementation below).<br><br>================================================================================<br><br>diff --git a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>index 84c024f0..d17386dd 100644<br>--- a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>+++ b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>@@ -222,7 +222,7 @@ static int tracer(pid_t chpid) {<br> int wstatus;<br> <br> /* Wait until <chpid> tracee is ready. */<br>- waitpid(chpid, &wstatus, 0);<br>+ wait_alive(chpid);<br> <br> /*<br> * Resume <chpid> tracee until <lj_ff_tostring>.<br><br>================================================================================<br><br>> > +<br>> > + /* Resume <chpid> tracee until <lj_ff_tostring>. */<br>> > + wstatus = continue_until(chpid, lj_ff_tostring);<br>> > +<br>> > + /* The tracee has to be alive and stopped by SIGTRAP. */<br>> > + assert_false(WIFEXITED(wstatus));<br>> > + assert_true(WIFSTOPPED(wstatus));<br>> > +<br>> > + /* Resume <chpid> tracee until <lj_fff_res1>. */<br>> > + wstatus = continue_until(chpid, lj_fff_res1);<br>> > +<br>> > + /* The tracee has to be alive and stopped by SIGTRAP. */<br>> > + assert_false(WIFEXITED(wstatus));<br>> > + assert_true(WIFSTOPPED(wstatus));<br>> This part is duplicated, let's move it to a separate `healthcheck`<br>> function, or something like that.<br><br>It's only duplicated in sense of reusing this particular code, no more.<br>However, let's consider these conditions are not parts of the test<br>assertions set, but rather invariants for <continue_until> helper (i.e.<br><continue_until> has to yield the execution with the "alive" tracee).<br><br>In this case, the patch for <continue_until> is the following:<br><br>================================================================================<br><br>diff --git a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>index 5a2523ef..84c024f0 100644<br>--- a/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>+++ b/test/tarantool-c-tests/gh-8594-sysprof-ffunc-crash.test.c<br>@@ -160,6 +160,18 @@ static int tracee(const char *luacode) {<br> return EXIT_SUCCESS;<br> }<br> <br>+static void wait_alive(pid_t chpid) {<br>+ int wstatus;<br>+<br>+ /* Wait <chpid> tracee signal-delivery-stop. */<br>+ waitpid(chpid, &wstatus, 0);<br>+<br>+ /* Check the tracee is still alive and just stopped. */<br>+ assert(!WIFEXITED(wstatus));<br>+ assert(!WIFSIGNALED(wstatus));<br>+ assert(WIFSTOPPED(wstatus));<br>+}<br>+<br> const uint8_t INT3 = 0xCC;<br> static inline unsigned long int3poison(unsigned long instruction) {<br> const size_t int3bits = sizeof(INT3) * 8;<br>@@ -167,8 +179,7 @@ static inline unsigned long int3poison(unsigned long instruction) {<br> return (instruction & int3mask) | INT3;<br> }<br> <br>-static int continue_until(pid_t chpid, void *addr) {<br>- int wstatus;<br>+static void continue_until(pid_t chpid, void *addr) {<br> struct user_regs_struct regs;<br> <br> /* Obtain the instructions at the <addr>. */<br>@@ -182,8 +193,12 @@ static int continue_until(pid_t chpid, void *addr) {<br> <br> /* Resume <chpid> tracee until SIGTRAP occurs. */<br> ptrace(PTRACE_CONT, chpid, 0, 0);<br>- /* Wait <chpid> tracee signal-delivery-stop. */<br>- waitpid(chpid, &wstatus, 0);<br>+<br>+ /*<br>+ * Wait <chpid> tracee signal-delivery-stop and check<br>+ * whether it's still alive and just stopped via SIGTRAP.<br>+ */<br>+ wait_alive(chpid);<br> <br> /* Obtain GPR set to tweak RIP for further execution. */<br> ptrace(PTRACE_GETREGS, chpid, 0, ®s);<br>@@ -201,9 +216,6 @@ static int continue_until(pid_t chpid, void *addr) {<br> regs.rip -= sizeof(INT3);<br> ptrace(PTRACE_SETREGS, chpid, 0, ®s);<br> ptrace(PTRACE_POKETEXT, chpid, addr, data);<br>-<br>- /* Return wait status to the caller for test checks. */<br>- return wstatus;<br> }<br> <br> static int tracer(pid_t chpid) {<br>@@ -212,19 +224,19 @@ static int tracer(pid_t chpid) {<br> /* Wait until <chpid> tracee is ready. */<br> waitpid(chpid, &wstatus, 0);<br> <br>- /* Resume <chpid> tracee until <lj_ff_tostring>. */<br>- wstatus = continue_until(chpid, lj_ff_tostring);<br>-<br>- /* The tracee has to be alive and stopped by SIGTRAP. */<br>- assert_false(WIFEXITED(wstatus));<br>- assert_true(WIFSTOPPED(wstatus));<br>-<br>- /* Resume <chpid> tracee until <lj_fff_res1>. */<br>- wstatus = continue_until(chpid, lj_fff_res1);<br>+ /*<br>+ * Resume <chpid> tracee until <lj_ff_tostring>.<br>+ * The tracee is alive and stopped by SIGTRAP if<br>+ * <continue_until> returns.<br>+ */<br>+ continue_until(chpid, lj_ff_tostring);<br> <br>- /* The tracee has to be alive and stopped by SIGTRAP. */<br>- assert_false(WIFEXITED(wstatus));<br>- assert_true(WIFSTOPPED(wstatus));<br>+ /*<br>+ * Resume <chpid> tracee until <lj_fff_res1>.<br>+ * The tracee is alive and stopped by SIGTRAP if<br>+ * <continue_until> returns.<br>+ */<br>+ continue_until(chpid, lj_fff_res1);<br> <br> /* Send SIGPROF to make sysprof collect the event. */<br> ptrace(PTRACE_CONT, chpid, 0, SIGPROF);<br><br>================================================================================<br><br>> > +<br><br><snipped><br><br>--<br>Best regards,<br>IM</div></div></div></div></blockquote><div> </div></div></blockquote></BODY></HTML>