search

eclipse / omr

Eclipse OMR™ Cross platform components for building reliable, high performance language runtimes
http://www.eclipse.org/omr
Other
945 stars 396 forks source link

[omrintrospect] Implement stack backtracing support on OSX #3506

Open babsingh opened 5 years ago

babsingh commented 5 years ago

The following omrintrospect functions are not implemented on OSX:

EricYangIBM commented 2 years ago

I am running into an issue with task_threads: https://github.com/eclipse/omr/blob/master/port/osx/omrintrospect.c#L142 When I print out the data->threadList returned by it the first thread (mach_port_t) is always 775 and the corresponding pthread does not exist in the avl tree created in javadump.cpp::writeThreadsWithNativeStacks. Also it is not the current thread/failing thread, which it is supposed to be. I'm not sure what this 775 thread is and if I should skip it or replace it with the current thread (which is in the data->threadList)

babsingh commented 2 years ago

https://developer.apple.com/documentation/kernel/1537751-task_threads

kern_return_t task_threads(task_inspect_t target_task, thread_act_array_t *act_list, mach_msg_type_number_t *act_listCnt);

Currently, in our code, data->threadList is of type thread_act_port_array_t. As per the above doc, it should be of type thread_act_array_t. Also, confirm if other input parameters to task_threads are valid.

Also, we need to suspend the entire task before suspending individual threads in order prevent the task from creating new threads: https://developer.apple.com/documentation/kernel/1538100-task_suspend

