Environment: jdk8 , use byteman with maven test.
I use byteman to instrument the following code into the java.util.ArrayList.size() menthod, but i meet a deadlock, it seems to a issue of byteman.
the instrument code: (as you can see, just sleep random time)
java.util.Random rand = new java.util.Random();
try{
int time = rand.nextInt(10);
Thread.sleep(time);
// System.out.println("sleep "+time+" ms");
} catch (InterruptedException e) {
e.printStackTrace();
}
Found one Java-level deadlock:
=============================
"pool-1-thread-1":
waiting to lock monitor 0x00007fee50003308 (object 0x00000000aad29098, a sun.misc.URLClassPath),
which is held by "surefire-forkedjvm-command-thread"
"surefire-forkedjvm-command-thread":
waiting to lock monitor 0x00007fee80005fe8 (object 0x00000000a342fc48, a org.jboss.byteman.modules.ClassbyteClassLoader),
which is held by "pool-1-thread-1"
Java stack information for the threads listed above:
===================================================
"pool-1-thread-1":
at sun.misc.URLClassPath.knownToNotExist(URLClassPath.java:379)
- waiting to lock <0x00000000aad29098> (a sun.misc.URLClassPath)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:336)
at java.lang.ClassLoader.loadClass(ClassLoader.java:405)
- locked <0x00000000a342fc48> (a org.jboss.byteman.modules.ClassbyteClassLoader)
at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
at sun.misc.Unsafe.defineClass(Native Method)
at sun.reflect.ClassDefiner.defineClass(ClassDefiner.java:63)
at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:399)
at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:394)
at java.security.AccessController.doPrivileged(Native Method)
at sun.reflect.MethodAccessorGenerator.generate(MethodAccessorGenerator.java:393)
at sun.reflect.MethodAccessorGenerator.generateConstructor(MethodAccessorGenerator.java:92)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:55)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.jboss.byteman.rule.Rule.execute(Rule.java:817)
at org.jboss.byteman.rule.Rule.execute(Rule.java:789)
at java.util.ArrayList.size(ArrayList.java:284)
at sun.misc.URLClassPath.getLoader(URLClassPath.java:510)
- locked <0x00000000aaf16ad8> (a sun.misc.URLClassPath)
at sun.misc.URLClassPath.getNextLoader(URLClassPath.java:495)
- locked <0x00000000aaf16ad8> (a sun.misc.URLClassPath)
at sun.misc.URLClassPath.getResource(URLClassPath.java:249)
at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
- locked <0x00000000a57ffbc8> (a java.lang.Object)
at java.lang.ClassLoader.loadClass(ClassLoader.java:405)
- locked <0x00000000a57ffb18> (a java.lang.Object)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:352)
at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
at org.junit.runner.notification.RunNotifier.fireTestStarted(RunNotifier.java:153)
at org.apache.maven.surefire.common.junit4.Notifier.fireTestStarted(Notifier.java:100)
at org.junit.internal.runners.model.EachTestNotifier.fireTestStarted(EachTestNotifier.java:42)
at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:364)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:103)
at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:63)
at org.junit.runners.ParentRunner$4.run(ParentRunner.java:331)
at org.apache.maven.surefire.junitcore.pc.Scheduler$1.run(Scheduler.java:410)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
at java.lang.Thread.run(Thread.java:750)
"surefire-forkedjvm-command-thread":
at sun.misc.Unsafe.defineClass(Native Method)
at sun.reflect.ClassDefiner.defineClass(ClassDefiner.java:63)
at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:399)
at sun.reflect.MethodAccessorGenerator$1.run(MethodAccessorGenerator.java:394)
at java.security.AccessController.doPrivileged(Native Method)
at sun.reflect.MethodAccessorGenerator.generate(MethodAccessorGenerator.java:393)
at sun.reflect.MethodAccessorGenerator.generateConstructor(MethodAccessorGenerator.java:92)
at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:55)
at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
at org.jboss.byteman.rule.Rule.execute(Rule.java:817)
at org.jboss.byteman.rule.Rule.execute(Rule.java:789)
at java.util.ArrayList.size(ArrayList.java:284)
at sun.misc.URLClassPath.getLoader(URLClassPath.java:510)
- locked <0x00000000aad29098> (a sun.misc.URLClassPath)
at sun.misc.URLClassPath.getNextLoader(URLClassPath.java:495)
- locked <0x00000000aad29098> (a sun.misc.URLClassPath)
at sun.misc.URLClassPath.getResource(URLClassPath.java:249)
at java.net.URLClassLoader$1.run(URLClassLoader.java:366)
at java.net.URLClassLoader$1.run(URLClassLoader.java:363)
at java.security.AccessController.doPrivileged(Native Method)
at java.net.URLClassLoader.findClass(URLClassLoader.java:362)
at java.lang.ClassLoader.loadClass(ClassLoader.java:418)
- locked <0x00000000a55f3b68> (a java.lang.Object)
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:352)
at java.lang.ClassLoader.loadClass(ClassLoader.java:351)
at org.apache.maven.surefire.booter.MasterProcessCommand.decode(MasterProcessCommand.java:139)
at org.apache.maven.surefire.booter.CommandReader$CommandRunnable.run(CommandReader.java:391)
at java.lang.Thread.run(Thread.java:750)
Found 1 deadlock.
It looks like a issue of byteman implementation.
Hmm, nice bug.
This is not actually a Byteman bug. It is a race in the JDK implementation of Constructor.newInstance which, if the wrong thread wins, can lead to out of order locking of class loader locks and result in deadlock.
What is happening here is that two threads (pool-1-thread-1 and surefire-forkedjvm-command-thread) are both triggering the rule on ArrayList.size underneath a call to ClassLoader.loadClass. You may wonder why is Constructor.newInstance called? Well, because the Byteman rule interpreter implements 'new Random()' by calling the newInstance method of class Random (it has to -- the only other way to implement new is by translating the rule to bytecode).
The implementation of newInstance delegates to NativeConstructorAccessorImpl.newInstance. This calls a native method to do the call up to some threshold limit for the number of times it has been called. After that threshold has been reached it uses a bytecode assembler to 'inflate' the method from native code to bytecode i.e. it creates bytecode that defines a class with a method that will use the new bytecode to instantiate the target class. After inflation a newly created accessor object is stashed in the constructor and its method can be called create the instance. In order to be able to create this accessor class and then create an instance the inflation code needs to call defineClass in the relevant loader i.e the main AppClassLoader. Both threads hit this inflation point at pretty much the same time so both of them try to create the auxiliary class at about the same time.
Defining the auxiliary class actually requires taking a lock on the main AppClassLoader and then on one of the URLClassLoaders it delegates to. The problem arises because the two threads have already taken locks on their own URLClassLoader before they hit the Byteman rule. One of them (pool-1-thread-1) gets ot rhe defineClass call first, locks the main AppClassLoader and then tries to lock the first URLClassLoader but cannot proceed because that URLClassLoader is already locked by the second thread (surefire-forkedjvm-command-thread). That second thread tries to lock the main AppClassLoader and cannot proceed because that AppClassLoader is already locked by the first thread.
So, why has this race not been seen already and fixed? Well, I don't believe this ever happens in normal JDK execution. Constructor.newInstance is not normally called underneath ClassLoader.loadClass. So, the race does not normally arise. However, if you inject code that executes a new into something that gets called under ClassLoader.loadClass (like ArrayList.size) then Byteman will call Constructor.newInstance to implement the new and the race is on.
What this shows is that you can are perfectly free to inject rule code into methods of JDK runtime core classes but you cannot always do so reliably. Injecting code into methods that update JDK runtime state (like the internal state of a ClassLoader, a Constructor or a Method) might well end up causing side-effects that mess up the JDK runtime's own internal assumptions. It may look innocuous to just create a new instance of Random but remember that this may involve running a lot of Java code, some of it making invisible changes to internal state for the purpose of optimizing performance.
Byteman merely provides the opportunity to do bytecode injection. It does not (cannot) guarantee that this will not cause problems, especially when the target is JDK runtime code.