Mailing-List: contact open-jpa-dev-help@incubator.apache.org; run by ezmlm
Precedence: bulk
Reply-To: open-jpa-dev@incubator.apache.org
Message-ID: <18123686.1168449387570.JavaMail.jira@brutus>
Date: Wed, 10 Jan 2007 09:16:27 -0800 (PST)
From: "Kevin Sutter (JIRA)" <jira@apache.org>
To: open-jpa-dev@incubator.apache.org
Subject: [jira] Commented: (OPENJPA-98) Java deadlock when insert in t1 and
 find in t2 when using IBM JVM 1.5.0
In-Reply-To: <29140214.1168374627749.JavaMail.jira@brutus>
MIME-Version: 1.0
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: 7bit


    [ https://issues.apache.org/jira/browse/OPENJPA-98?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_12463636 ] 

Kevin Sutter commented on OPENJPA-98:
-------------------------------------

I'll take ownership of this report (for now, at least).

I can now reproduce the problem.  Using the runtime enhancement and using previously created database tables, the problem reproduces itself quite easily.

>From looking at the resulting stack traces for the deadlock, the dynamic enhancement processing is definitely the source of the problem.  If the classes were statically enhanced before the execution, this particular problem would not surface.  But, I don't see any processing within the dynamic enhancement class loader that should cause this type of deadlock.

Here are snippets from the javacore thread dump for the two deadlocked threads:

3XMTHREADINFO      "main" (TID:0x41DF8C00, sys_thread_t:0x0038B9D8, state:B, native ID:0x00001744) prio=5
4XESTACKTRACE          at com/ibm/oti/vm/BootstrapClassLoader.loadClass(BootstrapClassLoader.java:63(Compiled Code))
4XESTACKTRACE          at java/lang/ClassLoader.loadClass(ClassLoader.java:587(Compiled Code))
4XESTACKTRACE          at java/lang/ClassLoader.loadClass(ClassLoader.java:587(Compiled Code))
4XESTACKTRACE          at sun/misc/Launcher$AppClassLoader.loadClass(Launcher.java:327(Compiled Code))
4XESTACKTRACE          at java/lang/ClassLoader.loadClass(ClassLoader.java:563(Compiled Code))
4XESTACKTRACE          at org/apache/openjpa/jdbc/kernel/JDBCStoreManager.getManagedType(JDBCStoreManager.java:562)
4XESTACKTRACE          at org/apache/openjpa/kernel/DelegatingStoreManager.getManagedType(DelegatingStoreManager.java:140)
4XESTACKTRACE          at org/apache/openjpa/kernel/BrokerImpl.newStateManagerImpl(BrokerImpl.java:1136)
4XESTACKTRACE          at org/apache/openjpa/kernel/BrokerImpl.find(BrokerImpl.java:826)
4XESTACKTRACE          at org/apache/openjpa/kernel/BrokerImpl.find(BrokerImpl.java:743)
4XESTACKTRACE          at org/apache/openjpa/kernel/DelegatingBroker.find(DelegatingBroker.java:169)
4XESTACKTRACE          at org/apache/openjpa/persistence/EntityManagerImpl.find(EntityManagerImpl.java:346)
4XESTACKTRACE          at com/ibm/ws/persistence/tests/simple/TestInsertAndFind.test001(TestInsertAndFind.java:51)
:

3XMTHREADINFO      "Finalizer thread" (TID:0x41ED6200, sys_thread_t:0x42299718, state:B, native ID:0x00001078) prio=5
4XESTACKTRACE          at java/lang/ClassLoader.loadClass(ClassLoader.java:563(Compiled Code))
4XESTACKTRACE          at java/lang/Class.forNameImpl(Native Method)
4XESTACKTRACE          at java/lang/Class.forName(Class.java:160(Compiled Code))
4XESTACKTRACE          at org/apache/openjpa/lib/util/TemporaryClassLoader.loadClass(TemporaryClassLoader.java:55(Compiled Code))
4XESTACKTRACE          at org/apache/openjpa/lib/util/TemporaryClassLoader.loadClass(TemporaryClassLoader.java:40(Compiled Code))
4XESTACKTRACE          at java/lang/Class.forNameImpl(Native Method)
4XESTACKTRACE          at java/lang/Class.forName(Class.java:160(Compiled Code))
4XESTACKTRACE          at org/apache/openjpa/enhance/PCClassFileTransformer.needsEnhance(PCClassFileTransformer.java:171(Compiled Code))
4XESTACKTRACE          at org/apache/openjpa/enhance/PCClassFileTransformer.transform(PCClassFileTransformer.java:117(Compiled Code))
:

As the "find" operation is performed in the main thread, additional classes need to be loaded to satisfy the request.  As part of that class loading, the runtime enhancement is kicked off to determine whether the classes being loaded need to be enhanced or not.

As part of this checking, the following conditional is executed:

        if (name.startsWith("java.") || name.startsWith("javax.")
            || name.startsWith("sun."))
            return Class.forName(name, resolve, getClass().getClassLoader());

This call to Class.forName() eventually requests the same lock that is already in place on the Main thread.  Everytime I hit this deadlock, it's the same stack traces.  And, it's always at the same spot in the testcode.  But, like Vlad and I have mentioned, it doesn't deadlock on every execution.

My gut reaction at this point is that we have a problem with the IBM JDK.  But, I wanted to post my findings to this Issue to see if this description jogs any memory bits from the original OpenJPA authors.

Thanks,
Kevin

> Java deadlock when insert in t1 and find in t2 when using IBM JVM 1.5.0
> -----------------------------------------------------------------------
>
>                 Key: OPENJPA-98
>                 URL: https://issues.apache.org/jira/browse/OPENJPA-98
>             Project: OpenJPA
>          Issue Type: Bug
>         Environment: OpenJPA:
> 0.9.6
> Java:
> java version "1.5.0"
> Java(TM) 2 Runtime Environment, Standard Edition (build pwi32dev-20061002a (SR3)
> )
> IBM J9 VM (build 2.3, J2RE 1.5.0 IBM J9 2.3 Windows XP x86-32 j9vmwi3223-2006100
> 1 (JIT enabled)
> J9VM - 20060915_08260_lHdSMR
> JIT  - 20060908_1811_r8
> GC   - 20060906_AA)
> JCL  - 20061002
> DB:
> Derby 10.2.1.6
>            Reporter: Vlad Tatavu
>         Assigned To: Kevin Sutter
>         Attachments: console.txt, javacore.20070109.114312.3868.zip, play.zip
>
>
> I have a simple test program that uses OpenJPA 0.9.6 to insert an object into a db in one transaction (t1) and retrieve it in another transaction (t2).  The program hangs in 30-50% of the executions right before the call to entitymanager.find() (used to retrieve the object in t2).  I'm using OpenJPA runtime enhancement.
> By looking at the JVM dump, I can see the following deadlock:
> 1LKDEADLOCK    Deadlock detected !!!
> NULL           ---------------------
> NULL           
> 2LKDEADLOCKTHR  Thread "main" (0x0015EC00)
> 3LKDEADLOCKWTR    is waiting for:
> 4LKDEADLOCKMON      sys_mon_t:0x41E40548 infl_mon_t: 0x41E40588:
> 4LKDEADLOCKOBJ      java/lang/Object@00D41010/00D4101C: 
> 3LKDEADLOCKOWN    which is owned by:
> 2LKDEADLOCKTHR  Thread "Finalizer thread" (0x41B36200)
> 3LKDEADLOCKWTR    which is waiting for:
> 4LKDEADLOCKMON      sys_mon_t:0x0035CD38 infl_mon_t: 0x0035CD78:
> 4LKDEADLOCKOBJ      sun/misc/Launcher$AppClassLoader@00D4E5B0/00D4E5BC: 
> 3LKDEADLOCKOWN    which is owned by:
> 2LKDEADLOCKTHR  Thread "main" (0x0015EC00)

-- 
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: https://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira