Uploaded image for project: 'camunda BPM'
  1. camunda BPM
  2. CAM-9379

Problems with jobs that have activationDate > 2037

    Details

    • Type: Bug Report
    • Status: Closed
    • Priority: L2 - Critical
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: None
    • Component/s: None
    • Labels:
      None
    • Environment:
      MariaDB, Redhat, Wildfly 10

      Description

      In our company we're doing some migration runs now for some orders that run in a process in Camunda. We are using MariaDB as our database engine.

      We have a timer that is set to activate on $

      {order.activationDate}

      , which is a java.util.Date on an object set as a variable "order".

      This has been going well until we had some instances of activationDate being set 2040-01-01. The exception we found was:

      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.JobEntity.insertTimer (batch index #5) failed. 4 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      ### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.JobEntity.insertTimer (batch index #5) failed. 4 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      java.sql.SQLDataException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      java.sql.SQLException: Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      Query is: insert into ACT_RU_JOB (
                  ID_,
                  TYPE_,
                  LOCK_OWNER_,
                  LOCK_EXP_TIME_,
                  EXCLUSIVE_,
                  EXECUTION_ID_,
                  PROCESS_INSTANCE_ID_,
                  PROCESS_DEF_ID_,
                  PROCESS_DEF_KEY_,
                  RETRIES_,
                  EXCEPTION_STACK_ID_,
                  EXCEPTION_MSG_,
                  DUEDATE_,
                  REPEAT_,
                  HANDLER_TYPE_,
                  HANDLER_CFG_,
                  DEPLOYMENT_ID_,
                  SUSPENSION_STATE_,
                  JOB_DEF_ID_,
                  PRIORITY_,
                  SEQUENCE_COUNTER_,
                  TENANT_ID_,
                  REV_
                )
          values ('31412988',
                  'timer',
                  <null>,
                  <null>,
                  1,
                  '31412986',
                  '31267329',
                  'CHBServiceOrder:1:24770465',
                  'CHBServiceOrder',
                  3,
                  <null>,
                  <null>,
                  '2040-01-01 01:00:00.0',
                  <null>,
                  'timer-intermediate-transition',
                  'Wa...
      '. Flush summary: 
       [
        INSERT HistoricVariableInstanceEntity[31412974]
        INSERT HistoricActivityInstanceEventEntity[UpdateChbOrderHistory:31412973]
        INSERT HistoricActivityInstanceEventEntity[WaitForActivationDate:31412987]
        INSERT ExecutionEntity[31412986]
        INSERT ByteArrayEntity[31412989]
        INSERT ByteArrayEntity[31412990]
        INSERT TimerEntity[31412988]
        DELETE MessageEntity[31272417]
        UPDATE VariableInstanceEntity[31267333]
        DELETE ByteArrayEntity[31267332]
        DELETE ByteArrayEntity[31267335]
        DELETE_BULK deleteByteArrayNoRevisionCheck 31272426
        UPDATE ExecutionEntity[31269171]
        UPDATE HistoricVariableInstanceEntity[31267333]
      ]
          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.JobEntity.insertTimer (batch index #5) failed. 4 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      ### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.JobEntity.insertTimer (batch index #5) failed. 4 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
          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.JobEntity.insertTimer (batch index #5) failed. 4 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
          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=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
          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.SQLDataException: (conn=40692) Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
          at org.mariadb.jdbc.internal.util.exceptions.ExceptionMapper.get(ExceptionMapper.java:167)
          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: Incorrect datetime value: '2040-01-01 01:00:00' for column 'DUEDATE_' at row 1
      Query is: insert into ACT_RU_JOB (
                  ID_,
                  TYPE_,
                  LOCK_OWNER_,
                  LOCK_EXP_TIME_,
                  EXCLUSIVE_,
                  EXECUTION_ID_,
                  PROCESS_INSTANCE_ID_,
                  PROCESS_DEF_ID_,
                  PROCESS_DEF_KEY_,
                  RETRIES_,
                  EXCEPTION_STACK_ID_,
                  EXCEPTION_MSG_,
                  DUEDATE_,
                  REPEAT_,
                  HANDLER_TYPE_,
                  HANDLER_CFG_,
                  DEPLOYMENT_ID_,
                  SUSPENSION_STATE_,
                  JOB_DEF_ID_,
                  PRIORITY_,
                  SEQUENCE_COUNTER_,
                  TENANT_ID_,
                  REV_
                )
          values ('31412988',
                  'timer',
                  <null>,
                  <null>,
                  1,
                  '31412986',
                  '31267329',
                  'CHBServiceOrder:1:24770465',
                  'CHBServiceOrder',
                  3,
                  <null>,
                  <null>,
                  '2040-01-01 01:00:00.0',
                  <null>,
                  'timer-intermediate-transition',
                  'Wa...
          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
      

      This seems to be a problem with Camunda setting _DUEDATE in ACT_RU_JOB as a TIMESTAMP(3), which as far as I know is a unix timestamp that overflows after year 2037.

      After this occurred our database has been severly acting up, instances are failing for no apparent reasons, can't complete because of foreign key constraints that don't belong to them and so on. Our only solution was to wipe the entire database and start anew, luckily this was only in our acceptance test environment.

      When we changed _DUEDATE to DateTime it seemed to be working fine again, so this seems to be an issue with the type of the field in the database.

      Thanks!

      Best Regards,
      Egil Risvoll Sørensen

        Issue Links

          Activity

          Hide
          egil Egil Risvoll Sørensen added a comment -
          Show
          egil Egil Risvoll Sørensen added a comment - This is connected to the forum post: https://forum.camunda.org/t/act-ru-job-duedate-timestamp-overflow/8900
          Hide
          thorben.lindhauer Thorben Lindhauer added a comment -

          Closing this in favour of CAM-9498, for which we will provide a fix with the 7.11 release.

          Show
          thorben.lindhauer Thorben Lindhauer added a comment - Closing this in favour of CAM-9498 , for which we will provide a fix with the 7.11 release.

            People

            • Assignee:
              Unassigned
              Reporter:
              egil Egil Risvoll Sørensen
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development