Byteman Blog

Byteman 2.0.0 Released

2012-01-10T03:49:00.000-08:00

Byteman 2.0.0 has been released. It includes a small number of bug fixes and new features and is available from the Byteman download page. If you are using Byteman from maven then the jars are available via the JBoss repository.

The release is accompanied by part two of the Byteman tutorial series, Fault Injection Testing With Byteman.

Byteman Squashes Drools Bug

2012-01-09T01:33:00.000-08:00

Martin Vecera is a senior member of our JBoss QE staff and one the Byteman project power users. He recognised Byteman's potential in its very early days and has provided valuable feedback during its development and been the project evangelist to our QE team. Martin has written up a very nice example of using Byteman for debugging and diagnosing a problem in Drools.

Using a conventional debugger is infeasible when a program repeatedly invokes the routine you want to investigate inside a long-running control loop. Product trace can help in such circumstances but it often fails because switching it on produces far more data than you actually need and does not always print the information you actually want to see.

So, Martin injected a simple Byteman rule into precisely the calls he is interested in and used a helper class to dump the critical data to a file in exactly the format he wants. Using Byteman he was able to inject the specific, controlled tracing behaviour he needed just where he needed it with out incurring any extra overheads. Enjoy.

Byteman 1.6.0 Released

2011-10-03T08:09:00.000-07:00

Byteman 1.6.0 has been released and can be downloaded

from the Byteman download page

or

via the JBoss maven repository

Byteman 1.6.0 is a patch release which fixes a small number of bugs. The main point of interest is that Byteman can now be used on JDK6 and JDK7.

Byteman now gitted and mavenized

2011-08-04T04:47:00.000-07:00

The Byteman source code has been moved to github and the build process has been converted to maven. Both of these changes have been made in order to make it easier for other developers to make contributions to the Byteman project or build extra capabilities on top of Byteman.

Byteman Demo at JUDCon

2011-05-16T19:00:00.001-07:00

I just got back online after a couple of weeks holiday following the Byteman talk at JUDCon in Boston. JUDCon is the part of Red Hat's JBossWorld/Summit conference where JBoss/Java tecchies get together to present all the neat things they have invented over the last 6 months/year. So, of course, one of the neat things on the agenda was Byteman.

The presentation was very well received and there were lots of interesting questions during and after the talk. A pdf is available from the Byteman docs page. The presentation included a small demo which showed some Byteman rules being injected into a simple Quartz timer bean stolen from one the JBoss EAP5 EJB tutorial. Like all demos it is slightly artificial but it does show just how simple it is to run up Byteman and introduce timing constraints into a threaded application. Since the demo was not recorded I'll present the code example here and show the demo output for those who missed the talk.

The Demo Code

The example code used in the demo displays the Quartz timer capability provided as part of the standard JBoss app server release. The original example was coded for EAP5 but I actually ran it quite happily on AS 6. To avoid introducing too much clutter into the demo output I modified the example code so that only the annotated Quartz timer bean is deployed. Here is the definition I used for the bean:

 @MessageDriven(activationConfig =
{@ActivationConfigProperty(propertyName =
"cronTrigger", propertyValue = "0/5 * * * * ?")})
@ResourceAdapter("quartz-ra.rar")
public class AnnotatedQuartzMDBBean implements Job
{
private static final Logger log =
Logger.getLogger(AnnotatedQuartzMDBBean.class);
public void
execute(JobExecutionContext jobExecutionContext)
throws JobExecutionException
{
AnnotatedQuartzMDBBean.log.info("************** here in annotated!!!!");
}
}

The bean is pretty simple. It just prints a message saying here I am when the callback is triggered. The annotation declares it as a message driven bean triggered by the Quartz timer and the cron trigger property requests that the callback is triggered every 5 seconds on a 5 second boundary.

Running The Demo

The bean is deployed by starting up JBoss AS and then running 'ant' in subdirectory jca_inflow_quartz of the downloaded tutorial code. Here's the output you get when the bean is deployed into JBoss AS 6.

 [adinn@localhost adinn]$ $JBOSS_HOME/bin/run.sh
