Search code examples
javascriptnode.jsprofilingdtraceomnios

No function names when using DTrace on Node.js program


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).


Solution

  • 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.