systemtap/dtrace support for nodejs #4164

jcwynholds · 2012-10-18T20:39:22Z

64/32bit linux. should work with any linux that supports systemtap's dtrace
notes section for sdt in generated node binary
Thanks FChE, TooTallNate.
TODO:
-add v8ustack.stp
-add any other .stp scripts
DONE:
-added systemtap.cc/.d and make stuff
-added license, ready for pull request

… be done GENERATED OBJECT FILE! notes section for sdt in generated node binary Thanks FChE, TooTallNate. TODO: -add v8ustack.stp -add any other .stp scripts DONE: -added systemtap.cc/.d and make stuff -added license, ready for pull request

jcwynholds · 2012-10-18T20:41:43Z

This is a rebased topic branch for one clean commit. If I did things wrong I would happily try to change anything to get this accepted.

fche · 2012-10-19T14:24:13Z

Jan, doesn't your most recent version work without the sys/sdt.h semaphores? If so, you probably don't need the .gyp stuff like:

     'libraries': [ '<(PRODUCT_DIR)/obj.target/node/src/node_systemtap_sema.o' ],

jcwynholds · 2012-10-19T17:33:32Z

Sure I'll try that, run through tests, and update this pull request. Was following the heapsort example.

bnoordhuis · 2012-10-20T14:07:17Z

configure

@@ -369,8 +369,12 @@ def configure_node(o):
  # SunOS, and we haven't implemented it.)
  if sys.platform.startswith('sunos'):
    o['variables']['node_use_dtrace'] = b(not options.without_dtrace)
+  elif sys.platform.startswith('linux'):
+    o['variables']['node_use_dtrace'] = 'false'
+    o['variables']['node_use_systemtap'] = b(not options.without_dtrace)


A --with-systemtap configure switch is preferable over piggybacking on the --with-dtrace switch.

No, skip that. I guess it doesn't matter much from an end user perspective.

bnoordhuis · 2012-10-20T14:21:25Z

Very nice work! Question: would it be possible to share (or even better: merge) the systemtap files with the dtrace ones? The differences don't look substantial.

piscisaureus · 2012-10-20T17:30:04Z

@bnoordhuis @jcwynholds

The ETW support also piggybacks on node_dtrace.cc. I think it would be best to add systemtap to the same file.

Maybe we should also (later) rename it to node_tracing.cc or something?

jcwynholds · 2012-10-21T22:24:38Z

@bnoordhuis Thanks! @piscisaureus Yes absolutely merging would probably be best. Just wanted to show what was working and give a picture for eventual merge.

Still working on the style fixes, the macros.py flub, and dropping the _sema.o object creation suggestion from @fche. So there will be a a couple more commits with all these changes very shortly.

Thanks again for all the great feedback!

jcwynholds · 2012-10-22T17:32:31Z

Another commit incoming: Merge node_systemtap.cc with node_dtrace.cc (w/ clear macro guards).

need a better solution than macro guarding every _ENABLED and every probe (passing struct to probe iso primitive) definition. also need to test _sema.o object creation (added in flurries of action)

jcwynholds · 2012-10-26T15:39:54Z

Guards for every PROBE_ENABLED macro and every probe. Not elegant. Works. Still warning on missing initializer.

still many macro guards

jcwynholds · 2012-10-27T00:09:47Z

Would love to hear a better solution than guarding all the different macros. Other than that, this is as ready as I can make it. Any other comments or suggestions welcomed.

jcwynholds · 2012-10-31T05:26:00Z

This is ready, verified on several of my systems (centos, ubuntu)
stap -l 'process("out/Release/node").function("*").call'
Can I do anything else?

fche · 2012-10-31T12:55:44Z

This is ready, verified on several of my systems (centos, ubuntu)
stap -l 'process("out/Release/node").function("*").call'
Can I do anything else?

To test the <sys/sdt.h> probes, use instead:

stap -l 'process("out/Release/node").mark("*")'

bnoordhuis · 2012-10-31T13:49:33Z

src/node_dtrace.cc

@@ -157,14 +180,20 @@

  nbytes = args[1]->Int32Value();


warning: variable ‘nbytes’ set but not used [-Wunused-but-set-variable]

bnoordhuis · 2012-10-31T13:56:47Z

Here is a patch that squelches the compiler warnings:

diff --git a/src/node_dtrace.cc b/src/node_dtrace.cc
index 36e8314..df42af2 100644
--- a/src/node_dtrace.cc
+++ b/src/node_dtrace.cc
@@ -56,6 +56,7 @@
 #define NODE_GC_START(arg0, arg1)
 #define NODE_GC_DONE(arg0, arg1)
 #endif
