Hide Forgot
Date of First Response: 2009-03-28 04:21:05 project_key: SOA We found the following issue when trying to execute performance test based on bpm_orchestration4. We are using the attached .esb archive (including sources) and sending 10 messages (transacted JMS session, persistent messages, messages are of type TextMessage). 2009-03-26 16:15:37,469 ERROR [org.hibernate.event.def.AbstractFlushingEventListener] (JbpmJobExector:10.34.32.154:1) Could not synchronize database state with session org.hibernate.exception.LockAcquisitionException: Could not execute JDBC batch update at org.hibernate.exception.SQLStateConverter.convert(SQLStateConverter.java:87) at org.hibernate.exception.JDBCExceptionHelper.convert(JDBCExceptionHelper.java:43) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:254) at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:93) at org.hibernate.jdbc.AbstractBatcher.prepareStatement(AbstractBatcher.java:88) at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2487) at org.hibernate.persister.entity.AbstractEntityPersister.delete(AbstractEntityPersister.java:2697) at org.hibernate.action.EntityDeleteAction.execute(EntityDeleteAction.java:74) at org.hibernate.engine.ActionQueue.execute(ActionQueue.java:250) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:234) at org.hibernate.engine.ActionQueue.executeActions(ActionQueue.java:146) at org.hibernate.event.def.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:298) at org.hibernate.event.def.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:27) at org.hibernate.impl.SessionImpl.flush(SessionImpl.java:1000) at org.hibernate.impl.SessionImpl.managedFlush(SessionImpl.java:338) at org.hibernate.transaction.CacheSynchronization.beforeCompletion(CacheSynchronization.java:59) at com.arjuna.ats.internal.jta.resources.arjunacore.SynchronizationImple.beforeCompletion(SynchronizationImple.java:114) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.beforeCompletion(TwoPhaseCoordinator.java:247) at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:86) at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177) at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1406) at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135) at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87) at org.jboss.tm.usertx.client.ServerVMClientUserTransaction.commit(ServerVMClientUserTransaction.java:146) at org.jbpm.persistence.jta.JtaDbPersistenceService.endUserTransaction(JtaDbPersistenceService.java:94) at org.jbpm.persistence.jta.JtaDbPersistenceService.close(JtaDbPersistenceService.java:63) at org.jbpm.svc.Services.close(Services.java:294) at org.jbpm.JbpmContext.close(JbpmContext.java:136) at org.jbpm.job.executor.JobExecutorThread.executeJob(JobExecutorThread.java:194) at org.jbpm.job.executor.JobExecutorThread.run(JobExecutorThread.java:60) Caused by: java.sql.BatchUpdateException: ORA-00060: deadlock detected while waiting for resource at oracle.jdbc.driver.DatabaseError.throwBatchUpdateException(DatabaseError.java:343) at oracle.jdbc.driver.OraclePreparedStatement.executeBatch(OraclePreparedStatement.java:10698) at org.jboss.resource.adapter.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:620) at org.hibernate.jdbc.BatchingBatcher.doExecuteBatch(BatchingBatcher.java:48) at org.hibernate.jdbc.AbstractBatcher.executeBatch(AbstractBatcher.java:247) ... 27 more The messages cannot be delivered and end in DLQ. We tried to use jms-jca-provider but it didn't help. Attached is a server log showing the problem with DEBUG level.
Attachment: Added: Performance4.esb
Attachment: Added: server.log.bz2
The issue was introduced in CR4 when jBPM was updated to fix the performance problem.
Attached server log with tracker JDBC driver installed on JbpmDS.
Attachment: Added: server.tracker.log.bz2
My current theory, from looking through the last log, is that the deadlock is caused by a modification to the JBPM_BYTEARRAY table, specifically 'delete from JBPM_BYTEARRAY where ID_=?.' From what I can see there are two tables which reference this table as a foreign key, JBPM_BYTEBLOCK and JBPM_VARIABLEINSTANCE, but I cannot find any indexes for their constraints. I believe the outcome of this is that Oracle will be forced into enforcing a table lock onto these tables whenever a row is deleted from JBPM_BYTEARRAY. My knowledge of Oracle is limited so advice should be sought from other sources, however I believe that this theory could easily be tested from a command line client.
I should also add that I believe a solution would be to create the indexes on the foreign key constraints. We should also check all other constraints to see whether they require indexes.
Kevin, thank you for your insights. In the original log that Martin posted, the error occurs around inserting a ByteArray. Deadlocks during both insertion and deletion can be explained by a missing index resulting in locking the whole table/block. I am going to review the index declarations in the relationships you mention and others.
Hiya Alejandro. The original log shows the same issue as the second, with the last statement being executed on the deadlocked thread being the full table lock on delete of JBPM_BYTEARRAY. The insert you are referring to is from a different thread and is not relevant to the deadlock, that thread should continue once the attempt to acquire a full table lock has been broken. Kev
Link: Added: This issue depends JBPM-1367
One of our users seems to have hit this very same problem recently, and proposed some index additions: JBPM-2094
Link: Added: This issue related JBPM-2094
I committed a test case based on the process definition in bpm_orchestration 4. http://fisheye.jboss.com/changelog/JbpmSvn/?cs=4363 Unfortunately I could not reproduce the problem. http://jbpm.dyndns.org:8180/hudson/job/jBPM3-JDK1.5/5/ Any thoughts as to what is missing in my test case? A pointer to the original test case would help too.
The attached patch provides the missing foreign key indexes in many-to-one mappings. It is ready to be applied once the deadlock is reproduced.
Attachment: Added: indexes.diff
The messages must be persistent and there must be a fork/join in the process
We are applying the patch and will hand it over to QE to try the test aginst it
The real trigger for this instance of the bug is concurrent access (from any source) to the BYTEARRAY variable tables within the context of a transaction. This is not necessarily from the same process instance although the fork/join within the bpm orchestration 4 does provoke it quickly.
Quickstart to reproduce the problem. Run with ant deploy, ant deployProcess, ant startProcess
Attachment: Added: bpm_orchestration_deadlock.tar.bz2
I was able to reproduce at last. I was missing the byte array variable updates as Kevin mentioned. The good news is that after applying the patch the problem went away :-)
The fix has been verified with test build from Julian and Trevor. Waiting for another CR to resolve the issue.
Verified with CR6.