db-jdo-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Michael Watzek <mwa.t...@spree.de>
Subject Re: JIRA JDO-59
Date Mon, 13 Jun 2005 14:56:29 GMT
Hi Erik,

yes, it is a database lock. By default, derby does row level locking. If 
it can not acquire a lock after 60 seconds (default lock wait timeout), 
then it throws this exception.

Curiously, I can not reproduce the exception with application identity. 
For this reason, the identity column handling might be the problem. Does 
JPOX implement anything special for datastore identity in contrast to 
application identity?

Regards,
Michael

> Hi,
> 
> I don't have a clear picture which resource is locked. Is it database
> deadlock? Can't it be solved by changing the transaction isolation? JPOX
> uses READ_COMMITTED by default.
> 
> Erik Bengtson 
> 
> -----Original Message-----
> From: Michael Watzek [mailto:mwa.tech@spree.de] 
> Sent: Friday, June 10, 2005 8:15 PM
> To: jdo-dev@db.apache.org
> Subject: Re: JIRA JDO-59
> 
> Hi,
> 
> the stacktraces I attached to my previous mail are not printed by the 
> test VM but by the maven VM. I explicitely named the threads in the 
> test, but they are not dumped. Blame on me :-(
> 
> However, I analysed further and found out the problem:
> 
> Actually, it is a race condition - in derby. Sometimes the two calls 
> "makePersistentAll" cause derby to throw a SQLException, because the 
> database timed out on a lock request (see below).
> 
> When an exception is thrown, the synchronization mechanism in the 4 
> tests does not work. This makes one of the two threads wait forever. 
> This is the same problem as JIRA JDO-13.
> 
> I suggest, that we fix the buggy synchronization. I can do that on 
> Monday. Then, we still have the Derby problem - but it will show up as 
> an error and we can include the test cases in the TCK.
> 
> Regards,
> Michael
> 
>      [java] ERROR 40XL1: A lock could not be obtained within the time 
> requested
>      [java]      at 
> org.apache.derby.iapi.error.StandardException.newException(StandardExcep
> tion.java)
>      [java]      at 
> org.apache.derby.impl.services.locks.LockSet.lockObject(LockSet.java)
>      [java]      at 
> org.apache.derby.impl.services.locks.SinglePool.lockAnObject(SinglePool.
> java)
>      [java]      at 
> org.apache.derby.impl.services.locks.SinglePool.lockObject(SinglePool.ja
> va)
>      [java]      at 
> org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(RowL
> ocking3.java)
>      [java]      at 
> org.apache.derby.impl.store.access.conglomerate.OpenConglomerate.lockPos
> itionForWrite(OpenConglomerat
> e.java)
>      [java]      at 
> org.apache.derby.impl.store.access.conglomerate.GenericConglomerateContr
> oller.fetch(GenericConglomera
> teController.java)
>      [java]      at 
> org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getSetAutoincrement
> Value(DataDictionaryImpl.java
> )
>      [java]      at 
> org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementVal
> ue(InsertResultSet.java)
>      [java]      at 
> org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValu
> e(BaseActivation.java)
>      [java]      at 
> org.apache.derby.exe.ac40348015x0104x675cxbca4xffffdab5f0bf0.e0(Unknown 
> Source)
>      [java]      at 
> org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGenerate
> dClass.java)
>      [java]      at 
> org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultS
> et.java)
>      [java]      at 
> org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(Norm
> alizeResultSet.java)
>      [java]      at 
> org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWr
> iteResultSet.java)
>      [java]      at 
> org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.j
> ava)
>      [java]      at 
> org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPrepar
> edStatement.java)
>      [java]      at 
> org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatemen
> t.java)
>      [java]      at 
> org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(Embed
> PreparedStatement.java)
>      [java]      at 
> org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPre
> paredStatement.java)
>      [java]      at 
> org.jpox.store.rdbms.request.Request.executeUpdate(Request.java:69)
>      [java]      at 
> org.jpox.store.rdbms.request.InsertRequest.execute(InsertRequest.java:25
> 3)
>      [java]      at 
> org.jpox.store.rdbms.table.ClassTable.insert(ClassTable.java:1673)
>      [java]      at 
> org.jpox.store.StoreManager.insert(StoreManager.java:634)
>      [java]      at 
> org.jpox.state.StateManagerImpl.internalMakePersistent(StateManagerImpl.
> java:2940)
>      [java]      at 
> org.jpox.state.StateManagerImpl.makePersistent(StateManagerImpl.java:291
> 3)
>      [java]      at 
> org.jpox.AbstractPersistenceManager.internalMakePersistent(AbstractPersi
> stenceManager.java:959)
>      [java]      at 
> org.jpox.AbstractPersistenceManager.makePersistentAll(AbstractPersistenc
> eManager.java:1034)
>      [java]      at 
> org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySideE
> ffects$RefreshArrThreadT1.run
> (RefreshAllWithArraySideEffects.java:176)
>      [java]      at java.lang.Thread.run(Thread.java:595)
> 
> 
>>Hi,
>>
>>JIRA JDO-59 complains that 4 tests hang with 
>>org.jpox.autoStartMechanism=None.
>>
>>I can reproduce the problem using datastore identity - regardless of
> 
> the 
> 
>>setting org.jpox.autoStartMechanism. I cannot reproduce it using 
>>application identity.
>>
>>However, the problem does not show up always. I could not find a 
>>deterministic way of reproducing it. If it shows up, then the VM
> 
> prints 
> 
>>always the same stacktraces using <CTRL>+<PAUSE> on Windows (see
> 
> below).
> 
>>I believe that the tests runs into a race condition. Unfortunately, I
> 
> do 
> 
>>not know if it occurs in JPOX, in the JDBC driver, or in Derby. I 
>>attached a workaround making the 4 tests pass. Be aware that this is
> 
> not 
> 
>>a fix, rather than a workaround:
>>
>>All tests execute 2 concurrent threads. Each thread performs a single 
>>transaction making one or more objects persistent. If the 
>>pm.makePersistent calls are prevented from executing in parallel then
> 
> I 
> 
>>can not reproduce the problem any more. This is what the patch does.
>>
>>Regards,
>>Michael
>>
>>
>>"Thread-2" daemon prio=5 tid=0x27096008 nid=0x6c8 runnable 
>>[0x27bff000..0x27bffd64]
>>        at java.io.FileInputStream.readBytes(Native Method)
>>        at java.io.FileInputStream.read(FileInputStream.java:177)
>>        at 
>>org.apache.tools.ant.taskdefs.StreamPumper.run(StreamPumper.java:105)
>>        at java.lang.Thread.run(Thread.java:595)
>>
>>"Thread-1" daemon prio=5 tid=0x273cec08 nid=0x7ac runnable 
>>[0x27bbf000..0x27bbf9e4]
>>        at java.io.FileInputStream.readBytes(Native Method)
>>        at java.io.FileInputStream.read(FileInputStream.java:194)
>>        at
> 
> java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> 
>>        at
> 
> java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
> 
>>        at
> 
> java.io.BufferedInputStream.read(BufferedInputStream.java:313)
> 
>>        - locked <0x0297a220> (a java.io.BufferedInputStream)
>>        at java.io.FilterInputStream.read(FilterInputStream.java:90)
>>        at 
>>org.apache.tools.ant.taskdefs.StreamPumper.run(StreamPumper.java:105)
>>        at java.lang.Thread.run(Thread.java:595)
>>
>>
>>
> 
> ------------------------------------------------------------------------
> 
>>Index: test/conf/exclude.list
>>===================================================================
>>--- test/conf/exclude.list	(revision 189925)
>>+++ test/conf/exclude.list	(working copy)
>>@@ -1,8 +1,3 @@
>> jdo.tck.exclude = \
>> org.apache.jdo.tck.enhancement.FieldAccessModified \
>>-org.apache.jdo.tck.enhancement.ImplementsPersistenceCapable \
>>-org.apache.jdo.tck.lifecycle.PMsCanSharePCClassesButNotPCInstances \
>>
> 
> -org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllNoParameterSi
> deEffects \
> 
> -org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySide
> Effects \
> 
> -org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithCollectio
> nSideEffects \
> 
>>-org.apache.jdo.tck.api.persistencemanager.cache.RefreshSideEffects
>>+org.apache.jdo.tck.enhancement.ImplementsPersistenceCapable
>>Index: test/conf/alltests.list
>>===================================================================
>>--- test/conf/alltests.list	(revision 189925)
>>+++ test/conf/alltests.list	(working copy)
>>@@ -125,6 +125,10 @@
>>
> 
> org.apache.jdo.tck.api.persistencemanager.cache.PassingNullToEvictHasNoE
> ffect \
> 
> org.apache.jdo.tck.api.persistencemanager.cache.PassingNullToRefreshAllT
> hrowsException \
> 
> org.apache.jdo.tck.api.persistencemanager.cache.PassingNullToRefreshHasN
> oEffect \
> 
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllNoParameterSi
> deEffects \
> 
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySide
> Effects \
> 
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithCollectio
> nSideEffects \
> 
>>+org.apache.jdo.tck.api.persistencemanager.cache.RefreshSideEffects \
>> org.apache.jdo.tck.api.persistencemanager.cache.Retrieve \
>>
> 
> org.apache.jdo.tck.api.persistencemanager.SameTransactionInstanceForAllC
> allsToCurrentTransaction \
> 
>> org.apache.jdo.tck.api.persistencemanager.flags.SetIgnoreCacheToFalse
> 
> \
> 
>>Index:
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEff
> ects.java
> 
>>===================================================================
>>---
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEff
> ects.java	(revision 189925)
> 
>>+++
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEff
> ects.java	(working copy)
> 
>>@@ -51,6 +51,9 @@
>>     /** */
>>     static final int DELAY = 100;
>> 
>>+    /** This object is used for synchronizing concurrent
> 
> makePersistentAll calls. */
> 
>>+    private static final Object synchronizationObject = new Object();
>>+    
>>     /**
>>      * The <code>main</code> is called when the class
>>      * is directly executed from the command line.
>>@@ -150,7 +153,9 @@
>>                 RefreshSideEffects.this.logger.debug("  ThreadT1:
> 
> START");
> 
>>                 tx.begin();
>>                 n1.setX(500);
>>-                pm.makePersistent(n1);
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistent(n1);
>>+                }
>>                 pm.refresh(n1);
>> 
>>                 RefreshSideEffects.this.logger.debug(
>>@@ -171,6 +176,7 @@
>>                     "  ThreadT1: commit finished.");
>>             }
>>             finally {
>>+                commitDone = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>@@ -210,7 +216,9 @@
>>                 RefreshSideEffects.this.logger.debug("  ThreadT2:
> 
> START");
> 
>>                 tx.begin();
>>                 p1.setX(201);
>>-                pm.makePersistent(p1);
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistent(p1);
>>+                }
>>                 pm.refresh(p1);
>>                 done = true;
>> 
>>@@ -230,6 +238,7 @@
>>                     "  ThreadT2: commit finished.");
>>             } 
>>             finally {
>>+                done = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>Index:
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> CollectionSideEffects.java
> 
>>===================================================================
>>---
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> CollectionSideEffects.java	(revision 189925)
> 
>>+++
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> CollectionSideEffects.java	(working copy)
> 
>>@@ -55,6 +55,9 @@
>>     /** */
>>     static final int DELAY = 100;
>> 
>>+    /** This object is used for synchronizing concurrent
> 
> makePersistentAll calls. */
> 
>>+    private static final Object synchronizationObject = new Object();
>>+    
>>     /**
>>      * The <code>main</code> is called when the class
>>      * is directly executed from the command line.
>>@@ -160,7 +163,9 @@
>>                 col1.add(n1);
>>                 col1.add(n2);
>> 
>>-                pm.makePersistentAll(col1);
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll(col1);
>>
> 
> RefreshAllWithCollectionSideEffects.this.logger.debug(
> 
>>                     "  ThreadT1: waiting for ThreadT2.done");
>>@@ -181,6 +186,7 @@
>>                     "  ThreadT1: commit finished.");
>>             } 
>>             finally {
>>+                commitDone = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>@@ -225,7 +231,9 @@
>>                 Collection col1 = new HashSet();
>>                 col1.add(p1);
>>                 col1.add(p2);
>>-                pm.makePersistentAll(col1);
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll(col1);
>>                 done = true;
>> 
>>@@ -245,6 +253,7 @@
>>                     "  ThreadT2: commit finished.");
>>             } 
>>             finally {
>>+                done = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>Index:
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> ArraySideEffects.java
> 
>>===================================================================
>>---
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> ArraySideEffects.java	(revision 189925)
> 
>>+++
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWith
> ArraySideEffects.java	(working copy)
> 
>>@@ -55,6 +55,9 @@
>>     /** */
>>     static final int DELAY = 100;
>> 
>>+    /** This object is used for synchronizing concurrent
> 
> makePersistentAll calls. */
> 
>>+    private static final Object synchronizationObject = new Object();
>>+    
>>     /**
>>      * The <code>main</code> is called when the class
>>      * is directly executed from the command line.
>>@@ -155,12 +158,14 @@
>>                 tx.begin();
>>                 n1.setX(500);
>>                 n2.setX(501);
>>-
>>+                
>>                 Collection col1 = new HashSet();
>>                 col1.add(n1);
>>                 col1.add(n2);
>>-
>>-                pm.makePersistentAll(col1);
>>+                
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll(col1.toArray());
>>                 RefreshAllWithArraySideEffects.this.logger.debug(
>>                     "  ThreadT1: waiting for ThreadT2.done");
>>@@ -181,6 +186,7 @@
>>                     "  ThreadT1: commit finished.");
>>             } 
>>             finally {
>>+                commitDone = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>@@ -222,16 +228,20 @@
>>                 tx.begin();
>>                 p1.setX(200);
>>                 p2.setX(201);
>>-
>>+                
>>                 Collection col1 = new HashSet();
>>                 col1.add(p1);
>>                 col1.add(p2);
>>-                pm.makePersistentAll(col1);
>>+                
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll(col1.toArray());
>>                 done = true;
>>-
>>+                
>>                 RefreshAllWithArraySideEffects.this.logger.debug(
>>                     "  ThreadT2: waiting for commit of ThreadT1");
>>+
>>                 while (!other.isCommitDone()) {
>>                     try {
>>                         Thread.sleep(DELAY);
>>@@ -246,6 +256,7 @@
>>                     "  ThreadT2: commit finished.");
>>             } 
>>             finally {
>>+                done = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>Index:
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllNoPa
> rameterSideEffects.java
> 
>>===================================================================
>>---
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllNoPa
> rameterSideEffects.java	(revision 189925)
> 
>>+++
> 
> test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllNoPa
> rameterSideEffects.java	(working copy)
> 
>>@@ -54,6 +54,9 @@
>>     /** */
>>     static final int DELAY = 100;
>> 
>>+    /** This object is used for synchronizing concurrent
> 
> makePersistentAll calls. */
> 
>>+    private static final Object synchronizationObject = new Object();
>>+    
>>     /**
>>      * The <code>main</code> is called when the class
>>      * is directly executed from the command line.
>>@@ -166,7 +169,9 @@
>>                 col1.add(n1);
>>                 col1.add(n2);
>> 
>>-                pm.makePersistentAll(col1);
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll();
>> 
>>                 RefreshAllNoParameterSideEffects.this.logger.debug(
>>@@ -187,6 +192,7 @@
>>                     "  ThreadT1: commit finished.");
>>             }
>>             finally {
>>+                commitDone = true;
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
>>@@ -232,7 +238,10 @@
>>                 Collection col1 = new HashSet();
>>                 col1.add(p1);
>>                 col1.add(p2);
>>-                pm.makePersistentAll(col1);
>>+                
>>+                synchronized (synchronizationObject) {
>>+                    pm.makePersistentAll(col1);
>>+                }
>>                 pm.refreshAll();
>>                 done = true; 
>> 
>>@@ -253,6 +262,7 @@
>>                     "  ThreadT2: commit finished.");
>>             }
>>             finally {
>>+                done = true; 
>>                 if ((tx != null) && tx.isActive())
>>                     tx.rollback();
>>             }
> 
> 
> 


-- 
-------------------------------------------------------------------
Michael Watzek                  Tech@Spree Engineering GmbH
mailto:mwa.tech@spree.de        Buelowstr. 66
Tel.:  ++49/30/235 520 36       10783 Berlin - Germany
Fax.:  ++49/30/217 520 12       http://www.spree.de/
-------------------------------------------------------------------

Mime
View raw message