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 Fri, 10 Jun 2005 18:14:45 GMT
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(DataDictionaryImpl.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(AbstractPersistenceManager.java:959)
     [java]      at 
org.jpox.AbstractPersistenceManager.makePersistentAll(AbstractPersistenceManager.java:1034)
     [java]      at 
org.apache.jdo.tck.api.persistencemanager.cache.RefreshAllWithArraySideEffects$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.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.SameTransactionInstanceForAllCallsToCurrentTransaction
\
>  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/
-------------------------------------------------------------------

Mime
View raw message