RFC stap/java backtracing

RFC stap/java backtracing

[Lukas Berk]

[-- Attachment #1.1: Type: text/plain, Size: 4775 bytes --]

Hey,

I've attached my patch for native java backtraces for systemtap.

How to use it:

I've added a java_backtrace() function which returns the backtrace as a
string.  One would use it as any other stap function, ie;

[lberk:~/code/tmp/classes]$ stap -DMAXSTRINGLEN=6000 -ve
'probe java("org.my.AppMain3").class("org.my.AppMain3").method("printMessage(String)")
{log("hit ".user_string($arg1)." ".java_backtrace())}'
    Pass 1: parsed user script and 99 library script(s) using 212540virt/28056res/2996shr/25632data kb, in 110usr/10sys/109real ms.
    Pass 2: analyzed script: 4 probe(s), 8 function(s), 2 embed(s), 1 global(s) using 367904virt/30900res/4204shr/27088data kb, in 10usr/60sys/79real ms.
    Pass 3: translated to C into "/tmp/stapImwsw0/stap_fa9d62d13587f9ebca29e3411b8fa6a0_4608_src.c" using 365428virt/30876res/4260shr/27088data kb, in 10usr/70sys/83real ms.
    Pass 4: compiled C into "stap_fa9d62d13587f9ebca29e3411b8fa6a0_4608.ko" in 1560usr/170sys/1758real ms.
    Pass 5: starting run.
    hit foobar java.lang.Throwable
            at org.systemtap.byteman.helper.HelperSDT.STAP_BACKTRACE(HelperSDT.java:9)
            at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
            at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
            at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
            at java.lang.reflect.Method.invoke(Method.java:606)
            at org.jboss.byteman.rule.expression.MethodExpression.interpret(MethodExpression.java:315)
            at org.jboss.byteman.rule.Action.interpret(Action.java:144)
            at org.systemtap.byteman.helper.HelperSDT_HelperAdapter_Interpreted_1.fire(toium-5999.btm)
            at org.systemtap.byteman.helper.HelperSDT_HelperAdapter_Interpreted_1.execute0(toium-5999.btm)
            at org.systemtap.byteman.helper.HelperSDT_HelperAdapter_Interpreted_1.execute(toium-5999.btm)
            at org.jboss.byteman.rule.Rule.execute(Rule.java:682)
            at org.jboss.byteman.rule.Rule.execute(Rule.java:651)
            at org.my.AppMain3.printMessage(AppMain3.java)
            at org.my.AppMain3$1.run(AppMain3.java:27)
     

How it works:

To start, java_backtrace() sets a new pragma:java_backtrace, which adds
a #define JAVA_BACTRACE in the kernel module.

Within parsing the probe point the user specified, I've added another
parameter to be passed to stapbm, signaling if a backtrace is going to
be needed.  This is done through the _bt() pure c function in java.stp
as well.  If its not, then carry on as usual.  However, if it is, we
add another helper method directly before calling our 'original' native
helper method, STAP_BACKTRACE('rulename').   STAP_BACKTRACE simply
triggers the e.printStackTrace() call, converting the output to a single
string, and passes said string through to a new native function
(METHOD_STAP_BT) along with the rulename.  The new native function is
required to make sure we don't overwrite/mangle a possible probe point
that only has on parameter (similar to the exapmle I used above), and
has the added advantage of being able to immediately call the correct
jni functions to exract the string, no guessing/trail and error
required.  

From systemtap's perspective, we watch for this information by adding
another probe point, ie
'process("/path/to/libHelperSDT_*").mark("method__bt"), and then passing
the string back to the probe point specified by the user via a global
variable, which is then the return value of java_backtrace().

I think the main issue is with possible collisions with the global
variable and multiple, concurrent probe points requesting stacktraces.
On a second look it may be possible to ditch the pragma, and trigger
adding #define JAVA_BACKTRACE simply via an internal variable, which
could allow the global to be internally defined as well (with a unique
runtime name, specific to the probe point).  The issue then would be to
have the java_backtrace() function return the proper global variable to
the original probe point (perhaps by returning the result of another,
internally defined function, ie __java_backtrace:string(), which is
passed the uniquely named global variable).  If there is a better or
more simple way please let me know.


Other Improvements:

- Add rulename check in the method__bt probe
- Iterate over the backtrace and pass it line by line through stap to
  avoid needing to set -DMAXSTRINGLEN (or just require it?)
- Make the method__bt probe point optional in cases where no backtrace
  is required (currently its always defined)

Any comments/thoughts/concerns are welcome and much appreciated!

Cheers,

Lukas

[-- Attachment #1.2: java_backtrace.patch --]
[-- Type: text/plain, Size: 13850 bytes --]

diff --git a/elaborate.cxx b/elaborate.cxx
index 6cdbca4..05d5816 100644
--- a/elaborate.cxx
+++ b/elaborate.cxx
@@ -1505,6 +1505,15 @@ public:
 		    current_function->name.c_str()) << endl;
 	session.need_symbols = true;
       }
