cancel
Showing results for 
Search instead for 
Did you mean: 

Multi thread exception

denissparhomenk
Champ in-the-making
Champ in-the-making
Hi, I make some stress tests for alfresco system, and receive exception when executing 20 simulates thread.

model
<type name="my:vfFolder">
         <title>VisiFlow Folder</title>
         <parent>cm:folder</parent>
         <properties>
            <property name="my:stringProp">
               <type>d:text</type>
               <mandatory>true</mandatory>
               <index enabled="true">
                  <atomic>false</atomic>
                  <stored>true</stored>
                  <tokenised>true</tokenised>
               </index>
            </property>
            <property name="my:intProp">
               <type>d:int</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:longProp">
               <type>d:long</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:floatProp">
               <type>d:float</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:doubleProp">
               <type>d:double</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:dateProp">
               <type>d:date</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:datetimeProp">
               <type>d:datetime</type>
               <mandatory>true</mandatory>
            </property>
            <property name="my:booleanProp">
               <type>d:boolean</type>
               <mandatory>true</mandatory>
            </property>
         </properties>
      </type>
java class
public class StressTest implements Runnable {

   private static final String TEST_NAMESPACE = "my.new.model";

   private ApplicationContext ctx;

   private ServiceRegistry registry;

   private NodeService nodeService;

   private StoreRef storeRef;

   private int pos;

   private int max = 40;

   public StressTest(ApplicationContext ctx, int pos) {
      this.ctx = ctx;
      this.registry = (ServiceRegistry) ctx
            .getBean(ServiceRegistry.SERVICE_REGISTRY);
      this.nodeService = registry.getNodeService();
      this.storeRef = new StoreRef(StoreRef.PROTOCOL_WORKSPACE,
            "streeTestStore");

      if (!nodeService.exists(storeRef)) {
         nodeService.createStore(storeRef.getProtocol(), storeRef
               .getIdentifier());
      }

      this.pos = pos;
   }

   /**
    * @param args
    */
   public static void main(String[] args) {
      ApplicationContext ctx = new ClassPathXmlApplicationContext(
            "alfresco/application-context.xml");

      for (int i = 0; i < 20; i++) {
         StressTest test = new StressTest(ctx, i);
         Thread t = new Thread(test);
         t.start();
      }

   }

   public void run() {
      System.out.println("Start thread");

      for(int i = 0 ; i < max ; i++){
         System.out.println("Create folder "+pos+"["+i+"]");
         UserTransaction trx = null;
         try {
            trx = registry.getTransactionService().getUserTransaction();
            trx.begin();
   
            NodeRef rootNodeRef = nodeService.getRootNode(storeRef);
   
            Map<QName, Serializable> nodeProperties = new HashMap<QName, Serializable>(
                  7);
            nodeProperties.clear();
            nodeProperties.put(ContentModel.PROP_NAME, "VF Folder");
            nodeProperties.put(QName.createQName("my.new.model", "stringProp"),
                  "VFPK" + Integer.toString(pos));
            nodeProperties.put(QName.createQName("my.new.model", "intProp"),
                  new Integer(pos));
            nodeProperties.put(QName.createQName("my.new.model", "longProp"),
                  new Long(pos));
            nodeProperties.put(QName.createQName("my.new.model", "floatProp"),
                  new Float(pos));
            nodeProperties.put(QName.createQName("my.new.model", "doubleProp"),
                  new Double(pos));
            nodeProperties.put(QName.createQName("my.new.model", "dateProp"),
                  new Date());
            nodeProperties.put(QName
                  .createQName("my.new.model", "datetimeProp"), new Date());
            nodeProperties.put(
                  QName.createQName("my.new.model", "booleanProp"),
                  pos % 2 == 0 ? Boolean.TRUE : Boolean.FALSE);
            ChildAssociationRef vfassocRef = nodeService.createNode(
                  rootNodeRef, ContentModel.ASSOC_CHILDREN, QName
                        .createQName(TEST_NAMESPACE, QName
                              .createValidLocalName("VF Folder")), QName
                        .createQName("my.new.model", "vfFolder"),
                  nodeProperties);
   
            NodeRef vffolderRef = vfassocRef.getChildRef();
            trx.commit();
         } catch (Exception exc) {
            if (trx != null) {
               try {
                  trx.rollback();
               } catch (Exception e) {
                  e.printStackTrace();
               }
            }
         }
      }

      System.out.println("Stop thread");

   }

}

