-
Bug Report
-
Resolution: Cannot Reproduce
-
L3 - Default
-
None
-
7.16.0, 7.17.0
-
None
Environment (Required on creation):
linux, java-17, mariadb, camunda-7.17.0, spring-boot-2.7.2
Description (Required on creation; please attach any relevant screenshots, stacktraces, log files, etc. to the ticket):
Calling
runtimeService.createVariableInstanceQuery()
.processInstanceIdIn(getActiveProcessInstanceIds())
.variableNameIn(variableNames)
.list();
in a transaction that does not update anything, camunda occasionally fails with two kinds of exceptions:
2022-08-18 09:25:56.292 level=ERROR 747375 --- [http-nio-8080-exec-10] correlationId=4f289d0f-e584-454c-aeaa-bf395fe27309, org.camunda.bpm.engine.context : 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:133) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:364) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:323) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:295) at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:272) at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:188) at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:119) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:72) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.CommandCounterInterceptor.execute(CommandCounterInterceptor.java:35) at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33) at org.camunda.bpm.engine.impl.AbstractQuery.executeResult(AbstractQuery.java:160) at org.camunda.bpm.engine.impl.AbstractQuery.list(AbstractQuery.java:142) ... Caused by: org.camunda.bpm.engine.ProcessEngineException: ENGINE-03004 Exception while executing Database Operation 'UPDATE VariableInstanceEntity[04ff3d83-da8e-11ec-8c15-001a4a3b025a]' with message ' ### Error updating database. Cause: java.sql.SQLException: (conn=6451307) Lock wait timeout exceeded; try restarting transaction ### The error may exist in org/camunda/bpm/engine/impl/mapping/entity/VariableInstance.xml ### The error may involve org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.updateVariableInstance-Inline ### The error occurred while setting parameters ### SQL: update ACT_RU_VARIABLE set REV_ = ?, EXECUTION_ID_ = ?, VAR_SCOPE_ = ?, TYPE_ = ?, BYTEARRAY_ID_ = ?, DOUBLE_ = ?, LONG_ = ?, TEXT_ = ?, TEXT2_ = ?, SEQUENCE_COUNTER_ = ? where ID_ = ? and REV_ = ? ### Cause: java.sql.SQLException: (conn=6451307) Lock wait timeout exceeded; try restarting transaction'. Flush summary: [ INSERT HistoricVariableUpdateEventEntity[e03cebc4-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e03f83d8-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0421bec-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e04465e0-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e046d6e4-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0496ef8-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e04bdffc-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e04e7810-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e050e914-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0535a18-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e056193c-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0586330-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e05ad434-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e05d9358-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e060045c-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0627560-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e064e564-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0677d78-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e069ee7c-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e06c5f80-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e06ed084-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0714188-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0738b7c-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0762390-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0789494-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e07b0598-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e07d9dac-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0800eb0-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0827fb4-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e084f0b8-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0873aac-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e089d2c0-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e08c43c4-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e08edbd8-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e09125cc-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e09396d0-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e0962ee4-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e09878d8-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e09b10ec-1ec6-11ed-8fc6-001a4a3b0259] INSERT HistoricVariableUpdateEventEntity[e09d81f0-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e03cebc2-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e03cebc3-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e03e2445-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e03f83d6-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e03f83d7-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e040bc59-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0421bea-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0421beb-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0432d5d-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04465de-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04465df-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0459e61-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e046d6e2-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e046d6e3-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0480f65-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0496ef6-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0496ef7-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04aa779-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04bdffa-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04bdffb-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04d187d-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04e780e-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04e780f-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e04f8981-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e050e912-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e050e913-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0522195-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0535a16-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0535a17-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e054b9a9-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e056193a-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e056193b-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0572aad-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e058632e-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e058632f-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0599bb1-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05ad432-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05ad433-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05c33c5-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05d9356-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05d9357-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e05ecbd9-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e060045a-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e060045b-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e0613cdd-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e062755e-1ec6-11ed-8fc6-001a4a3b0259] INSERT ByteArrayEntity[e062755f-1ec6-11ed-8fc6-001a4a3b0259]
or
2022-08-17 12:14:46.347 level=ERROR 747375 --- [http-nio-8080-exec-3] correlationId=000953cb-fefe-4c9c-a546-63dd2ddf1fc7, o.z.problem.spring.common.AdviceTraits : Internal Server Error org.camunda.bpm.engine.OptimisticLockingException: ENGINE-03005 Execution of 'UPDATE VariableInstanceEntity[04ff3d83-da8e-11ec-8c15-001a4a3b025a]' failed. Entity was updated by another transaction concurrently. at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.concurrentUpdateDbEntityException(EnginePersistenceLogger.java:137) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.handleConcurrentModification(DbEntityManager.java:413) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:356) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:323) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:295) at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:272) at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:188) at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:119) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:72) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.CommandCounterInterceptor.execute(CommandCounterInterceptor.java:35) at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33) at org.camunda.bpm.engine.impl.AbstractQuery.executeResult(AbstractQuery.java:160) at org.camunda.bpm.engine.impl.AbstractQuery.list(AbstractQuery.java:142)2022-08-17 12:14:46.347 level=ERROR 747375 --- [http-nio-8080-exec-3] correlationId=000953cb-fefe-4c9c-a546-63dd2ddf1fc7, o.z.problem.spring.common.AdviceTraits : Internal Server Error org.camunda.bpm.engine.OptimisticLockingException: ENGINE-03005 Execution of 'UPDATE VariableInstanceEntity[04ff3d83-da8e-11ec-8c15-001a4a3b025a]' failed. Entity was updated by another transaction concurrently. at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.concurrentUpdateDbEntityException(EnginePersistenceLogger.java:137) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.handleConcurrentModification(DbEntityManager.java:413) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:356) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:323) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:295) at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:272) at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:188) at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:119) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:72) at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:140) at org.camunda.bpm.engine.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:70) at org.camunda.bpm.engine.impl.interceptor.CommandCounterInterceptor.execute(CommandCounterInterceptor.java:35) at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33) at org.camunda.bpm.engine.impl.AbstractQuery.executeResult(AbstractQuery.java:160) at org.camunda.bpm.engine.impl.AbstractQuery.list(AbstractQuery.java:142)
The transation is started on http request (spring-mvc).
Steps to reproduce (Required on creation):
Not easy, actually. I guess it happens on larger load.
Observed Behavior (Required on creation):
Exception gets thrown.
Expected behavior (Required on creation):
Read operations should not result in deadlocks or OptimistiLockExceptions.
Root Cause (Required on prioritization):
Internally Camunda writes to its DB when only asked to read from it.
Solution Ideas (Optional):
Remove the code writing to DB on read-only queries.
Hints (optional):
Other complaints include:
One of them suggests adding disableCustomObjectDeserialization() when constructing the query. But I need it for JSON serialized vars 
This is the controller panel for Smart Panels app
[CAM-14818] Camunda fails variable queries with OptimisticLockException or deadlocks
Could you share a reproducible example? Maybe a test case that fails or a minimal project that reproduces the issue?
Unfortunately, I don't have such a test case.
You mentioned this happened under larger load. How much load? What else was executed when you experienced the issue?
The transaction that failed was querying for variable instances of all active process instances, while a couple of those process instances were quite actively executing and possibly updating those variables.
Do you have any log files from the time the issue occurred that you can share?
The log files do not contain anything useful around the entries I already pasted. Do you think full stacktraces could be helpful?
Initially I hoped a stacktrace that starts with query.list() and is caused by 'UPDATE VariableInstanceEntity' would immediately point to required code fixes...
Why oh why does it try to update variable when all I want is to read it?
What about Thorbens comments in forum about
a bug that variable updates were sometimes wrongfully triggered when a variable query was made
?
Hi andrius,
I'm afraid, without any way to reproduce the issue, we can not start to investigate it.
You can post the full stack trace, and I will have a look at them, but I am not sure if they will lead us closer to a solution. It might be worth a try though.
What about Thorbens comments in forum about
Thorbens forum post is now five years old and the versions mentioned are long out of maintenance. I could not find any fixed bugs related to your problem in the Camunda versions mentioned in the forum post.
Why oh why does it try to update variable when all I want is to read it?
It could happen for a number of reasons. Impossible to say without a way to debug what's happening.
How can we proceed now?
Please attach the full stacktraces and I will check if they help us to find the root cause.
If you manage to reproduce the issue reliably, please attach a minimal project. We are then able to investigate.
This is pretty much everything we can do in the scope of community support. If you need further assistance in rootcausing the exception, I encourage you to ask in our forum. For enterprise customers, we offer technical support and consulting according to our SLAs.
Best,
Miklas
Hi andrius,
At this point, there is nothing we can do in the scope of this ticket. I will close it for now, but please feel free to reopen it anytime when there is more information on how to reproduce the issue.
Best,
Miklas
Hi andrius,
Thank you for raising a bug report. Could you share a reproducible example? Maybe a test case that fails or a minimal project that reproduces the issue?
You mentioned this happened under larger load. How much load? What else was executed when you experienced the issue? Do you have any log files from the time the issue occurred that you can share?
We need this kind of information to be able to investigate the issue. With the current state of the ticket, we can not do much, unfortunately.
Best,
Miklas