DynamoRIO crashes when detaching using drconfig -detach

[jackgallagher-arm]

We have been trying to trace an already running process using drrun -attach and detach from it again using drconfig -detach but DynamoRIO crashes during the detach.
Using debug builds I have seen a few asserts failing including:

core/unix/signal.c:2826 mc != NULL && sc != NULL

core/unix/signal.c:1512 sigsegv_handler_is_ours() || removed_sig_handler

This was discovered on AArch64 Linux but might effect other platforms too.

This can be reproduced with simple applications. I have been using the linux.infloop test app:

cd dynamorio-build-dir
suite/tests/bin/linux.infloop &
bin64/drrun -attach $(jobs -p %1) &
bin64/drconfig -detach $(jobs -p %1)

[jackgallagher-arm]

I have been trying to debug this and these are the steps I observe happening:

The nudge signal is sent by dr_config and delivered to the process.
The nudge signal is delivered by the kernel which calls DynamoRIO's signal handler on one of the threads in the process.

In my testing I have seen that the nudge signal is delivered by the kernel during a syscall. The signal context PC corresponds to the ret instruction that follows the svc in dynamorio_syscall().

Inside that signal handler it stashes away a pointer to the signal context in the thread data structure for the current thread.

#ifdef LINUX
            sig_full_initialize(&sc_full, ucxt);
            ostd->nudged_sigcxt = &sc_full;
#endif

The signal handler interprets the signal as a detach nudge and queues up the nudge to be handled on the next iteration of the dispatch loop.

The signal handler then returns, the kernel finishes handling the syscall and the thread resumes after the svc.

Later the thread handles the detach nudge. detach_externally_on_new_stack()
triggers any other threads to go native, cleans up DynamoRIO's state and lastly it switches its own context to go native using the signal state from the nudge signal.

At first I saw an assert failing during the detach process:

core/unix/signal.c:2826 mc != NULL && sc != NULL

This happened when the nudge handler tried to convert the stashed nudged_sigcxt to a priv_mcontext_t because the signal context pointer that was stored in the thread data was pointing to memory on the signal stack and is now a dangling pointer.

I tried changing it to make a copy of the signal context on the heap instead, and that allowed us to get past the assert but the application still crashed as soon as the thread goes native.

Thinking about this more it seemed to me that the signal context is not the context we should actually be switching to. nudged_sigcxt is the context that the nudge signal returns to (dynamorio_syscall() in my testing, but it could be somewhere else). The signal has already returned and continued executing the thread so by the time we detach this context is stale.

I tried changing detach_externally_on_new_stack() to use the mcontext for the thread instead.

