bind issue with arrays ?

[stefanegli]

Having problems using the following binding:

BIND sql:String = $2, five:String[] = $5

Byteman reports:

null line 167 : invalid event
org.jboss.byteman.agent.Transformer : error parsing rule hibernatelog2 : org.jboss.byteman.rule.exception.ParseException: org.jboss.byteman.rule.Rule : error parsing rule

Which does not show up when not using the array for the binding five.

are binding of arrays not supported by byteman?

Cheers,
Stefan

[adinn]

Having problems using the following binding:

BIND sql:String = $2, five:String[] = $5

Byteman reports:

null line 167 : invalid event
org.jboss.byteman.agent.Transformer : error parsing rule hibernatelog2 org.jboss.byteman.rule.exception.ParseException: org.jboss.byteman.rule.Rule : error parsing rule

. . .

are binding of arrays not supported by byteman?

Yes, array type declarations and array references are supposed to work, This looks like a bug in the parser rule for type declarations. I will investigate and let you know.

In the meantime can you confirm whether this works if you omit the type specifier for variable five i.e.

BIND sql:String = $2, five = $5

The parser should be able to infer that five is of type String[] from the method signature. If this does parse then can you also check that it is ok to access elements of five in the rule body e.g.

DO traceln("out", "five[0] == " + five[0])

[adinn]

So, it turns out there were several problems to fix here.

Firstly, the parser would not allow BIND variables to be declared with array types.

Secondly, between JDK5 and JDK6 the semantics of ClassLoader.loadClass() was changed to disallow loading of array classes by default. This broke the existing array code. Because I did not have a proper test case for array usage I did not notice this change.

Thirdly, array code compilation only worked when accessing arrays whose base type was not also an array. It failed if the base type was another array e.g. an expression like oarray[0][0] would cause a compile error.

These have all been fixed by https://jira.jboss.org/jira/browse/BYTEMAN-30. I have also included a test which exercises array functionality in the tests directory as part of this fix.

I also detected a problem with String plus operations. These threw a NullPointerException if either operand was null. This has been fixed by https://jira.jboss.org/jira/browse/BYTEMAN-31 so that any null operand is substituted with the string "null". The array test also exercises this functionality.

[adinn]

I have also removed the need to supply the redefine:true option if you want System classes to be retransformed automatically. This is now done automatically after the transformer is installed. See https://jira.jboss.org/jira/browse/BYTEMAN-32

As part of this fix I have also renamed the redefine: option to listener: because all this option does now is control whether or not a listener thread is created to allow dynamic upload of rules and listing of current rule transforms.

[stefanegli]

Great stuff! I did actually try the BIND with String[] and it did fail (before your fix) because the parameter was null which seemed to confuse it.

Have to try the latest trunk with all those fixes.

Thanks!
Cheers,
Stefa

[adinn]

Have to try the latest trunk with all those fixes.

Ok, I'm keen to hear what happens . . . and keep those bug reports rolling in :-)

[stefanegli]

Tried the latest trunk and ran into problems with Transformer.getTransformer() being null and subsequent problems with installing any rules.

To see what's happening I added a static{} block to Transformer and printed out a stacktrace:

static {
 (new Exception("Transformer.<clinit>")).printStackTrace(System.out);
}

Here's the debug output:

