How I deal with mysql Innodb deadlock in my multi-threading application?
I use perrequest runtimemanager to get kiesession.
JBPMHelper.setupDataSource();
EntityManagerFactory emf = Persistence.createEntityManagerFactory("org.jbpm.persistence.jpa");
RuntimeEnvironmentBuilder builder = RuntimeEnvironmentBuilder.Factory.get()
.newClasspathKmoduleDefaultBuilder()
.entityManagerFactory(emf)
.userGroupCallback(new JBossUserGroupCallbackImpl("classpath:/usergroups.properties"));
return RuntimeManagerFactory.Factory.get().newPerRequestRuntimeManager(builder.get(), "com.sample:example:1.0");
I get a new RuntimeEngine by runtimemanager and start process in each thread.
@Override
public void run() {
System.out.println("Thread0 start");
RuntimeEngine engine = manager.getRuntimeEngine(null);
KieSession ksession = engine.getKieSession();
ksession.startProcess("defaultPackage.workFlow", params);
}
I use mysql innodb by setting the follwing property.
in persistence.xml
<property name="hibernate.dialect" value="org.hibernate.dialect.MySQL5InnoDBDialect"/>
in jBPM.properties
persistence.persistenceunit.dialect=org.hibernate.dialect.MySQL5InnoDBDialect
The db schema is created successfully. However, mysql deadlock occurs.
�T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.spi.SqlExceptionHelper logExceptions WARN: SQL Error: 1213, SQLState: 40001 �T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.spi.SqlExceptionHelper logExceptions WARN: SQL Error: 1213, SQLState: 40001 �T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.spi.SqlExceptionHelper logExceptions ERROR: Deadlock found when trying to get lock; try restarting transaction �T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.spi.SqlExceptionHelper logExceptions ERROR: Deadlock found when trying to get lock; try restarting transaction �T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl release INFO: HHH000010: On release of batch it still contained JDBC statements �T�� 11, 2016 11:20:22 �W�� org.hibernate.engine.jdbc.batch.internal.AbstractBatchImpl release INFO: HHH000010: On release of batch it still contained JDBC statements Exception in thread "pool-3-thread-1" Exception in thread "pool-3-thread-4" java.lang.RuntimeException: Unable to commit transaction Thread0 start at org.drools.persistence.jta.JtaTransactionManager.commit(JtaTransactionManager.java:239)Thread0 start at org.drools.persistence.SingleSessionCommandService$TransactionInterceptor.execute(SingleSessionCommandService.java:595) at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.execute(OptimisticLockRetryInterceptor.java:82) at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) at org.drools.persistence.jta.TransactionLockInterceptor.execute(TransactionLockInterceptor.java:73) at org.drools.persistence.SingleSessionCommandService.execute(SingleSessionCommandService.java:385) at org.drools.core.command.impl.CommandBasedStatefulKnowledgeSession.startProcess(CommandBasedStatefulKnowledgeSession.java:242) at org.jbpm.test.MyThread.run(ProcessKModuleMain.java:189) at java.lang.Thread.run(Thread.java:745) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: bitronix.tm.internal.BitronixRollbackException: RuntimeException thrown during beforeCompletion cycle caused transaction rollback at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:241) at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143) at org.drools.persistence.jta.JtaTransactionManager.commit(JtaTransactionManager.java:236) ... 12 more Caused by: javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not execute statement at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387) at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310) at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1316) at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:999) at org.drools.persistence.TriggerUpdateTransactionSynchronization.beforeCompletion(TriggerUpdateTransactionSynchronization.java:76) at org.drools.persistence.jta.JtaTransactionSynchronizationAdapter.beforeCompletion(JtaTransactionSynchronizationAdapter.java:54) at bitronix.tm.BitronixTransaction.fireBeforeCompletionEvent(BitronixTransaction.java:532) at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:235) ... 14 more Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement at org.hibernate.dialect.MySQLDialect$1.convert(MySQLDialect.java:412) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:124) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:189) at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:59) at org.hibernate.persister.collection.AbstractCollectionPersister.insertRows(AbstractCollectionPersister.java:1474) at org.hibernate.action.internal.CollectionUpdateAction.execute(CollectionUpdateAction.java:86) at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:308) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56) at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1195) at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:996) ... 18 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transaction at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:422) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1065) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4096) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4028) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2490) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2651) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2734) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359) at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64) at com.sun.proxy.$Proxy39.executeUpdate(Unknown Source) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:186) ... 28 more java.lang.RuntimeException: Unable to commit transaction at org.drools.persistence.jta.JtaTransactionManager.commit(JtaTransactionManager.java:239) at org.drools.persistence.SingleSessionCommandService$TransactionInterceptor.execute(SingleSessionCommandService.java:595) at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.execute(OptimisticLockRetryInterceptor.java:82) at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) at org.drools.persistence.jta.TransactionLockInterceptor.execute(TransactionLockInterceptor.java:73) at org.drools.persistence.SingleSessionCommandService.execute(SingleSessionCommandService.java:385) at org.drools.core.command.impl.CommandBasedStatefulKnowledgeSession.startProcess(CommandBasedStatefulKnowledgeSession.java:242) at org.jbpm.test.MyThread.run(ProcessKModuleMain.java:189) at java.lang.Thread.run(Thread.java:745) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Caused by: bitronix.tm.internal.BitronixRollbackException: RuntimeException thrown during beforeCompletion cycle caused transaction rollback at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:241) at bitronix.tm.BitronixTransactionManager.commit(BitronixTransactionManager.java:143) at org.drools.persistence.jta.JtaTransactionManager.commit(JtaTransactionManager.java:236) ... 12 more Caused by: javax.persistence.PersistenceException: org.hibernate.exception.LockAcquisitionException: could not execute statement at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1387) at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1310) at org.hibernate.ejb.AbstractEntityManagerImpl.convert(AbstractEntityManagerImpl.java:1316) at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:999) at org.drools.persistence.TriggerUpdateTransactionSynchronization.beforeCompletion(TriggerUpdateTransactionSynchronization.java:76) at org.drools.persistence.jta.JtaTransactionSynchronizationAdapter.beforeCompletion(JtaTransactionSynchronizationAdapter.java:54) at bitronix.tm.BitronixTransaction.fireBeforeCompletionEvent(BitronixTransaction.java:532) at bitronix.tm.BitronixTransaction.commit(BitronixTransaction.java:235) ... 14 more Caused by: org.hibernate.exception.LockAcquisitionException: could not execute statement at org.hibernate.dialect.MySQLDialect$1.convert(MySQLDialect.java:412) at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:49) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:124) at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:109) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:189) at org.hibernate.engine.jdbc.batch.internal.NonBatchingBatch.addToBatch(NonBatchingBatch.java:59) at org.hibernate.persister.collection.AbstractCollectionPersister.insertRows(AbstractCollectionPersister.java:1474) at org.hibernate.action.internal.CollectionUpdateAction.execute(CollectionUpdateAction.java:86) at org.hibernate.engine.spi.ActionQueue.execute(ActionQueue.java:395) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:387) at org.hibernate.engine.spi.ActionQueue.executeActions(ActionQueue.java:308) at org.hibernate.event.internal.AbstractFlushingEventListener.performExecutions(AbstractFlushingEventListener.java:349) at org.hibernate.event.internal.DefaultFlushEventListener.onFlush(DefaultFlushEventListener.java:56) at org.hibernate.internal.SessionImpl.flush(SessionImpl.java:1195) at org.hibernate.ejb.AbstractEntityManagerImpl.flush(AbstractEntityManagerImpl.java:996) ... 18 more Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Deadlock found when trying to get lock; try restarting transactionkcontext.getVariable loop1:2 kcontext.getVariable loop1:2 at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) kcontext.getVariable loop1:2 at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:422)kcontext.getVariable loop2:2 at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) kcontext.getVariable loop2:2 at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1065)kcontext.getVariable loop2:2 at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4096) kcontext.getVariable duration:0s at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4028) kcontext.getVariable duration:0s at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2490) kcontext.getVariable duration:0s at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2651) t.getName():Janet.getAge():11 at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2734) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155)t.getName():Janet.getAge():11 at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458)kcontext.getProcessInstance().getId():2190 at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375) t.getName():Janet.getAge():11 at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359) at sun.reflect.GeneratedMethodAccessor15.invoke(Unknown Source)kcontext.getProcessInstance().getId():2189 kcontext.getProcessInstance().getId():2191 at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:497) at bitronix.tm.resource.jdbc.BaseProxyHandlerClass.invoke(BaseProxyHandlerClass.java:64) at com.sun.proxy.$Proxy39.executeUpdate(Unknown Source) at org.hibernate.engine.jdbc.internal.ResultSetReturnImpl.executeUpdate(ResultSetReturnImpl.java:186) ... 28 more
The output, I run
show engine innodb status;
in mysql, is shown as follows.
culated from the last 33 seconds ----------------- BACKGROUND THREAD ----------------- srv_master_thread loops: 729 srv_active, 0 srv_shutdown, 41714 srv_idle srv_master_thread log flush and writes: 42443 ---------- SEMAPHORES ---------- OS WAIT ARRAY INFO: reservation count 5773 OS WAIT ARRAY INFO: signal count 5582 Mutex spin waits 11515, rounds 133876, OS waits 3982 RW-shared spins 1971, rounds 43361, OS waits 1190 RW-excl spins 7039, rounds 83965, OS waits 432 Spin rounds per wait: 11.63 mutex, 22.00 RW-shared, 11.93 RW-excl ------------------------ LATEST DETECTED DEADLOCK ------------------------ 2016-03-11 11:20:26 19e8 *** (1) TRANSACTION: TRANSACTION 534150, ACTIVE 0 sec inserting mysql tables in use 1, locked 1 LOCK WAIT 12 lock struct(s), heap size 2936, 10 row lock(s), undo log entries 65 MySQL thread id 112, OS thread handle 0x1c3c, query id 756476 localhost 127.0.0.1 hca update insert into EventTypes (InstanceId, element) values (2488, 'timer') *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 4113 page no 4 n bits 80 index `FK_nrecj4617iwxlc65ij6m7lsl1` of table `mydb`.`eventtypes` trx id 534150 lock_mode X insert intention waiting Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;; *** (2) TRANSACTION: TRANSACTION 534152, ACTIVE 0 sec inserting, thread declared inside InnoDB 5000 mysql tables in use 1, locked 1 12 lock struct(s), heap size 2936, 10 row lock(s), undo log entries 65 MySQL thread id 115, OS thread handle 0x19e8, query id 756554 localhost 127.0.0.1 hca update insert into EventTypes (InstanceId, element) values (2493, 'timer') *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 4113 page no 4 n bits 80 index `FK_nrecj4617iwxlc65ij6m7lsl1` of table `mydb`.`eventtypes` trx id 534152 lock mode S Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 4113 page no 4 n bits 80 index `FK_nrecj4617iwxlc65ij6m7lsl1` of table `mydb`.`eventtypes` trx id 534152 lock_mode X insert intention waiting Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0 0: len 8; hex 73757072656d756d; asc supremum;; *** WE ROLL BACK TRANSACTION (2) ------------ TRANSACTIONS ------------ Trx id counter 534501 Purge done for trx's n:o < 534501 undo n:o < 0 state: running but idle History list length 1548 LIST OF TRANSACTIONS FOR EACH SESSION: ---TRANSACTION 0, not started MySQL thread id 111, OS thread handle 0x2890, query id 766652 localhost ::1 hca init show engine innodb status
I use jbpm7.0.0-SNAPSHOT , jdk 1.8, and mysql 5.6.23-log. THX!
PS. If I get kiesession from singleton runtimemanager, my application runs successfully!
I change from singleton to perrequest runtimemanager, because I want to run more processes concurrently in one second.
Is it able to do that?