Deadlock problem with 'delete from ACT_GE_BYTEARRAY...'

[saram1]

Hello

I use engine to manage my workflow. It's well developed and had no problem so far. I prepared some final performance tests because in production it can reach 10k open processes. So I prepared simple workflow with random wait timer node. Start parameters was:
processes: 10k
random range: 3600s
random bias: 600s
So waitTime is calculated like:

new Random().nextInt(3600) + 600;‍

In my test environment after 600s i have spawned ca 1200 processes. So at this point spawning and resuming goes in parallel. The first occurrence of problem is at ca 3300 processes spawned and ca 100 processes resumed. So we can assume that there is ca 3k processes suspended.
Below is error log:
<blockcode>
2014-03-25 09:35:57.409 ERROR [org.activiti.engine.impl.interceptor.CommandContext] Error while closing command context
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: java.sql.SQLException: Transaction (Process ID 250) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
### The error may involve org.activiti.engine.impl.persistence.entity.ByteArrayEntity.deleteByteArray-Inline
### The error occurred while setting parameters
### SQL: delete from ACT_GE_BYTEARRAY where ID_ = ? and REV_ = ?
### Cause: java.sql.SQLException: Transaction (Process ID 250) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
   at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:150)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.delete(DefaultSqlSession.java:161)
   at org.activiti.engine.impl.db.DbSqlSession$CheckedDeleteOperation.execute(DbSqlSession.java:225)
   at org.activiti.engine.impl.db.DbSqlSession.flushDeletes(DbSqlSession.java:577)
   at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:445)
   at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:170)
   at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:117)
   at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66)
   at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
   at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
   at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:46)
   at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
   at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
   at java.lang.Thread.run(Unknown Source)
Caused by: java.sql.SQLException: Transaction (Process ID 250) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
   at net.sourceforge.jtds.jdbc.SQLDiagnostic.addDiagnostic(SQLDiagnostic.java:372)
   at net.sourceforge.jtds.jdbc.TdsCore.tdsErrorToken(TdsCore.java:2886)
   at net.sourceforge.jtds.jdbc.TdsCore.nextToken(TdsCore.java:2328)
   at net.sourceforge.jtds.jdbc.TdsCore.getMoreResults(TdsCore.java:638)
   at net.sourceforge.jtds.jdbc.JtdsStatement.processResults(JtdsStatement.java:614)
   at net.sourceforge.jtds.jdbc.JtdsStatement.executeSQL(JtdsStatement.java:573)
   at net.sourceforge.jtds.jdbc.JtdsPreparedStatement.execute(JtdsPreparedStatement.java:761)
   at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
   at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
   at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
   at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
   at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
   at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:148)
   … 14 more
</blockcode>

When I break process spawning loop I noticed that deadlock still occurs. The frequency was ca 1 error for 100 resumed processes. IMO error occurs after resuming process and failed transaction is NOT rerun by engine. It resulting resumed process finishes with success but engine tries rerun it after some time (I guess that suspend process state still persists in DB). That means process resume operation is not atomic. I do not want to point you on AE possible error or something. It's also possible there there is problem with database configuration or something. I read it happens before to some guys, but I could not find proper solution so far…
My point is to handle this error and apply workaround. I have two possibilities:

