I am trying to use DTrace for CPU profiling of a Node.js program according to this guide on an OmniOS VM in VirtualBox, which I set up following these steps exactly (except for using node 0.10.26).
Unfortunately, DTrace does not give me human-readable JS function names, but just the raw function addresses (as far as I understand), which looks like this and is not very helpful:
CPU ID FUNCTION:NAME
0 66407 :tick-30s
node`v8::internal::String::ComputeHashField(unibrow::CharacterStream*, int, unsigned int)+0x162
node`v8::internal::Utf8SymbolKey::Hash() [clone .part.342]+0xb9
node`v8::internal::HashTable<v8::internal::SymbolTableShape, v8::internal::HashTableKey*>::FindEntry(v8::internal::Isolate*, v8::internal::HashTableKey*)+0x20
node`v8::internal::SymbolTable::LookupKey(v8::internal::HashTableKey*, v8::internal::Object**)+0x38
node`v8::internal::SymbolTable::LookupSymbol(v8::internal::Vector<char const>, v8::internal::Object**)+0x4e
node`v8::internal::Heap::LookupSymbol(v8::internal::Vector<char const>)+0x34
node`v8::internal::Factory::LookupSymbol(v8::internal::Vector<char const>)+0x34
node`v8::internal::JSProxy::CallTrap(char const*, v8::internal::Handle<v8::internal::Object>, int, v8::internal::Handle<v8::internal::Object>*)+0x76
node`v8::internal::JSProxy::GetPropertyWithHandler(v8::internal::Object*, v8::internal::String*)+0x108
node`v8::internal::Object::GetProperty(v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::Object>, v8::internal::LookupResult*, v8::internal::Handle<v8::internal::String>, PropertyAttributes*)+0x57
node`v8::internal::LoadIC::Load(v8::internal::InlineCacheState, v8::internal::Handle<v8::internal::Object>, v8::internal::Handle<v8::internal::String>)+0x49d
node`v8::internal::LoadIC_Miss(v8::internal::Arguments, v8::internal::Isolate*)+0xbd
0xa730a376
0x8966eee0
0x8968bb7c
0xa7321899
0xa731308a
The above is the result of running these commands:
dtrace -n 'profile-97/pid == 12345 && arg1/{ @[jstack(150, 8000)] = count(); } tick-30s { exit(0); }' > stacks.out
gc++filt < stacks.out > demangled.out
I have no prior experience with DTrace, but from what have I gathered so far, Node's ustack helper should translate these addresses into readable names. This functionality should be enabled when building Node with the --with-dtrace
flag (which I did), but apparently it is not working for me.
Pretty much the exact same question has actually been asked before, but the accepted answer there did not help in my case, as I was using --dest-cpu=x64
anyway (also tried --dest-cpu=ia32
just to be sure, but that did not make any difference).
Figured it out, thanks to this excellent post about node.js+DTrace on FreeBSD. Starting Node with the DTRACE_DOF_INIT_DEBUG
flag resulted in a message suspiciously similar to the one mentioned in the article:
dtrace DOF: DTrace ioctl failed for DOF at cd5240 in /usr/local/bin/node: Arg list too long
dtrace DOF: DTrace ioctl succeeded for DOF at 1397e70 in /usr/local/bin/node
Even though the article is about FreeBSD, the relevant part of the DTrace source (dtrace_dof_copyin
in dtrace.c
) is almost identical (see FreeBSD source vs. OmniOS source). Hence, it looked like in my case, the Node ustack helper was also exceeding the size limit for DOFs/DTrace objects, even though that limit is set to 8 mb in OmniOS, as opposed to 256 kb in FreeBSD.
To verify the assumption, I tried the exact same procedure with Node v0.10.5 instead of v0.10.26, since that was the version that had apparently worked for at least 3 people before, and it also did trick in my case; starting Node with the aforementioned flag prints:
dtrace DOF: DTrace ioctl succeeded for DOF at cd6c88 in /usr/local/bin/node
dtrace DOF: DTrace ioctl succeeded for DOF at d122c8 in /usr/local/bin/node
And JS function names are appearing in DTrace output as expected.
EDIT: Node v0.10.20 is the most recent version where it works.