lberk
Thoughts of a open source hacker
Probing Java Methods With Systemtap
Posted by on June 20, 2013
Hi,
Today we’ll be looking at systemtap’s latest native java probing capabilities.
These go beyond systemtap’s existing hotspot-based probe points to actual entry,
exit, and line number specific to the relevant java method.
How to install (if running Fedora 19)
# yum install systemtap byteman
Alternatively, you can get the latest systemtap source by
$ git clone git://sourceware.org/git/systemtap.git
and following the README instructions for installation. Likewise, you can download the latest byteman version from;
http://www.jboss.org/byteman/downloads
Basic Usage
How do I use systemtap to probe a java method?
Below we have a simple threaded java program, which waits for our input on the command
line. Given the input ‘int’ or ‘long’, the program will print out a predetermined
variable (that we would like to know the value).
package foo.bar;
import java.lang.*;
import java.io.DataInputStream;
import java.io.BufferedReader;
import java.io.InputStreamReader;
class ThreadedExample
{
public static void printMessage(int message)
{
System.out.println("message: " + message);
}
public static void printMessage(long message)
{
System.out.println("message: " + message);
}
public static void main(String[] args)
{
try
{
BufferedReader in = new BufferedReader(new InputStreamReader(System.in));
String next = in.readLine();
while(next != null && next.length() > 0 && !next.contains("end"))
{
final String arg = next;
final int i = 42;
final long j = 987234864;
Thread thread = new Thread(arg)
{
public void run()
{
if(arg.equals("int"))
printMessage(i);
else if(arg.equals("long"))
printMessage(j);
else
System.out.println("Neither of the types");
}
};
thread.start();
try
{
thread.join();
} catch (Exception e){}
next = in.readLine();
}
} catch (Exception e){}
}
}
compile and run the java program in the typical way;
lberk:]$ javac foo/bar/ThreadedExample.java lberk:]$ java foo.bar.ThreadedExample int message: 42 test Neither of the types long message: 987234864
Good, now to run a systemtap script which will probe both printMessage methods
and display the parameter passed.
Java probe points in systemtap follow the basic syntax of
probe java(“PNAME”).class(“CLASS”).method(“METHOD”) { handler }
where PNAME is either the string of the java program as listed by jps -l or the
specific PID of the java program. It should be noted that the java program must
be already running at the time of script invocation. The CLASS parameter is the
fully qualified class, and the METHOD parameter is the method name with parameter
types.
An example of a systemtap script written for ThreadedExample.java is below:
ThreadExample.stp
#!/usr/bin/env stap
probe java("foo.bar.ThreadedExample").class("ThreadedExample").method("printMessage(int)")
{
printf("Hit printMessage(int): %d\n", $arg1)
}
probe java("foo.bar.ThreadedExample").class("ThreadedExample").method("printMessage(long)")
{
printf("Hit printMessage(long): %d\n", $arg1)
}
Running the systemtap script in another terminal (and specifying “int”, “long” respectively);
lberk:]$ stap ThreadedExample.stp Hit printMessage(int): 42 Hit printMessage(long): 987234864
JBoss-AS Example
This example will use the Jboss Application Server, using the helloworld example
which can be obtained by running:
git clone git://github.com/jboss-jdf/jboss-as-quickstart.git --branch jdf-2.1.2.Final
In order to probe a standalone server, we need to ensure both the byteman and systemtap
packages are visible for the target’s class loaders. We can do this by either editting
the configuration file directly, or by modifying the environment variable on server startup
to list org.jboss.byteman and org.systemtap.byteman.helper package in the
JBOSS_MODULES_SYSTEM_PKGS option. For our example we’ve launched the startup server using the environment variable.
lberk:]$ JBOSS_MODULES_SYSTEM_PKGS="org.jboss.byteman,org.systemtap.byteman.helper" $HOME/jboss-as-user-instance/bin/standalone.sh
We then deploy the helloworld example by running the following command in the
jboss-as-quickstart/helloworld directory:
lberk:]$ mvn clean package jboss-as:deploy
At this point, we have a running hello world example that displays a “Hello World!” at
http://localhost:8080/jboss-as-helloworld/HelloWorld
We can tell when this web page is requested, and how many times by writing a simple
systemtap script that targets the “doGet” method.
stap jboss-example.stp
———————-
#!/usr/bin/env stap
global counter
probe
java("/usr/share/jboss-as/jboss-modules.jar").class("org.jboss.as.quickstarts.helloworld.HelloWorldServlet").method("doGet")
{
counter++
printf("%s, %d\n", ctime(gettimeofday_s()), counter)
}
This will provide output similar to the following for each webpage request:
Mon Jun 17 02:37:05 2013, 1 Mon Jun 17 02:37:06 2013, 2 Mon Jun 17 02:37:07 2013, 3 Mon Jun 17 02:37:08 2013, 4 Mon Jun 17 02:37:08 2013, 5 Mon Jun 17 02:37:09 2013, 6 Mon Jun 17 02:37:09 2013, 7
Thermostat Example
Note: This example requires further OSGi class loading work, please refer to
the OSGi section in the tutorial.
Thermostat is an Open Source Java Tooling project aimed to improve monitoring
and instrumentation tooling. More information about the project can be found at
http://icedtea.classpath.org/thermostat/
In order to make the necessary OSGi class visibility changes, we’re going clone
thermostat and checkout the 0.9-branchpoint
lberk:]$ hg clone http://icedtea.classpath.org/hg/thermostat lberk:]$ hg checkout 0.9-branchpoint lberk:]$ mvn clean install
In this example we’re interested in Thermostat’s ability to inspect java threads
and their current state (ie, blocked, waiting, runnable, etc), and the effect
it has (if any) on recording information to storage. To do this we need to identify
the method used to write to the mongoDB, as well as the mechanism used to
trigger/enable the thread recording. In this case, it means placing method entry
and return probe points on addImpl and replaceImp, as well as recording the time
spent in both recording thread state and ‘normal’ operation by
placing a probe point on the GUI’s getToggleButton method in the ThreadMainPanel class.
We launch thermostat by executing
lberk:]$ distribution/target/bin/thermostat service
and in a seperate terminal running
lberk:]$ distribution/target/bin/thermostat gui
Once the two thermostat services are running, we can run our script in a third terminal
and toggle the thread recording switch in the Thermostat gui, and exit the script
with a ctrl-C
stap thermostat.stp
——
#!/usr/bin/env stap
global mongo, mongoreturn
global recording = 0
global timeinaddimpl, timeinreplace, t1, t2, threadtimestart = 0, threadtimeend = 0, nothreadstart = 0, nothreadend = 0
probe java("Thermostat").class("com.redhat.thermostat.storage.mongodb.internal.MongoStorage").method("addImpl")
{
t1 = gettimeofday_us()
if(recording==0)
mongo["non-threading"]<<<1
else
mongo["threading"]<<<1
}
probe java("Thermostat").class("com.redhat.thermostat.storage.mongodb.internal.MongoStorage").method("addImpl").return
{
timeinaddimpl<<<(gettimeofday_us() - t1)
if(recording==0)
mongoreturn["non-threading"]<<<1
else
mongoreturn["threading"]<<<1
}
probe java("Thermostat").class("com.redhat.thermostat.storage.mongodb.internal.MongoStorage").method("replaceImpl")
{
t2 = gettimeofday_us()
if(recording==0)
mongo["non-threading"]<<<1
else
mongo["threading"]<<<1
}
probe java("Thermostat").class("com.redhat.thermostat.storage.mongodb.internal.MongoStorage").method("replaceImpl").return
{
timeinreplace<<<(gettimeofday_us() - t2)
if(recording==0)
mongoreturn["non-threading"]<<<1
else
mongoreturn["threading"]<<<1
}
probe java("Thermostat").class("com.redhat.thermostat.thread.client.swing.impl.ThreadMainPanel").method("getToggleButton")
{
if( recording == 0){
threadtimestart = gettimeofday_s()
if (nothreadstart == 0){
nothreadend = 0}
else{
nothreadend = nothreadend + (gettimeofday_s() - nothreadstart)
}
printf("Thread recording has been enabled.\n")
recording = 1
}
else{
nothreadstart = gettimeofday_s()
threadtimeend = threadtimeend + (gettimeofday_s() - threadtimestart)
printf("Thread recording has been disabled.\n")
recording = 0 //recording is already 1, set to 0
}
}
probe end
{
printf("\n")
printf("Time in AddImpl (uS)\n")
print(@hist_log(timeinaddimpl))
printf("Time in ReplaceImpl (uS)\n")
print(@hist_log(timeinreplace))
}
While toggling the ‘Monitor Thread’ option a few times, the script output should look something similar to;
Thread recording has been enabled. Thread recording has been disabled. Thread recording has been enabled. Thread recording has been disabled. Thread recording has been enabled. Thread recording has been disabled. ^C Time in AddImpl (uS) value |-------------------------------------------------- count 16 | 0 32 | 0 64 |@@@@@@@@@@@@@@@@@@@@@@@@@ 305 128 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 452 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 575 512 |@@@@@@@@@@@ 135 1024 |@ 13 2048 | 2 4096 | 2 8192 | 2 16384 | 0 32768 | 0 Time in ReplaceImpl (uS) value |-------------------------------------------------- count 16 | 0 32 | 0 64 |@@@@@ 10 128 |@@ 5 256 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 75 512 |@@ 4 1024 | 1 2048 | 1 4096 | 0 8192 | 0 mongo["threading"] @count=1419 @min=1 @max=1 @sum=1419 @avg=1 mongo["non-threading"] @count=163 @min=1 @max=1 @sum=163 @avg=1 mongoreturn["threading"] @count=1419 @min=1 @max=1 @sum=1419 @avg=1 mongoreturn["non-threading"] @count=163 @min=1 @max=1 @sum=163 @avg=1
OSGI Note
Due to module class loaders and class visibility restrictions under OSGI,
a few further steps must be taken to properly probe java methods. The
specific instructions can vary widely from application to application,
however this overview should give the knowledge to make educated decisions
to implement class loading visibility to the bundles systemtap requires.
There are two aspects to address in working with OSGi applications, importing
the helper jars to each specific bundle, and making the OSGi application aware of our
helper jar’s existence (ie, adding the required changes to the framework classpath).
First, to add the bundles to the framework classpath, we must create a new
framework instance and list the classes we’d like tomake available to the
program, the basic functionality of this class must include;
Map<String, String> jarsWereAdding = new HashMap<String, String>(); jarsWereAdding.put(Constants.FRAMEWORK_SYSTEMPACKAGES_EXTRA, jarList); factories.next().newFramework(jarsWereAdding);
Where jarList is a file containing the following bundles
org.jboss.byteman.rule org.jboss.byteman.rule.exception org.jboss.byteman.rule.exception.EarlyReturnException org.jboss.byteman.rule.helper org.systemtap.byteman.helper.HelperSDT
The second portion is adding the import clause to the specific MANIFEST.MF of the
class you’re looking to probe. This is a standard import clause which should resemble
Import Package: org.jboss.byteman.rule, org.jboss.byteman.rule.exception, org.jboss.byteman.rule.helper
This may also be added to the respective pom.xml if you’re using a build system such as maven:
<Import-Package> org.jboss.byteman.rule,org.jboss.byteman.rule.exception,org.jboss.byteman.rule.helper,org.systemtap.byteman.helper,* </Import-Package>
Please take note of the additional ‘*’ appended to the clause. This explicit import is required
as previously ‘*’ was considered implied.
NOTE: If you’d like to modify the root pom.xml with a <Import-Package> statement, be sure to place it under
the maven-plugin-bundle artifactId
lberk 
Recent Comments