• rerun killed transaction
• prevent WE to resume suspended process (JobExecutor'll try resume it next time)

Here come my question. What is best and simplest way to made it?

---

If you need more details of my implementation here it comes:
<li> BPMN20

<definitions id="definitions" targetNamespace="http://activiti.org/bpmn20"
   xmlns:activiti="http://activiti.org/bpmn" xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL">
   <process id="AQ_Wait" name="AQ_Wait">
      <sequenceFlow sourceRef='theStart' targetRef='configureWorker' />
      <sequenceFlow sourceRef='configureWorker' targetRef='stage1_prepare' />      
      <sequenceFlow sourceRef='stage1_prepare' targetRef='timerEvent1' />      
        <intermediateCatchEvent id="timerEvent1" name="timerEvent1">
            <timerEventDefinition>
                <timeDuration>${nodeResult}</timeDuration>
            </timerEventDefinition>
        </intermediateCatchEvent>
      <sequenceFlow sourceRef='timerEvent1' targetRef='stage2_final' />      
      <sequenceFlow sourceRef='stage2_final' targetRef='assembleResponse' />
      <sequenceFlow sourceRef='assembleResponse' targetRef='activityCollector' />
      <sequenceFlow sourceRef='activityCollector' targetRef='theEnd' />
      
      <startEvent id="theStart" />
      <serviceTask id="configureWorker" 
         activiti:class="com.*.*.workflow.AqWait" >
      </serviceTask>
      <serviceTask id="stage1_prepare" 
          activiti:expression="#{worker.stage1prepare()}"
          activiti:resultVariable="nodeResult" >
      </serviceTask>      
      <serviceTask id="stage2_final" 
          activiti:expression="#{worker.stage2final()}"
          activiti:resultVariable="nodeResult" >
      </serviceTask>      
       <serviceTask id="assembleResponse" 
          activiti:expression="#{worker.assembleResponse(nodeResult)}" 
          activiti:resultVariable="jpdl_result"/>
      <serviceTask id="activityCollector" activiti:delegateExpression="${activityCollector}" />
      <endEvent id="theEnd" />
   </process>
</definitions> 
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

<li> applicationContext

   <bean id="processEngine" class="org.activiti.spring.ProcessEngineFactoryBean">
      <property name="processEngineConfiguration" ref="processEngineConfiguration" />
   </bean>

   <bean id="processEngineConfiguration"
      class="org.activiti.engine.impl.cfg.StandaloneProcessEngineConfiguration">
      <property name="jdbcDriver" value="net.sourceforge.jtds.jdbc.Driver" />
      <property name="jdbcUrl" value="jdbc:jtds:sqlserver://192.168.104.57:1433;databaseName=test" />
      <property name="jdbcUsername" value="sa" />
      <property name="jdbcPassword" value="*" />
      <property name="databaseSchemaUpdate" value="true" />
      <property name="jobExecutorActivate" value="false" />
      <property name="mailServerHost" value="mail.my-corp.com" />
      <property name="mailServerPort" value="5025" />
      <property name="classLoader" ref="deploymentClassLoader" />
      <property name="customDefaultBpmnParseHandlers">
         <list>
            <ref bean="processStopListener"/>   
         </list>
      </property>
      <property name="history" value="full" />      
   </bean>
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

<li> maven deps

  <dependencies>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-aop</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework.ws</groupId>
      <artifactId>spring-ws-core</artifactId>
      <version>2.1.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-aspects</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-context</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-jdbc</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-jms</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-orm</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-tx</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-web</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-webmvc</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework.security</groupId>
      <artifactId>spring-security-core</artifactId>
      <version>3.1.3.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework.security</groupId>
      <artifactId>spring-security-web</artifactId>
      <version>3.1.3.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework.security</groupId>
      <artifactId>spring-security-config</artifactId>
      <version>3.1.3.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework</groupId>
      <artifactId>spring-test</artifactId>
      <version>3.2.2.RELEASE</version>
      <scope>test</scope>
    </dependency>
    <dependency>
      <groupId>org.springframework.webflow</groupId>
      <artifactId>spring-webflow</artifactId>
      <version>2.3.1.RELEASE</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>junit</groupId>
      <artifactId>junit</artifactId>
      <version>4.11</version>
      <scope>test</scope>
    </dependency>
    <dependency>
      <groupId>com.caucho</groupId>
      <artifactId>hessian</artifactId>
      <version>3.1.5</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.hibernate</groupId>
      <artifactId>hibernate-entitymanager</artifactId>
      <version>4.2.4.Final</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>c3p0</groupId>
      <artifactId>c3p0</artifactId>
      <version>0.9.2.1</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.slf4j</groupId>
      <artifactId>slf4j-log4j12</artifactId>
      <version>1.6.6</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>log4j</groupId>
      <artifactId>log4j</artifactId>
      <version>1.2.17</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>hsqldb</groupId>
      <artifactId>hsqldb</artifactId>
      <version>1.8.0.7</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>com.oracle</groupId>
      <artifactId>ojdbc6</artifactId>
      <version>11.2.0.3</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>net.sourceforge.jtds</groupId>
      <artifactId>jtds</artifactId>
      <version>1.2.7-vx-p-1</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.mybatis</groupId>
      <artifactId>mybatis</artifactId>
      <version>3.2.2</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>joda-time</groupId>
      <artifactId>joda-time</artifactId>
      <version>2.2</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>com.h2database</groupId>
      <artifactId>h2</artifactId>
      <version>1.3.172</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.hibernate</groupId>
      <artifactId>hibernate-core</artifactId>
      <version>4.2.4.Final</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.apache.commons</groupId>
      <artifactId>commons-io</artifactId>
      <version>1.3.2</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.activiti</groupId>
      <artifactId>activiti-bpmn-model</artifactId>
      <version>5.14</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.activiti</groupId>
      <artifactId>activiti-bpmn-converter</artifactId>
      <version>5.14</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.activiti</groupId>
      <artifactId>activiti-engine</artifactId>
      <version>5.14</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.activiti</groupId>
      <artifactId>activiti-spring</artifactId>
      <version>5.14</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>org.activiti</groupId>
      <artifactId>activiti-simple-workflow</artifactId>
      <version>5.14</version>
      <scope>compile</scope>
    </dependency>
    <dependency>
      <groupId>javax.servlet</groupId>
      <artifactId>servlet-api</artifactId>
      <version>2.5</version>
      <scope>provided</scope>
    </dependency>
  </dependencies>
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[saram1]

I update do 5.15 and also try use native mssql driver - still error

<code>
2014-03-27 12:31:16.251 ERROR [org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable] exception during job execution:
### Error updating database.  Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 298) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
### The error may involve org.activiti.engine.impl.persistence.entity.ByteArrayEntity.deleteByteArray-Inline
### The error occurred while setting parameters
### SQL: delete from ACT_GE_BYTEARRAY where ID_ = ? and REV_ = ?
### Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 298) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 298) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
### The error may involve org.activiti.engine.impl.persistence.entity.ByteArrayEntity.deleteByteArray-Inline
### The error occurred while setting parameters
### SQL: delete from ACT_GE_BYTEARRAY where ID_ = ? and REV_ = ?
### Cause: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 298) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:150)
at org.apache.ibatis.session.defaults.DefaultSqlSession.delete(DefaultSqlSession.java:161)
at org.activiti.engine.impl.db.DbSqlSession$CheckedDeleteOperation.execute(DbSqlSession.java:244)
at org.activiti.engine.impl.db.DbSqlSession.flushDeletes(DbSqlSession.java:609)
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:477)
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:171)
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:118)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:52)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: com.microsoft.sqlserver.jdbc.SQLServerException: Transaction (Process ID 298) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.
at com.microsoft.sqlserver.jdbc.SQLServerException.makeFromDatabaseError(SQLServerException.java:197)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.getNextResult(SQLServerStatement.java:1493)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.doExecutePreparedStatement(SQLServerPreparedStatement.java:390)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement$PrepStmtExecCmd.doExecute(SQLServerPreparedStatement.java:340)
at com.microsoft.sqlserver.jdbc.TDSCommand.execute(IOBuffer.java:4575)
at com.microsoft.sqlserver.jdbc.SQLServerConnection.executeCommand(SQLServerConnection.java:1400)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeCommand(SQLServerStatement.java:179)
at com.microsoft.sqlserver.jdbc.SQLServerStatement.executeStatement(SQLServerStatement.java:154)
at com.microsoft.sqlserver.jdbc.SQLServerPreparedStatement.execute(SQLServerPreparedStatement.java:322)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:148)
… 14 more
</code>

