cancel
Showing results for 
Search instead for 
Did you mean: 

Deadlock while updating process variable (runTimeService.setVariable()) from multiple threads

zaki
Champ in-the-making
Champ in-the-making
Using runTimeService.setVariable(myExecutionId, myVariableName, someValue); to set the processVariable from multiple threads results in a database deadlock.
Running Activiti version: 5.12.1


12:42:34:185 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (http–0.0.0.0-8080-2) SQL Error: 0, SQLState: 40P01
12:42:34:187 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (http–0.0.0.0-8080-2) ERROR: deadlock detected
  Detail: Process 31789 waits for ShareLock on transaction 90486; blocked by process 31791.
Process 31791 waits for ShareLock on transaction 90485; blocked by process 31789.
  Hint: See server log for query details.
12:42:34:191 ERROR [org.activiti.engine.impl.interceptor.CommandContext] (http–0.0.0.0-8080-2) Error while closing command context: org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 31789 waits for ShareLock on transaction 90486; blocked by process 31791.
Process 31791 waits for ShareLock on transaction 90485; blocked by process 31789.
  Hint: See server log for query details.
### The error may involve org.activiti.engine.impl.persistence.entity.VariableInstanceEntity.updateByteArray_postgres-Inline
### The error occurred while setting parameters
### SQL: update ACT_GE_BYTEARRAY      set       REV_ = ?,       BYTES_ = ?     where ID_ = ?       and REV_ = ?
### Cause: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 31789 waits for ShareLock on transaction 90486; blocked by process 31791.
Process 31791 waits for ShareLock on transaction 90485; blocked by process 31789.
  Hint: See server log for query details.
   at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:147) [mybatis-3.1.1.jar:3.1.1]
   at org.activiti.engine.impl.db.DbSqlSession.flushUpdates(DbSqlSession.java:651) [activiti-engine-5.12.jar:5.12]
   at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:461) [activiti-engine-5.12.jar:5.12]
   at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:168) [activiti-engine-5.12.jar:5.12]
   at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:115) [activiti-engine-5.12.jar:5.12]
   at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:70) [activiti-engine-5.12.jar:5.12]
   at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:42) [activiti-spring-5.12.jar:]
   at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) [spring-tx-3.0.7.RELEASE.jar:3.0.7.RELEASE]
   at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:40) [activiti-spring-5.12.jar:]
   at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:37) [activiti-engine-5.12.jar:5.12]
   at org.activiti.engine.impl.RuntimeServiceImpl.setVariable(RuntimeServiceImpl.java:131) [activiti-engine-5.12.jar:5.12]

Caused by: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 31789 waits for ShareLock on transaction 90486; blocked by process 31791.
Process 31791 waits for ShareLock on transaction 90485; blocked by process 31789.
  Hint: See server log for query details.
   at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:129) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   at sun.proxy.$Proxy357.execute(Unknown Source)
   at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source) [:1.7.0_13]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_13]
   at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_13]
   at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:58) [mybatis-3.1.1.jar:3.1.1]
   at sun.proxy.$Proxy88.execute(Unknown Source)
   at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:108) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75) [mybatis-3.1.1.jar:3.1.1]
   at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:145) [mybatis-3.1.1.jar:3.1.1]
   … 79 more

Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected
  Detail: Process 31789 waits for ShareLock on transaction 90486; blocked by process 31791.
Process 31791 waits for ShareLock on transaction 90485; blocked by process 31789.
  Hint: See server log for query details.
   at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157) [postgresql-9.2-1002.jdbc4.jar:]
   at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886) [postgresql-9.2-1002.jdbc4.jar:]
   at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) [postgresql-9.2-1002.jdbc4.jar:]
   at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555) [postgresql-9.2-1002.jdbc4.jar:]
   at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417) [postgresql-9.2-1002.jdbc4.jar:]
   at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:410) [postgresql-9.2-1002.jdbc4.jar:]
   at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.execute(WrappedPreparedStatement.java:404)
   at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source) [:1.7.0_13]
   at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_13]
   at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_13]
   at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:122) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
   … 92 more
   