+
 namespace node {

 using namespace v8;
@@ -169,20 +170,17 @@ Handle<Value> DTRACE_NET_SOCKET_READ(const Arguments& args) {
 #endif

   HandleScope scope;
-  int nbytes;

   SLURP_CONNECTION(args[0], conn);

+#ifdef HAVE_SYSTEMTAP
+  NODE_NET_SOCKET_READ(conn.fd, conn.remote, conn.port, conn.buffered);
+#else
   if (!args[1]->IsNumber()) {
     return (ThrowException(Exception::Error(String::New("expected " 
       "argument 1 to be number of bytes"))));
   }
-
-  nbytes = args[1]->Int32Value();
-
-#ifdef HAVE_SYSTEMTAP
-  NODE_NET_SOCKET_READ(conn.fd, conn.remote, conn.port, conn.buffered);
-#else
+  int nbytes = args[1]->Int32Value();
   NODE_NET_SOCKET_READ(&conn, nbytes);
 #endif

@@ -196,20 +194,17 @@ Handle<Value> DTRACE_NET_SOCKET_WRITE(const Arguments& args) {
 #endif

   HandleScope scope;
-  int nbytes;

   SLURP_CONNECTION(args[0], conn);

+#ifdef HAVE_SYSTEMTAP
+  NODE_NET_SOCKET_WRITE(conn.fd, conn.remote, conn.port, conn.buffered);
+#else
   if (!args[1]->IsNumber()) {
     return (ThrowException(Exception::Error(String::New("expected " 
       "argument 1 to be number of bytes"))));
   }
-
-  nbytes = args[1]->Int32Value();
-
-#ifdef HAVE_SYSTEMTAP
-  NODE_NET_SOCKET_WRITE(conn.fd, conn.remote, conn.port, conn.buffered);
-#else
+  int nbytes = args[1]->Int32Value();
   NODE_NET_SOCKET_WRITE(&conn, nbytes);
 #endif

@@ -337,7 +332,7 @@ Handle<Value> DTRACE_HTTP_CLIENT_RESPONSE(const Arguments& args) {
   return Undefined();
 }

-#define NODE_PROBE(name) #name, name
+#define NODE_PROBE(name) #name, name, Persistent<FunctionTemplate>()

 static int dtrace_gc_start(GCType type, GCCallbackFlags flags) {
 #ifdef HAVE_SYSTEMTAP
@@ -374,11 +369,10 @@ void InitDTrace(Handle<Object> target) {
     { NODE_PROBE(DTRACE_HTTP_SERVER_REQUEST) },
     { NODE_PROBE(DTRACE_HTTP_SERVER_RESPONSE) },
     { NODE_PROBE(DTRACE_HTTP_CLIENT_REQUEST) },
-    { NODE_PROBE(DTRACE_HTTP_CLIENT_RESPONSE) },
-    { NULL }
+    { NODE_PROBE(DTRACE_HTTP_CLIENT_RESPONSE) }
   };

-  for (int i = 0; tab[i].name != NULL; i++) {
+  for (unsigned int i = 0; i < ARRAY_SIZE(tab); i++) {
     tab[i].templ = Persistent<FunctionTemplate>::New(
         FunctionTemplate::New(tab[i].func));
     target->Set(String::NewSymbol(tab[i].name), tab[i].templ->GetFunction());

bnoordhuis · 2012-10-31T14:11:29Z

Hmm, what are process("out/Release/node").function("*").call and process("out/Release/node").mark("*") supposed to print? I see nothing on my system:

$ uname -a
Linux zoidberg 3.6.0 #10 SMP Mon Oct 1 02:21:49 CEST 2012 x86_64 x86_64 x86_64 GNU/Linux
$ stap -l 'process("out/Release/node").mark("*")' | wc -l
0
$ stap -l 'process("out/Release/node").function("*").call' | wc -l
0

bnoordhuis · 2012-10-31T14:35:47Z

FWIW, I do see the probe nops in the binary:

(gdb) disassemble/m node::dtrace_gc_start(v8::GCType, v8::GCCallbackFlags) 
Dump of assembler code for function node::dtrace_gc_start(v8::GCType, v8::GCCallbackFlags):
337     static int dtrace_gc_start(GCType type, GCCallbackFlags flags) {
   0x0000000000732851 <+0>:     push   %rbp
   0x0000000000732852 <+1>:     mov    %rsp,%rbp
   0x0000000000732855 <+4>:     mov    %edi,-0x4(%rbp)
   0x0000000000732858 <+7>:     mov    %esi,-0x8(%rbp)

338     #ifdef HAVE_SYSTEMTAP
339       NODE_GC_START();
   0x000000000073285b <+10>:    nop

340     #else
341       NODE_GC_START(type, flags);
342     #endif
343       /*
344        * We avoid the tail-call elimination of the USDT probe (which screws up
345        * args) by forcing a return of 0.
346        */
347       return 0;
   0x000000000073285c <+11>:    mov    $0x0,%eax

348     }
   0x0000000000732861 <+16>:    pop    %rbp
   0x0000000000732862 <+17>:    retq   

End of assembler dump.

fche · 2012-10-31T14:59:31Z

Hi -

Hmm, what are process("out/Release/node").function("").call and
process("out/ Release/node").mark("") supposed to print? I see
nothing on my system:

If your version of systemtap is <1.8, or your kernel lacks necessary
settings like CONFIG_UPROBES, then stap will not list probes that,
while present, it can't use anyway.

Modern gdb can list ("info probes") and use ("break -probe-stap FOO")
them without such kernel support.

FChE

bnoordhuis · 2012-10-31T15:46:49Z

Thanks for the pointer, Frank. It turned out that there was an old stap binary on the path. I see the probes now:

$ stap -l 'process("out/Release/node").mark("*")'
process("out/Release/node").mark("gc__done")
process("out/Release/node").mark("gc__start")
process("out/Release/node").mark("http__client__request")
process("out/Release/node").mark("http__client__response")
process("out/Release/node").mark("http__server__request")
process("out/Release/node").mark("http__server__response")
process("out/Release/node").mark("net__server__connection")
process("out/Release/node").mark("net__socket__read")
process("out/Release/node").mark("net__socket__write")
process("out/Release/node").mark("net__stream__end")

jcwynholds · 2012-10-31T20:38:02Z

Great stuff thanks Ben and Frank!

bnoordhuis · 2012-10-31T22:14:37Z

Okay, turns out there's one rather crucial part missing:

diff --git a/src/node.cc b/src/node.cc
index d193610..60cc19c 100644
--- a/src/node.cc
+++ b/src/node.cc
@@ -2310,7 +2310,7 @@ void Load(Handle<Object> process_l) {
   Local<Object> global = v8::Context::GetCurrent()->Global();
   Local<Value> args[1] = { Local<Value>::New(process_l) };

-#if defined HAVE_DTRACE || defined HAVE_ETW
+#if defined HAVE_DTRACE || defined HAVE_ETW || defined HAVE_SYSTEMTAP
   InitDTrace(global);
 #endif

Without it, the probe wrappers aren't registered and you get errors like this:

$ out/Release/node -e 'require("http").get("http://nodejs.org/", function(res) { res.pipe(process.stdout) })'

http.js:846
    DTRACE_HTTP_CLIENT_REQUEST(this, this.connection);
    ^
ReferenceError: DTRACE_HTTP_CLIENT_REQUEST is not defined
    at ClientRequest.OutgoingMessage._finish (http.js:846:5)
    at ClientRequest.OutgoingMessage._flush (http.js:888:10)
    at http.js:1247:10
    at ClientRequest.onSocket (http.js:1555:17)
    at ClientRequest.g (events.js:195:14)
    at ClientRequest.EventEmitter.emit (events.js:93:17)
    at http.js:1538:9
    at process._tickCallback (node.js:335:13)

bnoordhuis · 2012-10-31T22:15:55Z

src/node_systemtap.d

@@ -0,0 +1,58 @@
+/*
+# Copyright (C) 2012 Jan C. Wynholds


Style: we use license boilerplate like this:

// Copyright Joyent, Inc. and other Node contributors. // // Permission is hereby granted, free of charge, to any person obtaining a // copy of this software and associated documentation files (the // "Software"), to deal in the Software without restriction, including // without limitation the rights to use, copy, modify, merge, publish, // distribute, sublicense, and/or sell copies of the Software, and to permit // persons to whom the Software is furnished to do so, subject to the // following conditions: // // The above copyright notice and this permission notice shall be included // in all copies or substantial portions of the Software. // // THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS // OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF // MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN // NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, // DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR // OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE // USE OR OTHER DEALINGS IN THE SOFTWARE.

bnoordhuis · 2012-10-31T22:20:01Z

Patch to create node_systemtap.h in out/Release/gen:

diff --git a/node.gyp b/node.gyp
index c93e846..cefa502 100644
--- a/node.gyp
+++ b/node.gyp
@@ -174,7 +174,7 @@
           'include_dirs': [ '<(SHARED_INTERMEDIATE_DIR)' ],
           'sources': [
             'src/node_dtrace.cc',
-            'src/node_systemtap.h',
+            '<(SHARED_INTERMEDIATE_DIR)/node_systemtap.h',
           ],
         } ],
         [ 'node_use_etw=="true"', {
@@ -343,7 +343,7 @@
             { 
               'action_name': 'node_systemtap_header',
               'inputs': [ 'src/node_systemtap.d' ],
-              'outputs': [ 'src/node_systemtap.h' ],
+              'outputs': [ '<(SHARED_INTERMEDIATE_DIR)/node_systemtap.h' ],
               'action': [ 'dtrace', '-h', '-C', '-s', '<@(_inputs)',
                 '-o', '<@(_outputs)' ]
             }

jcwynholds · 2012-11-01T00:11:14Z

4 above commits should be all the comments and diffs applied. Big whoops on the InitDTrace.

bnoordhuis · 2012-11-01T00:39:21Z

Thanks Jan, very nice. Squashed and landed in 06810b2.

bnoordhuis reviewed Oct 20, 2012
View reviewed changes

jan and others added 2 commits October 21, 2012 15:25

style whitespace and license fixes

1b865d4

removed _sema.o object creation and linking

81ca7c2

Jan Wynholds added 2 commits October 25, 2012 20:46

compiles! notes section probes! really lame macro guards.

61e9e9e

need a better solution than macro guarding every _ENABLED and every probe (passing struct to probe iso primitive) definition. also need to test _sema.o object creation (added in flurries of action)

removed unneeded _sema.o object in node.gyp

8f13b8a

fully merged node_systemtap.cc with node_dtrace.cc

7631263

still many macro guards

bnoordhuis reviewed Oct 31, 2012
View reviewed changes

compiler warnings fixed (all bnoordhuis, thanks!)

55761fc

added probe existence test to comments in .d

35916e7

bnoordhuis reviewed Oct 31, 2012
View reviewed changes

Jan Wynholds added 4 commits October 31, 2012 16:08

crucial miss of InitDtrace and HAVE_SYSTEMTAP

8e7e00e

license boilerplate

bf7602c

dtrace header to Release/gen

e40982f

cleanup comments

9ca1279

bnoordhuis closed this Nov 1, 2012

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

systemtap/dtrace support for nodejs #4164

systemtap/dtrace support for nodejs #4164

jcwynholds commented Oct 18, 2012

jcwynholds commented Oct 18, 2012

fche commented Oct 19, 2012

jcwynholds commented Oct 19, 2012

bnoordhuis Oct 20, 2012

bnoordhuis Oct 20, 2012

bnoordhuis commented Oct 20, 2012

piscisaureus commented Oct 20, 2012

jcwynholds commented Oct 21, 2012

jcwynholds commented Oct 22, 2012

jcwynholds commented Oct 26, 2012

jcwynholds commented Oct 27, 2012

jcwynholds commented Oct 31, 2012

fche commented Oct 31, 2012

bnoordhuis Oct 31, 2012

bnoordhuis commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

fche commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

jcwynholds commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

bnoordhuis Oct 31, 2012

bnoordhuis commented Oct 31, 2012

jcwynholds commented Nov 1, 2012

bnoordhuis commented Nov 1, 2012

systemtap/dtrace support for nodejs #4164

systemtap/dtrace support for nodejs #4164

Conversation

jcwynholds commented Oct 18, 2012

jcwynholds commented Oct 18, 2012

fche commented Oct 19, 2012

jcwynholds commented Oct 19, 2012

bnoordhuis Oct 20, 2012

Choose a reason for hiding this comment

bnoordhuis Oct 20, 2012

Choose a reason for hiding this comment

bnoordhuis commented Oct 20, 2012

piscisaureus commented Oct 20, 2012

jcwynholds commented Oct 21, 2012

jcwynholds commented Oct 22, 2012

jcwynholds commented Oct 26, 2012

jcwynholds commented Oct 27, 2012

jcwynholds commented Oct 31, 2012

fche commented Oct 31, 2012

bnoordhuis Oct 31, 2012

Choose a reason for hiding this comment

bnoordhuis commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

fche commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

jcwynholds commented Oct 31, 2012

bnoordhuis commented Oct 31, 2012

bnoordhuis Oct 31, 2012

Choose a reason for hiding this comment

bnoordhuis commented Oct 31, 2012

jcwynholds commented Nov 1, 2012

bnoordhuis commented Nov 1, 2012