In meantime I did also test on H2 in-memory database, It's not real production database, but log is more verbose:
<code>
2014-03-27 10:42:04.473 ERROR [org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable] exception during job execution:
### Error updating database.  Cause: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #7 (user: SA) is waiting to lock PUBLIC.ACT_HI_PROCINST while locking PUBLIC.ACT_RU_EXECUTION (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.ACT_RU_EXECUTION while locking PUBLIC.ACT_HI_ACTINST (exclusive), PUBLIC.ACT_GE_BYTEARRAY (exclusive), PUBLIC.ACT_HI_DETAIL (exclusive), PUBLIC.ACT_HI_VARINST (exclusive), PUBLIC.ACT_HI_PROCINST (exclusive), PUBLIC.ACT_RU_JOB (exclusive)."; SQL statement:
delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ? [40001-172]
### The error may involve org.activiti.engine.impl.persistence.entity.ExecutionEntity.deleteExecution-Inline
### The error occurred while setting parameters
### SQL: delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ?
### Cause: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #7 (user: SA) is waiting to lock PUBLIC.ACT_HI_PROCINST while locking PUBLIC.ACT_RU_EXECUTION (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.ACT_RU_EXECUTION while locking PUBLIC.ACT_HI_ACTINST (exclusive), PUBLIC.ACT_GE_BYTEARRAY (exclusive), PUBLIC.ACT_HI_DETAIL (exclusive), PUBLIC.ACT_HI_VARINST (exclusive), PUBLIC.ACT_HI_PROCINST (exclusive), PUBLIC.ACT_RU_JOB (exclusive)."; SQL statement:
delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ? [40001-172]
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #7 (user: SA) is waiting to lock PUBLIC.ACT_HI_PROCINST while locking PUBLIC.ACT_RU_EXECUTION (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.ACT_RU_EXECUTION while locking PUBLIC.ACT_HI_ACTINST (exclusive), PUBLIC.ACT_GE_BYTEARRAY (exclusive), PUBLIC.ACT_HI_DETAIL (exclusive), PUBLIC.ACT_HI_VARINST (exclusive), PUBLIC.ACT_HI_PROCINST (exclusive), PUBLIC.ACT_RU_JOB (exclusive)."; SQL statement:
delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ? [40001-172]
### The error may involve org.activiti.engine.impl.persistence.entity.ExecutionEntity.deleteExecution-Inline
### The error occurred while setting parameters
### SQL: delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ?
### Cause: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #7 (user: SA) is waiting to lock PUBLIC.ACT_HI_PROCINST while locking PUBLIC.ACT_RU_EXECUTION (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.ACT_RU_EXECUTION while locking PUBLIC.ACT_HI_ACTINST (exclusive), PUBLIC.ACT_GE_BYTEARRAY (exclusive), PUBLIC.ACT_HI_DETAIL (exclusive), PUBLIC.ACT_HI_VARINST (exclusive), PUBLIC.ACT_HI_PROCINST (exclusive), PUBLIC.ACT_RU_JOB (exclusive)."; SQL statement:
delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ? [40001-172]
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:150)
at org.apache.ibatis.session.defaults.DefaultSqlSession.delete(DefaultSqlSession.java:161)
at org.activiti.engine.impl.db.DbSqlSession$CheckedDeleteOperation.execute(DbSqlSession.java:244)
at org.activiti.engine.impl.db.DbSqlSession.flushDeletes(DbSqlSession.java:609)
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:477)
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:171)
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:118)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:52)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: "
Session #7 (user: SA) is waiting to lock PUBLIC.ACT_HI_PROCINST while locking PUBLIC.ACT_RU_EXECUTION (exclusive).
Session #6 (user: SA) is waiting to lock PUBLIC.ACT_RU_EXECUTION while locking PUBLIC.ACT_HI_ACTINST (exclusive), PUBLIC.ACT_GE_BYTEARRAY (exclusive), PUBLIC.ACT_HI_DETAIL (exclusive), PUBLIC.ACT_HI_VARINST (exclusive), PUBLIC.ACT_HI_PROCINST (exclusive), PUBLIC.ACT_RU_JOB (exclusive)."; SQL statement:
delete from ACT_RU_EXECUTION where ID_ = ? and REV_ = ? [40001-172]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
at org.h2.message.DbException.get(DbException.java:169)
at org.h2.message.DbException.get(DbException.java:146)
at org.h2.table.RegularTable.doLock(RegularTable.java:504)
at org.h2.table.RegularTable.lock(RegularTable.java:450)
at org.h2.command.dml.Delete.update(Delete.java:59)
at org.h2.command.CommandContainer.update(CommandContainer.java:79)
at org.h2.command.Command.executeUpdate(Command.java:235)
at org.h2.jdbc.JdbcPreparedStatement.execute(JdbcPreparedStatement.java:193)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:148)
… 14 more
</code>

