is private inner class supported?

[changgeng]

or even anonymous class?

I try to add some trigger in an inner class, but it doesn't work. The source file is http://anonsvn.jboss.org/repos/hornetq/tags/HornetQ_2_1_2_Final/src/main/org/hornetq/core/journal/impl/TimedBuffer.java, and I try to add some rule in the CheckTimer.run method, at Thread.yield statement.

I created the following rule, but it seems not work. Although I'm not 100% sure Thread.yield method is really got invoked, is private inner class supported by byteman?

RULE Trace Thread.yield

CLASS CheckTimer

METHOD run

AT INVOKE Thread.yield()

IF TRUE

DO

    createCounter("run.yield");

    System.out.println("run.yield called" + incrementCounter("run.yield"));

ENDRULE

Thanks.

[changgeng]

I tried to specify the class name with the fully qualifed package name and outer class name, but it's still not helpful.

CLASS org.hornetq.core.journal.impl.TimedBuffer$CheckTimer

[adinn]

Changgeng Li wrote:

I tried to specify the class name with the fully qualifed package name and outer class name, but it's still not helpful.

CLASS org.hornetq.core.journal.impl.TimedBuffer$CheckTimer

Yes, you are supposed to be able to refer to inner classes using a name like Outer$Inner.

I redefined your ruel as folows and ran it through the offline type checker script (bmcheck.sh) and it checked out ok:

[adinn@localhost tmp]$ cat foo.txt
RULE Trace Thread.yield 
CLASS TimedBuffer$CheckTimer
METHOD run
AT INVOKE Thread.yield()
IF TRUE
DO 
    createCounter("run.yield");
    System.out.println("run.yield called" + incrementCounter("run.yield"));
ENDRULE
[adinn@localhost tmp]$ ${BYTEMAN_HOME}/bin/bmcheck.sh \
  -cp ${JBOSS_HOME}/common/lib/hornetq-core.jar \
  -p org.hornetq.core.journal.impl foo.txt
checking rule Trace Thread.yield
parsed rule "Trace Thread.yield" for class org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
type checked rule "Trace Thread.yield"

TestScript: no errors
[adinn@localhost tmp]$ 

The -cp flag tells the type checker where to find any classes mentioned in the rules. I did not include the full package name in the rule definition. When your app loads this class the agent recognises that it applies to the class. However, the type checker needs to explicitly load the class. So, -p flag tells the type checker to try to resolve the target class 'TimedBuffer$CheckTimer' by appending the package prefix 'org.hornetq.core.journal.impl'. As an alternative you could write the full package-qualified name in the rule text

RULE Trace Thread.yield 
CLASS CLASS org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
METHOD run
AT INVOKE Thread.yield()
IF TRUE
DO 
    createCounter("run.yield");
    System.out.println("run.yield called" + incrementCounter("run.yield"));
ENDRULE

The type checker uses the same code as is used by the agent at runtime to transform classes. So, if your version of the rule was the liek this one then there must be some other problem which is stopping the rule from working. How are you installing the agent into the JVM? How are you submitting the rules?

You could try setting -Dorg.jboss.byteman.verbose on the java command line when you start up the JVM. This will print a lot of informaton telling you what the Byteman agent is doing and  may identify what is going wrong. Don't worry if you don't undertsand what some of the output means. Post it for me to have a look at and I will see if I can work out what is going wrong.

regards,

Andrew Dinn

[changgeng]

Hi Andrew,

Thanks for your reply. I'm using bminstall.sh to install the agent on fly, and then using bmsubmit.sh to submit the rule.

The output of bmsubmit.sh without arguments is following.

# File 1.rl line 5
RULE Trace Thread.yield
CLASS TimedBuffer$CheckTimer
METHOD run
AT INVOKE Thread.yield
IF TRUE
DO
createCounter("run.yield");
System.out.println("run.yield called" + incrementCounter("run.yield"));
ENDRULE
Transformed in:
loader: org.jboss.mx.loading.UnifiedClassLoader3@f5e0873{ url=null ,addedOrder=2}
trigger method: org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run() void

The outout in the server.log after adding -Dorg.jboss.byteman.verbose

