ACT_RU_JOB DUEDATE_ timestamp overflow

KNA · September 13, 2018, 12:12pm

Hi,

We are using Camunda for processing various types of orders. Orders are processed in 4 distinct bpmn processes. DB is mariaDB. This has been working flawless until recently. It started by some long running process tasks, which caused transaction exceptions and rollbacks. (task was iterating over a list of produkt details, registering them through REST calls on an external resource). As the list of product has grown this triggered a timeout on 300 seconds. However the process was changed to process this list in a parallel multi instance implementation; no longer experiencing the timeout.

After this incident we are experiencing new exception which has never occurred before:

ENGINE-03083 Exception while executing Batch Database Operations with message
Message is null.
java.util.NoSuchElementException
at java.util.ArrayList$Itr.next(ArrayList.java:860)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.checkFlushResults(DbEntityManager.java:359)

After checking both the resent changes in our code, searching this forum etc. I am a bit lost as where to look. What could cause these exceptions (which from the look of it seems related)? Are they just a form of optimisticLockingExceptions? Could the timed out transactions from previous runs have invalidated our database?

Also there seems to be no apparent pattern to these exceptions, they are occuring on most tasks.

Folloing is the full stack trace from Camunda cockpit for the 2 exceptions. I have also included the bpmn which was subject for change.

Stacktrace 1:

