Loading...

Details

Type: Bug Report
Resolution: Fixed
Priority: L3 - Default
Fix Version/s: 7.13.0, 7.12.5, 7.13.0-alpha4
Affects Version/s: 7.11.0
Component/s: engine
Labels:
- SUPPORT
Environment:
db2 11.1, WebSphere 9

Description

Steps:

setup websphere 9 + db2 11.1
In cockpit open Batch operations
Run set removal time to process/decision instance, please mark some amount of instances (at least > 5) to absolute time

Expected:
The batch operation is performed successfully.

Observed:
An exception is thrown for some of the jobs. However, after rerun the jobs finish successfully. Please find the exception below:

org.camunda.bpm.engine.ProcessEngineException: ENGINE-03004 Exception while executing Database Operation 'UPDATE_BULK updateByteArraysByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}' with message '
### Error updating database.  Cause: com.ibm.db2.jcc.am.SqlTransactionRollbackException: DB2 SQL Error: SQLCODE=-911, SQLSTATE=40001, SQLERRMC=2, DRIVER=4.22.29
### The error may involve org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.updateByteArraysByProcessInstanceId-Inline
### The error occurred while setting parameters
### SQL: update ACT_GE_BYTEARRAY       set REMOVAL_TIME_ = ?       where ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_VARINST         WHERE PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_DEC_IN I         INNER JOIN ACT_HI_DECINST D         ON I.DEC_INST_ID_ = D.ID_         WHERE D.PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_DEC_OUT O         INNER JOIN ACT_HI_DECINST D         ON O.DEC_INST_ID_ = D.ID_         WHERE D.PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT JOB_EXCEPTION_STACK_ID_         FROM ACT_HI_JOB_LOG         WHERE PROCESS_INSTANCE_ID_ = ?       ) or ID_ IN (                  SELECT ERROR_DETAILS_ID_         FROM ACT_HI_EXT_TASK_LOG         WHERE PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT CONTENT_ID_         FROM ACT_HI_ATTACHMENT A         LEFT JOIN ACT_HI_TASKINST T ON A.TASK_ID_ = T.ID_         WHERE A.PROC_INST_ID_ = ?           OR T.PROC_INST_ID_ = ?       )
### Cause: com.ibm.db2.jcc.am.SqlTransactionRollbackException: DB2 SQL Error: SQLCODE=-911, SQLSTATE=40001, SQLERRMC=2, DRIVER=4.22.29'. Flush summary: 
 [
  INSERT HistoricJobLogEventEntity[c6251010-7e03-11e9-891c-0242ac110003]
  DELETE MessageEntity[be7d392d-7e03-11e9-891c-0242ac110003]
  DELETE_BULK deleteByteArrayNoRevisionCheck c4edef99-7e03-11e9-891c-0242ac110003
  DELETE_BULK deleteByteArrayNoRevisionCheck be7d392c-7e03-11e9-891c-0242ac110003
  UPDATE_BULK updateHistoricActivityInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricTaskInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricVariableInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricDetailsByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricIncidentsByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateExternalTaskLogByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateJobLogByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateUserOperationLogByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateIdentityLinkLogByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateCommentsByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateAttachmentsByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateByteArraysByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricProcessInstanceByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricDecisionInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricDecisionInputInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
  UPDATE_BULK updateHistoricDecisionOutputInstancesByProcessInstanceId {processInstanceId=4af766b1-7d64-11e9-b07b-0242ac110003, removalTime=Tue Sep 24 11:09:00 CEST 2019}
]
	at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationException(EnginePersistenceLogger.java:131)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:346)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:325)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:297)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:208)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:137)
	at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:116)
	at org.camunda.bpm.engine.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:46)
	at org.springframework.transaction.jta.WebSphereUowTransactionManager$UOWActionAdapter.run(WebSphereUowTransactionManager.java:345)
	at com.ibm.ws.uow.embeddable.EmbeddableUOWManagerImpl.runUnderNewUOW(EmbeddableUOWManagerImpl.java:798)
	at com.ibm.ws.uow.embeddable.EmbeddableUOWManagerImpl.runUnderUOW(EmbeddableUOWManagerImpl.java:377)
	at org.springframework.transaction.jta.WebSphereUowTransactionManager.execute(WebSphereUowTransactionManager.java:289)
	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:125)
	at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:44)
	at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70)
	at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:51)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:44)
	at org.camunda.bpm.container.impl.ejb.JobExecutionHandlerMDB.executeJob(JobExecutionHandlerMDB.java:41)
	at sun.reflect.GeneratedMethodAccessor239.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:508)
	at com.ibm.ejs.container.EJSContainer.invokeProceed(EJSContainer.java:5323)
	at com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:652)
	at com.ibm.ws.cdi.ejb.impl.InterceptorChain.proceed(InterceptorChain.java:115)
	at com.ibm.ws.cdi.ejb.impl.EJBCDIInterceptorWrapper.invokeInterceptors(EJBCDIInterceptorWrapper.java:140)
	at com.ibm.ws.cdi.ejb.impl.EJBCDIInterceptorWrapper.aroundInvoke(EJBCDIInterceptorWrapper.java:56)
	at sun.reflect.GeneratedMethodAccessor130.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:508)
	at com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:201)
	at com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:632)
	at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73)
	at com.ibm.ws.cdi.ejb.impl.WeldSessionBeanInterceptorWrapper.aroundInvoke(WeldSessionBeanInterceptorWrapper.java:58)
	at sun.reflect.GeneratedMethodAccessor129.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
	at java.lang.reflect.Method.invoke(Method.java:508)
	at com.ibm.ejs.container.interceptors.InterceptorProxy.invokeInterceptor(InterceptorProxy.java:201)
	at com.ibm.ejs.container.interceptors.InvocationContextImpl.proceed(InvocationContextImpl.java:632)
	at com.ibm.ejs.container.interceptors.InvocationContextImpl.doAroundInterceptor(InvocationContextImpl.java:306)
	at com.ibm.ejs.container.interceptors.InvocationContextImpl.doAroundInvoke(InvocationContextImpl.java:273)
	at com.ibm.ejs.container.EJSContainer.invoke(EJSContainer.java:5215)
	at org.camunda.bpm.container.impl.ejb.MDBProxyJobExecutionHandlerMDB_53d2ac45.executeJob(MDBProxyJobExecutionHandlerMDB_53d2ac45.java)
	at org.camunda.bpm.container.impl.threading.ra.inflow.JcaInflowExecuteJobsRunnable.executeJob(JcaInflowExecuteJobsRunnable.java:76)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:61)
	at org.camunda.bpm.container.impl.threading.ra.commonj.CommonjWorkRunnableAdapter.run(CommonjWorkRunnableAdapter.java:36)
	at com.ibm.ws.asynchbeans.J2EEContext.run(J2EEContext.java:1046)
	at com.ibm.ws.asynchbeans.WorkWithExecutionContextImpl.go(WorkWithExecutionContextImpl.java:199)
	at com.ibm.ws.asynchbeans.CJWorkItemImpl.run(CJWorkItemImpl.java:236)
	at com.ibm.ws.util.ThreadPool$Worker.run(ThreadPool.java:1892)
