L3 - Default Steps to reproduce:
- Setup Camunda DB schema based on 7.12 on Postgresql
- Break the DB schema, for example, by deleting the column ACT_RU_JOB#REPEAT_OFFSET_
- Start Camunda (with jdbcBatchProcessing = true)
- Deploy a BPMN process containing a timer event
- Start a process instance
Expected behavior:
- The engine fails to insert the timer because of the missing column REPEAT_OFFSET_
- The respective exception message contains the database exception pointing out that the column REPEAT_OFFSET_ is not present, e.g.,
ENGINE-03004 Exception while executing Database Operation 'INSERT TimerEntity[ca202cdf-7a75-11ea-86ee-0242ac12000a]' with message ' ### Error updating database. Cause: org.postgresql.util.PSQLException: ERROR: column "repeat_offset_" of relation "act_ru_job" does not exist Position: 397 ### The error may involve org.camunda.bpm.engine.impl.persistence.entity.JobEntity.insertTimer-Inline ### The error occurred while setting parameters ### SQL: 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_, REPEAT_OFFSET_, HANDLER_TYPE_, HANDLER_CFG_, DEPLOYMENT_ID_, SUSPENSION_STATE_, JOB_DEF_ID_, PRIORITY_, SEQUENCE_COUNTER_, TENANT_ID_, CREATE_TIME_, REV_ ) values (?, 'timer', ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 ) ### Cause: org.postgresql.util.PSQLException: ERROR: column "repeat_offset_" of relation "act_ru_job" does not exist ...
Observed behavior:
- The engine fails to insert the timer because of the missing column REPEAT_OFFSET_
- But the exception message does not provide any information on while the insert failed, e.g.,
ENGINE-03004 Exception while executing Database Operation 'INSERT TimerEntity[fd286b14-73e9-11ea-b3fd-0242ac12000b]' with message ' ### Error flushing statements. Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.JobEntity.insertTimer (batch index #3) failed. 2 prior sub executor(s) completed successfully, but will be rolled back. Cause: java.sql.BatchUpdateException: Batch entry 0 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_, REPEAT_OFFSET_, HANDLER_TYPE_, HANDLER_CFG_, DEPLOYMENT_ID_, SUSPENSION_STATE_, JOB_DEF_ID_, PRIORITY_, SEQUENCE_COUNTER_, TENANT_ID_, CREATE_TIME_, REV_ ) values ('fd286b14-73e9-11ea-b3fd-0242ac12000b', 'timer', NULL, NULL, '1', 'fd25d302-73e9-11ea-b3fd-0242ac12000b', 'b916e17d-73e9-11ea-b3fd-0242ac12000b', 'process:1:90ea74f7-73e9-11ea-b3fd-0242ac12000b', 'process', 3, NULL, NULL, '2020-04-01 07:25:45.008000 +00:00', NULL, 0, 'timer-intermediate-transition', 'foo', '90e1c264-73e9-11ea-b3fd-0242ac12000b', 1, '90ea9c08-73e9-11ea-b3fd-0242ac12000b', 0, 1, NULL, '2020-04-01 07:25:40.008000 +00:00', 1 ) was aborted. Call getNextException to see the cause. Flush summary: [ ... ] at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationException(EnginePersistenceLogger.java:131) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:355) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:322) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:294) at org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:263) at org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:186) ...
Hint:
- To get the actual exception, the user has to disable JDBC batch processing in the process engine configuration.
- For example, the difference between 7.11.0 and 7.12.0 is:
- 7.11.0: The method #flushDbOperationsException() is called which went over #getNextException() to collect all exceptions, see https://github.com/camunda/camunda-bpm-platform/blob/7.11.0/engine/src/main/java/org/camunda/bpm/engine/impl/db/entitymanager/DbEntityManager.java#L362
- 7.12.0: The method #flushDbOperationException() is called which gets only the exception which will be used to get the exception message but it does not "resolve" the next exceptions by calling #getNextException().
- With the 7.10.0 and 7.11.0 the engine logged, for example, DB2 SQL exceptions like this:
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.ExecutionEntity.deleteExecution (batch index #8) failed. 7 prior sub executor(s) completed successfully, but will be rolled back. Cause: com.ibm.db2.jcc.am.BatchUpdateException: [jcc][t4][102][10040][4.19.26] Batch failure. The batch was submitted, but at least one exception occurred on an individual member of the batch. Use getNextException() to retrieve the exceptions for specific batched elements. ERRORCODE=-4229, SQLSTATE=null ### Cause: org.apache.ibatis.executor.BatchExecutorException: org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.deleteExecution (batch index #8) failed. 7 prior sub executor(s) completed successfully, but will be rolled back. Cause: com.ibm.db2.jcc.am.BatchUpdateException: [jcc][t4][102][10040][4.19.26] Batch failure. The batch was submitted, but at least one exception occurred on an individual member of the batch. Use getNextException() to retrieve the exceptions for specific batched elements. ERRORCODE=-4229, SQLSTATE=null com.ibm.db2.jcc.am.BatchUpdateException: [jcc][t4][102][10040][4.19.26] Batch failure. The batch was submitted, but at least one exception occurred on an individual member of the batch. Use getNextException() to retrieve the exceptions for specific batched elements. ERRORCODE=-4229, SQLSTATE=null com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: Error for batch element #1: DB2 SQL Error: SQLCODE=-532, SQLSTATE=23504, SQLERRMC=CAMUNDA.ACT_RU_VARIABLE.ACT_FK_VAR_EXE, DRIVER=4.19.26 com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: Error for batch element #2: DB2 SQL Error: SQLCODE=-532, SQLSTATE=23504, SQLERRMC=CAMUNDA.ACT_RU_EXECUTION.ACT_FK_EXE_SUPER, DRIVER=4.19.26 '. Flush summary: [ ... ] at org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationsException(EnginePersistenceLogger.java:692) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperations(DbEntityManager.java:361) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:324) at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:296) ...