java.lang.Exception: Transformer.<clinit>
 at org.jboss.byteman.agent.Transformer.<clinit>(Transformer.java:51)
 at org.jboss.byteman.agent.Main.premain(Main.java:85)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.lang.reflect.Method.invoke(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(Unknown Source)
new Transformer()
java.lang.Exception: Transformer.<clinit>
 at org.jboss.byteman.agent.Transformer.<clinit>(Transformer.java:51)
 at org.jboss.byteman.agent.adapter.EntryTriggerAdapter$EntryTriggerMethodAdapter.injectTriggerPoint(EntryTriggerAdapter.java:106)
 at org.jboss.byteman.agent.adapter.EntryTriggerAdapter$EntryTriggerMethodAdapter.visitVarInsn(EntryTriggerAdapter.java:161)
 at org.objectweb.asm.ClassReader.accept(ClassReader.java:1276)
 at org.objectweb.asm.ClassReader.accept(ClassReader.java:394)
 at org.jboss.byteman.agent.Transformer.transform(Transformer.java:575)
 at org.jboss.byteman.agent.Transformer.transform(Transformer.java:399)
 at sun.instrument.TransformerManager.transform(Unknown Source)
 at sun.instrument.InstrumentationImpl.transform(Unknown Source)
 at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
 at sun.instrument.InstrumentationImpl.retransformClasses(Unknown Source)
 at org.jboss.byteman.agent.Transformer.installBootScripts(Transformer.java:309)
 at org.jboss.byteman.agent.Main.premain(Main.java:119)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.lang.reflect.Method.invoke(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(Unknown Source)

It's a bit fishy - looks like Transformer is being loaded by two Classloaders.

Any idea?

[stefanegli]

PS: have locally reverted Main.java to revision 29187 - works in that version

[adinn]

Hi Stefan,

java.lang.Exception: Transformer.<clinit>
 at org.jboss.byteman.agent.Transformer.<clinit>(Transformer.java:51)
 at org.jboss.byteman.agent.Main.premain(Main.java:85)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.lang.reflect.Method.invoke(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(Unknown Source)
new Transformer()
java.lang.Exception: Transformer.<clinit>
 at org.jboss.byteman.agent.Transformer.<clinit>(Transformer.java:51)
 at org.jboss.byteman.agent.adapter.EntryTriggerAdapter$EntryTriggerMethodAdapter.injectTriggerPoint
(EntryTriggerAdapter.java:106)
 at org.jboss.byteman.agent.adapter.EntryTriggerAdapter$EntryTriggerMethodAdapter.visitVarInsn(Entry
TriggerAdapter.java:161)
 at org.objectweb.asm.ClassReader.accept(ClassReader.java:1276)
 at org.objectweb.asm.ClassReader.accept(ClassReader.java:394)
 at org.jboss.byteman.agent.Transformer.transform(Transformer.java:575)
 at org.jboss.byteman.agent.Transformer.transform(Transformer.java:399)
 at sun.instrument.TransformerManager.transform(Unknown Source)
 at sun.instrument.InstrumentationImpl.transform(Unknown Source)
 at sun.instrument.InstrumentationImpl.retransformClasses0(Native Method)
 at sun.instrument.InstrumentationImpl.retransformClasses(Unknown Source)
 at org.jboss.byteman.agent.Transformer.installBootScripts(Transformer.java:309)
 at org.jboss.byteman.agent.Main.premain(Main.java:119)
 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
 at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
 at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
 at java.lang.reflect.Method.invoke(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndStartAgent(Unknown Source)
 at sun.instrument.InstrumentationImpl.loadClassAndCallPremain(Unknown Source)

Hmm, that's very interesting :-). The clinit routine is getting called twice which ain't supposed to happen. But that may just be because you have thrown an exception the first time it gets called (which you ain't supposed to do). I'll note that you get two traces above preMain but it should only get called once.. So your debug trace here is probably misleading you as to what is really going on.

Perhaps you can explain a few things about the original error:

You say

Tried the latest trunk and ran into problems with Transformer.getTransformer() being null

Do you mean Transformer.getTheTransformer()? (n.b. an exception trace for this would really help). If so then I think this may be a simple synchronizaton bug and I may have a simple patch for it.

What was the rule script you were using when the original error happened? Does this error only occur for this script or does it happen for other scripts?

Can you rerun this adding the following JVM command line argument

 -Dorg.jboss.byteman.verbose

This should reveal whether existing loaded bootstrap classes are being retransformed and whether this is maybe the cause of the problem.

[stefanegli]

I wasn't really throwing an exception in the static block - that stacktrace is only passed to system.out, not thrown.

Yes, it was Transformer.getTheTransformer() which was null.

That happened in Compiler.getHelperAdapter() on line 77.

PS: yeah, I think it would have to do with the class being retransformed (maybe Transformer itself gets retransformed - have to run it again with verbose later today). The fact that the class gets loaded twice (without exception in the static :) can only mean two things: either there are two classloaders involved (which sort of can't be) or it's because retransforming a class causes it to be loaded again later (interesting but kind of makes a lot of sense)

[adinn]

Hi, Stefan.

I wasn't really throwing an exception in the static block - that stacktrace is only passed to system.out, not thrown.

Yes, my mistake, I just reread the code and saw that you were only using the exception to derive a stack trace. The repeated call to clinit is rather weird. However, I am still not sure that these are independent calls to premain.

Yes, it was Transformer.getTheTransformer() which was null.

That happened in Compiler.getHelperAdapter() on line 77.

Ok, is this under the call to Transformer.installBootScripts() when it calls InstrumentationImpl.retransformClasses()? Or is it in another thread which happens concurrently to be loading a class mentioned in one of the scripts. IN theory, the latter case might just account for what is happening.

Transformer.getTheTransformer reads a static field of Transformer,

 private static Transformer theTransformer = null;

 public static Transformer getTheTransformer()
 {
 return theTransformer;
 }

This field is initialized on the first line of the constructor

 public Transformer(Instrumentation inst, List<String> scriptPaths, List<String> scriptTexts, boolean isRedefine)
 throws Exception
 {
 theTransformer = this;
 this.inst = inst;
 this.isRedefine = isRedefine;
 . . .

The constructor gets called from preMain as follows.

 . . .
 transformer = new Transformer(inst, scriptPaths, scripts, isRedefine);
 }

 inst.addTransformer(transformer, true);
 if (isRedefine) {
 transformer.installBootScripts();
 }

Now, in theory, on a multi-processor box the subsequent call to addTransformer exposes the transformer to other threads. So, this could allow another concurrent thread loading a target class to access it and call Transformer.transform() before the write to the static field is visible. But the method you mention, getHelperAdapter(), is called by the rule compiler which gets run very late. The window where the write was not visible would have to cover injection of the rule code into the target method, invocation of the target method and then type checking of the rule at this first call. This seems rather a long time for a writeback to be pending :-)

Besides which, there really ought to be a synchronization inside the call to addTransformer and a matching synchronization in the thread which calls transform (presuambly the list of installed transformers is guarded against concurrent access/update). If so then this synchronization should ensure that the writeback of the static field in Transformer has happened before transform (and eventually getHelperAdapter) gets called.

So, I suspect this problem is because clinit is not executing to completion for some reason. It would be nice to know what is causing that. But as you can see form the code above it ought not to be possible for the transformer to screw that up because the clinit code should have completed well before the transformer is capable of injecting a rule which might break anything called by the clinit code.

PS: yeah, I think it would have to do with the class being retransformed (maybe Transformer itself gets retransformed - have to run it again with verbose later today). The fact that the class gets loaded twice (without exception in the static :) can only mean two things: either there are two classloaders involved (which sort of can't be) or it's because retransforming a class causes it to be loaded again later (interesting but kind of makes a lot of sense)

The transformer checks all loaded classes and refuses to modify bytecode for anything whose fully qualified name starts with java.lang or org.jboss.byteman (except it does allow org.jboss.byteman.test :-). So, the transformer should not attempt to modify byteman classes. BUt it is definitely possible to screw up a class Byteman needs. In that respect it's a fully loaded, high-calibre weapon -- don't point it anywhere near your foot :-)

[stefanegli]

The interesting part is: I reverted Main.java to revision 29187 and then it works fine!

So the bug must be within that last checkin of Main.java

[adinn]

The interesting part is: I reverted Main.java to revision 29187 and then it works fine!

So the bug must be within that last checkin of Main.java

Hmm, possibly :-)

The main difference introduced in that checkin was to move the method which redefines already loaded classes (installBootClasses) from class Retransformer to class Transformer. If you use the older version with the redefine:true option then it runs the same code.

So, the bug might already be in there but just depend on the exact order in which things happen.

[adinn]

Hi Stefan,

I have found out what the bug is. The problem is indeed to do with class loaders as you originally surmised (I should have listened more carefully to what you were saying :-). If you don't compile the rules to bytecode the bug does not manifest. If you do then it blows up.

I will need to have a think about how to deal with this problem. The problem is that I am getting two versions of the Byteman code, one loaded in the system classloader and one loaded in the bootstrap class loader.

For recompilation of bootstrap classes to work properly I need to have the byteman jar available in the bootstrap class path. If it is not in this path then compilation of a bootstrap class fails with unresolved class references.

However, the transformer installed under the -javaagent call is created from class org.jboss.byteman.agent.Main which gets loaded by the system classloader, So, this links against class Transformer loaded by the same class loader because the reference to Transformer has already been resolved during loading of class Main before the boot classpath is updated. As a result, I end up with two versions of Transformer, Rule, etc.

I will have a look at how I can fix this. I think that if I remove any explicit linkage from Main to Transformer then I should be able to access the bootstrap classpath version of Transformer indirectly using classloader.loadClass() once I have modified the boot classpath. I will get back to you when I have had a look at this.

[adinn]

Hi Stefan,

This should now be fixed as per

 https://jira.jboss.org/jira/browse/BYTEMAN-34

Try updating to the latest trunk to test it.

I also patched a problem with compilation of THROW expressions as per

 https://jira.jboss.org/jira/browse/BYTEMAN-35

Let me know if it is ok or not.