In Part 1 of Probe Java Methods with Systemtap, we took a look at the basics of pinpoint java probing.  Today we're going to take a look at a more involved example with a tool called Thermostat and components from RHSCL 1.1.

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/.  Considering we're building thermostat from source, we need to ensure the build requirements have been installed.  This can be easily done via the yum-builddep command if the srpm is available (if not, I've compiled a list of packages that should be installed at the bottom of the article).

root:]# yum-builddep thermostat1-thermostat

Depending on your setup it may also be worthwhile to install the package to make sure all the runtime requirements are present.

root:]# yum install thermostat1-thermostat

Next we also need to make sure we're explicitly installing mongodb (from RHSCL-1.1) as this database interaction is the area we'll be inspecting and thermostat uses mongodb for storage purposes.  Be sure to enable the scl shell after installing mongodb.

root:]# yum install mongodb24-mongodb-server mongodb24-mongo-java-driver mongodb24-mongo-java-driver-bson
lberk:]$ scl enable mongodb24 bash

In order to make the necessary OSGi class visibility changes, we're going to clone
thermostat, checkout the 0.15-branchpoint and build with the altered export and imported package lists.

lberk:]$ hg clone http://icedtea.classpath.org/hg/thermostat && cd thermostat
lberk:]$ hg checkout 0.15-branchpoint
< make required modifications >
lberk:]$ mvn -D=skipTests=True 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/image/bin/thermostat service

and in a separate terminal running (make sure you've enabled the scl shell here too)

lberk:]$ distribution/target/image/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 (under the 'thread' tab), 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

Looking at the @count aggregates and comparing the 'threading' and 'non-threading' cases, we can clearly tell database transactions have increased while thread inspection recording was activated.

 

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 to make 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 (in the case of thermostat we can just add this list to distribution/config/osgi-export.properties and be on our way)

org.jboss.byteman.rule
org.jboss.byteman.rule.exception
org.jboss.byteman.rule.exception.EarlyReturnException
org.jboss.byteman.rule.helper
org.systemtap.byteman.helper

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 (in our case we've just added it to thermostat's root pom.xml):

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

Build Require Package List

In the case thermostat's srpm is not immediately available, below is a list of packages that should allow for thermostat to be built.

java-devel
jpackage-utils
maven-local
xmvn
maven-dependency-plugin
maven-surefire-plugin
maven-surefire-provider-junit4
maven-war-plugin
maven-clean-plugin
maven-assembly-plugin
maven-plugin-bundle
maven-javadoc-plugin
libgnome-keyring-devel
felix-framework
fusesource-pom
gtk2-devel
tomcat-servlet-3.0-api
apache-commons-cli
jansi
apache-commons-logging
apache-commons-beanutils
apache-commons-codec
httpcomponents-core
httpcomponents-client

Editor's note:  Thermostat is now available with Red Hat Software Collections 1.1 (beta).

Last updated: November 2, 2023