output
10:17:15,687 INFO  [service.descriptor.DescriptorService] Alfresco started (Community Network) - v1.0.0; repository v1.0.0
Run thread
Create folder 0[0]
Run thread
Create folder 1[0]
Run thread
Create folder 3[0]
Run thread
Create folder 2[0]
Run thread
Create folder 4[0]
Run thread
Create folder 5[0]
Run thread
Create folder 7[0]
Run thread
Create folder 8[0]
Run thread
Create folder 6[0]
Run thread
Create folder 9[0]
Create folder 8[1]
Run thread
Create folder 10[0]
Create folder 3[1]
Run thread
Create folder 11[0]
Create folder 5[1]
Run thread
Create folder 12[0]
Run thread
Create folder 13[0]
Create folder 2[1]
10:17:19,218 ERROR [hibernate.util.JDBCExceptionReporter] Connection is read-only. Queries leading to data modification are not allowed
10:17:19,218 ERROR [event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:91)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:79)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:200)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
   at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:169)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2047)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2426)
   at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:905)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:345)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:401)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:264)
   at test.StressTest.run(StressTest.java:113)
   at java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:532)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:193)
   … 19 more
Create folder 0[1]
Create folder 4[1]
Create folder 7[1]
org.springframework.jdbc.UncategorizedSQLException: (HibernateTransactionManager): encountered SQLException [Connection is read-only. Queries leading to data modification are not allowed]; nested exception is java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:532)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:193)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)Create folder 1[1]

   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
   at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:169)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2047)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2426)
   at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:905)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:345)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:401)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:264)
   at test.StressTest.run(StressTest.java:113)
   at java.lang.Thread.run(Unknown Source)
java.lang.IllegalStateException: The transaction has already been rolled backCreate folder 9[1]

   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:308)
   at test.StressTest.run(StressTest.java:117)
   at java.lang.Thread.run(Unknown Source)
10:17:20,140 ERROR [hibernate.util.JDBCExceptionReporter] Connection is read-only. Queries leading to data modification are not allowed
10:17:20,155 ERROR [event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:91)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:79)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:200)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
   at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:169)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2047)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2426)
   at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:905)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:345)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:401)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:264)
   at test.StressTest.run(StressTest.java:113)
   at java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:532)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:193)
   … 19 more
Run thread
Create folder 14[0]
org.springframework.jdbc.UncategorizedSQLException: (HibernateTransactionManager): encountered SQLException [Connection is read-only. Queries leading to data modification are not allowed]; nested exception is java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:532)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:193)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
   at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:169)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2047)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2426)
   at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)Run thread
Create folder 15[0]

   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:905)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:345)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:401)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:264)
   at test.StressTest.run(StressTest.java:113)
   at java.lang.Thread.run(Unknown Source)
java.lang.IllegalStateException: The transaction has already been rolled back
   at org.alfresco.util.transaction.SpringAwareUserTransaction.rollback(SpringAwareUserTransaction.java:308)
   at test.StressTest.run(StressTest.java:117)
   at java.lang.Thread.run(Unknown Source)
Create folder 11[1]
Create folder 8[2]
Create folder 3[2]

Can anyone tell is it alfreco problem or hibernate ?

Deniss
5 REPLIES 5

derek
Star Contributor
Star Contributor
Hi,