2011-02-28 05:47:05,418 INFO  [STDOUT](Attach Listener) TransformListener() : accepting requests on localhost:9091
2011-02-28 05:47:24,859 INFO  [STDOUT](Thread-147) TransformListener() : handling connection on port 9091
2011-02-28 05:47:24,935 INFO  [STDOUT](Thread-147) retransforming org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
2011-02-28 05:47:25,035 INFO  [STDOUT](Thread-147) org.jboss.byteman.agent.Transformer : possible trigger for rule Trace Thread.yield in class org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
2011-02-28 05:47:25,080 INFO  [STDOUT](Thread-147) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run() void for rule Trace Thread.yield
2011-02-28 05:47:25,085 INFO  [STDOUT](Thread-147) org.jboss.byteman.agent.Transformer : inserted trigger for Trace Thread.yield in class org.hornetq.core.journal.impl.TimedBuffer$CheckTimer

Also I used jstack to dump the stack trace, and  I did see the statement Thread.yield is invoked while there's no other STDOUT in server.log file.

"hornetq-buffer-timeout" prio=10 tid=0x00002aabc95c3000 nid=0x48ea runnable [0x000000004380a000]
   java.lang.Thread.State: RUNNABLE
        at java.lang.Thread.yield(Native Method)
        at org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run(TimedBuffer.java:441)
        at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
        - None

[adinn]

Changgeng Li wrote:

Hi Andrew,

Thanks for your reply. I'm using bminstall.sh to install the agent on fly, and then using bmsubmit.sh to submit the rule.

The output of bmsubmit.sh without arguments is following.

# File 1.rl line 5
RULE Trace Thread.yield
CLASS TimedBuffer$CheckTimer
METHOD run
AT INVOKE Thread.yield
IF TRUE
DO
createCounter("run.yield");
System.out.println("run.yield called" + incrementCounter("run.yield"));
ENDRULE
Transformed in:
loader: org.jboss.mx.loading.UnifiedClassLoader3@f5e0873{ url=null ,addedOrder=2}trigger method: org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run() void

Ok, so the rule has been definitely injected into the run method but it has not been type checked and executed. If so the output would include the text "compiled successfully" if it type checked and ok or "failed to compile" if there was a type error. So, at this point no thread has actually run the new version of the method.

The outout in the server.log after adding -Dorg.jboss.byteman.verbose

2011-02-28 05:47:05,418 INFO  [STDOUT](Attach Listener) TransformListener() : accepting requests on localhost:9091
2011-02-28 05:47:24,859 INFO  [STDOUT](Thread-147) TransformListener() : handling connection on port 9091
2011-02-28 05:47:24,935 INFO  [STDOUT](Thread-147) retransforming org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
2011-02-28 05:47:25,035 INFO  [STDOUT](Thread-147) org.jboss.byteman.agent.Transformer : possible trigger for rule Trace Thread.yield in class org.hornetq.core.journal.impl.TimedBuffer$CheckTimer
2011-02-28 05:47:25,080 INFO  [STDOUT](Thread-147) RuleTriggerMethodAdapter.injectTriggerPoint : inserting trigger into org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run() void for rule Trace Thread.yield
2011-02-28 05:47:25,085 INFO  [STDOUT](Thread-147) org.jboss.byteman.agent.Transformer : inserted trigger for Trace Thread.yield in class org.hornetq.core.journal.impl.TimedBuffer$CheckTimer

Also I used jstack to dump the stack trace, and  I did see the statement Thread.yield is invoked while there's no other STDOUT in server.log file.

"hornetq-buffer-timeout" prio=10 tid=0x00002aabc95c3000 nid=0x48ea runnable [0x000000004380a000]
   java.lang.Thread.State: RUNNABLE
        at java.lang.Thread.yield(Native Method)
        at org.hornetq.core.journal.impl.TimedBuffer$CheckTimer.run(TimedBuffer.java:441)
        at java.lang.Thread.run(Thread.java:619)
 
   Locked ownable synchronizers:
        - None