=========================================================================
JBoss Bootstrap Environment
JBOSS_HOME: /home/adinn/jboss/jbossas/jboss-6.0.0.Final
. . .
[6.0.0.Final "Neo"] Started in 22s:617ms
06:12:27,678 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@1809001556{vfs:///ssd/home/adinn/jboss/jbossas/jboss-6.0.0.Final/server/default/deploy/jboss-ejb3-tutorial-jca_inflow_quartz.jar}
. . .
06:12:27,748 INFO [org.jboss.ejb3.deployers.JBossASKernel] Added bean(jboss.j2ee:jar=jboss-ejb3-tutorial-jca_inflow_quartz.jar,name=AnnotatedQuartzMDBBean,service=EJB3) to KernelDeployment of: jboss-ejb3-tutorial-jca_inflow_quartz.jar
06:12:27,800 INFO [org.jboss.ejb3.EJBContainer] STARTED EJB: org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean ejbName: AnnotatedQuartzMDBBean
06:12:30,083 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
06:12:35,010 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
06:12:40,004 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
06:12:45,006 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
06:12:50,004 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
06:12:52,923 INFO [org.jboss.ejb3.EJBContainer] STOPPED EJB: org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean ejbName: AnnotatedQuartzMDBBean
06:12:52,948 INFO [org.jboss.ejb3.instantiator.deployer.BeanInstantiatorDeployerBase] Uninstalled org.jboss.ejb3.instantiator.impl.Ejb31SpecBeanInstantiator@2f385f78 from MC at org.jboss.ejb.bean.instantiator/jboss-ejb3-tutorial-jca_inflow_quartz/jboss-ejb3-tutorial-jca_inflow_quartz/AnnotatedQuartzMDBBean

As you can see the bean callback is executed every 5 seconds as expected.

The Byteman Rules

The Byteman demo uses two rules defined as follows:

RULE set up rendezvous
CLASS AnnotatedQuartzMDBBean
METHOD <init>
AT EXIT
IF NOT isRendezvous("quartz", 3)
DO createRendezvous("quartz", 3, true)
ENDRULE

RULE delay quartz bean
CLASS AnnotatedQuartzMDBBean
METHOD execute
AT ENTRY
IF isRendezvous("quartz", 3)
DO traceln("**** enter quartz rendezvous ");
traceln("*** exit " + rendezvous("quartz"));
ENDRULE

The first rule is attached to the constructor method for the timer bean class (<init> is the internal name used by the JVM for a constructor method). It is triggered when an instance of the timer bean class is created just before the constructor method returns. The rule uses the standard Byteman built-in operation createRendezvous to create a rendezvous identified using the String "quartz". The call to isRendezvous in the condition ensures that only one rendezvous is ever created.

A rendezvous is used to introduce a synchronization point for some given number of threads (a rendezvous is also commonly referred to as a barrier). Any thread which attempts to enter the rendezvous may be suspended until the required number of threads has arrived. Once the required number of threads have entered all of them are released and allowed to continue past the rendezvous call. In this case the rendezvous count is supplied by the second argument, 3.

Normally when a rendezvous has been met by all the required threads it gets deleted. Any thread which subsequently tries to enter the rendezvous just continues without suspending. The 3rd boolean argument true supplied in the create call makes this a repeatable rendezvous. So, after 3 threads arrive the rendezvous is reinstated allowing a further 3 threads to meet and so on.

The second rule is injected at the start of the timer bean callback method execute and it is this rule which makes the timer threads enter the rendezvous. The condition ensures the rule only fires if the rendezvous is present. The first statement in the rule action is a call to builtin operation traceln which prints a message to System.out saying the thread is entering the rendezvous. The second call to traceln prints a String created by pasting together the prefix "exit *** " and the integer value returned by calling built-in method rendezvous. This printout will not be executed until the call to rendezvous returns.

So, when the first timer callback is created the timer thread will print the enter message, call rendezvous and suspend. 5 seconds later Quartz creates a new thread to run the second callback and this also prints the enter message then calls rendezvous and suspends. 5 seconds later the 3rd callback thread prints its enter message and calls rendezvous. All 3 threads are released and they all print the exit message. The return value is either 0, 1 or 2 depending upon which thread arrived in which order. All 3 threads go on to execute the body of the callback and exit. 5 seconds later the whole cycle starts again.

Running the Demo With Byteman

This time after booting up AS 6 we load the agent into the app server and then load the rule script. The rules need to be loaded before the quartz bean is created so that the <init> rule is in place before the timer bean is created. The agent can be loaded on the JVM command line but it is easier to start up AS 6 and then load the agent once the app server is running.

 [adinn@localhost jca_inflow_quartz]$ ${BYTEMAN_HOME}/bin/bminstall.sh org.jboss.Main
[adinn@localhost jca_inflow_quartz]$

The script bminstall.sh uploads the byteman agent into a running JVM. You can specify which JVM by supplying as argument either its process id or, as in this case, the name of the application class providing the JVM entry point.

The agent can now be talked to using script bmsubmit.sh. If we provide it with the name of the rule script file as an argument it will upload rules into the JVM ready for injection into the classes mentioned in the rules.

 [adinn@localhost jca_inflow_quartz]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh rules.btm
install rule set up rendezvous
install rule delay quartz bean
[adinn@localhost jca_inflow_quartz]$

If we now execute bmsubmit.sh with no arguments it will show us that the rules are loaded but not yet injected. This is because the classes they apply to have not yet been deployed It is possible to install rules into classes which have already been loaded into the JVM but in this case we want to trigger the <init> rule when the timer bean is created. That will happen during loading so we need to install the rules before deploying the application.

 [adinn@localhost jca_inflow_quartz]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh
# File rules.btm line 13
RULE delay quartz bean
CLASS AnnotatedQuartzMDBBean
METHOD execute
AT ENTRY
IF isRendezvous("quartz", 3)
DO traceln("**** enter quartz rendezvous ");
traceln("*** exit " + rendezvous("quartz"));
ENDRULE
# File rules.btm line 5
RULE set up rendezvous
CLASS AnnotatedQuartzMDBBean
METHOD <init>
AT EXIT
IF NOT isRendezvous("quartz", 3)
DO createRendezvous("quartz", 3, true)
ENDRULE
[adinn@localhost jca_inflow_quartz]$

The listing from the agent shows that the rules are in place. When we deploy the app they get injected into the bean code as it is loaded. The rendezvous gets created and the subsequent timer thread output is delayed until a group of 3 threads have arrived at the rendezvous. The next 3 threads are also grouped and so on.

 07:00:44,028 INFO [org.jboss.bootstrap.impl.base.server.AbstractServer] JBossAS [6.0.0.Final "Neo"] Started in 23s:706ms
07:00:59,209 INFO [org.jboss.ejb3.deployers.Ejb3DependenciesDeployer] Encountered deployment AbstractVFSDeploymentContext@1865896779{vfs:///ssd/home/adinn/jboss/jbossas/jboss-6.0.0.Final/server/default/deploy/jboss-ejb3-tutorial-jca_inflow_quartz.jar}
. . .
07:00:59,334 INFO [org.jboss.ejb3.EJBContainer] STARTED EJB: org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean ejbName: AnnotatedQuartzMDBBean
07:01:00,192 INFO [STDOUT] **** enter quartz rendezvous
07:01:05,018 INFO [STDOUT] **** enter quartz rendezvous
07:01:10,006 INFO [STDOUT] **** enter quartz rendezvous
07:01:10,007 INFO [STDOUT] *** exit 0
07:01:10,007 INFO [STDOUT] *** exit 2
07:01:10,007 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:10,007 INFO [STDOUT] *** exit 1
07:01:10,007 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:10,007 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:15,004 INFO [STDOUT] **** enter quartz rendezvous
07:01:20,004 INFO [STDOUT] **** enter quartz rendezvous
07:01:25,004 INFO [STDOUT] **** enter quartz rendezvous
07:01:25,005 INFO [STDOUT] *** exit 1
07:01:25,005 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:25,005 INFO [STDOUT] *** exit 2
07:01:25,006 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:25,006 INFO [STDOUT] *** exit 0
07:01:25,008 INFO  [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!

At this point if we run the submit script with no arguments we can see that the rules have been injected into the target methods. The listing now shows the class and method the rule was injected into and the classloader which loaded the rule. It also indicates that the rule was injected, type-checked and compiled correctly.

 [adinn@localhost jca_inflow_quartz]$ bmsubmit
# File rules.btm line 13
RULE delay quartz bean
CLASS AnnotatedQuartzMDBBean
METHOD execute
AT ENTRY
IF isRendezvous("quartz", 3)
DO traceln("**** enter quartz rendezvous ");
traceln("*** exit " + rendezvous("quartz"));
ENDRULE
Transformed in:
loader: BaseClassLoader@25f4cf3c{vfs:///ssd/home/adinn/jboss/jbossas/jboss-6.0.0.Final/server/default/deploy/jboss-ejb3-tutorial-jca_inflow_quartz.jar}
trigger method: org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean.execute(org.quartz.JobExecutionContext) void
compiled successfully
# File rules.btm line 5
RULE set up rendezvous
CLASS AnnotatedQuartzMDBBean
METHOD <init>
AT EXIT
IF NOT isRendezvous("quartz", 3)
DO createRendezvous("quartz", 3, true)
ENDRULE
Transformed in:
loader: BaseClassLoader@25f4cf3c{vfs:///ssd/home/adinn/jboss/jbossas/jboss-6.0.0.Final/server/default/deploy/jboss-ejb3-tutorial-jca_inflow_quartz.jar}
trigger method: org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean.<init>() void
compiled successfully
[adinn@localhost jca_inflow_quartz]$

We can run the script again with the -u flag to remove the rules.

 [adinn@localhost jca_inflow_quartz]$ bmsubmit -u
uninstall RULE delay quartz bean
uninstall RULE set up rendezvous
[adinn@localhost jca_inflow_quartz]$

We now see that the injected code is removed, the timer bean reverts to its normal behaviour and once again the messages start being printed every 5 seconds.

 07:01:30,010 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:35,005 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:40,006 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!
07:01:45,005 INFO [org.jboss.tutorial.quartz.bean.AnnotatedQuartzMDBBean] ************** here in annotated!!!!

Byteman Release 1.5.1 is now available

2011-02-02T03:17:00.000-08:00

The Byteman 1.5.1 patch release is now available from the JBoss maven
repo and from the Byteman project download page.

1.5.1 upgrades the BMUnit contrib package to integrate Byteman into both
the JUnit and (new) TestNG test frameworks. The upgrade also simplifies
the deployment process. In particular, this means that you can now plug
Byteman rules into your maven Surefire tests simply by adding the
Byteman jars as test dependencies. So, now there is no excuse for not
using fault injection in your tests.

Full details are in the BMUnit package README.

Byteman 1.5.0 JUnit Integration Makes Fault Injection Simple

2011-01-17T07:42:00.000-08:00

Byteman 1.5.0 has just been released and the major new feature is a really nice user contributed package, BMUnit, which provides integration with JUnit. It makes fault injection testing and execution tracing unbelievably simple.

BMUnit provides annotations which you use to identify the Byteman rules needed for each of your JUnit tests. Annotations attached to a test class specify rules which apply to all test methods. Annotations attached to a method identify rules which only apply for that specific test.

The BMUnit test runner ensures the Byteman agent is installed in the JUnit JVM before any testing starts. It automatically loads all required rules into the JVM before running a test and unloads them when they are no longer needed. All you need to do to use BMUnit is is attach an @RunWith(BMUnitRunner.class) annotation to your test class.

Here's a simple example to show you how quick and easy BMUnit is to use

@RunWith(BMUnitRunner.class)
public class FileOpenTest {
  @BMRule(name="throw security exception",
    targetClass="FileInputStream",
    targetMethod="<init>(File)",
    condition="$1.getName().equals\"badname.txt\")"
    action="throw new SecurityException(\"bad name!\")")
  @Test
  public void testSecurityException() {
    MyTestClass myTestObj = new MyTestClass();
    myTestObj.processFile("badname.txt");
  }
  . . .
}

In this example a single rule is provided inline in the test program itself, using a @BMRule annotation attached to test method testSecurityException. The rule is triggered on entry to the constructor FileInputStream(File). The condition restricts the rule to firing only when the File argument has name "badname.txt" (which we have cunningly arranged to be the name supplied in the test call). When the rule does fire the action causes a SecurityException to be thrown from the constructor.

So, when this unit test is run the runner class, BMUnitRunner, will install the agent into the test JVM then load the rule defined in the annotation into the agent database, injecting it into the constructor method. When a file open is attempted under the call to myTestObj.processFile() the rule is triggered, ensuring that the test class, MyTestClass, receives a SecurityException.

Clearly, it would be more interesting if we could be sure that the security exception was handled correctly. A few more rules can be used to check that the correct handler code has been called or, if not, force a test failure. In this case we will place the rules in a separate script to avoid adding too much clutter to the test class. First we change the annotation to @BMScript, pointing the BMUnit test runner at a rule script file.

@RunWith(BMUnitRunner.class)
public class FileOpenTest {
  @BMScript(value="security-exception", dir="scripts")
  @Test
  public void testSecurityException() {
    MyTestClass myTestObj = new MyTestClass();
    myTestObj.processFile("badname.txt");
  }
  . . .
}

The BMScript annotation identifies the name and location of the script file. Locations with a non-absolute path are interpreted relative to the working directory of the test JVM. The script file name is looked for using either a ".btm" or ".txt" extension. So, let's assume we have placed the following rules in a file called "security-exception.btm" located in subdirectory "scripts".

RULE throw security exception 
CLASS FileInputStream 
METHOD <init>(File)", 
IF "$1.getName().equals\"badname.txt\" 
DO clear("handled"); 
   throw new SecurityException("bad name!") 
ENDRULE 
RULE track handler call, 
CLASS MyTestClass 
METHOD handle(SecurityException) 
IF true 
DO flag("handled") 
ENDRULE 
RULE ensure handler call 
CLASS MyTestClass 
METHOD processFile(File) 
AT RETURN 
IF !flagged("handled") 
DO throw new RuntimeException("unhandled security exception") 
ENDRULE

The first rule is essentially the same as the one we had in the @BMRule annotation. The only difference is that it clears any flag associated with keyword "handled". The second rule is triggered when method handle(SecurityException) of class MyTestClass gets called. It fires unconditionally, setting a flag labelled by the keyword string "handled". We will assume that calling this method is enough to guarantee that the test has passed. The third rule is triggered when method processFile(File) returns normally. If the "handled" flag has not been set it throws an exception, causing the unit test to fail. If processFile(File) returns abnormally this rule will be bypassed but the exception will be detected by JUnit, also indicating a failure.

Of course, we could have used the BMScript and BMRule annotations in combination, defining, say, the first rule inline and the second and third rule in the script. We can also specify more than one rule or more than one script by using the annotations @BMRules and @BMScripts. The values of these annotations are an array of, respectively, @BMRule or @BMScript annotations. For example

@RunWith(BMUnitRunner.class)
public class FileOpenTest {
  @BMRules( {
    @BMRule(name = "throw security exception", ...)
    @BMRule(name = "track handler call", ...)
  })
  @Test
  public void testSecurityException() {
    MyTestClass myTestObj = new MyTestClass();
    myTestObj.processFile("badname.txt");
  }
  . . .
}

Full details of how to use the package are included in the README located in the contrib/bmunit subdirectory of the 1.5.0 release.

Meet Byteman at JBoss Asylum

2010-12-22T12:01:00.000-08:00

Not to be confused with Arkham Asylum, JBoss Community Asylum is a podcast about, for and by the JBoss Community. It provides news about what the JBoss community is up, including interviews with JBoss developers. The latest sensational podcast reveals the identity of the man behind the mask, Byteman lead developer Andrew Dinn. If you want to hear how Byteman chases down and banishes evil bugs or find out how Byteman was conceived and grew into one of software's toughest enforcers then tune in to the JBoss Asylum Byteman Christmas Special at

http://in.relation.to/Bloggers/Podcast16BytemanBegins

Byteman 1.4.1 Now Available For Download

2010-11-25T01:16:00.000-08:00

Byteman patch release 1.4.1 is now available at the project download page or from the JBoss maven repository. The release patches a few important bugs and omissions including:

a regression introduced into AT LINE triggers has been corrected
assignment of arrays and creation of arrays has been implemented
e.g. you can now write things like BIND strArray = new String[2] and DO strArray[0] = "foo"

The release also provides a couple of new features:

trigger points can now include local or parameter variable accesses
e.g. the rule location can now be something like AT READ $loopvar where $loopvar identifies a local variable or AFTER WRITE $1 where $1 identifies the first method parameter
AFTER INVOKE rules can now read and reassign $!, the value returned by the method invocation which triggered rule processing
e.g. a rule injected into the trigger method after a call to myIntMethod (location AFTER INVOKE myIntMethod) might employ the condition IF $! < 0 and action DO $! = 0 to ensure that the value returned from myintMethod was never negative.

Details of all features and bug fixes are provided in the release notes. A full explanation of all new behaviour is available in the programmer's guide.

Collecting and Displaying Runtime Statistics With Byteman

2010-10-28T07:07:00.000-07:00

The latest 1.4.0 Byteman release includes a couple of example rule scripts in the sample directory which show off just how powerful a tool Byteman is. Both scripts use Byteman rules to count statistically important events. One of them monitors events in the JVM like Thread creates, and starts, FileStream opens etc. The other counts the number of times your application makes calls to any of the javax Transaction API methods. Well, that's not exactly very impressive is it? I mean, it's fairly easy to inject code which increments a counter, no?

The nice part is that the rules in the script automatically turn those counters into a variety of statistics then format and present the statistics in a dynamically generated MBean displayed in the JMX console. Even nicer the rules in the script control what gets counted and how it gets presented. So, if you can write a rule to count events you are interested in, either in JVM code or in your application code, then you can automatically present this data as statistics. The MBean gets installed when you load your Byteman rules. Unload the rules and the MBean gets uninstalled. Tweak the rules and reload them and you can measure different data. Ad hoc monitoring of your JVM or your app is now fully dynamic and takes just seconds.

In the rest of this blog I'm going to take a walk through how the script operates. For those who want to see the end result here is a quick look ahead at the MBean display for the JVM stats script. After that I talk about how the scripts are written. Hopefully, by the end of it you should know enough to be able to write your own counting rules and generate a statistics display for your own app. Here's the screenshot

JVMMBeanStats.txt is the script which was used to create and populate that MBean. First off let's see how it counts raw events. As one example, consider the following rule

# this rule counts Thread creates
RULE count thread creates
CLASS java.lang.Thread
METHOD <init>
AT EXIT
IF TRUE
DO debug("create thread " + $0.getName());
incrementCounter("thread creates")
ENDRULE

The rule gets injected into any constructor method of class java.lang.Thread and, since its condition is TRUE, it always fires. It uses the built-in method incrementCounter to add one to the counter identified by the String object "thread creates". Now, every thread create, whether for a java.lang.Thread or for a subclass of java.lang.Thread will end up executing one of the constructor methods and triggering this rule. So, effectively the counter tracks the number of threads created in the JVM.

Note that the rule is injected AT EXIT -- i.e. it triggers just before the method returns. This ensures that the Thread instance has been initialised before the debug statement in the rule makes a call to Thread.getName().

It is obviously relatively simple to inject Byteman rules into any JVM or application method and have them increment or decrement counters in order to track what the runtime/application is doing. Note that method incrementCounter() can be provided with an extra integer argument defining the value to be added to the counter. Method readCounter() allows the counter to be reset to zero while retrieving the current count atomically. This makes it is possible to count in many different ways e.g. by adding in the value of a method parameter or field value each time the rule is triggered.

Sometimes the location and condition of a rule need to be a little more sophisticated in order to ensure that only relevant events are counted. For example, the following rule only counts calls to run methods of Thread classes when they are entered from the VM.

# this rule counts Thread runs
RULE count thread run
CLASS ^java.lang.Thread
METHOD run()
# only count run when called from JVM i.e. when there is no caller frame
IF !callerMatches(".*")
DO debug("run thread " + $0.getName());
incrementCounter("thread runs")
ENDRULE

This rule uses the ^ notation in the CLASS clause. This means that the rule is injected down the class hierarchy i.e. not just into Thread.run() but also into any overriding implementation of run() defined by a subclass of Thread.

The condition in this rule uses the built-in operation callerMatches() to ensure that the call is made from the JVM itself (i.e. in response to a call to Thread.start()) rather than from Java code. Method callerMatches() is implemented with a variety of argument patterns; in this one the argument is a regular expression (regexp) to be matched against the name of the method which directly called the trigger method. callerMatches() returns true if the caller method name matches the regexp; if not it returns false. Here's an example of a call which would not fire the rule. In this case the caller method name would be runFooThread.

class FooThreadExecutor {
public runFooThread(FooThread fooThread) {
fooThread.run();
}
}

Now, the pattern ".*" in the Byteman rule will match any method name. So, in the example above the call returns true making the condition false. The only way callerMatches can return false when called with ".*" as an argument is if there is no caller frame in the stack when the run() method gets entered. This is precisely the situation where run() is called from the JVM as a result of some other thread calling Thread.start(). So, this rule does not count pseudo-run operations like the example above.

That's all very well as far as doing the raw counting is concerned but how do the statistics get sampled and displayed to the user? Well, there's a give away in the name of the example scripts, both of which contain the word MBean. The rules in both scripts employ a special helper class called JMXHelper which collects the raw counter data and then presents it in an MBean.

At the top of each script is a line like this

 HELPER org.jboss.byteman.sample.helper.JMXHelper

This means that all the rules in the script will use this class unless they specify their own helper by including a HELPER clause in the rule body. A rule's helper class is used to resolve built-in calls like the ones in the example rules above, incrementCounter() or debug(). Built-in calls have no target object and look like static method calls but without any package qualifier.

Helper classes do not need to implement any special interface or be annotated in any specific way. JMXHelper is just a POJO class. It can be found in the byteman-sample jar included with the Byteman release. JMXHelper inherits from Byteman's default helper class which is why the example rules are able to call the standard built-in methods. So, for example, debug(String) is a public instance method of the default helper and the call to debug("run thread " + $0.getName()) in the example rules gets executed by calling this method. Any public instance method provided by the helper can be called in the rule body as a built-in.

Actually, JMXHelper does not add any extra public methods to the set provided by the default helper class. However, what it does do is implement some public static lifecycle methods. Helper lifecycle methods get called when rules which employ the helper are installed and/or deinstalled by Byteman. Here is one of the methods on JMXHelper

public static void activated()
{
if (theHelper == null) {
theHelper = new JMXHelper(null);
theHelper.start();
}
}

This method gets run when the first rule which employs the helper class is installed into the JVM by Byteman. So, if you load one of these scripts on the java command line or if you upload the rules at runtime using the bmsubmit.sh script then this method will get called once only.

The lifecycle method assigns an instance of JMXHelper to static field theHelper and then runs the instance's start() method. The latter method starts a background thread which wakes up at regular intervals and samples the counters incremented by the rules in the script. The background thread also creates and installs a DynamicMBean into the JVM's MBean server to display the counter values.

Of course, it is possible to use the bmsubmit.sh script provided with the release to deinstall the rules which employ JMXHelper from the runtime. Once all these rules have been removed it is only appropriate to unregister the MBean and shutdown the background thread. Naturally, there is a corresponding lifecycle method which gets called when the last rule employing JMXHelper gets removed from the runtime

public static void deactivated()
{
if (theHelper != null) {
theHelper.shutdown();
theHelper = null;
}
}

Ok, so that explains how the sampling and display operates (well modulo the details of exactly how the thread and MBean get created and started/stopped but that's just bread and butter coding). The more important question is how does the background thread know which counters to sample, how often to sample them and how to display them in the MBean. It would not be much use if these values were hard-wired into class JMXHelper since that would mean that every time you wanted to collect different statistics you would need to rewrite and redeploy the class.

In fact it is perfectly possible to use Byteman rules to parameterise the behaviour of the helper and the MBean. Class JMXHelper provides three methods which are called by the background thread when it is started. A script can inject code into these methods which supplies all the information needed to configure the behaviour of the background thread and the MBean.

So, the first rule we will look at is the one which defines the sample period i.e. how long the background thread waits before waking up and checking the value of the counters used in the script. Here is the method implemented by JMXHelper

public final static long DEFAULT_PERIOD = 10000L;
private long samplePeriod()
{
return DEFAULT_PERIOD;
}

So, by default the background thread wakes up every 10,000 milliseconds i.e. every 10 seconds. The scripts override this period using the following rule which resets the sample period to 5 seconds by injecting code which returns value 5000 when the method is called.

# this rule is triggered when the periodic helper thread starts
# it returns a sample period in milliseconds for which the
# periodic helper thread sits and waits before sampling each
# of the counters and updating the MBean
RULE set period
CLASS JMXHelper
METHOD samplePeriod()
AT ENTRY
IF TRUE
DO RETURN 5000
ENDRULE

So, how about configuring the counters and the MBean display? Well, the background thread calls the following method during startup

private KeyInfo keyInfo()
{
// if the rule set does not generate a keyinfo value then we return this one to indicate
// that something is missing.
String[] keyNames = new String[1];
keyNames[0] = "No counters defined";
return new KeyInfo("Byteman Periodic Statistics", keyNames);
}

The method returns a KeyInfo object. Essentially this contains 3 lists of data. The first list identifies the names of the counters to be sampled. The second list identifies the format in which each corresponding counter value should be displayed and the third provides a descriptive label for each counter. The default implementation above creates a KeyInfo object with only one counter which, presumably, never gets incremented. The format and description take the default values.

This method is overridden by the JVMMBeanStats script as follows

# this rule is triggered when the periodic helper thread starts
# it returns a KeyInfo object identifying the stats counters
# updated by rules in this rule set
RULE return key info
CLASS JMXHelper
METHOD keyInfo()
BIND keyInfo : KeyInfo = new KeyInfo("JVM Statistics in a Dynamic MBean")
IF TRUE
DO keyInfo.addKey("thread creates", KeyInfo.KEY_TYPE_CUMULATIVE, "Thread() total calls");
keyInfo.addKey("thread runs", KeyInfo.KEY_TYPE_CUMULATIVE, "Thread.run() total calls");
...
keyInfo.addKey("thread creates", KeyInfo.KEY_TYPE_RATE, "Thread() calls per second");
keyInfo.addKey("thread runs", KeyInfo.KEY_TYPE_RATE, "Thread.run() calls per second");
...
keyInfo.addKey("class loads", KeyInfo.KEY_TYPE_MEAN, "ClassLoader.defineClass() mean calls per sample");
RETURN keyInfo
ENDRULE

The rule creates a KeyInfo object in the BINDS clause binding it to variable keyInfo. The rule action calls the addkey method repeatedly to add the name, format type and description for each of the counters updated in the rule set. Finally it returns the object identified by keyInfo to the background thread. The thread uses this object to construct a dynamic MBean populated with fields each of whose name, format, description and value is derived from each key entry and associated counter. Every time the thread wakes up it samples the value of the counters. When the MBean is refreshed the latest sampled values are used to recompute the displayed statistic.

Note that the same counter can be used more than once with a different format. So, for example, the first counter, "thread creates", is added with format CUMULATIVE and then added again later with format RATE. Format CUMULATIVE indicates that the MBean should display the last sampled value for the counter. With this format the counter is simply being presented as raw data.

By contrast format RATE means that the MBean should compute the difference between successive sample values and divide it by the sample period to compute the rate at which the counter is changing. So, if the latest sampled value for "thread creates" is 5090 and the previous sampled value was 4940 then the statistic displayed in the MBean would be (5090 - 4944) / 5.0 i.e. 29.2 Thread() calls per second.

In fact the sampling is slightly more sophisticated in order to smooth out variations which occur because of wakeup delays and overlap of application phase changes with the sample intervals. The RATE algorithm can be configured to employ up to 11 prior samples (i.e up to 10 differences) and it divides the difference by the actual time interval between samples rather than the nominal wakeup period.

The MEAN statistic provides another view of the counter data. It computes the change in the counter value across a sample period i.e. it represents how many things were counted during the period. Once again it can be based on up to 11 sample counter readings and the value is corrected to allow for the number of samples included and the variation in the sample intervals.

How is the sample set count defined? Well, that's the third method of class JMXHelper which can be overridden by a rule. It's called sampleSetSize() and it returns 5 as the default set size. It can be overridden using a rule as follows

# this rule is triggered when the periodic helper thread starts
# it returns a count for the number of samples which will be
# combined when computing counter rates or counter sample period
# means
RULE set sample set size
CLASS JMXHelper
METHOD sampleSetSize()
IF TRUE
DO RETURN 3
ENDRULE

Ok, so it's clear that JMXHelper provides a general purpose display mechanism which can be used to present any statistics which you can gather by injecting calls to incrementCounter(). How do you actually install it into a running JVM and what does the final display look like?
Well, the scripts themselves contain detailed instructions but for now I'll show you how to install the JVMMBeanStats script into a JBoss Application Server instance. In the process I'll show off another neat feature of the latest Byteman release

Normally, in order to be able to load and unload byteman rules into a JVM you need to install the Byteman agent when you start up the JVM. There is a useful script in the installed bin directory called bmjava.sh which simplifies this job in the case where you are starting your program using the java command. In most cases you simply call bmjava.sh instead of java. Unfortunately, JBoss AS wraps up the call to java inside its own startup script. This means that you have to set environment variable JAVA_OPTS to pass the -javaagent argument on the java command line. Also, the javaagent argument needs to have several options appended to it to identify the location of the byteman jar and either point Byteman at a rule script or switch on the agent listener so you can upload rules using bmsubmit.sh after the program is started.

With the 1.4.0 release you can now start up JBoss and then upload the agent once the JVM is running. This is possible on any JVM which implements the server side of the com.sun.tools.attach.VirtualMachine API. Ok, you don't actually need to know what that means but you do need to know that it has been found to work on Sun's JDK6 (naturally), OpenJDK6 and JRockit JDK6. I have not yet found an IBM JDK6 on which it does work (although the other Byteman features all appear to work fine) but I have not made a comprehensive survey of all their releases so you'll have to verify this for yourselves.

So, first off you need to start your JBoss instance by calling run.sh

 [adinn@localhost adinn]$ $JBOSS_HOME/bin/run.sh
=========================================================================
JBoss Bootstrap Environment
JBOSS_HOME: /home/adinn/jboss/jbossas/trunk/build/target/jboss-6.0.0-SNAPSHOT
JAVA: /usr/java/jdk1.6.0_21/bin/java
...

Now you need to identify the process id of the JBoss AS process

 [adinn@localhost adinn]$ jps -l
23812 org.jboss.Main
23892 sun.tools.jps.Jps

Now you run the bminstall.sh script to upload the agent into the JBoss JVM

 [adinn@localhost adinn]$ ${BYTEMAN_HOME}/bin/bminstall.sh -b \
-Dorg.jboss.byteman.transform.all=true 23812

I have added a couple of extra arguments to the install command. The -b argument ensures that the agent jar is installed into the JVM bootstrap classpath and the -D argument sets a system property checked by the agent. Why are these needed? Well, the JVMMBeanStats script needs to be able to inject code into JVM classes in the java.* packages. This feature is normally disabled to stop you shooting yourself in the foot. Setting this system property when the agent is loaded allows injection into any class including those in the java.* package. Even with this enabled injection into java.* classes will not 'just work'. The problem is that the injected code must be able to reference exception types declared in the byteman jar. Since the java.* classes live in the bootstrap classpath the agent jar must also be added to that path.

Ok, so just to check that the agent is running let's see if we can talk to it using the bmsubmit.sh script.

 [adinn@localhost adinn]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh -l
no rules installed

Good, the agent is running and responding. Now, with JBoss also up and running we can take a look at the JMX console.

Nothing there at present that mentions Byteman. That's because we haven't yet loaded any rules which use JMXHelper. So, let's upload the rules in the JVMMBeanStats rule set and then run some code to exercise them. Before loading the rule set we also need to install the sample jar into the boot classpath so that our injected rule code can reference classes JMXHelper and KeyInfo. We use bmsubmit.sh with the -b flag to load a jar into the bootstrap classpath and then again with the -l flag to load a rule script.

[adinn@localhost adinn]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh -b ${BYTEMAN_HOME}/sample/lib/byteman-sample.jar
append boot jar /home/adinn/jboss/byteman/trunk/install/sample/lib/byteman-sample.jar
[adinn@localhost adinn]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh ${BYTEMAN_HOME}/sample/scripts/JVMMBeanStats.txt
install rule return key info
install rule set period
install rule set sample set size
install rule count thread create
install rule count thread start
install rule count thread run
install rule count thread exit
install rule count file open read File
install rule count file open read File Descriptor
install rule count file open write File
install rule count file open write File Descriptor
install rule count file input stream close
install rule count file output stream close
install rule count class loads

Right, the agent should now have injected the rules into the relevant methods of classes Thread, FileOutputStream etc and then activated the JMXHelper class. So lets take another look at the JMX console. We can see that a new bean has popped up in the left hand side menu. Clicking on it reveals it to be the bean added by Byteman.
A click on the PeriodicStats element in the display shows us the actual stats.

The period (5) and sample set size (5) are displayed at the top followed by the statistics for each entry defined in the key info. We can see that the total number of threads created since the rule set was loaded is 34. The number created in the last five sample intervals must be 5 since the creation rate appears to be exactly 0.2 per second. Only 2 threads have exited which, presumably, indicates that the allocated threads are being used to fill up a thread pool.

Note that the sample period is a writeable property resettable from the MXBean. The MXBean also provides an operation (off screen in this snapshot) which allows all counters to be reset to zero.

Finally, we can use the bmsubmit.sh script to deinstall all the rules. This causes JMXHelper to be deactivated and it removes the MBean from the display. The agent removes all the injected rule code, restoring the affected JVM methods back exactly as they were before the rule script was uploaded.

[adinn@localhost adinn]$ ${BYTEMAN_HOME}/bin/bmsubmit.sh -u /home/adinn/jboss/byteman/trunk/install/sample/scripts/JVMMBeanStats.txt
uninstall RULE return key info
uninstall RULE set period
uninstall RULE set sample set size
uninstall RULE count thread create
uninstall RULE count thread start
uninstall RULE count thread run
uninstall RULE count thread exit
uninstall RULE count file open read File
uninstall RULE count file open read File Descriptor
uninstall RULE count file open write File
uninstall RULE count file open write File Descriptor
uninstall RULE count file input stream close
uninstall RULE count file output stream close
uninstall RULE count class loads

Here's the JMX console again, with the Byteman stats MBean removed

If we want to vary the information displayed or the way it is computed we can just tweak the rule script to record different events or use different counting rules for the same events and then reload the script by calling bmsubmit.sh. The MBean is automatically recreated and reloaded into the JMX console.

If you want to try this out you can download the latest release from the Byteman downloads page. The binary and full source releases both include the sample jar and scripts plus the latest Byteman programmers guide. I'll also be happy to answer any questions you have or advise on developing rules to track your application behaviour on the Byteman user forum. Enjoy!

Allowing full access to objects in rules

2010-10-11T02:08:00.000-07:00

Some months back one of the developers at JBoss was trying to use Byteman to test some code and he was rather puzzled that his rule was not compiling correctly. It turned out that his rule action included an assignment to a private field. Up until now Byteman has only allowed rule actions to change public state or call public methods. Rule conditions and actions have no special privileges as far as encapsulation is concerned.

As an example, given this class

class Regulator
{
  private float throttle;
  public void adjustThrottle(float amount);
}

the following rule fails

CLASS SteamEngine
METHOD adjustPressure(float)
AT CALL Regulator.adjustThrottle
IF ($0.getRegulator().throttle + $1 > 0.95)
DO traceln("Illegal setting for throttle"),
   traceStack(),
   THROW new BoilerRupture("too much  pressure")
ENDRULE

Class Regulator allows clients to increment or decrement the throttle setting but it does not enable access to the current value, presumably because it handles any illegal settings itself. However, when testing or validating the application it is useful to be able to identify erroneous situations such as the one above where a client is making an invalid request. Regulator may handle the error but it is still important to know where errors arise.

Unfortunately, the rule does not typecheck correctly. Byteman complains that the condition is trying to access an unknown field called throttle. The same issue applies with method invocations. If a method is private then any attempt to call it inside a rule condition or action leads to an unknown method error during type checking. Well, the answer is obvious isn't it. Why not just let rules access whatever state they want?

I have modified the trunk release of Byteman to do just this. It is working and there don't appear to be any problems with it. Of course, enabling this feature raises a whole load more opportunities for you to shoot yourself in the foot when using Byteman. In particular, if you use Byteman to modify JVM static and instance data or call private JVM methods you can easily break your Java runtime into shiny little pieces. But then again, this feature makes it possible to do a whole load more tracing and verification of your application's behaviour and to engineeer a lot more unexpected situations during testing. Caveat emptor, as the Romans used to say.

Assuming no issues arise during testing over the next few weeks this feature should be included in the upcoming 1.3.1 Byteman release. If you want an early peek then check out and build the trunk code and give it a try.

Byteman 1.3.0 Available Now

2010-06-24T09:45:00.001-07:00

Byteman 1.3.0 has been released and is now available at the project download page and the JBoss maven repository. The release contains several new features and about a dozen bug fixes. It also includes the first byteman user contrib package, dtest.

New User Package

dtest is a tool contributed by JBossTS project lead Jonathan Halliday which uses Byteman to instrument and validate execution of distributed test programs. It has been used to test the JTA/XTS transaction bridge crash recovery code running in a JBoss AS container started by a stand-alone test client.

New Features

The following is a summary of the new features added in release 1.3.0. Full details are provided in the programmer guide.

Lifecycle events
1.3.0 introduces lifecycle events for rules and helper classes. If a rule helper class implements specific lifecycle methods then Byteman will ensure these methods are invoked as rules which employ the helper are loaded into or removed from the JVM.

static method activate is invoked immediately after the first rule mentioning a helper is injected into a trigger method and compiled

static method deactivate is invoked just before the last rule mentioning the helper is removed from a trigger method at unload

static method install is called immediately after an individual rule mentioning the helper is injected into a trigger method and compiled.

static method deinstall is called just before an individual rule mentioning the helper is removed from a trigger method at unload

The samples distributed with the release includes a simple example script and helper class which rely on lifecycle events to generate periodic statistics on JVM execution. The rules use the counter built-ins to count JVM events such as thread starts and exits, file opens and closes etc.

When the rules are loaded into the JVM the rule helper is activated and it spawns a thread which periodically calls method periodicTrigger. A rule attached to this method collects and resets the counters used by the other rules then dumps the statistics to System.out.

The spawned thread sleeps for a fixed interval before looping and calling periodicTrigger again. The example script uses an AT RETURN rule attached to method getPeriod to redefine this interval.

When the rules are unloaded the helper is deactivated and it shuts down the thread returning the JVM to the state it was in before the rules were loaded.

Special variables
Several new special variables have been added to provide access to more trigger method state

$^ available in AT THROW rules bound to the Throwable on the stack at the point where the rule is triggered
$* bound to an Object[] containing this at index 0 (or null if the trigger method is static) and the trigger method arguments at index 1 . . .
$# bound to the number of trigger method arguments
$@ available in AT INVOKE rules bound to an Object[] containing the invoked method target at index 0 (or null if the invoked method is static) and the invoked method arguments at index 1 . . .

AT ALL Locations
Locations which previously employed a count to identify which of several trigger points should be selected now also support the ALL keyword to request injection at every occurence. For example, specifying location AT READ name ALL will cause the rule to be injected at every place in the target method where field name is read.

Overriding the default HELPER
If a rule does not specify a HELPER clause in its body (between the RULE and ENDRULE clauses) it inherits the default HELPER class org.jboss.byteman.helper.rule.Helper. Rule scripts can now include HELPER clauses at the start or between rules to reset the default helper class. This will be used for all subsequent rules in the script which do not specify their own helper until another HELPER clause resets the class again or an empty HELPER clause reverts to the usual default HELPER.

New Helper methods
Several of the methods provided in the sample library have now been migrated to the default helper class and supplemented with related functionality. In particular, this includes methods which support checking the call stack, and formatting and printing stack traces.

Call stack checking is very useful in rule conditions to ensure that rules are only fired when the trigger method is called from certain code paths. For example, a rule attached to String.append() can use condition IF callerEquals("MyClass.myMethod", true) to ensure that the rule only fires when it is called from method myMethod of class MyClass.

bytemancheck package parameters
The target class for a rule specified in the CLASS clause may omit the package qualifier. Byteman responds by injecting the rule into any class loaded during application execution whose unqualified name matches the supplied value. This causes a problem for the offline type checker tool bytemancheck. It cannot identify which classes to load in order to check the rule without loading and running the application. bytemancheck now accepts one or more optional -p package name arguments. These package names are prefixed to unqualified target class names until a loadable class is found which can be used to typecheck the rule.

Byteman 1.2.2 released

2010-02-22T02:49:00.000-08:00

The 1.2.2 Byteman release is now available for download. It includes a small number of bug fixes as well as a few interesting additional features, most notably:

the problem which was causing rule injection into superclasses to fail intermittently (BYTEMAN-80) has been resolved. more importantly, the fix has avoided adding significant costs to class loading. So it is still possible to inject rule code through interfaces and down class hierarchies without seriously perturbing execution of the original application.

expressions in rule scripts may now employ the new operator(BYTEMAN-85) and the assignment (=) operator (BYTEMAN-81), with the usual Java syntax and semantics. assignment can be used to modify the value of all rule bindings

variables introduced in the BINDS clause
trigger method local variables: $i, $myString etc
trigger method parameters: $1, $myParam (but not $this/$0 which is implicitly final)
the stacked trigger method return value: $! (only available in AT EXIT rules)

note also that in the latter three cases assignment does not just reset the value used to resolve references in subsequent rule expressions. it also updates the local state of the trigger method. the assigned values will be employed on resumption of the method to resolve references to local or parameter variables or to supply the result returned to its caller.

Managing the Byteman Agent using RHQ

2010-01-04T07:34:00.000-08:00

John Mazzitelli is a Red Hat developer working on the RHQ management platform and its downstream projects such as Jopr and JBoss Operations Network. RHQ is a powerful tool which enables integrated systems monitoring and management for a range of different products on a broad range of platforms. It provides a console interface from which it is possible to display the current or historical state of multiple managed applications as well as start/stop them, adjust their configuration and otherwise control their operation.

RHQ's architecture is plug-in based which means that it is relatively easy to extend RHQ to manage new applications. John used that capability to build me a nice little Christmas present, a Byteman-aware plug-in for RHQ. The plug-in automatically detects Java apps which have been started with the Byteman agent listener enabled. It provides a neat GUI interface allowing you to view the agent state. You can see which rules have been loaded and whether they have been successfully parsed and injected into loaded classes. You can identify jars which have been added to the classpath by the agent. You can also upload new rules or delete currently installed rules on the fly. The plug-in organises all this information in a simple, clear tree-based display with nifty point and click controls.

John's blog describes what he has done in more detail. It also links to a demo which shows him using the Byteman RHQ plug-in to drive an agent running inside JBoss App Server. John uses the plug-in to install some rules and helper class libraries into the App Server, obtain the trace output he is interested in and then uninstall the rules. The rules themselves trace the execution of servlet code by counting servlet requests and computing average timing, writing the resulting statistics to the JBoss console. John uses the JBoss RHQ plug-in to filter the console output, presenting the trace in its own display window.

Thank you, John. It sure beats the pair of socks I got last year.

Byteman 1.2.0 Bytes Deeper Into Your Code

2009-12-01T10:14:00.000-08:00

The latest (1.2.0) version of Byteman is now available and it includes some new features which make it easier to specify where you want side effects to be injected to your code. These features are particularly useful for tracing but they are also of great benefit when it comes to using Byteman for its primary purpose which is fault injection testing.

Recap For Newcomers

For those of you who are new to Byteman or who did not see the earlier blog post about Monitoring the JVM using Byteman I'll just recap that Byteman is a bytecode injection tool which can be used to tweak application or JVM runtime code, adding side effects at specific points in any Java method. The injected code is not restricted to performing unintrusive actions like gathering statistics or printing trace output. It can access in scope objects and invoke public methods, changing either the application or the runtime state if it needs to. It can also short circuit the call to the modified method, forcing an immediate return or throwing an exception.

Byteman makes it easy to inject code which traces and verifies program execution and this is often all that is needed to test simple programs. However, in more complex tests the injected code will set up situations which exercise specific code paths by doing things like returning a spurious value, throwing an unexpected exception, inserting a timing delay, suspending one thread until another thread has completed some activity and so on. The most complex tests scenarios require multiple, highly specific interventions to propagate the effect of an initial fault. Byteman provides a simple, clear and expressive rule language based on Java which enables you to perform all these tasks. The programmer's guide is a good place to start if you want to full details of the language and how to use it to script test scenarios.

Back To The Program: A Sample Rule

Ok, so let's get back to those new features in 1.2.0 by introducing an example. I'm mostly going to stick to injecting trace code in the rest of this post but it should be obvious how the same features can be useful when defining rules which inject or propagate faults.

Here's one of the Byteman sample rules taken from the release which traces execution of the JVM Socket code.

RULE Socket trace bind
CLASS ^java.net.Socket
METHOD bind(SocketAddress)
HELPER org.jboss.byteman.sample.helper.StackTraceHelper
AT EXIT
IF TRUE
DO traceStack("*** bind " + $this, 15)
ENDRULE

This rule is attached to CLASS Socket and targets METHOD bind(SocketAddress). It is triggered at EXIT from a call to bind and is fired unconditionally (i.e. the IF condition is TRUE) because we want to trace all calls to bind. The rule employs a HELPER class called StackTraceHelper which is provided in the sample library contained in the release. This helper class implements a method traceStack(String prefix, int depth) which can be called in the body of the rule as a built-in operation (i.e. with no target for the method call). Unsurprisingly, this helper method prints a prefix line and then dumps the stack. The depth argument provides an upper limit on the number of stack frames displayed.

The prefix in this case is constructed by concatenating the String literal "*** bind " with the parameter variable $this. The latter refers to the target instance for the bind call i.e. the socket being bound. The rule type checker identifies that $this is of type Socket, recognises that it is being consumed by a string plus operation where a String value is expected and automatically promotes $this to the correct type by inserting a toString() method invocation into the expression chain.

A helper method is used merely to simplify the rule, in this case wrapping up the code which traverses the stack and dumps details of each stack frame into a single call. The default helper provides, amongst other things, methods which can be used to synchronize independent threads, making it easy to orchestrate quite complex interactions in a multi-threaded application. Using custom helpers is particularly beneficial when scripting complex tests because many rules will perform common operations such as gathering statistics or detecting application-specific conditions and providing simple pre-canned calls keeps the rules clear.

It is perfectly possible to write code directly into the rule condition or action without using helper calls. Rule conditions and actions can call static methods or instance methods of accessible objects. For example, the following rule checks the port to which a socket has been bound and in one specific case prints a message to System.out then throws an exception

RULE Socket emergency!
CLASS ^java.net.Socket
METHOD bind(SocketAddress)
HELPER org.jboss.byteman.sample.helper.StackTraceHelper
AT EXIT
IF $0.getLocalPort() == 999
DO System.out.println("Found the 999 call"),
  throw IOException("Call the police!")
ENDRULE

Note that this version must be invoked at EXIT because the call to getLocalPort() will only return the bound port after the call to bind has completed and is about to return.

So What's New In 1.2?

Now, the observant reader will have noticed that there is one small detail of the rule definition which I have not actually referred to yet: the ^ character preceding the class name. This bit of syntax is new with release 1.2.0 and although it comprises only a single character it makes the world of difference to the meaning of the rule.

The previous Byteman release contained a version of the 'Socket trace bind' rule without the ^ prefix and, in certain circumstances, this meant that bind calls were not traced. The problem is that in the Sun JVM there is a class called sun.nio.ch.SocketAdaptor which extends java.net.Socket. This method provides its own overriding implementation of bind(SocketAddress) and the overriding implementation does not make a call to super.bind(SocketAddress). The old version of the rule only gets injected into the bind method of class Socket. That means when a SocketAdaptor was bound the call to bind was not traced.

The ^ annotation means that the rule should apply to any implementation of method bind(SocketAddress) either on class Socket or a subclass which overrides the method. So, when using the Sun JVM the rule gets injected into class Socket and class SocketAdaptor. It also gets injected into abstract class com.sun.net.ssl.internal.ssl.BaseSSLSocketImpl and into any other application specific class which overrides Socket.bind(SocketAddress). So, with this new syntax there is no danger of missing a socket bind on the 999 port.

A Must-Have Override Example

Another example of the value of overriding rules is provided by the following rule taken from the sample scripts.

RULE FinalizeMonitor trace finalize
CLASS ^java.lang.Object
METHOD finalize
HELPER org.jboss.byteman.sample.helper.StackTraceHelper
AT RETURN
IF TRUE
DO traceStack("finalizing " + $0, 1)
ENDRULE

This method traces every call to a finalize method and the ^ annotation ensures that it is injected into every overriding implementation of Object.finalize(). Note that without the ^ annotation the rule is useless because the garbage collector never calls finalize for objects whose class does not override Object.finalize()!

What About Interfaces?

So, that's one half of the extra functionality provided in Byteman 1.2.0, injection down class hierarchies. The other half is to allow injection through interfaces. All the examples so far have talked about injecting code into methods but when it comes to interfaces there are no methods to consider, only signatures. Here's an example taken from another of the sample rules.

  RULE ThreadMonitor trace Runnable.run
INTERFACE java.lang.Runnable
METHOD run()
HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper
AT ENTRY
IF TRUE
DO traceRun($0)
ENDRULE

This rule is attached to a method of interface Runnable and is triggered by a call to the interface method run(). It uses a subclass of StackTraceHelper called ThreadMonitorHelper as its helper class. The built-in method traceRun prints the Runnable and its type and then prints details of the caller method which invoked run().

But what exactly does it mean to say "triggered by a call to the interface method run()"? Byteman identifies all classes which implement interface Runnable and injects the rule into the implementation of run() on these classes. So, for example, it will inject the rule into java.lang.Thread.run(), java.util.TimerThread.run() and so on.

Orthogonal? Composable?

Now, this is good because it means we don't have to write a rule for every class which implements Runnable. However, it is not quite enough to guarantee that every call to run() will be traced. For example, an application class which extends java.lang.Thread and provides its own implementation of run() will not be caught by this rule because it does not directly implement Runnable. The same applies to anonymous classes created to wrap an inline code block following a new expression such as

  Thread myWorker = new Thread() {
   public void run() { doBackGroundWork(); }
 };
 myWorker.start();

The anonymous class associated with myWorker does implement a run() method, overriding the implementation in Thread, but the class does not declare Runnable in its list of implemented classes. So, Byteman will not inject trace code into this overriding implementation and, hence, any call to myWorker.run() will not be traced.

The solution to this problem is simple. Just prefix the interface with the ^ annotation and injection is performed through the interface and down the resulting class hierarchies. The two new injection modes are orthogonal and composable.

Let's See That In Action

RULE ThreadMonitor trace Runnable.run
INTERFACE ^java.lang.Runnable
METHOD run()
HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper
AT ENTRY
IF TRUE
DO traceRun($0)
ENDRULE

This version of the rule injects the rule code through the interface into implementing classes and down their subclass hierarchies into overriding implementations. It prints details of every call to and caller of Runnable.run() either internal to the JVM runtime or in application code. Here's a sample of the output when this rule is used to trace execution of the latest JBoss Application Server startup.

 starting server default 
========================================================================= 
 JBoss Bootstrap Environment 
 JBOSS_HOME: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT 
 JAVA: /usr/java/jdk1.6.0_14/bin/java 
 JAVA_OPTS: -Dprogram.name=run.sh -server -Xms600M -Xmx600M -XX:MaxPermSize=128m -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005 -Dorg.jboss.byteman.transform.all -javaagent:/home/adinn/jboss/byteman/trunk/install/lib/byteman.jar=listener:true,script:TraceRun.txt,boot:/home/adinn/jboss/byteman/trunk/install/lib/byteman.jar,boot:/home/adinn/jboss/byteman/trunk/install/sample/lib/byteman-sample.jar -Djava.net.preferIPv4Stack=true 
 CLASSPATH: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/bin/run.jar:/usr/java/jdk1.6.0_14/lib/tools.jar 
========================================================================= 
Listening for transport dt_socket at address: 5005 
 *** Thread run main java.lang.Thread  
   from VM runtime  
12:52:04,447 INFO [JBossASServerImpl] Server Configuration: 
     Bootstrap URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/bootstrap.xml 
     JBOSS_HOME URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/ 
     Common Base URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/common/ 
     Common Library URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/common/lib/ 
     Server Name: default 
     Server Base URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/ 
     Server Library URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/lib/ 
     Server Config URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/ 
     Server Home URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/ 
     Server Data URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/data/ 
     Server Log URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/log/ 
     Server Temp URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/tmp/ 
 *** Thread run Thread-3 java.lang.Thread  
   from VM runtime  
 *** Runnable run org.jboss.bootstrap.impl.base.server.AbstractServer$StartServerTask@1aecc3a org.jboss.bootstrap.impl.base.server.AbstractServer.StartServerTask  
   from java.lang.Thread.run at Thread.java:619  
12:52:04,462 INFO [AbstractServer] Starting: JBoss Server[6.0.0.SNAPSHOT (build: SVNTag=JBoss_6.0.0-SNAPSHOT date=r93729)] 
12:52:05,881 INFO [AbstractMCServerBase] Starting Microcontainer, Main bootstrapURL=file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/bootstrap.xml 
*** Thread run Timer-0 java.util.TimerThread  
   from VM runtime  
 *** Runnable run org.jboss.util.TimedCachePolicy$ResolutionTimer@1415727 org.jboss.util.TimedCachePolicy.ResolutionTimer  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Runnable run org.jboss.util.TimedCachePolicy@c0fc8e org.jboss.util.TimedCachePolicy  
   from org.jboss.util.TimedCachePolicy$ResolutionTimer.run at TimedCachePolicy.java:483  
12:52:07,243 INFO [VFSCacheFactory] Initializing VFSCache [org.jboss.virtual.plugins.cache.CombinedVFSCache] 
12:52:07,247 INFO [VFSCacheFactory] Using VFSCache [CombinedVFSCache[real-cache: null]] 
12:52:07,839 INFO [CopyMechanism] VFS temp dir: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/tmp 
12:52:07,866 INFO [ZipEntryContext] VFS force nested jars copy-mode is enabled. 
 *** Thread run ZipFile Lock Reaper java.util.TimerThread  
   from VM runtime  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
12:52:10,964 INFO [ServerInfo] Java version: 1.6.0_14,Sun Microsystems Inc. 
12:52:10,964 INFO [ServerInfo] Java Runtime: Java(TM) SE Runtime Environment (build 1.6.0_14-b08) 
12:52:10,964 INFO [ServerInfo] Java VM: Java HotSpot(TM) Server VM 14.0-b16,Sun Microsystems Inc. 
12:52:10,964 INFO [ServerInfo] OS-System: Linux 2.6.30.9-99.fc11.i686.PAE,i386 
12:52:10,965 INFO [ServerInfo] VM arguments: -Dprogram.name=run.sh -Xms600M -Xmx600M -XX:MaxPermSize=128m -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005 -Dorg.jboss.byteman.transform.all -javaagent:/home/adinn/jboss/byteman/trunk/install/lib/byteman.jar=listener:true,script:TraceRun.txt,boot:/home/adinn/jboss/byteman/trunk/install/lib/byteman.jar,boot:/home/adinn/jboss/byteman/trunk/install/sample/lib/byteman-sample.jar -Djava.net.preferIPv4Stack=true -Djava.endorsed.dirs=/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/lib/endorsed  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 12:52:11,041 INFO [JMXKernel] Legacy JMX core initialized  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
  . . .  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
12:52:28,684 INFO [AbstractServerConfig] JBoss Web Services - Native Server 
12:52:28,684 INFO [AbstractServerConfig] 3.2.0.GA 
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Thread run SubscriptionWatchDog java.lang.Thread  
   from VM runtime  
 *** Runnable run org.jboss.ws.extensions.eventing.mgmt.SubscriptionManager$WatchDog@6b9547 org.jboss.ws.extensions.eventing.mgmt.SubscriptionManager.WatchDog  
   from java.lang.Thread.run at Thread.java:619  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
  . . .  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Thread run RMI TCP Accept-1090 java.lang.Thread  
   from VM runtime  
 *** Runnable run sun.rmi.transport.tcp.TCPTransport$AcceptLoop@7598d7 sun.rmi.transport.tcp.TCPTransport.AcceptLoop  
   from java.lang.Thread.run at Thread.java:619  
 *** Thread run RMI TCP Accept-0 java.lang.Thread  
   from VM runtime  
 *** Runnable run sun.rmi.transport.tcp.TCPTransport$AcceptLoop@19de1ba sun.rmi.transport.tcp.TCPTransport.AcceptLoop  
   from java.lang.Thread.run at Thread.java:619  
 *** Thread run RMI Reaper java.lang.Thread  
   from VM runtime  
 *** Runnable run sun.rmi.transport.ObjectTable$Reaper@185576 sun.rmi.transport.ObjectTable.Reaper  
   from java.lang.Thread.run at Thread.java:619  
 *** Thread run GC Daemon sun.misc.GC.Daemon  
   from VM runtime  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Thread run RMI TCP Connection(idle) java.lang.Thread  
   from VM runtime  
 *** Runnable run java.util.concurrent.ThreadPoolExecutor$Worker@132e9d5 java.util.concurrent.ThreadPoolExecutor.Worker  
   from java.lang.Thread.run at Thread.java:619  
 *** Runnable run sun.rmi.transport.tcp.TCPTransport$ConnectionHandler@1231023 sun.rmi.transport.tcp.TCPTransport.ConnectionHandler  
   from java.util.concurrent.ThreadPoolExecutor$Worker.runTask at ThreadPoolExecutor.java:886  
 *** Thread run RMI Scheduler(0) java.lang.Thread  
   from VM runtime  
 *** Runnable run java.util.concurrent.ThreadPoolExecutor$Worker@701c57 java.util.concurrent.ThreadPoolExecutor.Worker  
   from java.lang.Thread.run at Thread.java:619  
 *** Thread run RMI RenewClean-[127.0.0.1:47945] java.lang.Thread  
   from VM runtime  
 *** Runnable run sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread@1e88ea sun.rmi.transport.DGCClient.EndpointEntry.RenewCleanThread  
   from java.lang.Thread.run at Thread.java:619  
 *** Thread run RMI TCP Connection(idle) java.lang.Thread  
   from VM runtime  
 *** Runnable run java.util.concurrent.ThreadPoolExecutor$Worker@1c35be0 java.util.concurrent.ThreadPoolExecutor.Worker  
   from java.lang.Thread.run at Thread.java:619  
 *** Runnable run sun.rmi.transport.tcp.TCPTransport$ConnectionHandler@9ba7c9 sun.rmi.transport.tcp.TCPTransport.ConnectionHandler  
   from java.util.concurrent.ThreadPoolExecutor$Worker.runTask at ThreadPoolExecutor.java:886  
 *** Runnable run sun.rmi.transport.DGCClient$EndpointEntry$RenewCleanThread@1e88ea sun.rmi.transport.DGCClient.EndpointEntry.RenewCleanThread  
   from java.lang.Thread.run at Thread.java:619  
 12:52:57,324 INFO [JMXConnectorServerService] JMX Connector server: service:jmx:rmi://127.0.0.1/jndi/rmi://127.0.0.1:1090/jmxconnector 
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Thread run ServerSocketRefresh org.jboss.remoting.transport.socket.SocketServerInvoker.ServerSocketRefresh  
   from VM runtime  
 *** Thread run AcceptorThread[ServerSocket[addr=/127.0.0.1,port=0,localport=4457]] org.jboss.remoting.transport.socket.SocketServerInvoker.AcceptThread  
   from VM runtime  
 *** Thread run secondaryServerSocketThread[0] org.jboss.remoting.transport.bisocket.BisocketServerInvoker.SecondaryServerSocketThread  
   from VM runtime  
 *** Thread run ServerSocketRefresh org.jboss.remoting.transport.socket.SocketServerInvoker.ServerSocketRefresh  
   from VM runtime  
 *** Thread run AcceptorThread[ServerSocket[addr=/127.0.0.1,port=0,localport=3873]] org.jboss.remoting.transport.socket.SocketServerInvoker.AcceptThread  
   from VM runtime  
 *** Runnable run org.jboss.virtual.plugins.context.zip.ZipFileLockReaper$ReaperTimerTask@10a519 org.jboss.virtual.plugins.context.zip.ZipFileLockReaper.ReaperTimerTask  
   from java.util.TimerThread.mainLoop at Timer.java:512  
 *** Thread run HDScanner java.lang.Thread  
   from VM runtime  
 *** Runnable run java.util.concurrent.ThreadPoolExecutor$Worker@1d64598 java.util.concurrent.ThreadPoolExecutor.Worker  
   from java.lang.Thread.run at Thread.java:619
*** Runnable run sun.rmi.transport.tcp.TCPTransport$ConnectionHandler@9ba7c9 sun.rmi.transport.tcp.TCPTransport.ConnectionHandler
   from java.util.concurrent.ThreadPoolExecutor$Worker.runTask at ThreadPoolExecutor.java:886

Where the Runnable is an instance of Thread the helper code prints the thread name and class. For non-threads it prints the Runnable instance and its class then details of the caller method. Notice that all the run calls associated with threads have no caller frame. This is because the thread stack is set up by the JVM with the run method as its entry point.

Most of the non-Thread Runnables are executed as the target of a dedicated thread and in these cases the call to run is made from Thread.run(). There are a few examples where the run method is invoked by pool threads, for example the last traced call shows a worker from the concurrent thread pool package being used to execute a Runnable which handles a TCP connection. In this case the call to run is made from the worker's execute method.

Cross Posting - Now that Byteman has its own Blog

2009-10-23T07:20:00.000-07:00

It's great to see that Byteman has its own blog!

Here's a cross-link to a post that I wrote last week - it's a 'helloworld' style introduction to Byteman:

http://java.dzone.com/news/fault-injection-testing-first?mz=3006-jboss

Monitoring your JVM using Byteman 1.1.1

2009-10-23T02:23:00.001-07:00

Byteman is a bytecode injection tool developed to support testing of Java code using a technique called fault injection. However, it is also very useful for debugging and tracing Java program execution, including execution of the JVM itself. In this post I walk through an example Byteman script which monitors creation, start and exit of threads inside the JBoss Application Server.

The latest version of Byteman (1.1.1) has just been released and it includes the first batch in a series of sample Byteman scripts, all of which provide examples of how to monitor different aspects of JVM operation. The scripts inject tracing code into different JVM classes so that you can watch the JVM as it starts or stops threads, opens sockets, closes files, finalizes instances etc.

Seeing these scripts at work can be very educational -- for example, runnning up the JBoss App Server with script ThreadMonitor.txt installed I could see exactly which threads are created, started and stopped during AS bootstrap.

The script only needs 3 simple rules:

 ########################################################################
#
# Rule to trace thread creation
#

RULE ThreadMonitor trace create
CLASS java.lang.Thread
METHOD <init>
HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper
AT EXIT
IF TRUE
DO traceCreate($0)
ENDRULE

########################################################################
#
# Rule to trace thread start
#

RULE ThreadMonitor trace start
CLASS java.lang.Thread
METHOD start
HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper
AT EXIT
IF TRUE
DO traceStart($0)
ENDRULE

########################################################################
#
# Rule to trace thread exit
#

RULE ThreadMonitor trace exit
CLASS java.lang.Thread
METHOD exit
HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper
AT ENTRY
IF TRUE
DO traceExit($0)
ENDRULE

The first rule is injected into the constructor for java.lang.Thread, the second into Thread.start() and the third into Thread.exit(). The conditions are all TRUE because we want to see every call in the trace output. The rule actions call built-in methods traceCreate(Thread), traceStart(Thread) and traceExit(Thread),respectively. The argument to these calls, $0, is the thread object which is the target of the method invocation which triggers the rule, i.e. the one being created, started or exited. The built-in methods access this object to identify the thread's name and it's class name.

The implementation of the three trace methods is provided by a custom HELPER class, ThreadMonitorHelper, which specialises the library class StackTraceHelper provided in the sample lib jar. There is nothing special about this class -- it does not need to use Byteman library code to do its job. It is just a POJO which wraps up the code needed to print meaningful trace with a neat, simple API. All three methods print a line of text identifying the thread event (create, start or exit), thread name and thread class. The first two also use methods inherited from StackTraceHelper to look down the stack for the frame from which new Thread() or Thread.start() was called and print the details of the calling method.

Here's a sample of the output when running JBoss AS with these rules installed:


starting server default
=========================================================================

JBoss Bootstrap Environment

JBOSS_HOME: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT

JAVA: /usr/java/jdk1.6.0_14/bin/java

JAVA_OPTS: -Dprogram.name=run.sh -server -Xms600M -Xmx600M -XX:MaxPermSize=128m -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005 -Dorg.jboss.byteman.transform.all -javaagent:/home/adinn/byteman/install/lib/byteman.jar=listener:true,boot:/home/adinn/byteman/install/lib/byteman.jar,boot:/home/adinn/byteman/install/sample/lib/byteman-sample.jar,script:/home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt -Djava.net.preferIPv4Stack=true

CLASSPATH: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/bin/run.jar:/usr/java/jdk1.6.0_14/lib/tools.jar

=========================================================================

 *** Thread create JDWP Transport Listener: dt_socket java.lang.Thread  
 from VM runtime  
Listening for transport dt_socket at address: 5005
 *** Thread create JDWP Event Helper Thread java.lang.Thread  
 from VM runtime  
 *** Thread create CompilerThread0 java.lang.Thread  
 from VM runtime  
 *** Thread create CompilerThread1 java.lang.Thread  
 from VM runtime  
 *** Thread create Low Memory Detector java.lang.Thread  
 from VM runtime  
 *** Thread create main java.lang.Thread  
 from org.jboss.Main.main at Main.java:719  
 *** Thread start main java.lang.Thread  
 from org.jboss.Main.main at Main.java:719  
 *** Thread exit main java.lang.Thread  
 *** Thread create DestroyJavaVM java.lang.Thread  
 from VM runtime  
 *** Thread create Thread-1 java.util.logging.LogManager.Cleaner  
 from java.util.logging.LogManager$Cleaner.<init> at LogManager.java:200  
 *** Thread create Thread-2 org.jboss.Main.ShutdownHook  
 from org.jboss.Main$ShutdownHook.<init> at Main.java:883  
12:38:16,588 INFO [JBossASServerImpl] Server Configuration:

Bootstrap URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/bootstrap.xml
JBOSS_HOME URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/
Common Base URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/common/
Common Library URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/common/lib/
Server Name: default
Server Base URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/
Server Library URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/lib/
Server Config URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/
Server Home URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/
Server Data URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/data/
Server Log URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/log/
Server Temp URL: file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/tmp/

 *** Thread create Thread-3 java.lang.Thread  
 from org.jboss.bootstrap.impl.base.server.AbstractServer.start at AbstractServer.java:350  
 *** Thread start Thread-3 java.lang.Thread  
 from org.jboss.bootstrap.impl.base.server.AbstractServer.start at AbstractServer.java:352  
12:38:16,590 INFO [AbstractServer] Starting: JBoss Server[6.0.0.SNAPSHOT (build: SVNTag=JBoss_6.0.0-SNAPSHOT date=r93729)]
12:38:17,344 INFO [AbstractMCServerBase] Starting Microcontainer, Main bootstrapURL=file:/home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/conf/bootstrap.xml
 *** Thread create Thread-4 java.util.TimerThread  
 from java.util.TimerThread.<init> at Timer.java:456  
 *** Thread start Timer-0 java.util.TimerThread  
 from java.util.Timer.<init> at Timer.java:154  
12:38:18,259 INFO [VFSCacheFactory] Initializing VFSCache [org.jboss.virtual.plugins.cache.CombinedVFSCache]
12:38:18,262 INFO [VFSCacheFactory] Using VFSCache [CombinedVFSCache[real-cache: null]]
12:38:18,670 INFO [CopyMechanism] VFS temp dir: /home/adinn/jboss/jbossas/trunk/build/output/jboss-6.0.0-SNAPSHOT/server/default/tmp
12:38:18,675 INFO [ZipEntryContext] VFS force nested jars copy-mode is enabled.
 *** Thread create Thread-5 java.util.TimerThread  
 from java.util.TimerThread.<init> at Timer.java:456  
 *** Thread start ZipFile Lock Reaper java.util.TimerThread  
 from java.util.Timer<init> at Timer.java:154

During this initial stage of bootstrap most of the threads are created by the VM itself. The first one actually created and started by the AS is identified by the following lines:

*** Thread create main java.lang.Thread
from org.jboss.Main.main at Main.java:719
*** Thread start main java.lang.Thread
from org.jboss.Main.main at Main.java:719
*** Thread exit main java.lang.Thread

The trace shows that the name of the newly created thread is main and it is an instance of class java.lang.Thread. It is created and immediately started by a call to Thread.start() in method org.jboss.Main.main at line 719 of file Main.java. Here's the actual code:

701    Runnable worker = new Runnable() {
702      public void run()
703      {
. . .
716      };
717
718    ThreadGroup threads = new ThreadGroup("jboss");
719    new Thread(threads, worker, "main").start();

The third trace line is a little confusing. The thread which has exited is not actually the JBoss main thread just created. It is in fact the parent thread, created by the VM and also called main. The JBoss main thread goes on to create a whole lot of other threads, connection handlers, pool threads and so on.

Clearly, there are lots of possibilities for developing alternative scripts which provide different, more interesting tracing behaviour. The other scripts in the samples directory provide further simple examples of how you might instrument other JVM classes to provide runtime trace. By coding more selective rule conditions or more complex rule sets it is possible to make the tracing much more fine-grained and specific to particular circumstances. Adding more actions, possibly using other custom helper classes, would allow a variety of different statistics to be gathered and displayed.

I will explain next how you set up your program to inject these rules. The trace above shows Byteman injecting the scripted rules from program start. However, when it comes to tracing execution it would be nice if it were possible to start up your program without any scripts installed and then switch on tracing by loading and unloading rules as needed. Well, of course, it is possible to do just and I'll go on to explain what you need to change to achieve that too.

First off let's run through how JBossAS was configured to start up the byteman agent and execute this script from JVM bootstrap. All that is needed is to supply the java command which starts the JBossAS Main class with a -javaagent argument. Passing this argument to JBossAS is most easily achieved by inserting it into environment variable JBOSS_OPTS ans the running the normal JBossAS startup script.

The actual setting required was displayed in one of the very long lines of trace output:

 JAVA_OPTS: -Dprogram.name=run.sh -server -Xms600M -Xmx600M -XX:MaxPermSize=128m -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005 -Dorg.jboss.byteman.transform.all -javaagent:/home//byteman/install/lib/byteman.jar=listener:true,boot:/home/adinn/byteman/install/lib/byteman.jar,boot:/home/adinn/byteman/install/sample/lib/byteman-sample.jar,script:/home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt -Djava.net.preferIPv4Stack=true

Let's look at the actual -javaagent argument to understand what is needed to point the agent at the script and the relevant libraries. To make it a bit easier to see what is going on I have added line breaks after the equal sign and commas which separate the different options. In reality the argument needs to be supplied as one long string with no spaces or line breaks.

 -javaagent:/home/adinn/byteman/install/lib/byteman.jar=
listener:true,
boot:/home/adinn/byteman/install/lib/byteman.jar,
boot:/home/adinn/byteman/install/sample/lib/byteman-sample.jar,
script:/home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt

Before we look at these options in detail I'll also point out that the java command line included the following property setting

 -Dorg.jboss.byteman.transform.all

This property enables injection into java.lang classes. Normally the agent ignores rules which apply to this package on the grounds that by modifying these classes it will likely shoot itself in the foot changing the JVM functionality it relies on to execute rules. Setting this flag tells it to remove this restriction. There is no great harm in trying this but beware! Get your rules wrong and you will probably see a JVM error such as a stack overflow.

Ok, warnings aside let's return to the -javaagent argument. The first value following the -javaagent: prefix is the location of the byteman jar. If BYTEMAN_HOME identifies the directory into which the release has been installed then the library is located in $BYTEMAN_HOME/lib/byteman.jar, in this case /home/adinn/byteman/install/lib/byteman.jar.

The = sign following the jar file name is used to separate it from the agent options which configure various aspects of the agent's behaviour. Where more than one option is supplied then they must be separated using commas. The options provided in this case include a script: option. This points the agent at the script file containing rules which trace thread activity. You can provide multiple script: options if you want to inject several sets of rules. For example, you might also want to use the ClassLoadMonitor script to monitor class loading. The agent options list also contains two boot: options which supply jars to be added to the bootstrap classpath (we'll come to this later) and a listener: option which is used to start the agent listener.

The first option is listener:true. This causes the agent to start a listener thread which can be communicated with using the submit.sh script located in the Byteman bin directory. The submit script allows you to manage the rule base at runtime. You can check which rules have been injected, compiled and executed. You can also load and unload rules while the program is running, including loading updated versions of rules to fix errors or patch the rule behaviour. The listener will not be started if listener:false is provided or if the listener option is omitted.

So, if you want to be able to switch tracing on and off you must provide option listener:true. If not then you cannot add or remove any rules and you will be stuck with whatever rules were loaded at boot time. You can, of course, omit the script: option. It's ok to start with a vanilla JVM. If you do this then you can load the rules later when you want to turn tracing on.

Let's take a closer look at the submit script. Running submit.sh with no arguments lists all the currently installed rules:

 [adinn@toby trunk]$ $BYTEMAN_HOME/bin/submit.sh
 # File /home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt line 66 
 RULE ThreadMonitor trace start 
 CLASS java.lang.Thread 
 METHOD start 
 HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper 
 AT EXIT 
 IF TRUE 
 DO traceStart($0) 
 ENDRULE 
 Transformed in: 
 loader: sun.misc.Launcher$AppClassLoader@480457 
 trigger class: java.lang.Thread 
 compiled successfully 
 # File /home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt line 52 
 RULE ThreadMonitor trace create 
 CLASS java.lang.Thread 
 METHOD <init> 
 HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper 
 AT EXIT 
 IF TRUE 
 DO traceCreate($0) 
 ENDRULE 
 Transformed in: 
 loader: sun.misc.Launcher$AppClassLoader@480457 
 trigger class: java.lang.Thread 
 compiled successfully 
 # File /home/adinn/byteman/install/sample/scripts/ThreadMonitor.txt line 80 
 RULE ThreadMonitor trace exit 
 CLASS java.lang.Thread 
 METHOD exit 
 HELPER org.jboss.byteman.sample.helper.ThreadMonitorHelper 
 AT ENTRY 
 IF TRUE 
 DO traceExit($0) 
 ENDRULE 
 Transformed in: 
 loader: sun.misc.Launcher$AppClassLoader@480457 
 trigger class: java.lang.Thread 
 compiled successfully

The output shows each of the 3 rules which were in the original script and shows that they have been injected into class java.lang.Thread loaded by the bootstrap class loader (it actually says sun.misc.Launcher$AppClassLoader@480457 but no other classloader will load this class). The last line of output for each rule indicates that the rule was parsed and type-checked successfully.

Running the submit script with the -u flag causes the rules to be unloaded:

 [adinn@toby trunk]$ $BYTEMAN_HOME/bin/submit.sh -u $BYTEMAN_HOME/sample/scripts/ThreadMonitor.txt
 uninstall RULE ThreadMonitor trace create 
 uninstall RULE ThreadMonitor trace start 
 uninstall RULE ThreadMonitor trace exit 
[adinn@toby trunk]$ $BYTEMAN_HOME/bin/submit.sh
 no rules installed

The agent responds to the uninstall request by removing any rules defined in the supplied scripts (n.b. if submit.sh -u is run with no script arguments it removes all rules). The agent recompiles the methods of any affected classes to remove the injected trigger code. In this case the rules only apply to class Thread so only one class needs to be recompiled. When submit completes the Thread methods will have reverted to operating as they would do normally and no more trace will be generated. So, tracing has been switched off.

The rules can be reinstated by resubmitting the script:

 [adinn@toby trunk]$ $BYTEMAN_HOME/bin/submit.sh $BYTEMAN_HOME/sample/scripts/ThreadMonitor.txt
 install rule ThreadMonitor trace create  
install rule ThreadMonitor trace start  
install rule ThreadMonitor trace exit

The agent handles an install request by identifying all classes to which the rules apply and recompiling them, injecting the newly uploaded trigger code. In this case the only class affected is Thread so its methods are recompiled inserting trigger code for the tracing rules once again.

If an uploaded rule has the same name as one that is currently loaded then the old trigger code is removed and new code injected. So, the submit script can be used to modify injected rules on the fly. If your rule shows something interesting and you want to see more details then just redefine and upload your trace rules to print out more details.

In other cases uploaded rules may not match any currently loaded classes. However, they are still added to the agent's rule base. The rule code will be injected when a class is loaded to which the rule applies.

Ok, finally, let's return to the boot: options provided as part of the -javaagent argument. The options are used to ensure that the two jar files are available when the trigger/rule code are type-checked and compiled.

The first jar to consider is the sample library /home/adinn/byteman/install/sample/lib/byteman-sample.jar which contains the implementation of the helper classes StackTraceHelper and ThreadMonitorHelper. When the rules are injected these classes need to be available in the JVM classpath or else the rule code will fail to typecheck and compile.

Normally, it would be sufficient to place the samples library jar in the runtime classpath provided on the java command line. Once this is done it does not usually matter what classloader the trigger class is loaded by since the system classloader is normally a parent for it. So, when type checking the injected rule the helper class will be found by delegation. As an alternative, the agent option sys: can be used to append the jar file to the system classpath. This also ensures the helper classes will be found by delegation.

The only problem with this is that the rules in the thread monitor script need to be injected into JVM classes. These classes are loaded by the bootstrap loader. Unfortunately, the system classloader is not a parent loader for the bootstrap loader -- in fact, the parent relationship is the other way round. Adding the sample library jar to the bootstrap classpath means that it is visible when injecting into JVM classes. Hence, we need to supply the boot: option for this jar.

If you didn't install your helper jar at boot time then you could always use submit.sh to install it at runtime. As long as you have started the listener you can call submit -s my.jar or submit -b my.jar to add a jar to, respectively, the system classpath or bootstrap classpath. Obviously, you need to do this before you load any rules which refer to the helper classes. Unfortunately, there is no way to remove jar files once they have been added in this way.

The other jar supplied using the boot: option is the byteman jar itself. The reasoning here is much the same -- the agent classes need to be visible to bootstrap classes. Normally, when the agent jar is installed its classes get loaded by the system classloader. However, in this case we want to inject a trigger call into a JVM class. If the agent classes such as Rule etc are loaded by the system classloader then they will not be visible from classes such as Thread. So, we also need to supply the boot: option for the byteman jar.

Note that it is not possible to add the byteman jar to the bootstrap classpath using submit. By the time the listener is up and running some agent classes will already have been loaded into the system classloader. Trying to install the byteman jar into the bootstrap classpath at this point will send you straight to classloader hell.

So, let's recap. If you want to start the agent so you can load and unload scripts at runtime and inject into any class, including JVM classes, you need to set

 export BJAR=$BYTEMAN_HOME/lib/byteman.jar

and then run your java command with arguments

 -javaagent:$BJAR=listener:true,boot:$BJAR -Dorg.jboss.byteman.quodlibet

When you want to start tracing (firsttime only) you install your helper jar using

 $BYTEMAN_HOME/bin/submit.sh -b $BYTEMAN_HOME/sample/lib/byteman-sample.jar

You can then load your script using command

 $BYTEMAN_HOME/bin/submit.sh $BYTEMAN_HOME/sample/scripts/ThreadMonitor.txt

To check that your rules have been injected and compiled use command

 $BYTEMAN_HOME/bin/submit.sh

To stop tracing you unload the script using

 $BYTEMAN_HOME/bin/submit.sh -u $BYTEMAN_HOME/sample/scripts/ThreadMonitor.txt