Could you modify the code slightly - just to get the whole picture.


         } catch (Throwable exc) {
             exc.printStackTrace();

I have not been able to get the exception on my machine; but that is the nature of concurrency issues…  The exception being seen is probably caused by one of the pre-Hibernate flush processes marking the transaction for rollback and hence read-only.  So it is the initial error that we need to get hold of.

Could you describe the environment that you are operating in, please?

Thanks for your interest.  We'll make sure we follow up with this as quickly as possible.

Regards

denissparhomenk
Champ in-the-making
Champ in-the-making
The original exception is :
09:37:13,783 ERROR [event.def.AbstractFlushingEventListener] Could not synchronize database state with session
org.hibernate.exception.GenericJDBCException: Could not execute JDBC batch update
   at org.hibernate.exception.SQLStateConverter.handledNonSpecificException(SQLStateConverter.java:91)
   at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:79)
   at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:200)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:91)
   at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:86)
   at org.hibernate.jdbc.AbstractBatcher.prepareBatchStatement(AbstractBatcher.java:169)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2047)
   at org.hibernate.persister.entity.AbstractEntityPersister.insert(AbstractEntityPersister.java:2426)
   at org.hibernate.action.EntityInsertAction.execute(EntityInsertAction.java:51)
   at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:243)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:227)
   at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:140)
   at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:296)
   at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27)
   at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:905)
   at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:345)
   at org.hibernate.transaction.JDBCTransaction.commit(JDBCTransaction.java:106)
   at org.springframework.orm.hibernate3.HibernateTransactionManager.doCommit(HibernateTransactionManager.java:488)
   at org.springframework.transaction.support.AbstractPlatformTransactionManager.commit(AbstractPlatformTransactionManager.java:401)
   at org.alfresco.util.transaction.SpringAwareUserTransaction.commit(SpringAwareUserTransaction.java:264)
   at test.StressTest.run(StressTest.java:109)
   at java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLException: Connection is read-only. Queries leading to data modification are not allowed
   at com.mysql.jdbc.ServerPreparedStatement.executeBatch(ServerPreparedStatement.java:532)
   at org.apache.commons.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:294)
   at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:58)
   at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:193)
   … 19 more

My environment:

Ms Wndows,
Java 1.5,
MySQL 4.1
Alfresco 1.0

andy
Champ on-the-rise
Champ on-the-rise
Hi

Can you confirm that you are using InnoDB tables in mysql?

If you are using InnoDB tables it is possible you have got simultaneous updates to the same node and are getting a transaction rolled back by the database, which is being hidden. Is there anything in the mysql log?

It lools like some earlier error has marked the transaction for roll back.
Have you got the stack trace for this error?

Regards

Andy

derek
Star Contributor
Star Contributor
Hi,

Could you post or send your MySQL my.ini file as well as the MySQL service properties, please?

Regards

derek
Star Contributor
Star Contributor
Hi,

After some investigation and debugging, it looks likely that the database connection is being provided as read-only; this is reinforced by the fact that the transaction is NOT marked for rollback before the failure occurs.

It seems likely that the datasource is returning a read-only connection, and although I have not been able to find any code that would do it, I did have a play with the dataSource bean in application-context.xml.


    <bean id="dataSource" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
        <property name="driverClassName">
            <value>${db.driver}</value>
        </property>
        <property name="url">
            <value>${db.url}</value>
        </property>
        <property name="username">
            <value>${db.username}</value>
        </property>
        <property name="password">
            <value>${db.password}</value>
        </property>
        <property name="initialSize" >
            <value>10</value>
        </property>
        <property name="maxActive" >
            <value>50</value>
        </property>
    </bean>

If I lowered the maxActive count to 1, then the failure would occur quite reliably.  Raising it to 50 did the trick even when I set the number of threads up to 50.  Ofcourse, you will have to set your maximum allowed connections in the database to take advantage of this.  I have modified the test so that a given thread's first pass through the transaction is more likely to correspond to the other threads' first passes.  When I run this, it succeeds with a connection count of 50 but sometimes fails with a connection count of 49.



                trx = registry.getTransactionService().getUserTransaction();
                trx.begin();
               
                // wait a little, so that all the other threads get into their transactions as well
                // thereby consuming as many of the pooled connections as possible
                synchronized(this)
                {
                    try { wait(10L); } catch (InterruptedException e) {}
                }

                NodeRef rootNodeRef = nodeService.getRootNode(storeRef);


Also, the ConcurrentNodeServiceTest is similar to this test, except that it commits a hierarchy of nodes instead of a single node.  I'll probably add this test in there for good measure.

So, quite apart from the good advice to check that you are running mysqld-max-nt with InnoDB tables, have a go at increasing the number of connections in the pool, and let us know what the result is.

Regards