I'm really determined to find some good situation handler. Database errors occurs in real word and i need to handle it and guarantee coherent process state.
Now in H2 tests I got different errors but in result the managed process also was resumed more than once!!!.

---

I also noticed other errors when running on H2, but i ignored it… not sure if it means anything but lack of some database capabilities:
<code>
2014-03-27 10:44:15.046 ERROR [org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable] exception during job execution:
### Error updating database.  Cause: org.h2.jdbc.JdbcSQLException: Wartosc za dluga dla kolumny "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"
Value too long for column "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"; SQL statement:
insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)
    values (
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?
    ) [22001-172]
### The error may involve org.activiti.engine.impl.persistence.entity.HistoricVariableInstanceEntity.insertHistoricVariableInstance-Inline
### The error occurred while setting parameters
### SQL: insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)     values (       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?     )
### Cause: org.h2.jdbc.JdbcSQLException: Wartosc za dluga dla kolumny "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"
Value too long for column "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"; SQL statement:
insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)
    values (
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?
    ) [22001-172]
org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: org.h2.jdbc.JdbcSQLException: Wartosc za dluga dla kolumny "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"
Value too long for column "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"; SQL statement:
insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)
    values (
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?
    ) [22001-172]
### The error may involve org.activiti.engine.impl.persistence.entity.HistoricVariableInstanceEntity.insertHistoricVariableInstance-Inline
### The error occurred while setting parameters
### SQL: insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)     values (       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?,       ?     )
### Cause: org.h2.jdbc.JdbcSQLException: Wartosc za dluga dla kolumny "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"
Value too long for column "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"; SQL statement:
insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)
    values (
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?
    ) [22001-172]
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:150)
at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:137)
at org.activiti.engine.impl.db.DbSqlSession.flushInserts(DbSqlSession.java:572)
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:475)
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:171)
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:118)
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:66)
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:31)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:40)
at org.activiti.engine.impl.cfg.CommandExecutorImpl.execute(CommandExecutorImpl.java:35)
at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:52)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)
Caused by: org.h2.jdbc.JdbcSQLException: Wartosc za dluga dla kolumny "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"
Value too long for column "TEXT2_ VARCHAR(4000) SELECTIVITY 32": "STRINGDECODE('com.*.*.workflow.AqWait@4f33271e\n<?xml version=\""1.0\"" encoding=\""UTF-8\"" standalone=\""yes\""?>… (8592)"; SQL statement:
insert into ACT_HI_VARINST (ID_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, NAME_, REV_, VAR_TYPE_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_, CREATE_TIME_, LAST_UPDATED_TIME_)
    values (
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?,
      ?
    ) [22001-172]