+
+    if (! session.java_backtrace
+	&& c->code.find("/* pragma:java_backtrace */") != string::npos)
+      {
+	if (session.verbose > 2)
+	  clog << _F("Turning on java backtrace, pragma:java_backtrace found in %s",
+		     current_function->name.c_str()) << endl;
+	session.java_backtrace = true;
+      }
   }
 };
 
diff --git a/java/HelperSDT.c b/java/HelperSDT.c
index acf15ca..ea175d5 100644
--- a/java/HelperSDT.c
+++ b/java/HelperSDT.c
@@ -491,3 +491,16 @@ JNIEXPORT void JNICALL Java_org_systemtap_byteman_helper_HelperSDT_METHOD_1STAP_
     arg10.vartype.c = get_java_string(env, _arg10);
   STAP_PROBE11(HelperSDT, method__10, arg1.vartype.d, arg2.vartype.d, arg3.vartype.d, arg4.vartype.d, arg5.vartype.d, arg6.vartype.d, arg7.vartype.d, arg8.vartype.d, arg9.vartype.d, arg10.vartype.d, rulename);
 }
+
+/*
+ * Class:     HelperSDT
+ * Method:    METHOD_STAP_BT
+ * Signature: (Ljava/lang/String;Ljava/lang/String;)V
+ */
+JNIEXPORT void JNICALL Java_org_systemtap_byteman_helper_HelperSDT_METHOD_1STAP_1BT
+(JNIEnv *env, jobject obj, jstring _rulename, jstring _exception)
+{
+  char* rulename = get_java_string(env, _rulename);
+  char* excp = get_java_string(env, _exception);
+  STAP_PROBE2(HelperSDT, method__bt, excp, rulename);
+}
diff --git a/java/HelperSDT.h b/java/HelperSDT.h
index ea58eac..f842817 100644
--- a/java/HelperSDT.h
+++ b/java/HelperSDT.h
@@ -95,6 +95,15 @@ JNIEXPORT void JNICALL Java_org_systemtap_byteman_helper_HelperSDT_METHOD_1STAP_
 JNIEXPORT void JNICALL Java_org_systemtap_byteman_helper_HelperSDT_METHOD_1STAP_1PROBE10
   (JNIEnv *, jobject, jstring, jobject, jobject, jobject, jobject, jobject, jobject, jobject, jobject, jobject, jobject);
 
+/*
+ * Class:     HelperSDT
+ * Method:    METHOD_STAP_BT
+ * Signature: (Ljava/lange/String;Ljava/lang/String;)V
+ */
+JNIEXPORT void JNICALL Java_org_systemtap_byteman_helper_HelperSDT_Method_1STAP_1BT
+  (JNIEnv *, jobject, jstring, jstring);
+
+
 #ifdef __cplusplus
 }
 #endif
diff --git a/java/org/systemtap/byteman/helper/HelperSDT.java b/java/org/systemtap/byteman/helper/HelperSDT.java
index 41c8dd3..c377ac9 100644
--- a/java/org/systemtap/byteman/helper/HelperSDT.java
+++ b/java/org/systemtap/byteman/helper/HelperSDT.java
@@ -1,6 +1,17 @@
 package org.systemtap.byteman.helper;
