Project: AspectJ
Bug 155148 jdk14 trace deadlock in oc4j
Reported: 2006-08-24 20:59:00 | Status: resolved fixed

I turned on tracing for the Aj class inside of Oracle's OC4J server. In one test (not always) it deadlocked. It looks like the threads are each trying to lock each other's loader. Notice that one of the threads is in the toString method of the Oracle ClassLoader (perhaps another reason to prefer tracing argument class names and system identity hashcodes). Here's a thread dump from Ctrl+BREAK: Found one Java-level deadlock: ============================= "WorkExecutorWorkerThread-1": waiting to lock monitor 0x003384ec (object 0x05239e48, a oracle.classloader.Po licyClassLoader), which is held by "OC4J Launcher" "OC4J Launcher": waiting to lock monitor 0x0033848c (object 0x0554f0e8, a oracle.classloader.Po licyClassLoader), which is held by "WorkExecutorWorkerThread-1" Java stack information for the threads listed above: =================================================== "WorkExecutorWorkerThread-1": at oracle.classloader.SearchPolicy.loadClass(SearchPolicy.java:641) - waiting to lock <0x05239e48> (a oracle.classloader.PolicyClassLoader) at oracle.classloader.PolicyClassLoader.askParentForClass(PolicyClassLoa der.java:1284) at oracle.classloader.SearchPolicy$AskParent.getClass(SearchPolicy.java: 69) at oracle.classloader.SearchSequence.getClass(SearchSequence.java:119) at oracle.classloader.SearchPolicy.loadClass(SearchPolicy.java:642) - locked <0x0554f0e8> (a oracle.classloader.PolicyClassLoader) at oracle.classloader.PolicyClassLoader.askParentForClass(PolicyClassLoa der.java:1284) at oracle.classloader.SearchPolicy$AskParent.getClass(SearchPolicy.java: 69) at oracle.classloader.SearchSequence.getClass(SearchSequence.java:119) at oracle.classloader.PolicyClassLoader.internalLoadClass(PolicyClassLoa der.java:1660) - locked <0x056a9ed0> (a oracle.classloader.PolicyClassLoader) at oracle.classloader.PolicyClassLoader.loadClass(PolicyClassLoader.java :1621) at oracle.classloader.PolicyClassLoader.loadClass(PolicyClassLoader.java :1606) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319) - locked <0x056a9ed0> (a oracle.classloader.PolicyClassLoader) at oracle.j2ee.ra.jms.generic.WorkConsumer.doReceive(WorkConsumer.java:9 87) at oracle.j2ee.ra.jms.generic.WorkConsumer.run(WorkConsumer.java:215) - locked <0x05de2718> (a oracle.j2ee.ra.jms.generic.WorkConsumer) at oracle.j2ee.connector.work.WorkWrapper.runTargetWork(WorkWrapper.java :242) at oracle.j2ee.connector.work.WorkWrapper.doWork(WorkWrapper.java:215) at oracle.j2ee.connector.work.WorkWrapper.run(WorkWrapper.java:190) at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExec utor.java:814) at java.lang.Thread.run(Thread.java:595) "OC4J Launcher": at oracle.classloader.PolicyClassLoader.toString(PolicyClassLoader.java: 1846) - waiting to lock <0x0554f0e8> (a oracle.classloader.PolicyClassLoader) at java.text.MessageFormat.subformat(MessageFormat.java:1237) at java.text.MessageFormat.format(MessageFormat.java:828) at java.text.Format.format(Format.java:133) at java.text.MessageFormat.format(MessageFormat.java:804) at java.util.logging.Formatter.formatMessage(Formatter.java:130) - locked <0x0514e920> (a java.util.logging.SimpleFormatter) at java.util.logging.SimpleFormatter.format(SimpleFormatter.java:63) - locked <0x0514e920> (a java.util.logging.SimpleFormatter) at java.util.logging.StreamHandler.publish(StreamHandler.java:179) - locked <0x0514a0a8> (a java.util.logging.FileHandler) at java.util.logging.FileHandler.publish(FileHandler.java:555) - locked <0x0514a0a8> (a java.util.logging.FileHandler) at java.util.logging.Logger.log(Logger.java:428) at java.util.logging.Logger.doLog(Logger.java:450) at java.util.logging.Logger.logp(Logger.java:619) at java.util.logging.Logger.entering(Logger.java:870) at org.aspectj.weaver.tools.Jdk14Trace.enter(Jdk14Trace.java:32) at org.aspectj.weaver.loadtime.Aj.preProcess(Aj.java:67) at org.aspectj.weaver.loadtime.ClassPreProcessorAgentAdapter.transform(C lassPreProcessorAgentAdapter.java:55) at sun.instrument.TransformerManager.transform(TransformerManager.java:1 22) at sun.instrument.InstrumentationImpl.transform(InstrumentationImpl.java :155) at java.lang.ClassLoader.defineClass1(Native Method) at java.lang.ClassLoader.defineClass(ClassLoader.java:620) at oracle.classloader.PolicyClassLoader.defineClass(PolicyClassLoader.ja va:2224) at oracle.classloader.PolicyClassLoader.findLocalClass(PolicyClassLoader .java:1457) at oracle.classloader.SearchPolicy$FindLocal.getClass(SearchPolicy.java: 167) at oracle.classloader.SearchSequence.getClass(SearchSequence.java:119) at oracle.classloader.PolicyClassLoader.internalLoadClass(PolicyClassLoa der.java:1660) - locked <0x05239e48> (a oracle.classloader.PolicyClassLoader) at oracle.classloader.PolicyClassLoader.loadClass(PolicyClassLoader.java :1621) at oracle.classloader.PolicyClassLoader.loadClass(PolicyClassLoader.java :1606) at java.lang.ClassLoader.loadClassInternal(ClassLoader.java:319) - locked <0x05239e48> (a oracle.classloader.PolicyClassLoader) at com.evermind.server.http.HttpRequestHandler.<init>(HttpRequestHandler .java:97) at com.evermind.server.http.HttpConnectionListener$HttpNIOAcceptHandler. getReadHandler(HttpConnectionListener.java:116) at oracle.oc4j.network.ReadHandlerPool.getContextFromBackend(ReadHandler Pool.java:63) at com.evermind.util.BBPool.startPool(BBPool.java:42) at oracle.oc4j.network.ReadHandlerPool.register(ReadHandlerPool.java:25) - locked <0x05ec9290> (a java.util.ArrayList) at oracle.oc4j.network.ServerSocketAcceptHandler.setPoolOptions(ServerSo cketAcceptHandler.java:140) at com.evermind.server.http.HttpConnectionListener.setRequestHandlerPool (HttpConnectionListener.java:232) at com.evermind.server.http.HttpConnectionListener.initHandlers(HttpConn ectionListener.java:226) at com.evermind.server.http.HttpConnectionListener.<init>(HttpConnection Listener.java:174) at com.evermind.server.http.HttpServer.getListener(HttpServer.java:481) - locked <0x05ec4f88> (a com.evermind.server.http.HttpServer) at com.evermind.server.http.HttpServer.setSites(HttpServer.java:267) - locked <0x05ec4f88> (a com.evermind.server.http.HttpServer) at com.evermind.server.http.HttpServer.setConfig(HttpServer.java:180) at com.evermind.server.ApplicationServer.initializeHttp(ApplicationServe r.java:2296) at com.evermind.server.ApplicationServer.setConfig(ApplicationServer.jav a:944) at com.evermind.server.ApplicationServerLauncher.run(ApplicationServerLa uncher.java:113) - locked <0x0530eb20> (a java.lang.Object) at java.lang.Thread.run(Thread.java:595) Found 1 deadlock.

Files changed in fix:
loadtime/src/org/aspectj/weaver/loadtime/DefaultWeavingContext.java weaver/src/org/aspectj/weaver/tools/AbstractTrace.java weaver/testsrc/org/aspectj/weaver/AbstractTraceTest.java weaver5/java5-src/org/aspectj/weaver/tools/Jdk14Trace.java