Using DTrace to get stack traces / profiling data on Rust

Question

I'm trying to get a nice flamegraph of my Rust code. Unfortunately, Xcode 8.3 doesn't support exporting profiling data anymore, so I've been trying to use DTrace to get the profiling data.

I have enabled debug info in my Cargo.toml for the release binaries:

[profile.release]
debug = true

Then I run the release binary (mybinaryname), and sample stack traces using DTrace:

sudo dtrace -n 'profile-997 /execname == "mybinaryname"/ { @[ustack(100)] = count(); }' -o out.user_stacks

The end result is something like this:

          0x10e960500
          0x10e964632
          0x10e9659e0
          0x10e937edd
          0x10e92aae2
          0x10e92d0d7
          0x10e982c8b
          0x10e981fc1
          0x7fff93c70235
          0x1
            1

For comparison, getting traces of iTerm2 gets me nice traces like this:

          CoreFoundation`-[__NSArrayM removeAllObjects]
          AppKit`_NSGestureRecognizerUpdate+0x769
          CoreFoundation`__CFRUNLOOP_IS_CALLING_OUT_TO_AN_OBSERVER_CALLBACK_FUNCTION__+0x17
          CoreFoundation`__CFRunLoopDoObservers+0x187
          CoreFoundation`__CFRunLoopRun+0x4be
          CoreFoundation`CFRunLoopRunSpecific+0x1a4
          HIToolbox`RunCurrentEventLoopInMode+0xf0
          HIToolbox`ReceiveNextEventCommon+0x1b0
          HIToolbox`_BlockUntilNextEventMatchingListInModeWithFilter+0x47
          AppKit`_DPSNextEvent+0x460
          AppKit`-[NSApplication(NSEvent) _nextEventMatchingEventMask:untilDate:inMode:dequeue:]+0xaec
          AppKit`-[NSApplication run]+0x39e
          AppKit`NSApplicationMain+0x4d5
          iTerm2`main+0x6e
          libdyld.dylib`start+0x1
          iTerm2`0x1
            1

Is it possible to get stack traces with debug info in Rust code? (Xcode's Instruments for sure can see the function names, so they are there!) If it is possible, do I need to do take some additional steps, or am I just doing something wrong?

Could it be related to [issue #24346](https://github.com/rust-lang/rust/issues/24346), referred to in [this question](http://stackoverflow.com/q/43303465/1233251)? — E_net4, Apr 18 '17 at 10:12
@E_net4 I don't think so. That issue refers to the backtrace functionality built into Rust itself. One of the workarounds listed there is to use a debugger, which better knows how to use the debug symbols to get the backtrace. Like OP shows, Instruments knows the symbols as well. — Shepmaster, Apr 18 '17 at 12:43
Is there a way of telling dtrace where to look for symbols? I wonder if there's something different about where Rust places the `.dSYM` files that causes dtrace to not be able to find them. — Shepmaster, Apr 18 '17 at 12:45
I'll check that! (Actually I have no idea how the debug info is stored, so thanks for the pointer.) — GolDDranks, Apr 19 '17 at 02:27
It's even weirder now. For ONE run, it happened to find the debug symbols. Similar run that I traced right after didn't found the symbols – undeterminism! Btw. I suspect this has something to do with the problems I earlier had with the backtrace crate: https://github.com/brson/error-chain/issues/129#issuecomment-281946612 On Apple platforms, a framework called CoreSymbolication is used. (a reverse engineering attempt: https://github.com/mountainstorm/CoreSymbolication) — GolDDranks, Apr 19 '17 at 06:53
Btw. Xcode Instruments doesn't have trouble finding debug symbols even if I compile *without* them. I'm baffled about all the weird behaviours I'm encountering. — GolDDranks, Apr 19 '17 at 06:56
Here's still one more spark of wisdom: http://dtrace-discuss.opensolaris.narkive.com/pk1HBus5/more-dtrace-questions-release-builds-performance "The OS X dtrace uses spotlight to find dSYM(s), if you want to disable this, move the dSYM to a directory not indexed by spotlight, or turn off spotlight." Spotlight might explain a large part of the indeterminism. — GolDDranks, Apr 19 '17 at 06:59

score 5 · Accepted Answer · edited Apr 19 '17 at 12:46

I found a workaround and got some insight why it might not have worked, but the reason why is not 100% clear.

The debug symbols that rustc produces can be found in target/release/deps/mybinaryname-hashcode.dSYM. In the same directory there is a binary file target/release/deps/mybinaryname-hashcode to which the symbols correspond to.

The debug symbol finding library on MacOS is highly magical – as is mentioned in the LLDB docs, symbols are found using various methods, including Spotlight search. I'm not even sure which Frameworks are the ones being used by Xcode's Instruments and the bundled DTrace. (There are mentions about frameworks called DebugSymbols.framework and CoreSymbolication.framework.) Because of this magic, I gave up trying to understand why didn't it work.

The workaround is to pass dtrace the -p option along with the PID of the inspected process:

sudo dtrace -p $PID -n 'profile-997 /pid == '$PID'/ { @[ustack(100)] = count(); }' -o $TMPFILE &>/dev/null

Here's the man of -p:

Grab the specified process-ID pid, cache its symbol tables, and exit upon its completion. If more than one -p option is present on the command line, dtrace exits when all commands have exited, reporting the exit status for each process as it terminates. The first process-ID is made available to any D programs specified on the command line or using the -s option through the $target macro variable.

It's not clear why the debug info of various other binaries is shown by default, or why Rust binaries need the -p option, but it does its job as a workaround.

I later found out that the directory the debug symbols were on a block list of Spotlight. Removing the list entry and letting Spotlight re-index fixed the problem. — GolDDranks, Jan 15 '19 at 06:19

Using DTrace to get stack traces / profiling data on Rust

1 Answers1