An exception occurred in the persistence layer related with insert authorization

Adriano_Campos1 · February 8, 2023, 10:36pm

My application is implemented with Camunda 7 and Mysql 8.0.30 both running on Dockers. Everthing works fine but sometime we have errors related with Database in the Camunda ouput. Camunda keeps working but slowly for some time until recover. Looks like some issue related with “insertAuthorization” on some request. Any ideia to fix my problem?

The error message is that:

SEVERE [http-nio-8080-exec-12940] org.camunda.commons.logging.BaseLogger.logError ENGINE-16004 Exception while closing command context: An exception occurred in the persistence layer. Please check the server logs for a detailed message and the entire exception stack trace.
org.camunda.bpm.engine.ProcessEngineException: An exception occurred in the persistence layer. Please check the server logs for a detailed message and the entire exception stack trace.
at org.camunda.bpm.engine.impl.util.ExceptionUtil.wrapPersistenceException(ExceptionUtil.java:263)
at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationException(EnginePersistenceLogger.java:132)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:364)

…
Caused by: org.camunda.bpm.engine.ProcessEngineException: ENGINE-03004 Exception while executing Database Operation ‘INSERT AuthorizationEntity[7b692910-a7b2-11ed-8cf1-02425542710d]’ with message ’
### Error flushing statements. Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

java.sql.BatchUpdateException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’
java.sql.SQLIntegrityConstraintViolationException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’
'. Flush summary:
[
INSERT TaskMeterLogEntity[7b692912-a7b2-11ed-8cf1-02425542710d]
INSERT AuthorizationEntity[7b692910-a7b2-11ed-8cf1-02425542710d]
INSERT UserOperationLogEntryEventEntity[7b695024-a7b2-11ed-8cf1-02425542710d]
INSERT HistoricIdentityLinkLogEventEntity[7b692911-a7b2-11ed-8cf1-02425542710d]
UPDATE TaskEntity[3133d097-a7b2-11ed-8cf1-02425542710d]
UPDATE HistoricActivityInstanceEventEntity[return_to_booth:3133d096-a7b2-11ed-8cf1-02425542710d]
UPDATE HistoricTaskInstanceEventEntity[3133d097-a7b2-11ed-8cf1-02425542710d]
]
at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationException(EnginePersistenceLogger.java:131)
… 70 more
Caused by: org.apache.ibatis.exceptions.PersistenceException:

Error flushing statements. Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

	at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.flushStatements(DefaultSqlSession.java:254)
	at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.flushBatchOperations(DbSqlSession.java:444)
	at org.camunda.bpm.engine.impl.db.sql.BatchDbSqlSession.executeDbOperations(BatchDbSqlSession.java:74)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:341)
	... 69 more
Caused by: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry 'isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d' for key 'ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER'
	at org.apache.ibatis.executor.BatchExecutor.doFlushStatements(BatchExecutor.java:149)
	at org.apache.ibatis.executor.BaseExecutor.flushStatements(BaseExecutor.java:129)
	at org.apache.ibatis.executor.BaseExecutor.flushStatements(BaseExecutor.java:122)
	at org.apache.ibatis.executor.CachingExecutor.flushStatements(CachingExecutor.java:114)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.flushStatements(DefaultSqlSession.java:252)
	... 72 more