Caused by: org.apache.ibatis.exceptions.PersistenceException: 
### Error updating database.  Cause: com.ibm.db2.jcc.am.SqlTransactionRollbackException: DB2 SQL Error: SQLCODE=-911, SQLSTATE=40001, SQLERRMC=2, DRIVER=4.22.29
### The error may involve org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.updateByteArraysByProcessInstanceId-Inline
### The error occurred while setting parameters
### SQL: update ACT_GE_BYTEARRAY       set REMOVAL_TIME_ = ?       where ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_VARINST         WHERE PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_DEC_IN I         INNER JOIN ACT_HI_DECINST D         ON I.DEC_INST_ID_ = D.ID_         WHERE D.PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT BYTEARRAY_ID_         FROM ACT_HI_DEC_OUT O         INNER JOIN ACT_HI_DECINST D         ON O.DEC_INST_ID_ = D.ID_         WHERE D.PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT JOB_EXCEPTION_STACK_ID_         FROM ACT_HI_JOB_LOG         WHERE PROCESS_INSTANCE_ID_ = ?       ) or ID_ IN (                  SELECT ERROR_DETAILS_ID_         FROM ACT_HI_EXT_TASK_LOG         WHERE PROC_INST_ID_ = ?       ) or ID_ IN (                  SELECT CONTENT_ID_         FROM ACT_HI_ATTACHMENT A         LEFT JOIN ACT_HI_TASKINST T ON A.TASK_ID_ = T.ID_         WHERE A.PROC_INST_ID_ = ?           OR T.PROC_INST_ID_ = ?       )
### Cause: com.ibm.db2.jcc.am.SqlTransactionRollbackException: DB2 SQL Error: SQLCODE=-911, SQLSTATE=40001, SQLERRMC=2, DRIVER=4.22.29
	at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:200)
	at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.executeUpdate(DbSqlSession.java:259)
	at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.updateBulk(DbSqlSession.java:285)
	at org.camunda.bpm.engine.impl.db.AbstractPersistenceSession.executeDbOperation(AbstractPersistenceSession.java:58)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:341)
	... 48 more