+import java.io.StringWriter;
+import java.io.PrintWriter;
+import java.lang.Throwable;
+
 public class HelperSDT<T2, T3, T4, T5, T6, T7, T8, T9, T10, T11>
 {
+    public void STAP_BACKTRACE(String rulename){
+	Throwable e = new Throwable();
+	StringWriter sw = new StringWriter();
+	e.printStackTrace(new PrintWriter(sw));
+	String exceptionAsString = sw.toString();
+	METHOD_STAP_BT(rulename, sw.toString());
+    }
     public native void METHOD_STAP_PROBE0(String rulename);
     public native void METHOD_STAP_PROBE1(String rulename, T2 arg1);
     public native void METHOD_STAP_PROBE2(String rulename, T2 arg1, T3 arg2);
@@ -12,6 +23,7 @@ public class HelperSDT<T2, T3, T4, T5, T6, T7, T8, T9, T10, T11>
     public native void METHOD_STAP_PROBE8(String rulename, T2 arg1, T3 arg2, T4 arg3, T5 arg4, T6 arg5, T7 arg6, T8 arg7, T9 arg8);
     public native void METHOD_STAP_PROBE9(String rulename, T2 arg1, T3 arg2, T4 arg3, T5 arg4, T6 arg5, T7 arg6, T8 arg7, T9 arg8, T10 arg9);
     public native void METHOD_STAP_PROBE10(String rulename, T2 arg1, T3 arg2, T4 arg3, T5 arg4, T6 arg5, T7 arg6, T8 arg7, T9 arg8, T10 arg9, T11 arg10);
+    public native void METHOD_STAP_BT(String rulename, String exceptionAsString);
     static{
         System.loadLibrary("HelperSDT_" + System.getProperty("os.arch"));
     }
diff --git a/java/stapbm.in b/java/stapbm.in
index 186d2c9..0cc79ac 100755
--- a/java/stapbm.in
+++ b/java/stapbm.in
@@ -7,11 +7,12 @@
 # $5 - method
 # $6 - number of args
 # $7 - entry/exit/line
+# $8 - backtrace trigger
 
 exec 1>&2  # redirect byteman/etc. tracing output to stderr, for easier filtering
 
-if [ $# -ne 7 ]; then
-    echo "need exactly seven arguments"
+if [ $# -ne 8 ]; then
+    echo "need exactly eight arguments"
     exit 1
 fi
 
@@ -22,6 +23,7 @@ arg_class=$4
 arg_method=$5
 arg_argcount=$6
 arg_probetype=$7
+arg_backtrace=$8
 
 SYSTEMTAP_DIR=${SYSTEMTAP_DIR-$HOME/.systemtap}
 BYTEMAN_HOME=${BYTEMAN_HOME-/usr/share/java/byteman}
@@ -174,18 +176,23 @@ function echo_bytemanrule()
 	    ;;
     esac
     echo "IF TRUE"
+    if [ "$arg_backtrace" == "1" ]; then
+	echo 'DO STAP_BACKTRACE("'$arg_rulename'");'
+    else
+	echo -n 'DO '
+    fi
     case "$arg_argcount" in
-        0) echo 'DO METHOD_STAP_PROBE0("'$arg_rulename'")' ;;
-        1) echo 'DO METHOD_STAP_PROBE1("'$arg_rulename'", $1)' ;;
-        2) echo 'DO METHOD_STAP_PROBE2("'$arg_rulename'", $1, $2)' ;;
-        3) echo 'DO METHOD_STAP_PROBE3("'$arg_rulename'", $1, $2, $3)' ;;
-        4) echo 'DO METHOD_STAP_PROBE4("'$arg_rulename'", $1, $2, $3, $4)' ;;
-        5) echo 'DO METHOD_STAP_PROBE5("'$arg_rulename'", $1, $2, $3, $4, $5)' ;;
-        6) echo 'DO METHOD_STAP_PROBE6("'$arg_rulename'", $1, $2, $3, $4, $5, $6)' ;;
-        7) echo 'DO METHOD_STAP_PROBE7("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7)' ;;
-        8) echo 'DO METHOD_STAP_PROBE8("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8)' ;;
-        9) echo 'DO METHOD_STAP_PROBE9("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8, $9)' ;;
-	10) echo 'DO METHOD_STAP_PROBE10("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8, $9, $10)' ;;
+        0) echo 'METHOD_STAP_PROBE0("'$arg_rulename'")' ;;
+        1) echo 'METHOD_STAP_PROBE1("'$arg_rulename'", $1)' ;;
+        2) echo 'METHOD_STAP_PROBE2("'$arg_rulename'", $1, $2)' ;;
+        3) echo 'METHOD_STAP_PROBE3("'$arg_rulename'", $1, $2, $3)' ;;
+        4) echo 'METHOD_STAP_PROBE4("'$arg_rulename'", $1, $2, $3, $4)' ;;
+        5) echo 'METHOD_STAP_PROBE5("'$arg_rulename'", $1, $2, $3, $4, $5)' ;;
+        6) echo 'METHOD_STAP_PROBE6("'$arg_rulename'", $1, $2, $3, $4, $5, $6)' ;;
+        7) echo 'METHOD_STAP_PROBE7("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7)' ;;
+        8) echo 'METHOD_STAP_PROBE8("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8)' ;;
+        9) echo 'METHOD_STAP_PROBE9("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8, $9)' ;;
+	10) echo 'METHOD_STAP_PROBE10("'$arg_rulename'", $1, $2, $3, $4, $5, $6, $7, $8, $9, $10)' ;;
         *) echo 'bad arg-count'; exit 1 ;;
     esac
     echo "ENDRULE"
