Fix profiling on OS X #4159

Keno · 2013-08-26T20:47:57Z

Fixes #3971 .

Apple's version of libunwind does not handle the case when we're in a prologue or epilogue. This introduces a modified version that adds support for that where possible. Note that you will still experience segfaults if you are using Clang < 3.3 as there was a bug in the way LLVM generates the Compact Unwind Info in prior versions.

Apart from that, this also replaces the SIGALRM based version of the profiler with a Mach-based one to reduce interference with libraries that may make use of SIGALRM as well as preventing the profiler from being blocked by blocking that signal.

StefanKarpinski · 2013-08-26T21:01:33Z

Seems to work on my system. Do we have any code that we know this didn't work for before?

blakejohnson · 2013-08-26T21:04:23Z

I'll try it on some previously failing cases.

Keno · 2013-08-26T21:08:45Z

@blakejohnson Make sure you're running a version of Clang > 3.2. Otherwise, you might still see segfaults.

blakejohnson · 2013-08-27T01:09:08Z

Indeed, with latest Apple build of Clang (Apple LLVM version 4.2 (clang-425.0.24)), I still see segfaults.

Is the homebrew recipe up to date for Clang?

Keno · 2013-08-27T01:12:01Z

@blakejohnson You can just set BUILD_LLVM_CLANG = 1 in your Make.user and use that clang.

blakejohnson · 2013-08-27T01:24:24Z

Once I have an up to date Clang, what needs to be recompiled? libosxunwind, libjulia, ...?

Keno · 2013-08-27T01:53:04Z

Everything you want to profile.

ViralBShah · 2013-08-27T02:16:15Z

All the failures I have seen are in openblas.

blakejohnson · 2013-08-27T03:15:10Z

I haven't had time this evening to rebuild everything, but my previously failing test spends most of its time in OpenBLAS, so I started with that. Unfortunately, it still segfaults at least 50% of the time. I'll try running it through GDB tomorrow to see if it is still crashing inside an OpenBLAS stack trace.

Keno · 2013-08-27T03:19:02Z

Can you give me a testcase?

ViralBShah · 2013-08-27T06:07:04Z

See: timholy/IProfile.jl#14

blakejohnson · 2013-08-27T12:45:09Z

@loladiro try https://gist.github.com/blakejohnson/6353018

blakejohnson · 2013-08-27T19:19:51Z

The backtraces are not very enlightening. Here's an example

Program received signal SIGSEGV, Segmentation fault.
[Switching to process 47725 thread 0x2503]
0x00000001009ecc13 in libunwind::CompactUnwinder_x86_64<libunwind::LocalAddressSpace>::stepWithCompactEncodingRBPFrame ()
(gdb) bt
#0  0x00000001009ecc13 in libunwind::CompactUnwinder_x86_64<libunwind::LocalAddressSpace>::stepWithCompactEncodingRBPFrame ()
#1  0x00000001009eacf1 in libunwind::UnwindCursor<libunwind::LocalAddressSpace, libunwind::Registers_x86_64>::step ()
#2  0x00000001000e2a55 in rec_backtrace_ctx (data=0x104036d68, maxsize=971922, uc=0x107fd0a38) at task.c:561
#3  0x00000001000f5bd5 in mach_profile_listener (arg=0x0) at profile.c:155
#4  0x00007fff8d16d8bf in _pthread_start ()
#5  0x00007fff8d170b75 in thread_start ()

Keno · 2013-08-27T19:49:48Z

I know what the problem is. I'll have a patch momentarily.

See the comment in src/profile.c for an explanation for what this is doing

Keno · 2013-08-27T20:23:31Z

PR Updated

blakejohnson · 2013-08-27T21:18:59Z

That does seem to do the trick. I now see "unrooted" backtraces like what we have on linux #3469, but this is worlds better than segfaulting.

Awesome work, Keno.

Keno · 2013-08-27T21:36:40Z

I'll have a look at the truncated backtraces issue.

Keno · 2013-08-27T22:16:27Z

