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:[EMAIL PROTECTED] Sent: Friday, June 10, 2005 8:15 PM To: [email protected] 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 [EMAIL PROTECTED] Engineering GmbH mailto:[EMAIL PROTECTED] Buelowstr. 66 Tel.: ++49/30/235 520 36 10783 Berlin - Germany Fax.: ++49/30/217 520 12 http://www.spree.de/ -------------------------------------------------------------------