at org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
at org.h2.message.DbException.get(DbException.java:169)
at org.h2.table.Column.validateConvertUpdateSequence(Column.java:317)
at org.h2.table.Table.validateConvertUpdateSequence(Table.java:699)
at org.h2.command.dml.Insert.insertRows(Insert.java:122)
at org.h2.command.dml.Insert.update(Insert.java:86)
at org.h2.command.CommandContainer.update(CommandContainer.java:79)
at org.h2.command.Command.executeUpdate(Command.java:235)
at org.h2.jdbc.JdbcPreparedStatement.execute(JdbcPreparedStatement.java:193)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:100)
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:148)
… 13 more
</code>

[trademak]

Which transaction isolation are you using on SQL Server?
About the H2 error message. Can you create a unit test showing this issue?

Best regards,

[saram1]

We use READ_COMMITTED_SNAPSHOT on SQL Server.

I'm trying prepare unit test, bu so far I can not reproduce error in it. I have a lot of additional logic around and inside my process and I need to put it step by step into unit test. In my logic I use Hibernate with datasource for other database - so I assume that it does not interact with activity engine database operations. In my test with H2 I setup only activity connection to H2, my logic still used SQL Server.
That's why a assumed that replicate database error is no easy so it can be easier to handle this error and apply proper reaction:

<blockquote>
My point is to handle this error and apply workaround. I have two possibilities:

• rerun killed transaction
• prevent WE to resume suspended process (JobExecutor'll try resume it next time)

Here come my question. What is best and simplest way to made it?
</blockquote>

[trademak]

Letting the job executor take care of it is the easiest solution I guess.
You only need to be aware of jobs failing more than 3 times (the default), as they'll not be retried anymore.

Best regards,

[saram1]

Letting the job executor take care of it is the easiest solution I guess.

I wish to.

You only need to be aware of jobs failing more than 3 times

My observation is that job is executed but there is problem when deleting information that job should by resumed (executed) fails. So in future job is executed one again - witch I want to prevent to.
This comes from my business tests because so far can not get this error in unit test.

[trademak]

Okay, it's possible to change the retry count of the job executor from 3 to 0, but that wouldn't be a best practice to do. If you don't want to retry then modeling it in the process definition to a wait state would probably be the best solution. So when the error occurs you take the sequence flow that leads to this wait state.

Best regards,

[saram1]

Thanks for replay. I'm afraid that we have misunderstanding and my situation is not exactly what you answering to. Now  I can not spend much time to prepare junit test with this situation, but i must do it in near future.
Now my workaround is to set only 1 thread to serve jobexecutor queue. I also can not use READ_COMMITTED_SNAPSHOT because there was deadlocks too (very strange).

I did lot of debugging and this is how it works from my point of view:
- job executor takes process to be resumed
- job executor reads process state from database and setup the process context
- job executor executes process (resumes it in fact)
- job executor gets OK execution status
- job executor deletes process state from database - ERROR

The database delete operation occurs earlier, but at the very end is called ibatis flush - which makes database operation in fact.
This cause the problem - job is executed, but database is not updated to proper state.  I believe it works that way, but can not prepare test case. The deadlock is not major problem. The database errors occurs in real word and can be more or less predictable.
IMO you can get this if have mock test and trigger randomly exception when call 'delete from ACT_GE_BYTEARRAY' (at flush point).

[trademak]

Hi Saram,

Did you saw this post?

http://forums.activiti.org/content/activiti-thread-safety

Don't know if it applies to your environment, but might be interesting to test.

Best regards,