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();
}