diff --git a/core/synch.c b/core/synch.c
index eba8fb5b6..860b8db69 100644
--- a/core/synch.c
+++ b/core/synch.c
@@ -2384,8 +2384,7 @@ detach_externally_on_new_stack()
         if (threads[i]->dcontext == my_dcontext) {
             my_idx = i;
             my_tr = threads[i];
-            DEBUG_DECLARE(ok =)
-            thread_get_nudged_mcontext(threads[i], &my_mcontext);
+            my_mcontext = *get_mcontext(my_dcontext);
             DEBUG_DECLARE(ok =)
             translate_mcontext(threads[i], &my_mcontext, true /*restore mem*/,
                                NULL /*f*/);

This represents the current app state of the thread which is the context we want to actually resume.

With that change DynamoRIO appears to be able to detach from the process now, but not reliably.
Sometimes it succeeds, sometimes it crashes in DynamoRIO code during detach, sometimes it detaches then crashes in the native app code.

@derekbruening Have I correctly understood how this is supposed to work? Is there a situation where it makes sense to switch to the nudged_sigcxt state?

[derekbruening]

You can see from the history that nudge-triggered detach on Linux was added by @onroadmuwl in PR #6513 (before it only worked on Windows). (Internal-app-triggered detach has been used on Linux for a long time and is what we use extensively.). It does seem like mcontext should be used; not sure whether nudged_sigcxt was part of an earlier version of PR #6513 that didn't delay and so it made sense then, but I agree with you it seems to not be the right state to use.

[onroadmuwl]

@jackgallagher-arm, thanks for pointing this out. I re-evaluated your findings and agree that using get_mcontext is indeed a reasonable solution. In my earlier testing, when nudged_sigcxt was NULL, translate_mcontext succeeded because it invokes get_mcontext internally as a fallback.
I'd like to better understand the instability you mentioned after using get_mcontext directly. Could you share steps to reproduce the unexpected behavior? I’d be happy to help investigate this further.

[derekbruening]

@jackgallagher-arm how is client.detach_test passing on the Github Actions runs if this is broken? It passes on aarch64 and x86 Linux, right?

[derekbruening]

Xref other failures of this test: #6764 and #6536

Both have this test on the ignore list for x86: but PR #6780 put the #6764 ignore entry on the Linux 32-bit x86 instead of the Windows 32-bit x86 ignore list??

[jackgallagher-arm]

@jackgallagher-arm how is client.detach_test passing on the Github Actions runs if this is broken? It passes on aarch64 and x86 Linux, right?

I think we get different results depending on when the detach nudge gets delivered. My manual testing procedure is actually quite close to what client.detach_test does anyway. The main difference is that I have been running drrun with logging turned on.

I have seen log files where the nudge main_signal_handler: ... log message appears in the middle of another log message. I suspect the nudge signal is being delivered during a SYS_write syscall from the logging system. If I add -loglevel 2 to the dr_ops for the client.detach_test test then it reproduces the assert, however when I apply PR #7581 to fix the assert the test hangs.

runall.cmake is hanging waiting for the test to print "done.".
The detatch_test.dll client prints "detach" in event_pre_detach() then infloop prints "done." in its signal handler when it gets a SIGTERM.
runall.cmake sees "detach" and sends the SIGTERM using kill <infloop_pid>. I think there is a race between the detach process and the kill command.

If I add a short wait in runall.cmake after it detects "detach" before the kill then the test passes which is not the most robust fix but it confirms the race.

[jackgallagher-arm]

@jackgallagher-arm, thanks for pointing this out. I re-evaluated your findings and agree that using get_mcontext is indeed a reasonable solution. In my earlier testing, when nudged_sigcxt was NULL, translate_mcontext succeeded because it invokes get_mcontext internally as a fallback. I'd like to better understand the instability you mentioned after using get_mcontext directly. Could you share steps to reproduce the unexpected behavior? I’d be happy to help investigate this further.

Hi @onroadmuwl, thanks for commenting. I have been running this script to reproduce the issue. The script assumes it is being run from a DynamoRIO build directory.

suite/tests/bin/linux.infloop &

bin64/drrun -attach $(jobs -p %1) -loglevel 4 &
sleep 5
bin64/drconfig -detach $(jobs -p %1)
wait $(jobs -p)

You can also swap the infloop command for other workloads and I have found more complicated apps trigger issues more frequently.

For example:

python3 loop.py &

bin64/drrun -attach $(jobs -p %1) -loglevel 4 &
sleep 5
bin64/drconfig -detach $(jobs -p %1)
wait $(jobs -p)

where loop.py is:

for i in range(70000000):
    pass
print('done')

When running it with python I get a CURIOSITY assert and a segfault:

<Starting application /usr/bin/python3.8 (1471202)>
<Initial options = -no_dynamic_options -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct >
<get_memory_info mismatch! (can happen if os combines entries in /proc/pid/maps)
	os says: 0x0000fffd6905f000-0x0000fffd690df000 prot=0x00000003
	cache says: 0x0000fffd6905f000-0x0000fffd6909f000 prot=0x00000003
>
<received nudge mask=0x4 id=0x00000000 arg=0x0000000000000000>
<Detaching from application /usr/bin/python3.8 (1471202)>
<CURIOSITY : tdcontext != get_thread_private_dcontext() || (((OPTION_IS_INTERNAL_stress_recreate_pc)) ? ((((void)(((dynamo_options.checklevel >= (1)) && !(!((OPTION_IS_STRING_stress_recreate_pc)) || ((atomic_aligned_read_int(&(&options_lock)->num_readers) > 0) || self_owns_write_lock(&options_lock)))) ? (d_r_internal_error("/home/user/dynamorio/core/translate.c", 1032, "!((OPTION_IS_STRING_stress_recreate_pc)) || READWRITE_LOCK_HELD(&options_lock)"), 0) : 0)), dynamo_options.stress_recreate_pc)) : ((((dynamo_options.checklevel >= (1)) && !((0))) ? (d_r_internal_error("non-internal option argument " "stress_recreate_pc" " @" "/home/user/dynamorio/core/translate.c", 1032, "false"), (void)0) : (void)0), (((void)(((dynamo_options.checklevel >= (1)) && !(!((OPTION_IS_STRING_stress_recreate_pc)) || ((atomic_aligned_read_int(&(&options_lock)->num_readers) > 0) || self_owns_write_lock(&options_lock)))) ? (d_r_internal_error("/home/user/dynamorio/core/translate.c", 1032, "!((OPTION_IS_STRIN
version 11.90.20298, custom build
-no_dynamic_options -code_api -stack_size 56K -signal_stack_size 32K -max_elide_jmp 0 -max_elide_call 0 -no_inline_ignored_syscalls -native_exec_default_list '' -no_native_exec_managed_code -no_indcall2direct 
0x0000fffd68ef7e70 0x00000000711ff7a8
0x0000fffd68ef8000 0x0000000071201ec8
0x0000fffd68ef8100 0x0000000071202480
0x0000fffd68ef9550 0x00000000711d04f8
0x0000fffd68ef9590 0x00000000711d7a14
0x0000fffd68ef95f0 0x000000007144c064
0x0000fffd69168d90 0x000000007105bea8
0x0000fffd69168de0 0x00000000710afe14
0x0000fffd69168e70 0x00000000710af6a8
0x0000fffd69168f40 0x000000000056ac80
0x0000ffffcaba6fe0 0x00000000004feb60
0x0000ffffcaba7030 0x00000000004fc14c
0x0000ffffcaba71c0 0x000000000065f5e0
0x0000ffffcaba72c0 0x000000000064b690
0x0000ffffcaba72d0 0x000000000064b75c
/home/user/debug/lib64/debug/libdynamorio.so=0x0000000071000000>
<failed to translate>
<Detaching from process, entering final cleanup>
./reproduce.sh: line 7: 1471202 Segmentation fault      (core dumped) python3 loop.py

The CURIOSITY is coming from recreate_app_state_from_ilist() and I think it is related to this issue:

                    /* Prefix instructions are not added to recreate_fragment_ilist()
                     * FIXME: we should do so, and then we can at least restore
                     * our spills, just in case.
                     */

because the PC (before translation) corresponds a prefix instruction in the fragment.

The results seem to be affected by whether or not logging is enabled. Today it segfaults more often when logging is disabled.

I have tried checking for corrupted register state after detach by running a simple assembly program that sets all the registers to a known state and loops but it didn't show any corruption during detach (it did identify registers being zeroed during ptrace attach though #7577). Either my test app is not triggering the bug, or it is caused by memory corruption rather than register corruption.

All of my testing has been done on AArch64 Ubuntu 20.04/22.04.

[derekbruening]

We have the detach_state test which does systematic register state checks across detach. I would suggest adapting that for use with a nudge for thorough state checking. (For non-detach we have the drstatecmp extension but that doesn't help here.)

[onroadmuwl]

@derekbruening after further analyzing the original implementation of DynamoRIO’s detachment on AArch64, I’ve made several observations that may help analyze the root causes. Below is a summary of my findings:

prefix instructions are unlikely the cause

I don’t think the crash is caused by the prefix instructions (prefix entry) on AArch64. On AArch64, the prefix instruction is consistently structured as follows:

  ———— prefix entry: ————
  0x0000ffff3c61bc40  a9400780   ldp    (%x28)[16byte] -> %x0 %x1
  ———— normal entry: ————
  0x0000ffff3c61bc44  aa0103e7   orr    %xzr %x1 lsl $0x00 -> %x7
  0x0000ffff3c61bc48  f90000c1   str    %x1 -> (%x6)[8byte]

The prefix instructions primarily affect the values of %x0 and %x1 in the first instruction of the normal entry, which must be correctly restored by translate_mcontext. To verify translation correctness, I created a simple assembly program with fixed registers. The test shows that the register states were accurately translated; however, the error still occurred, which suggests that the error isn’t caused by prefix instructions.

crash in debug builds of DynamoRIO

There is a segmentation fault that appears only in debug builds of DynamoRIO — not in release builds. By analyzing logs and call stacks, I found that the crash happens during vmheap cleanup inside vmm_heap_unit_exit, specifically at this instruction:

os_heap_free(vmh->alloc_start, vmh->alloc_size, &error_code);
I initially suspected that the issue might be caused by an overlap between the vmheap and the newly allocated d_r_detachstack. However, after adding additional logging, I found that there is no such overlap.

d_r_detachstack start:fffd52f74000; d_r_detachstack end:fffd52f82000

vmh->start_addr:fffd52f82000; vmh->end_addr:ffff52f82000

I suspect there may be a bug in the Debug version of DynamoRIO that needs to be addressed. To make the function work in this version, I temporarily bypassed the crash by commenting out the call to dynamo_shared_exit and inserting the following check before the ASSERT of ASSERT(syscall_signal || safe_is_in_fcache(dcontext, pc, (byte *)sc->SC_XSP));

if (!(syscall_signal || safe_is_in_fcache(dcontext, pc, (byte *)sc->SC_XSP)))
    return;

Invalid memory access on resumption

The more critical issue lies in resuming memory access in certain programs, such as 605.mcf_s in SPEC CPU2017. I haven’t encountered this problem with applications like MySQL or Memcached. Analyzing the core dump with GDB, I found an invalid memory access at the following instruction:

(gdb) x/i $pc
=> 0x4052ac <primal_bea_mpp+452>:       str     x1, [x6]

Registers at the time:

(gdb) info registers
x0             0xffffe0daac10      281474454170640
x1             0xffff97c9bb20      281473228323616
x2             0xffff97c9bb20      281473228323616
x3             0x988711            9996049
x4             0x0                 0
x5             0x2                 2
x6             0x0                 0
x7             0xffff97c9bb20      281473228323616

The crash is caused by a zero value in the x6 register, which results in an invalid memory access.

Could you help me understand the possible causes and potential solutions for the last issue of invalid memory access? Specifically, is the incorrect translation problem due to memory that is newly allocated in the vmheap but not properly copied or mapped into the application’s heap?

Thanks.

[derekbruening]

Re: SIGSEGV at call to os_heap_free(): what is the precise instruction triggering SIGSEGV and what are the register and siginfo values? Is it the call instruction itself and the stack overflowed or is messed up, or what?

Re: post-detach crashes: it can be difficult to track such things back to the original error. It would be better to add systematic testing of all app state across the detach, as we do today for internal detach in the detach_state test. That test should be adapted and used with external detach as noted in #7576 (comment).

[onroadmuwl]

Thank you for your response. After further testing, I’ve observed that earlier versions of DynamoRIO (such as cronbuild-10.0.19755 and prior releases) correctly support MySQL workload detachment. However, this functionality no longer works as expected in the latest version.

[derekbruening]

Thank you for your response. After further testing, I’ve observed that earlier versions of DynamoRIO (such as cronbuild-10.0.19755 and prior releases) correctly support MySQL workload detachment. However, this functionality no longer works as expected in the latest version.

Please perform a binary search and identify the precise culprit change.