Byteman Demo at JUDCon

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