Caused by: java.sql.BatchUpdateException: Duplicate entry 'isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d' for key 'ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER'
	at jdk.internal.reflect.GeneratedConstructorAccessor209.newInstance(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
	at java.base/java.lang.reflect.Constructor.newInstance(Constructor.java:490)
	at com.mysql.cj.util.Util.handleNewInstance(Util.java:192)
	at com.mysql.cj.util.Util.getInstance(Util.java:167)
	at com.mysql.cj.util.Util.getInstance(Util.java:174)
	at com.mysql.cj.jdbc.exceptions.SQLError.createBatchUpdateException(SQLError.java:224)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeBatchSerially(ClientPreparedStatement.java:853)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeBatchInternal(ClientPreparedStatement.java:435)
	at com.mysql.cj.jdbc.StatementImpl.executeBatch(StatementImpl.java:794)
	at jdk.internal.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.apache.tomcat.jdbc.pool.StatementFacade$StatementProxy.invoke(StatementFacade.java:114)
	at com.sun.proxy.$Proxy7.executeBatch(Unknown Source)
	at org.apache.ibatis.executor.BatchExecutor.doFlushStatements(BatchExecutor.java:123)
	... 76 more
Caused by: java.sql.SQLIntegrityConstraintViolationException: Duplicate entry 'isabel.martins-1-7-3133d097-a7b2-11ed-8cf1-02425542710d' for key 'ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER'
	at com.mysql.cj.jdbc.exceptions.SQLError.createSQLException(SQLError.java:117)
	at com.mysql.cj.jdbc.exceptions.SQLExceptionsMapping.translateException(SQLExceptionsMapping.java:122)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeInternal(ClientPreparedStatement.java:953)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeUpdateInternal(ClientPreparedStatement.java:1092)
	at com.mysql.cj.jdbc.ClientPreparedStatement.executeBatchSerially(ClientPreparedStatement.java:832)
	... 84 more

jonathan.lukas · February 10, 2023, 12:59pm

Hello @Adriano_Campos1 ,

it looks like at some point, there is an authorization created that already exists.
Do you have implementations on your side that would do this?

Jonathan

Adriano_Campos1 · February 14, 2023, 12:36am

Hi @jonathan.lukas
The problem seems a problem with some camunda batch mechanism to roll back transactions.
Maybe because two users is trying to submit a task at the same time, and then camunda have to roll back one. This make any sense?

Should I protect on my side two users to submit at same time?

I have this in the log:

13-Feb-2023 09:51:24.182 WARNING [http-nio-8080-exec-2972] org.camunda.commons.logging.BaseLogger.logWarn ENGINE-REST-HTTP500 org.camunda.bpm.engine.rest.exception.RestException: Cannot complete task 06d5bed4-ab83-11ed-89d7-02425542710d: ENGINE-03005 Execution of ‘INSERT VariableInstanceEntity[f9ce36f2-ab83-11ed-89d7-02425542710d]’ failed. Entity was updated by another transaction concurrently.

Caused by: org.camunda.bpm.engine.OptimisticLockingException: ENGINE-03005 Execution of ‘INSERT VariableInstanceEntity[f9ce36f2-ab83-11ed-89d7-02425542710d]’ failed. Entity was updated by another transaction concurrently.

13-Feb-2023 09:57:41.367 SEVERE [http-nio-8080-exec-2919] org.camunda.commons.logging.BaseLogger.logError ENGINE-16004 Exception while closing command context: An exception occurred in the persistence layer. Please check the server logs for a detailed message and the entire exception stack trace.

Caused by: org.camunda.bpm.engine.ProcessEngineException: ENGINE-03004 Exception while executing Database Operation ‘INSERT AuthorizationEntity[dad2bcba-ab84-11ed-89d7-02425542710d]’ with message ’

Error flushing statements. Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘mjoao.mendonca-1-7-8177b40e-aaed-11ed-89d7-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.AuthorizationEntity.insertAuthorization (batch index #2) failed. 1 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Duplicate entry ‘mjoao.mendonca-1-7-8177b40e-aaed-11ed-89d7-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

java.sql.BatchUpdateException: Duplicate entry ‘mjoao.mendonca-1-7-8177b40e-aaed-11ed-89d7-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’
java.sql.SQLIntegrityConstraintViolationException: Duplicate entry ‘mjoao.mendonca-1-7-8177b40e-aaed-11ed-89d7-02425542710d’ for key ‘ACT_RU_AUTHORIZATION.ACT_UNIQ_AUTH_USER’

jonathan.lukas · February 15, 2023, 2:42pm

Hello @Adriano_Campos1 ,

this transaction rollback is intended to provide a consistent state for the process engine.

However, it looks to me as if there were 2 problems:

13-Feb-2023 09:51:24.182 → OLE, possibly related to two users completing a task at the same time. Here, you should find out which variable is modified concurrently and probably decouple the task completion from the variable modification. Concurrent variable modification sometimes happens for example if you have a user task inside some kind of multi-instance or parallel flow. To prevent this error to affect the user, you could for example create an empty variable container inside a multi-instance (subprocess) and merge these variables in an exclusive async continuation.
13-Feb-2023 09:57:41.367 Some Batch tried to modify authorizations which failed as the authorization that was tried to be inserted did already exist / an authorization for the user did already exist. If you could identify the type and parameters of the batch that failed, that would be helpful

Jonathan

Adriano_Campos · March 2, 2023, 3:00pm

Hi,
About 2 users submiting the same task a protect with in your backend to avoid this error.
Now We have another error:

01-Mar-2023 11:41:56.718 WARNING [http-nio-8080-exec-16745] org.camunda.commons.logging.BaseLogger.logWarn ENGINE-REST-HTTP500 org.camunda.bpm.engine.rest.exception.RestException: Cannot put process instance variable files: ENGINE-03005 Execution of ‘INSERT VariableInstanceEntity[11d0fbdb-b826-11ed-89d7-02425542710d]’ failed. Entity was updated by another transaction concurrently.

jonathan.lukas · March 2, 2023, 4:58pm

Hello @Adriano_Campos ,

this looks like 2 threads try to update a variable value at the same time.

This can be prevented by scoping the variables towards executions and merging them in an exclusive job.

Jonathan

Adriano_Campos · March 2, 2023, 6:14pm

HI @jonathan.lukas
How 2 threads can update the same variable at the same time? Do you any ideia how to identify what Task, Service, Job, … are doing that?

ENGINE-03005 Execution of 'INSERT VariableInstanceEntity[b93ff205-ac50-11ed-89d7-02425542710d]' failed

Any ideia to identify where 2 threads can update the same variable at the same time

jonathan.lukas · March 2, 2023, 7:37pm

Hello @Adriano_Campos ,

this can happen if 2 tasks are executed really parallel, for example jobs that executed not exclusive or 2 external tasks that are completed at the same time.

Jonathan