Caused by: com.ibm.db2.jcc.am.SqlTransactionRollbackException: DB2 SQL Error: SQLCODE=-911, SQLSTATE=40001, SQLERRMC=2, DRIVER=4.22.29
	at com.ibm.db2.jcc.am.ld.a(ld.java:797)
	at com.ibm.db2.jcc.am.ld.a(ld.java:66)
	at com.ibm.db2.jcc.am.ld.a(ld.java:140)
	at com.ibm.db2.jcc.am.up.c(up.java:2796)
	at com.ibm.db2.jcc.t4.bb.v(bb.java:1076)
	at com.ibm.db2.jcc.t4.bb.m(bb.java:450)
	at com.ibm.db2.jcc.t4.bb.a(bb.java:62)
	at com.ibm.db2.jcc.t4.p.a(p.java:50)
	at com.ibm.db2.jcc.t4.wb.b(wb.java:220)
	at com.ibm.db2.jcc.am.vp.vc(vp.java:3568)
	at com.ibm.db2.jcc.am.vp.a(vp.java:4613)
	at com.ibm.db2.jcc.am.vp.b(vp.java:4151)
	at com.ibm.db2.jcc.am.vp.pc(vp.java:2871)
	at com.ibm.db2.jcc.am.vp.execute(vp.java:2846)
	at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.execute(WSJdbcPreparedStatement.java:632)
	at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:46)
	at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:74)
	at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:50)
	at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:117)
	at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:76)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:198)
	... 52 more

Root Cause:

When the referenced byte arrays (like job's configuration and job's exception stack trace) are deleted, the respective rows are exclusively locked.
When executing the UPDATE statement to update the byte array's removal time, then DB2 performs a full table scan of ACT_GE_BYTEARRAY.
When doing the full table scan, DB2 decides to lock all existing rows in ACT_GE_BYTEARRAY exclusively.
If two commands try to set the removal time (for different process instance), the deadlock happens in the following sequence of events:
1. Participant 1 deletes the byte arrays first. Therefore, participant 1 will acquire exclusively locks on those rows in ACT_GE_BYTEARRAY.
2. Participant 2 deletes the byte arrays first. Therefore, participant 2 will acquire exclusively locks on those rows in ACT_GE_BYTEARRAY.
3. Participant 2 is a bit faster and starts to execute the query updateByteArraysByProcessInstanceId. Participant 2 exclusively acquires locks on each row in ACT_GE_BYTEARRAY in sequential order.
4. Participant 2 tries to acquire an exclusive lock on the rows which participant 1 wants to delete. Because participant 1 already holds the exclusive locks, participant 2 waits for participant 1 to release these locks.
5. Participant 1 starts to execute the query updateByteArraysByProcessInstanceId.
6. Participant 1 tries to acquire an exclusive lock on the first row in ACT_GE_BYTEARRAY. Because participant 2 already holds the exclusive lock on that row, participant 1 waits for participant 2 to release that lock.

Solution:

Divide the UPDATE statement updateByteArraysByProcessInstanceId into six dedicated UPDATE statements to update the corresponding byte arrays accordingly.
The solution has been already validated with an existing customer.
For further details please check CAM_10360.diff.

mgm-controller-panel

This is the controller panel for Smart Panels app

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

CAM_10360.diff
5 kB
27/Mar/20 3:12 PM

Issue Links

is related to

CAM-12904 Deadlock exception with DB2 when executing set removal time batch for decisions

Closed

Deadlock exception when set removal time batch is executed

Details

Description

mgm-controller-panel

This is the controller panel for Smart Panels app

Attachments

Attachments

Issue Links

Activity

People

Dates

Salesforce