2018-09-12 17:14:12,318 ERROR [org.camunda.bpm.engine.context] (pool-35-thread-264) ENGINE-16004 Exception while closing command context: ENGINE-03083 Exception while executing Batch Database Operations with message '
### Error flushing statements.  Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.SQLIntegrityConstraintViolationException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.SQLException: Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
Query is: delete from ACT_GE_BYTEARRAY where ID_ = '60121065'
'. Flush summary: 
 [
  INSERT HistoricActivityInstanceEventEntity[EndEvent_1ubuiwo:60914019]
  INSERT HistoricActivityInstanceEventEntity[ExclusiveGateway_1e6c3ih:60914018]
  INSERT HistoricActivityInstanceEventEntity[OrderItemDone:60914022]
  INSERT HistoricActivityInstanceEventEntity[TerminateCleanupGateway:60914020]
  INSERT HistoricActivityInstanceEventEntity[TerminateCleanupJoinGateway:60914021]
  INSERT MessageEntity[60914023]
  DELETE EventSubscriptionEntity[60913751]
  DELETE MessageEntity[60914010]
  DELETE VariableInstanceEntity[60913753]
  DELETE VariableInstanceEntity[60913754]
  DELETE VariableInstanceEntity[60913755]
  DELETE VariableInstanceEntity[60913758]
  DELETE VariableInstanceEntity[60913760]
  DELETE VariableInstanceEntity[60913762]
  DELETE VariableInstanceEntity[60913764]
  DELETE VariableInstanceEntity[60913797]
  DELETE VariableInstanceEntity[60913798]
  DELETE VariableInstanceEntity[60913799]
  DELETE VariableInstanceEntity[60913800]
  DELETE VariableInstanceEntity[60914101]
  DELETE VariableInstanceEntity[60914102]
  DELETE VariableInstanceEntity[60914103]
  DELETE VariableInstanceEntity[60914104]
  DELETE VariableInstanceEntity[60914105]
  DELETE ByteArrayEntity[60913759]
  DELETE ByteArrayEntity[60913763]
  DELETE_BULK deleteByteArrayNoRevisionCheck 60914017
  UPDATE ExecutionEntity[60913734]
  DELETE ExecutionEntity[60913757]
  DELETE ExecutionEntity[60914112]
  DELETE ExecutionEntity[60914113]
  DELETE ExecutionEntity[60914108]
  DELETE ExecutionEntity[60913766]
  DELETE ExecutionEntity[60913756]
  DELETE ExecutionEntity[60913750]
  UPDATE HistoricActivityInstanceEventEntity[CompleteOrderR6:60914109]
  UPDATE HistoricActivityInstanceEventEntity[ExclusiveGateway_1e6c3ih:60914129]
  UPDATE HistoricActivityInstanceEventEntity[HandleOrderItemSubProcess#multiInstanceBody:60913752]
  UPDATE HistoricActivityInstanceEventEntity[HandleOrderItemSubProcess:60913767]
  UPDATE HistoricVariableInstanceEntity[60913754]
  UPDATE HistoricVariableInstanceEntity[60913755]
]: org.camunda.bpm.engine.ProcessEngineException: ENGINE-03083 Exception while executing Batch Database Operations with message '
### Error flushing statements.  Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.SQLIntegrityConstraintViolationException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
java.sql.SQLException: Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
Query is: delete from ACT_GE_BYTEARRAY where ID_ = '60121065'
'. Flush summary: 
 [
  INSERT HistoricActivityInstanceEventEntity[EndEvent_1ubuiwo:60914019]
  INSERT HistoricActivityInstanceEventEntity[ExclusiveGateway_1e6c3ih:60914018]
  INSERT HistoricActivityInstanceEventEntity[OrderItemDone:60914022]
  INSERT HistoricActivityInstanceEventEntity[TerminateCleanupGateway:60914020]
  INSERT HistoricActivityInstanceEventEntity[TerminateCleanupJoinGateway:60914021]
  INSERT MessageEntity[60914023]
  DELETE EventSubscriptionEntity[60913751]
  DELETE MessageEntity[60914010]
  DELETE VariableInstanceEntity[60913753]
  DELETE VariableInstanceEntity[60913754]
  DELETE VariableInstanceEntity[60913755]
  DELETE VariableInstanceEntity[60913758]
  DELETE VariableInstanceEntity[60913760]
  DELETE VariableInstanceEntity[60913762]
  DELETE VariableInstanceEntity[60913764]
  DELETE VariableInstanceEntity[60913797]
  DELETE VariableInstanceEntity[60913798]
  DELETE VariableInstanceEntity[60913799]
  DELETE VariableInstanceEntity[60913800]
  DELETE VariableInstanceEntity[60914101]
  DELETE VariableInstanceEntity[60914102]
  DELETE VariableInstanceEntity[60914103]
  DELETE VariableInstanceEntity[60914104]
  DELETE VariableInstanceEntity[60914105]
  DELETE ByteArrayEntity[60913759]
  DELETE ByteArrayEntity[60913763]
  DELETE_BULK deleteByteArrayNoRevisionCheck 60914017
  UPDATE ExecutionEntity[60913734]
  DELETE ExecutionEntity[60913757]
  DELETE ExecutionEntity[60914112]
  DELETE ExecutionEntity[60914113]
  DELETE ExecutionEntity[60914108]
  DELETE ExecutionEntity[60913766]
  DELETE ExecutionEntity[60913756]
  DELETE ExecutionEntity[60913750]
  UPDATE HistoricActivityInstanceEventEntity[CompleteOrderR6:60914109]
  UPDATE HistoricActivityInstanceEventEntity[ExclusiveGateway_1e6c3ih:60914129]
  UPDATE HistoricActivityInstanceEventEntity[HandleOrderItemSubProcess#multiInstanceBody:60913752]
  UPDATE HistoricActivityInstanceEventEntity[HandleOrderItemSubProcess:60913767]
  UPDATE HistoricVariableInstanceEntity[60913754]
  UPDATE HistoricVariableInstanceEntity[60913755]
]
	at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationsException(EnginePersistenceLogger.java:689)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:343)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:314)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:286)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:203)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:132)
	at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:113)
	at org.camunda.bpm.engine.impl.interceptor.JtaTransactionInterceptor.execute(JtaTransactionInterceptor.java:58)
	at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:66)
	at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:36)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:29)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.executeJob(ExecuteJobsRunnable.java:88)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:57)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: org.apache.ibatis.exceptions.PersistenceException: 
### Error flushing statements.  Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
	at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:30)
	at org.apache.ibatis.session.defaults.DefaultSqlSession.flushStatements(DefaultSqlSession.java:255)
	at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.flushOperations(DbSqlSession.java:88)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:341)
	... 15 more