Alright, re: truncated backtraces, I know what the issue is, but there is now way to fix it in general without implementing a full x86_64 emulator (which is what e.g. lldb does - and to some extent so do I in libosxunwind). I can however fix at least OpenBlas to generate the necessary debug information (on Mac at least, on linux you'd have to create DWARF debug info).

StefanKarpinski · 2013-08-27T22:22:40Z

Why the #@$! is generating backtraces so damned hard?!? There's a standard for this and it's just a linked list. Why can't compilers just respect that when you ask them to? Ugh.

timholy · 2013-08-27T22:23:44Z

Really nice work, @loladiro!

Keno · 2013-08-27T22:38:11Z

@StefanKarpinski there's two problems with that:

You might currently be at an instruction modifying the linked list (what now?)
x86_64 doesn't actually have a frame chain

Both issues are solvable if you know the function boundaries and what registers are being saved since you can use some highly successful heuristics (I'm doing this in libosxunwind). However, as mentioned, that requires some debug information about the function. Libunwind (the non-OSX version), has some heuristics for doing unwinding without debug info if the function does happen to use a frame chain, but that is really just in there because of signal handlers and PLT as in general if your function doesn't have debug info it's also not very likely to adhere to the frame chain.

blakejohnson · 2013-08-27T22:39:25Z

I previously noticed that OpenBLAS uses bizarre prologue/epilogue conventions in its Mac asm kernels. Is that what you are looking to fix?

Regarding truncated backtraces in general: where there is a straightforward fix, I would grab it. But, they are generally rare enough in practice to not make a significant difference in profiling or other uses. So, I don't think it would be worth the effort to fix all instances.

On Tuesday, August 27, 2013 at 6:16 PM, Keno Fischer wrote:

Alright, re: truncated backtraces, I know what the issue is, but there is now way to fix it in general without implementing a full x86_64 emulator (which is what e.g. lldb does - and to some extent so do I in libosxunwind). I can however fix at least OpenBlas to generate the necessary debug information (on Mac at least, on linux you'd have to create DWARF debug info).

—
Reply to this email directly or view it on GitHub (#4159 (comment)).

Keno · 2013-08-27T22:40:23Z

@blakejohnson It's a question of adding an extra Mach-0 section (32bits/ function so I think it's ok).

Fix profiling on OS X

blakejohnson · 2013-08-28T01:02:09Z

@loladiro I'm rather naive about these things, but OpenBLAS defines PROLOGUE and EPILOGUE like so

#define PROLOGUE .text;.align 5; .globl REALNAME; REALNAME:
#define EPILOGUE    .subsections_via_symbols

and I guess I was expecting to see .cfi_startproc at the end of the PROLOGUE, and .cfi_endproc in the EPILOGUE, as I've read that those are necessary to get the compiler to generate .eh_frame information.

Keno · 2013-08-28T01:05:55Z

That's one thing that's necessary, but it might not be sufficient, since I don't know if the system assembler will generate compact unwind info and unfortunately due to (what I assume to be) a liker bug, the unwinder expects the function to have compact unwind info.

vtjnash · 2013-08-28T01:24:33Z

src/profile.c

+            if (forceDwarf == 0) {
+                // Save the backtrace
+                bt_size_cur += rec_backtrace_ctx((ptrint_t*)bt_data_prof+bt_size_cur, bt_size_max-bt_size_cur-1, &uc);
+            } else if(forceDwarf == 1) {


i don't think you want else here

I do. It jumps back to unw_getcontext on segv.

oh, i see you are using unw_getcontext/unw_setcontext profiler_uc as a setjmp/longjmp jmp_buf. so this is correct. perhaps a comment here may be useful?

I thought that was covered by the if that results in a segfault, we retry with DWARF info.

but I guess I can add a comment explicitly mentioning it being a jump buffer.

blakejohnson · 2013-08-28T01:26:20Z

I guess we'll have to to try it and find out what the assembler does.

Do you have any interest in submitting a bug report to Apple w.r.t. their libunwind implementation? I had started writing something a while back, but had only gotten as far as recognizing that there was a problem, whereas you have actually fixed it :).

BobPortmann · 2013-09-03T23:18:29Z

I had to revert commit 924fb0f on Mac OSX 10.6.8 in order to compile julia. Otherwise I get the error:

make[3]: Circular src/libuwind.cxx <- src/libuwind.cxx.o dependency dropped.
cc1plus: error: unrecognized command line option "-std=c++11"
make[3]: *** [src/libuwind.cxx.o] Error 1
make[2]: *** [libosxunwind-0.0.1-rc3/libosxunwind.dylib] Error 2
make[1]: *** [julia-release] Error 2
make: *** [release] Error 2

Keno · 2013-09-03T23:21:34Z

Try updating gcc.

staticfloat · 2013-09-03T23:53:24Z

@loladiro would clang maybe work as well?

Keno · 2013-09-03T23:56:51Z

Yes, clang does work, but I thought clang was the default on OS X (meaning that @BobPortmann would have had to explicitly change it, hence I didn't suggest it).

BobPortmann · 2013-09-03T23:57:51Z

I am on OSX 10.6 where gcc is the default. I was under the impression that clang did not work on 10.6.

staticfloat · 2013-09-04T00:02:57Z

@BobPortmann it depends on what version of clang you have installed, which depends on how old your Xcode/CLI tools are. It's been a while since I've been on 10.6 so I can't verify that it will work, but that is probably easier than building/installing a new GCC.

BobPortmann · 2013-09-04T01:51:58Z

When I try using gcc 4.7.3 from Macports I get the error

src/unw_getcontext.s:219:invalid character '_' in mnemonic
src/unw_getcontext.s:220:invalid character '_' in mnemonic
src/unw_getcontext.s:221:invalid character '_' in mnemonic
src/unw_getcontext.s:223:no such instruction: `li r3, 0'
src/unw_getcontext.s:223:no such instruction: `return UNW_ESUCCESS'
src/unw_getcontext.s:224:no such instruction: `blr'
make[3]: *** [src/unw_getcontext.s.o] Error 1
make[2]: *** [libosxunwind-0.0.1-rc3/libosxunwind.dylib] Error 2
make[1]: *** [julia-release] Error 2
make: *** [release] Error 2

I have not tried using clang yet but the version on 10.6 is very old. I could try the Macports version. I thought there was a reason for the default being gcc on 10.6?

StefanKarpinski · 2013-09-04T11:28:58Z

I'm pretty sure that's the reason – because 10.6's clang is so old.

ViralBShah · 2013-09-06T19:55:59Z

10.6 does not even have clang, IIRC.

BobPortmann · 2013-09-07T03:12:36Z

Crow julia> uname -v
10.6 does seem to have clang:

uname -v
Darwin Kernel Version 10.8.0: Tue Jun 7 16:33:36 PDT 2011; root:xnu-1504.15.3~1/RELEASE_I386
where clang
clang is /usr/bin/clang
clang -v
Apple clang version 1.6 (tags/Apple/clang-70)
Target: x86_64-apple-darwin10
Thread model: posix

BobPortmann · 2013-09-07T03:15:07Z

sorry that got munged:

> uname -v
Darwin Kernel Version 10.8.0: Tue Jun  7 16:33:36 PDT 2011; root:xnu-1504.15.3~1/RELEASE_I386
> where clang
clang is /usr/bin/clang
> clang -v
Apple clang version 1.6 (tags/Apple/clang-70)
Target: x86_64-apple-darwin10
Thread model: posix

Keno added 3 commits August 26, 2013 16:43

Fancy Mac Profiler

b510c8c

Don't skip frames

c0eac16

Use modified version of Apple's libunwind

72d2154

Add Profiler equivalent of 'On Error Resume Next'

8b74988

See the comment in src/profile.c for an explanation for what this is doing

Use KERN_INVALID_ARGUMENT instead of magic -309

9c56286

Keno added a commit that referenced this pull request Aug 28, 2013

Merge pull request #4159 from JuliaLang/kf/profile

924fb0f

Fix profiling on OS X

Keno merged commit 924fb0f into master Aug 28, 2013

vtjnash reviewed Aug 28, 2013
View reviewed changes

BobPortmann mentioned this pull request Sep 24, 2013

Binary of Julia Beta v0.2-prerelease does not work on Mac OS X 10.6 #4215

Closed

StefanKarpinski deleted the kf/profile branch November 16, 2013 16:43

maleadt mentioned this pull request Jul 26, 2018

Ignore SEGV during profiler unwind on Unix #28291

Merged

timholy mentioned this pull request Sep 17, 2018

Profiler segmentation fault #28648

Closed

Fix profiling on OS X #4159

Fix profiling on OS X #4159

Conversation

Keno commented Aug 26, 2013

StefanKarpinski commented Aug 26, 2013

blakejohnson commented Aug 26, 2013

Keno commented Aug 26, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

ViralBShah commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

ViralBShah commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

Keno commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

Keno commented Aug 27, 2013

StefanKarpinski commented Aug 27, 2013

timholy commented Aug 27, 2013

Keno commented Aug 27, 2013

blakejohnson commented Aug 27, 2013

Keno commented Aug 27, 2013

blakejohnson commented Aug 28, 2013

Keno commented Aug 28, 2013

vtjnash Aug 28, 2013

Choose a reason for hiding this comment

Keno Aug 28, 2013

Choose a reason for hiding this comment

vtjnash Aug 28, 2013

Choose a reason for hiding this comment

Keno Aug 28, 2013

Choose a reason for hiding this comment

Keno Aug 28, 2013

Choose a reason for hiding this comment

blakejohnson commented Aug 28, 2013

BobPortmann commented Sep 3, 2013

Keno commented Sep 3, 2013

staticfloat commented Sep 3, 2013

Keno commented Sep 3, 2013

BobPortmann commented Sep 3, 2013

staticfloat commented Sep 4, 2013

BobPortmann commented Sep 4, 2013

StefanKarpinski commented Sep 4, 2013

ViralBShah commented Sep 6, 2013

BobPortmann commented Sep 7, 2013

BobPortmann commented Sep 7, 2013