5 REPLIES 5

trademak
Star Contributor
Star Contributor
A couple of questions:

- Does it try to set variables on the same execution or is it for difference instances?
- Is the variable a primitive or a POJO?
- Do you have long running transactions? Because I also see that the stacktrace contains Hibernate classes, this means that you are reusing the transaction manager. How many tasks are you executing synchronously?

Best regards,

zaki
Champ in-the-making
Champ in-the-making
Using Activiti version "5.12".
I posted "5.12.1" in the first post by mistake.

- Does it try to set variables on the same execution or is it for difference instances?
It is the same execution (same processInstanceId).

- Is the variable a primitive or a POJO?
The process variable is a JPA persistent entity.

- Do you have long running transactions? Because I also see that the stacktrace contains Hibernate classes, this means that you are reusing the transaction manager. How many tasks are you executing synchronously?
The tasks are executed in a web environment, ie, each http request modifies some fields of the process variable (JPA entity) in its own transaction. Currently, this problem can be reproduced in our environment with just two http requests (two transactions). The transaction manager config is: <code>
<bean id="txManager" class="org.springframework.orm.jpa.JpaTransactionManager">
        <property name="entityManagerFactory" ref="entityManagerFactory" />
</bean>

<bean id="activitiProcessEngineConfiguration" class="org.activiti.spring.SpringProcessEngineConfiguration">
    <property name="databaseType" value="postgres" />
    <property name="dataSource" ref="dataSource" />
    <property name="transactionManager" ref="txManager" />
    <property name="databaseSchemaUpdate" value="true" />
    <property name="jobExecutorActivate" value="false" />
    <property name="transactionsExternallyManaged" value="true" />
    <property name="idBlockSize" value="1" />
    <property name="history" value="audit" />
</bean>
</code>

Based on our logs, the queries causing the deadlock seem to be either for tables: "ACT_HI_VARINST" or "ACT_GE_BYTEARRAY".

Heres the log for the other table (from the one posted in the first post):
<code>14:41:14:868 WARN  [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (http–0.0.0.0-8080-3) SQL Error: 0, SQLState: 40P01
14:41:14:874 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (http–0.0.0.0-8080-3) ERROR: deadlock detected
  Detail: Process 1074 waits for ShareLock on transaction 90498; blocked by process 1105.
Process 1105 waits for ShareLock on transaction 90497; blocked by process 1074.
  Hint: See server log for query details.
14:41:14:881 ERROR [org.activiti.engine.impl.interceptor.CommandContext] (http–0.0.0.0-8080-3) Error while closing command context: org.apache.ibatis.exceptions.PersistenceException:
### Error updating database.  Cause: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 1074 waits for ShareLock on transaction 90498; blocked by process 1105.
Process 1105 waits for ShareLock on transaction 90497; blocked by process 1074.
  Hint: See server log for query details.
### The error may involve org.activiti.engine.impl.persistence.entity.HistoricVariableInstanceEntity.updateHistoricVariableInstance-Inline
### The error occurred while setting parameters
### SQL: update ACT_HI_VARINST set       REV_ = ?,       BYTEARRAY_ID_ = ?,       DOUBLE_ = ?,       LONG_ = ?,       TEXT_ = ?,       TEXT2_ = ?     where ID_ = ?       and REV_ = ?
### Cause: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 1074 waits for ShareLock on transaction 90498; blocked by process 1105.
Process 1105 waits for ShareLock on transaction 90497; blocked by process 1074.
  Hint: See server log for query details.
at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:147) [mybatis-3.1.1.jar:3.1.1]
at org.activiti.engine.impl.db.DbSqlSession.flushUpdates(DbSqlSession.java:651) [activiti-engine-5.12.jar:5.12]
at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:461) [activiti-engine-5.12.jar:5.12]
at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:168) [activiti-engine-5.12.jar:5.12]
at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:115) [activiti-engine-5.12.jar:5.12]
at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:70) [activiti-engine-5.12.jar:5.12]
at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:42) [activiti-spring-5.12.jar:]
at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130) [spring-tx-3.0.7.RELEASE.jar:3.0.7.RELEASE]
at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:40) [activiti-spring-5.12.jar:]
at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:37) [activiti-engine-5.12.jar:5.12]
at org.activiti.engine.impl.RuntimeServiceImpl.setVariable(RuntimeServiceImpl.java:131) [activiti-engine-5.12.jar:5.12]