The verbose trace also shows that the rule has been injected. So, the run method should contain trigger code just before the call to Thread.yield(). If that code was present when the yield call was made then the first thing you should see in the log is a verbose trace message saying "Executing rule trace Thread.yield". In a minute I'll show you how to set another command line flag to check that the code really has been injected and also see what it is. For now though I think we need to look at a few other possibilities.

The call to the CheckTimer.run() method which is shown by jstack may have happened before the rule has been injected. Are you certain that your program is executing the call to Thread.yield() after the submit request has completed? Or is it possible that you loaded the rule after this call was made and that no more calls occurred after the submit?

If you are definitely sure that the code in CheckTimer.run() was called after the rule was loaded then I can only think of one other possibility. The run() method is the top-level entry point for the HornetQ CheckTimer thread. When the rule is injected this method gets redefined and the JVM installs the new version containing the injected trigger code in the class's method table. However, if the CheckTimer thread has already started and is running inside the while loop then there is no guarantee that it will be able to switch over from the old version of the code to the new version straight away. It would have to do so while it was in the middle of executing the method which is being replaced. JVM compilers can actually generate code to do this -- when you think about it that's quite a tricky thing to do -- but even when they dothe switchover cannot alwayshappen straight away. It depends upon the code arriving at a safe point called an on stack replacement point. There may not be such a safe point in this method or it may be that the switchover happened after the next yield() call (say after the release() call).

One thing you can do to ensure the rule is present before the call to CheckTimer.run() happens is to install the agent and the script when you start the JVM. Here are the extra arguments you need to put on the command line:

java -Dorg.jboss.byteman.verbose -javaagent:${BYTEMAN_HOME}/lib/byteman.jar=listener:true,script:/path/to/myscript ...

The -javaagent argument tells the JVM to load the agent from the jar following the first : character up to the = sign. BYTEMAN_HOME is an environment variable which shoudl be set to the directory where you installed byteman (on windows you would use %BYTEMAN_HOME%). The text following the = is a sequence of options passed to the agent which are separated by , characters. Each option has a name and a setting separated by a : character. Setting the listener option to true means that you can talk to the agent using bmsubmit.sh to see what scripts are loaded. The script option identifies a file which contains rules to be loaded by teh agent during JVM startup. So, you need to put a path to your script after script: (if the file is in the working directory where you execute the java command then you can just put the file name without needin g a directory path).

So, that should ensure the rule is installed when the JVM is starting up before any HornetQ code gets executed. Try running again and check the output to see if you see some more messages this time.

The other thing you can do to be find out more about what is happening is to dump the bytecode containing the injected rule trigger. First create a directory called dump below the working directory of your JVM. Then define the following properties either when you start the JVM or as arguments to bminstall.sh (in the latter case put them before the process id argument).

-Dorg.jboss.byteman.dump.generated.classes -Dorg.jboss.byteman.dump.generated.classes.directory=dump

These properties tells Byteman to dump to disk the bytecode of any class it injects rules into. After the run you should find a file called TimedBuffer$CheckTimer.class in directory dump/org/hornetq/core/journal/impl/. You can print the contents of this file using this command

javap -c -classpath dump org/hornetq/core/journal/impl/TimedBuffer\$CheckTimer

(If you are on windows yo uwill need to use \ in place of / and you don't need the \ in front of the $ sign)

The bytecode for method run() should contain several very obvious references to Byteman classes including, most importantly, a call to Rule.execute() just before the call to Thread.yield(). Don't worry about trying to decipher this bytecode. Just post it and I will check to see if it is correct or not.

[changgeng]

Again, thanks for the informative response. I'm sure that the Thread.yield method happened called after the injection. I will try to inject the rule during JVM start and get it back to you.

[changgeng]

Ok, I tried to install the rule during JVM start, and it works fine!

[adinn]

Changgeng Li wrote:

Ok, I tried to install the rule during JVM start, and it works fine!

Excellent. That seems to confirm the hypothesis that the rule has been injected but the new version of the code has not picked up  by the HornetQ thread. It's very interesting to know that this sort of thing can happen as it implies there are limits the effectiveness of runtime injection. Thank you very much for reporting and then helping to diagnose this problem.