if (KERN_SUCCESS == task_suspend(task)) {

After suspending all the threads, we will need to resume the task: https://developer.apple.com/documentation/kernel/1537977-task_resume

if (KERN_SUCCESS == task_resume(task)) {
EricYangIBM commented 2 years ago

task_suspend stops the current thread from executing and hangs the process

EricYangIBM commented 2 years ago

Update: got javacore to output not only anonymous native threads and also got the correct current thread javacore.txt Trying to figure out why all native stacks are the same.

EricYangIBM commented 2 years ago

The reason why all native stacks look the same is because backtrace is called by the current thread every time. I'm trying to get the backtrace call inside the upcallHandler like in the unix case but siginfo->si_value.sival_ptr is null (which is needed to get the PlatformWalkData to pass to introspect_backtrace_thread). Looking into setting a global variable to get this data

babsingh commented 2 years ago

Trying to figure out why all native stacks are the same.

You're correct. backtrace will give the native stack of the thread which invokes it. To get the correct native stack for each thread, backtrace needs to be invoked from each individual thread.

Currently, osx/omrintrospect.c has getThreadContext -> Sends SUSPEND_SIG == SIGUSR1 to a thread -> Invokes upcallHandler -> Stores context which is read in setupNativeThread. Does signalHandlerContext (ucontext_t instance) provide any valuable information to generate the native stack on OSX?

We can try the approach in https://github.com/eclipse/omr/blob/master/port/unix/omrintrospect.c where the upcall_handler ends up calling backtrace. If we take this approach,

babsingh commented 2 years ago

re https://github.com/eclipse/omr/issues/3506#issuecomment-984036440:

running into an issue with task_threads

https://github.com/eclipse/omr/issues/16 reports a potential race condition related to suspendAllPreemptive() -> task_threads():

-- Does this function assume that task_threads() will always return >= the previous number of threads? What prevents a thread from exiting between the calls to task_threads() and thread_suspend()? Can you suspend a thread that has exited? Does task_threads() always return threads in the same order? Can you suspend a thread twice? -- If this function encounters an error, then the runtime is stuck in a permanently bad state, correct?

Since we have already started to notice issues related to the above code, we can also monitor the occurrences of the above-mentioned race condition. If the race condition is existent, then we will need to come up with solutions to avoid it.

EricYangIBM commented 2 years ago

Does signalHandlerContext (ucontext_t instance) provide any valuable information to generate the native stack on OSX?

No, threadInfo->context is never used in omrintrospect_backtrace_thread_raw

EricYangIBM commented 2 years ago

Backtrace is working now for all threads: threads_section.txt A linux javacore's current thread section has the crashing symbol Java_jdk_internal_misc_ScopedMemoryAccess_closeScope0+0x18 but osx doesn't. I think it is the address below _sigtramp+0x1d ((0x0000000010989900 [<unknown>+0x0])) Also linux crashes produce a stack backtrace to std out without signal handler frames:

----------- Stack Backtrace -----------
Java_jdk_internal_misc_ScopedMemoryAccess_closeScope0+0x18 (0x00007FCCE8E660C8 [libjclse29.so+0x580c8])
(0x00007FCCEA60865A [libj9vm29.so+0x1a865a])
(0x00007FCCEA60693C [libj9vm29.so+0x1a693c])
(0x00007FCCEA503466 [libj9vm29.so+0xa3466])
(0x00007FCCEA4F20D5 [libj9vm29.so+0x920d5])
(0x00007FCCEA595412 [libj9vm29.so+0x135412])
---------------------------------------

Whereas currently for osx it shows all frames. Will look into why the faulting address isn't found during backtrace.

EricYangIBM commented 2 years ago

The backtrace library call itself is not producing all of the stack frames; many of the earlier frames were not generated. I debugged the core files using lldb and found 17 frames at the bottom of the stack that were not found in the backtrace output. The faulting address was also found in the core but not in backtrace output. The only reason I could find for this is the signal handler modifying the stack upon segfault: https://stackoverflow.com/questions/52693431/backtrace-info-different-on-macos-v-s-linux The other (non-faulting) threads have correct backtrace outputs (all the way to thread_start)

*Actually, it seems like linux javacores also omit many of the bottom frames that are present in gdb backtrace. So the only issue is that the faulting address is not present

EricYangIBM commented 2 years ago

If it's true that macos modifies the stack upon signal handler call and return, then I don't see a way to get the correct faulting address to discard the signal handler frames. I tried to look for the signal handler address (as in _sigtramp's address) but I'm not sure how to find it.

babsingh commented 2 years ago

@EricYangIBM, you have made excellent progress.

re https://stackoverflow.com/questions/52693431/backtrace-info-different-on-macos-v-s-linux:

First, none of the functions you call in your handler are valid to call from a signal handler. Therefore, you're completely in undefined behavior territory.

We can explore the libunwind API. Unlike backtrace, it is thread-safe and signal-safe. It may give us more flexibility. @EricYangIBM Can you verify the following points?

libunwind: https://www.nongnu.org/libunwind/man/libunwind(3).html

Although https://github.com/eclipse/omr/pull/3843 was not merged, it specifies the build system changes and sample code changes for using libunwind.

Just to confirm: the below code won't get the correct faulting address for the modified stack of the signal handler call? https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/linux/omrosbacktrace_impl.c#L134-L140

Backup your current work in a separate branch before looking into libunwind. We may come back to it or use it as reference.

EricYangIBM commented 2 years ago

That code gets the correct address but it does not show up in backtrace probably because of the signal handler modifying stack frames, therefore it never matches addresses[i] == *faultingAddress. The javacore and terminal output show the correct faulting address:

1XHEXCPMODULE  Module: /Users/jenkins/babsing/openj9-openjdk-jdk17/build/macosx-x86_64-server-release/images/jdk/lib/default/libjclse29.dylib
1XHEXCPMODULE  Module_base_address: 00000000056AC000
1XHEXCPMODULE  Symbol: Java_jdk_internal_misc_ScopedMemoryAccess_closeScope0
1XHEXCPMODULE  Symbol_address: 00000000056F75F0

so it is a problem with signal handling and backtrace.

EricYangIBM commented 2 years ago

The problem with using libunwind is that it will still be called during signal handling for the current/failing thread - which is the only one we are discarding signal handler frames from given a faulting address. If the omrintrospect functions are called after the sigsegv handler then it doesn't matter what we use to get the stack frames since the signal handling modifies the stack on entry and return. Therefore I don't believe there is an easy way to get the correct backtrace unless we can somehow see how the signal handler modified the stack

babsingh commented 2 years ago

libunwind may account for the stack changes that are done during signal handling. Can we write a small micro-test to verify that libunwind will behave similar to backtrace when called during signal handling for the current/failing thread?

babsingh commented 2 years ago

Also, on Linux, we set the context of the current thread differently: https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/unix/omrintrospect.c#L1429-L1438 getcontext is also available on OSX. Will this help us to get the correct backtrace for the current/failing thread?

EricYangIBM commented 2 years ago

state->current_thread->context is not used in the backtrace functions, also I think it is the same as OMRUnixSignalInfo.platformSignalInfo.context

EricYangIBM commented 2 years ago

I have produced the correct native stack trace for the stdout output with libunwind:

----------- Stack Backtrace -----------
Java_jdk_internal_misc_ScopedMemoryAccess_closeScope0+0x1b (0x000000000A02160B [libjclse29.dylib+0x4b60b])
ffi_call_unix64+0x52 (0x0000000007CBD952 [libj9vm29.dylib+0x263952])
ffi_call_int+0x33e (0x0000000007CBCFAE [libj9vm29.dylib+0x262fae])
_ZN32VM_BytecodeInterpreterCompressed3runEP10J9VMThread+0x1d46d (0x0000000007B02F1D [libj9vm29.dylib+0xa8f1d])
bytecodeLoopCompressed+0x8d (0x0000000007AE5A9D [libj9vm29.dylib+0x8ba9d])
---------------------------------------

I tried to use libunwind to get the backtrace for all threads but I could not capture the entire stack for the non failing threads (they stop at the signal handler _sigtramp): libunwind_all.txt Using libunwind only for the failing thread I can get more stack information with the non failing threads: libunwind_failing.txt

So I think we should only use libunwind for the failing thread and backtrace for the rest. Also, libunwind was unable to obtain all the earlier stack frames (it stops at bytecodeLoopCompressed) but it is comparable to the linux implementation so I think it is enough.

EricYangIBM commented 2 years ago

Question, why does the unix and osx implementations call introspect_backtrace_threads if it fails in the upcall handler? https://github.com/eclipse/omr/blob/master/port/unix/omrintrospect.c#L1445 introspect_backtrace_threads is called inside the upcall handler by the thread we want to backtrace. If it fails, why are we calling introspect_backtrace_threads from the controller/filter thread? This will get the backtrace of the controller/filter thread (and put it inside state->current_thread->callstack, mismatching the native thread and its callstack). I think we should only call https://github.com/eclipse/omr/blob/master/port/unix/omrintrospect.c#L1450 if it is the controller thread.

babsingh commented 2 years ago

re https://github.com/eclipse/omr/issues/3506#issuecomment-991107820:

Let's create a PR with the proposed changes.

The preference will be to use an API consistently throughout the implementation: either backtrace or libunwind. libunwind has an upper hand since it is signal-safe and thread-safe. We can try to troubleshoot via experiments to get libunwind to work correctly for non failing threads. We will have to look at the working of the API and existing examples to verify if we are using libunwind correctly. If we are unable to make any progress on this front, then we can propose a mixture of backtrace or libunwind.

EricYangIBM commented 2 years ago

PR here: https://github.com/eclipse/omr/pull/6267

babsingh commented 2 years ago

re https://github.com/eclipse/omr/issues/3506#issuecomment-991116297:

why does the unix and osx implementations call introspect_backtrace_threads if it fails in the upcall handler?

Unix

https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/unix/omrintrospect.c#L1572-L1579

Referring to the above code, there are two instances where SUSPEND_SIG is masked in the Unix implementation. In both instances, the thread which iterates over the native threads won't receive the SUSPEND_SIG signal. For this thread, upcall_handler won't be invoked. Instead, introspect_backtrace_threads will be invoked from setup_native_thread.

This code has not changed since 2009 (first contribution). The code is little cryptic. It does not highlight the reasons for invoking introspect_backtrace_threads outside upcall_handler. The code assumes that upcall_handler will successfully set the callstack for all threads except for the thread iterating over all native threads. As you noted, there is a bug over here. If upcall_handler fails for any reason, then we will incorrectly set the wrong native stack for a thread. This behaviour was noticed on OSX where upcallHandler does not invoke introspect_backtrace_threads currently. We need better control logic in setup_native_thread so that introspect_backtrace_threads is only invoked for the thread which is iterating over all the native threads. Assuming that we only need to invoke introspect_backtrace_threads outside upcall_handler for the iterator thread. If my understanding is correct, the new control logic to invoke introspect_backtrace_threads outside upcall_handler will be as follows:

/* upcall_handler is not invoked for the iterator thread. */
if (state->current_thread->thread_id == omrthread_get_ras_tid()) {
     /* Retrieve the backtrace for the iterator thread if absent. */
     if (state->current_thread->callstack == NULL) {
         ...

OSX

On OSX, we suspend all threads except the one thread which is iterating over all the native threads. https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/osx/omrintrospect.c#L148-L156

Unlike Unix, we send SUSPEND_SIG to the iterator thread even though it is not suspended: https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/osx/omrintrospect.c#L290-L292

What happens if we do not send SUSPEND_SIG to the iterator thread on OSX? In this case, we do not want to invoke getThreadContext for the iterator thread. This will prevent upcallHandler from being invoked. Instead, we want to invoke introspect_backtrace_thread from setupNativeThread. getcontext will be required to get the iterator thread's context, which gets passed to introspect_backtrace_thread.

EricYangIBM commented 2 years ago

We don't send the signal to the iterator thread because we pass signal_info to setupNativeThread and skips getThreadContext: https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/osx/omrintrospect.c#L239. So it is the same as unix, for now I have put

if (data->filterThread == data->threadList[data->threadIndex]) {

as a condition for the instrospect_backtrace_thread in setupNativeThread.

babsingh commented 2 years ago

Is it always guaranteed that signal_info will be non-null + valid?

babsingh commented 2 years ago

https://github.com/eclipse-openj9/openj9/blob/ff268e520c907fdac24821b116866b5bd1770c84/runtime/rasdump/javadump.cpp#L2301-L2308

    if ((NULL != vmThread) && (NULL != vmThread->gpInfo)) {
        /* Extract the OS thread */
        closure.gpInfo = vmThread->gpInfo;

        returnValue = j9sig_protect(protectedStartDoWithSignal, &closure, handlerNativeThreadWalk, this, J9PORT_SIG_FLAG_SIGALLSYNC | J9PORT_SIG_FLAG_MAY_RETURN, (UDATA*)&nativeThread);
    } else {
        returnValue = j9sig_protect(protectedStartDo, &closure, handlerNativeThreadWalk, this, J9PORT_SIG_FLAG_SIGALLSYNC | J9PORT_SIG_FLAG_MAY_RETURN, (UDATA*)&nativeThread);
    }

In case of protectedStartDo -> omrintrospect_threads_startDo, signal_info will be NULL.

EricYangIBM commented 2 years ago

Ok, I think we should add an extra condition

if (state->current_thread->thread_id == omrthread_get_ras_tid())

and getcontext like in unix.

EricYangIBM commented 2 years ago

Also, I think there may be another bug in the unix implementation: https://github.com/eclipse/omr/blob/master/port/unix/omrintrospect.c#L1436-L1438 This will never be executed since if (heapAllocate || sigContext) { will always be false for other threads (since nextDo calls result = setup_native_thread(state, NULL, 0);; only startDo calls it with nonnull second and third args for the iterator thread. Therefore } else if (state->current_thread->thread_id == omrthread_get_ras_tid()) { will always be true

babsingh commented 2 years ago

For test coverage, we want cover both the code paths mentioned in https://github.com/eclipse/omr/issues/3506#issuecomment-991297995: protectedStartDo and protectedStartDoWithSignal.

I think

babsingh commented 2 years ago

re https://github.com/eclipse/omr/issues/3506#issuecomment-991307585:

Our limited usage of setup_native_thread stops the below code from ever executing: https://github.com/eclipse/omr/blob/5a958d70833bf7e3c5c71b11cf905ca14498686e/port/unix/omrintrospect.c#L1436-L1438

But, setup_native_thread is a standalone function, which can also be invoked as setup_native_thread(state, NULL, 1). If invoked in such manner from omrintrospect_threads_nextDo where (state->current_thread->thread_id == omrthread_get_ras_tid()) won't be true, then the above mentioned code will be exercised.

Rather than a bug, it is an unused capability of setup_native_thread, which adds completeness to its implementation.

EricYangIBM commented 2 years ago

Currently with unw_init_local only the signal handler frames are returned. I tried using unw_init_remote_thread to get the stack for a different thread but it seems like remote backtracing is not implemented on osx:

Undefined symbols for architecture x86_64:
  "_unw_init_remote_thread", referenced from:
      _omrintrospect_backtrace_thread_raw in omrosbacktrace_impl.c.o
  "_unw_local_addr_space", referenced from:
      _omrintrospect_backtrace_thread_raw in omrosbacktrace_impl.c.o
ld: symbol(s) not found for architecture x86_64

Also, see https://reviews.llvm.org/D57252 Given that we can't unwind a different thread's stack, we must call the introspect_backtrace functions from a signal handler so I'm not sure what else I can change with libunwind. Maybe I could try unw_getcontext from the signal handler and pass it in a new field for J9PlatformThread and pass it to unw_init_local

babsingh commented 2 years ago

Maybe I could try unw_getcontext from the signal handler and pass it in a new field for J9PlatformThread and pass it to unw_init_local

Invoking introspect_backtrace_thread from the signal handler looks equivalent to invoking unw_getcontext from the signal handler. How will it be different to invoke unw_getcontext directly from the signal handler?

In our code, upcallHandler matches the handler in the sigaction documentation. The third argument is an instance of ucontext_t.

void upcallHandler(int signal, siginfo_t *siginfo, void *context)

void handler(int, siginfo_t *info, ucontext_t *uap);

As per unw_getcontext documentation,

On IA-64, unw_context_t has a layout that is compatible with that of ucontext_t and such structures can be initialized with getcontext() instead of unw_getcontext(). However, the reverse is not true and it is not safe to use structures initialized by unw_getcontext() in places where a structure initialized by getcontext() is expected. The reason for this asymmetry is that unw_getcontext() is optimized for maximum performance and does not, for example, save the signal mask.

If the ucontext_t received by the upcallHandler is valid, what kind of native stack does it yield when passed as unw_context_t to the libunwind API? Similarly, does the libunwind API give the same native stack with getcontext() and unw_getcontext()?

EricYangIBM commented 2 years ago

I forgot to mention that getcontext is deprecated on osx so I think the only way to get context of a thread is from the signal handler.

EricYangIBM commented 2 years ago

I have tried calling unw_getcontext directly from the signal handler and pass it to introspect_backtrace but it only captured the signal handler frame. I have also tried using the sigaction ucontext parameter for unw_init_local but it didn't work (0 frames to walk).

babsingh commented 2 years ago

For the observation in https://github.com/eclipse/omr/issues/3506#issuecomment-991107820: I found that libunwind does not support signal trampoline on OSX i.e. the API stops iterating through native stacks once _sigtramp is encountered.

Potential fix: In libunwind, we iterate via unw_step(&cursor). Once _sigtramp is encountered while iterating, we can manually update the cursor to point at the frame preceding _sigtramp. Then, continue iterating frames via unw_step(&cursor). Manually updating the cursor will require us to update the following regs: ip, rsp, rbp, rdi, rsi, rax, rbx, rcx, rdx and r8-r15 using unw_set_reg. At _sigtramp, the previous frame info is available through ((ucontext_t *)rbx)->uc_mcontext; rbx can be read using unw_get_reg. You can use existing API, infoForGPR and infoForControl, to extract reg info from uc_mcontext.

EricYangIBM commented 2 years ago

Latest commit in my PR successfully iterates frames beyond _sigtramp. Other than some cleanup, I believe this is everything for the implementation. javacore.txt