Caused by: org.hibernate.exception.GenericJDBCException: ERROR: deadlock detected
  Detail: Process 1074 waits for ShareLock on transaction 90498; blocked by process 1105.
Process 1105 waits for ShareLock on transaction 90497; blocked by process 1074.
  Hint: See server log for query details.
at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:54) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:125) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:110) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:129) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
at org.hibernate.engine.jdbc.internal.proxy.AbstractProxyHandler.invoke(AbstractProxyHandler.java:81) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
at sun.proxy.$Proxy428.execute(Unknown Source)
at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source) [:1.7.0_13]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_13]
at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_13]
at org.apache.ibatis.logging.jdbc.PreparedStatementLogger.invoke(PreparedStatementLogger.java:58) [mybatis-3.1.1.jar:3.1.1]
at sun.proxy.$Proxy88.execute(Unknown Source)
at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:108) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75) [mybatis-3.1.1.jar:3.1.1]
at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:145) [mybatis-3.1.1.jar:3.1.1]
… 79 more
Caused by: org.postgresql.util.PSQLException: ERROR: deadlock detected
  Detail: Process 1074 waits for ShareLock on transaction 90498; blocked by process 1105.
Process 1105 waits for ShareLock on transaction 90497; blocked by process 1074.
  Hint: See server log for query details.
at org.postgresql.core.v3.QueryExecutorImpl.receiveErrorResponse(QueryExecutorImpl.java:2157) [postgresql-9.2-1002.jdbc4.jar:]
at org.postgresql.core.v3.QueryExecutorImpl.processResults(QueryExecutorImpl.java:1886) [postgresql-9.2-1002.jdbc4.jar:]
at org.postgresql.core.v3.QueryExecutorImpl.execute(QueryExecutorImpl.java:255) [postgresql-9.2-1002.jdbc4.jar:]
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:555) [postgresql-9.2-1002.jdbc4.jar:]
at org.postgresql.jdbc2.AbstractJdbc2Statement.executeWithFlags(AbstractJdbc2Statement.java:417) [postgresql-9.2-1002.jdbc4.jar:]
at org.postgresql.jdbc2.AbstractJdbc2Statement.execute(AbstractJdbc2Statement.java:410) [postgresql-9.2-1002.jdbc4.jar:]
at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.execute(WrappedPreparedStatement.java:404)
at sun.reflect.GeneratedMethodAccessor332.invoke(Unknown Source) [:1.7.0_13]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_13]
at java.lang.reflect.Method.invoke(Method.java:601) [rt.jar:1.7.0_13]
at org.hibernate.engine.jdbc.internal.proxy.AbstractStatementProxyHandler.continueInvocation(AbstractStatementProxyHandler.java:122) [hibernate-core-4.1.2.Final.jar:4.1.2.Final]
… 92 more
</code>

trademak
Star Contributor
Star Contributor
Postgres automatically locks a row when it's updated. So when there are multiple threads trying to update the same row, one of them fails. So if you need this multithreading functionality, you should expect such an exception and handle it (for example by retrying).

Best regards,

zaki
Champ in-the-making
Champ in-the-making
Is there any way I could use Optimistic locking for the Activiti tables? It would be easier to handle the OptimisticLockException or StaleObjectException at the application level instead of handling the database deadlock exceptions.

frederikherema1
Star Contributor
Star Contributor
There is no way for activiti to detect this kind of issue, other than when it get's the deadlock itself, so don't think any optimistic locking will do any good.