Caused by: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.VariableInstanceEntity.deleteByteArrayNoRevisionCheck (batch index #7) failed. 6 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
	at org.apache.ibatis.executor.BatchExecutor.doFlushStatements(BatchExecutor.java:146)
	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:253)
	... 17 more
Caused by: java.sql.BatchUpdateException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
	at org.mariadb.jdbc.MariaDbStatement.executeBatchExceptionEpilogue(MariaDbStatement.java:282)
	at org.mariadb.jdbc.MariaDbPreparedStatementClient.executeBatch(MariaDbPreparedStatementClient.java:294)
	at org.jboss.jca.adapters.jdbc.CachedPreparedStatement.executeBatch(CachedPreparedStatement.java:714)
	at org.jboss.jca.adapters.jdbc.WrappedStatement.executeBatch(WrappedStatement.java:1190)
	at org.apache.ibatis.executor.BatchExecutor.doFlushStatements(BatchExecutor.java:122)
	... 21 more
Caused by: java.sql.SQLIntegrityConstraintViolationException: (conn=10161) Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:171)
	at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.getException(ExceptionMapper.java:110)
	at org.mariadb.jdbc.MariaDbStatement.executeBatchExceptionEpilogue(MariaDbStatement.java:279)
	... 25 more
Caused by: java.sql.SQLException: Cannot delete or update a parent row: a foreign key constraint fails (`orderhandler`.`ACT_RU_JOB`, CONSTRAINT `ACT_FK_JOB_EXCEPTION` FOREIGN KEY (`EXCEPTION_STACK_ID_`) REFERENCES `ACT_GE_BYTEARRAY` (`ID_`))
Query is: delete from ACT_GE_BYTEARRAY where ID_ = '60121065'
	at org.mariadb.jdbc.internal.util.LogQueryTool.exceptionWithQuery(LogQueryTool.java:119)
	at org.mariadb.jdbc.internal.protocol.AbstractQueryProtocol$1.handleResultException(AbstractQueryProtocol.java:567)
	at org.mariadb.jdbc.internal.protocol.AsyncMultiRead.call(AsyncMultiRead.java:140)
	at org.mariadb.jdbc.internal.protocol.AsyncMultiRead.call(AsyncMultiRead.java:67)
	at java.util.concurrent.FutureTask.run(FutureTask.java:266)
	... 3 more

Stacktrace 2:

java.util.NoSuchElementException
	at java.util.ArrayList$Itr.next(ArrayList.java:860)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.checkFlushResults(DbEntityManager.java:359)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:345)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:314)
	at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:286)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:203)
	at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:132)
	at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:113)
	at org.camunda.bpm.engine.impl.interceptor.JtaTransactionInterceptor.execute(JtaTransactionInterceptor.java:58)
	at org.camunda.bpm.engine.impl.interceptor.ProcessApplicationContextInterceptor.execute(ProcessApplicationContextInterceptor.java:66)
	at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:36)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobHelper.executeJob(ExecuteJobHelper.java:29)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.executeJob(ExecuteJobsRunnable.java:88)
	at org.camunda.bpm.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:57)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)

orderProcess.bpmn (45.4 KB)

KNA · September 25, 2018, 9:26am

After further digging the issue is isolated to the timer task. Orders received might have future activation dates. Some even past year 2038. As the timer task is created/scheduled the insert into ACT_RU_JOB fails. The DUEDATE_ field is actually a 32 bit unix timestamp, which overflows at 03:14:07 UTC on 19 January 2038.
The horrible thing here is that the failing insert is somehow not only stopping the current process instance, but also others.
Are there alternative approaches for supporting post 2038 dates in timer events?

The camunda version is 7.8.0 btw…

KNA · September 25, 2018, 11:42am

Changed the DUEDATE_ field to DATETIME type, which seemingly works. Is that a viable fix? If so you should probably change this for next release…

egil · September 26, 2018, 7:45pm

I created an issue in the Camunda Jira for this, hopefully they will find a solution:

https://app.camunda.com/jira/browse/CAM-9379

system · January 30, 2024, 11:22am