diff --git a/session.cxx b/session.cxx
index bf65248..96509ec 100644
--- a/session.cxx
+++ b/session.cxx
@@ -145,6 +145,7 @@ systemtap_session::systemtap_session ():
   need_uprobes = false;
   need_unwind = false;
   need_symbols = false;
+  java_backtrace = false;
   uprobes_path = "";
   load_only = false;
   skip_badvars = false;
@@ -325,6 +326,7 @@ systemtap_session::systemtap_session (const systemtap_session& other,
   need_uprobes = false;
   need_unwind = false;
   need_symbols = false;
+  java_backtrace = false;
   uprobes_path = "";
   load_only = other.load_only;
   skip_badvars = other.skip_badvars;
diff --git a/session.h b/session.h
index ee467b8..ad0272e 100644
--- a/session.h
+++ b/session.h
@@ -208,6 +208,7 @@ public:
   bool need_uprobes;
   bool need_unwind;
   bool need_symbols;
+  bool java_backtrace;
   std::string uprobes_path;
   std::string uprobes_hash;
   bool load_only; // flight recorder mode
diff --git a/tapset-method.cxx b/tapset-method.cxx
index fb609f3..e3da263 100644
--- a/tapset-method.cxx
+++ b/tapset-method.cxx
@@ -208,6 +208,71 @@ java_builder::build (systemtap_session & sess,
   if (! (has_pid_int || has_pid_str) )
     throw SEMANTIC_ERROR (_("missing JVMID"));
 
+  /* Java native backtrace probe point
+
+     In the event a java backtrace is requested (signaled by a '1' returned by the
+     _bt() stap function and appended to the stapbm call),  we need to place a
+     probe point on the method__bt marker in the libHelperSDT_*.so .  We've created
+     this new marker as we don't want it interfering with the method__X markers of
+     the same rulename.  The overall flow of backtraces are the same as 'regular'
+     method probes, however run through STAP_BACKTRACE helper method, and
+     METHOD_STAP_BT native method in turn.
+
+     STAP_BACKTRACE also converts the throwable object to a string for us to pass/report
+
+     The end result is we need to place another probe point automatically for the user;
+     process("$pkglibdir/libHelperSDT_*.so").provider("HelperSDT").mark("method__bt")
+     and pass the backtrace string to the java_backtrace_string variable, which then gets
+     immediately passed to the subsequent mark("method_XX") probe through the java_backtrace()
+     function's return value.
+   */
+
+  string bt_helper_location = PKGLIBDIR; // probe process("$pkglibdir/libHelperSDT_*.so").provider("HelperSDT").mark("method__bt")
+  bt_helper_location.append("/libHelperSDT_*.so"); // just as below, the wildcard is delibarate to catch all architectures
+  vector<probe_point::component*> bt_marker;
+  bt_marker.push_back (new probe_point::component
+		       (TOK_PROCESS, new literal_string (bt_helper_location)));
+  bt_marker.push_back (new probe_point::component
+		       (TOK_PROVIDER, new literal_string ("HelperSDT")));
+  bt_marker.push_back (new probe_point::component
+		       (TOK_MARK, new literal_string ("method__bt")));
+
+  probe_point * bt_derived_loc = new probe_point (bt_marker);
+  block *bt = new block;
+  bt->tok = base->body->tok;
+
+  //XXX add in the rulename check here (for multiple simultaneous backtraces), similar to below
+
+  target_symbol *btc = new target_symbol; // $arg1, ie the backtrace string
+  btc->tok = bt->tok;
+  btc->name = "$arg1";
+
+  functioncall *btcc = new functioncall; // user_string($arg1)
+  btcc->function = "user_string";
+  btcc->type = pe_string;
+  btcc->tok = bt->tok;
+  btcc->args.push_back(btc);
+
+  symbol *jbs = new symbol; // the global variable java_backtrace_string from java.stp
+  jbs->tok = bt->tok;
+  jbs->name = "java_backtrace_string";
+
+  assignment *bte = new assignment;  // java_backtrace_string = user_string($arg1)
+  bte->op = "=";
+  bte->tok = bt->tok;
+  bte->left = jbs;
+  bte->right = btcc;
+
+  expr_statement *bts = new expr_statement; // build the assignment
+  bts->tok = bt->tok;
+  bts->value = bte;
+
+  bt->statements.push_back(bts);
+
+  bt_derived_loc->components = bt_marker;
+  probe* new_mark_bt_probe = new probe (base, bt_derived_loc);
+  new_mark_bt_probe->body = bt;
+  derive_probes(sess, new_mark_bt_probe, finished_results);
   /* The overall flow of control during a probed java method is something like this:
 
      (java) java-method ->
@@ -307,6 +372,7 @@ java_builder::build (systemtap_session & sess,
      $5 - method
      $6 - number of args
      $7 - entry/exit/line
+     $8 - backtrace
   */
 
   literal_string* leftbits =
@@ -341,12 +407,22 @@ java_builder::build (systemtap_session & sess,
   midright->op = ".";
   midright->tok = base->body->tok;
 
+  functioncall* bt_fcall = new functioncall; //_bt check and definition
+  bt_fcall->tok = base->body->tok;
+  bt_fcall->function = "_bt";
+
+  concatenation* bt_final = new concatenation; // "midright"._bt()
+  bt_final->tok = base->body->tok;
+  bt_final->left = midright;
+  bt_final->op = ".";
+  bt_final->right = bt_fcall;
+
   block *bb = new block;
   bb->tok = base->body->tok;
   functioncall *fc = new functioncall;
   fc->function = "system";
   fc->tok = bb->tok;
-  fc->args.push_back(midright);
+  fc->args.push_back(bt_final);
 
   expr_statement* bs = new expr_statement;
   bs->tok = bb->tok;
@@ -393,10 +469,16 @@ java_builder::build (systemtap_session & sess,
   midright->op = ".";
   midright->tok = bb->tok;
 
+  bt_final = new concatenation;
+  bt_final->left = midright;
+  bt_final->right = bt_fcall;
+  bt_final->op = ".";
+  bt_final->tok = bb->tok;
+
   fc = new functioncall;
   fc->function = "system";
   fc->tok = bb->tok;
-  fc->args.push_back(midright);
+  fc->args.push_back(bt_final);
 
   bs = new expr_statement;
   bs->tok = bb->tok;
@@ -443,4 +525,3 @@ register_tapset_java (systemtap_session& s)
     ->bind (builder);
 #endif
 }
-
diff --git a/tapset/java.stp b/tapset/java.stp
new file mode 100644
index 0000000..442df4f
--- /dev/null
+++ b/tapset/java.stp
@@ -0,0 +1,21 @@
+global java_backtrace_string = ""
+
+function _java_backtrace () %{ /* pragma:java_backtrace */ %}
+
+function java_backtrace:string () {
+  _java_backtrace() //just set the pragma
+  return java_backtrace_string
+}
+
+function _bt:string () %{ /* pure */
+#ifdef JAVA_BACKTRACE
+  STAP_RETVALUE[0] = ' ';
+  STAP_RETVALUE[1] = '1';
+  STAP_RETVALUE[2] = '\0';
+#else
+  STAP_RETVALUE[0] = ' ';
+  STAP_RETVALUE[1] = '0';
+  STAP_RETVALUE[2] = '\0';
+#endif
+
+%}
\ No newline at end of file
diff --git a/translate.cxx b/translate.cxx
index f99e0d7..0165085 100644
--- a/translate.cxx
+++ b/translate.cxx
@@ -6813,6 +6813,9 @@ translate_pass (systemtap_session& s)
       s.op->newline() << "#include \"time.c\"";  // Don't we all need more?
       s.op->newline() << "#endif";
 
+      if (s.java_backtrace)
+	s.op->newline() << "#define JAVA_BACKTRACE 1";
+
       for (map<string,stapdfa*>::iterator it = s.dfas.begin(); it != s.dfas.end(); it++)
         {
           assert_no_interrupts();

[-- Attachment #2: Type: application/pgp-signature, Size: 836 bytes --]