|
Home > Archive > Apache JDO Project > June 2005 > JIRA JDO-59
You are viewing an archived Text-only version of the thread.
To view this thread in it's original format and/or if you want to reply to
this thread please [click here]
|
|
| Michael Watzek 2005-06-10, 5:45 pm |
| 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)
--
-------------------------------------------------------------------
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/
-------------------------------------------------------------------
| |
| Michael Watzek 2005-06-10, 5:45 pm |
| 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(StandardException.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.java)
[java] at
org.apache.derby.impl.store.raw.xact.RowLocking3.lockRecordForWrite(RowLocking3.java)
[java] at
org.apache.derby.impl.store.access.conglomerate.OpenConglomerate.lockPositionForWrite(OpenConglomerat
e.java)
[java] at
org.apache.derby.impl.store.access.conglomerate.GenericConglomerateController.fetch(GenericConglomera
teController.java)
[java] at
org.apache.derby.impl.sql.catalog.DataDictionaryImpl. getSetAutoincrementValue(DataDictionaryI
mpl.java
)
[java] at
org.apache.derby.impl.sql.execute.InsertResultSet. getSetAutoincrementValue(InsertResultSet
.java)
[java] at
org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java)
[java] at
org.apache.derby.exe.ac40348015x0104x675cxbca4xffffdab5f0bf0.e0(Unknown
Source)
[java] at
org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java)
[java] at
org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java)
[java] at
org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java)
[java] at
org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java)
[java] at
org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java)
[java] at
org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java)
[java] at
org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java)
[java] at
org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java)
[java] at
org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java)
[java] at
org.jpox.store.rdbms.request.Request.executeUpdate(Request.java:69)
[java] at
org.jpox.store.rdbms.request.InsertRequest.execute(InsertRequest.java:253)
[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:2913)
[java] at
org.jpox.AbstractPersistenceManager. internalMakePersistent(AbstractPersisten
ceManager.java:959)
[java] at
org.jpox.AbstractPersistenceManager. makePersistentAll(AbstractPersistenceMan
ager.java:1034)
[java] at
org.apache.jdo.tck.api.persistencemanager.cache. RefreshAllWithArraySideEffects$RefreshAr
rThreadT1.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.RefreshAllNoParameterSideEffects \
> -org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySideEffects \
> -org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithCollectionSideEffects \
> -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.PassingNullToEvictHasNoEffect \
> org.apache.jdo.tck.api.persistencemanager.cache.PassingNullToRefreshAllThrowsException \
> org.apache.jdo.tck.api.persistencemanager.cache.PassingNullToRefreshHasNoEffect \
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllNoParameterSideEffects \
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySideEffects \
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithCollectionSideEffects \
> +org.apache.jdo.tck.api.persistencemanager.cache.RefreshSideEffects \
> org.apache.jdo.tck.api.persistencemanager.cache.Retrieve \
> org.apache.jdo.tck.api.persistencemanager. SameTransactionInstanceForAllCallsToCurr
entTransaction \
> org.apache.jdo.tck.api.persistencemanager.flags.SetIgnoreCacheToFalse \
> Index: test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEffects.java
> ========================================
===========================
> --- test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEffects.java (revision 189925)
> +++ test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshSideEffects.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/RefreshAllWithCollectionSideEffects.java
> ========================================
===========================
> --- test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWithCollectionSideEffects.java (revision 189925)
> +++ test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWithCollectionSideEffects.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/RefreshAllWithArraySideEffects.java
> ========================================
===========================
> --- test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWithArraySideEffects.java (revision 189925)
> +++ test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllWithArraySideEffects.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/RefreshAllNoParameterSideEffects.java
> ========================================
===========================
> --- test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllNoParameterSideEffects.java (revision 189925)
> +++ test/java/org/apache/jdo/tck/api/persistencemanager/cache/RefreshAllNoParameterSideEffects.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/
-------------------------------------------------------------------
| |
|
| 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/
-------------------------------------------------------------------
| |
| Michael Watzek 2005-06-13, 5:45 pm |
| 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)
>
>
>
> the
>
>
> prints
>
>
> below).
>
>
> do
>
>
> not
>
>
> I
>
>
> java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
>
>
> java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
>
>
> java.io.BufferedInputStream.read(BufferedInputStream.java:313)
>
>
> ------------------------------------------------------------------------
>
>
> -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.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.SameTransactionInstanceForAllC
> allsToCurrentTransaction \
>
>
> \
>
>
> 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)
>
>
> makePersistentAll calls. */
>
>
> START");
>
>
> START");
>
>
> 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)
>
>
> makePersistentAll calls. */
>
>
> RefreshAllWithCollectionSideEffects.this.logger.debug(
>
>
> 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)
>
>
> makePersistentAll calls. */
>
>
> 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)
>
>
> makePersistentAll calls. */
>
>
>
>
--
-------------------------------------------------------------------
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/
-------------------------------------------------------------------
|
|
|
|
|