Error on correlating a message

[testhelper1...@gmail.com]

Hello.

Im facing a little problem...im building a process driven tool for managing helpers for a (sport) event using camunda bpm (7.4.0).

Please have a look at the process:

http://camunda.org/share/#/process/d0fff8f4-8ae6-4405-a62e-2fb8a6536fc3

As the process waits for the message 'MSG_HELP_CALLBACK' to be correlated, the helper managed by the particular process (there is one process instance for each helper) has a generated html mail where he can choose one of the following options ('manuell zuweisen', 'wie zuvor', --> see outgoing edges of the exclusive gateway following the message catch event). Each of these options is represented by a link in that mail. Clicking a link, a jsp page deployed to my bpm tomcat 7.4.0 is called which in the end calls 'runtimeService.correlateMessage(...)'.

Now, if i (as a helper) click one of these links, then wait until the complete operation is done (jsp takes parameters, engine correlates the message, a result message is rendered on the jsp page), and then click another option, i (of course) get a 'MismatchingMessageCorrelationException', as the process engine has already correlated the message. This is normal behaviour which i can handle reliable.

But, if i clicked two of the links at nearly the same time, which means, that i start a second request before the first one returns (and implicitely correlate the same message two times), the engine behaves unpredictable. If im lucky, i get an exception coming out of the engine ('OptimisticLockingException'), but if im not, then the error strikes through down the the database giving me an ibatis exception, when the bpm framework tries to remove an event subscription which is already gone. This not so good, as it propably leads to unpredictable beahviour.

As i dont think that my use case is a very strange one, my feeling tells me that excpetion handling at that point should be improved...do you agree?

I have my project on github, and (if desired) i can give additional information on how to build it (it is very easy) by mail or phone.

Thanks,
Stefan

[thorben....@camunda.com]

Hi Stefan,

Please post the mybatis exception and stack trace. In case the process engine attempts to delete an entity that is already gone, it should fail with an OptimisticLockingException too.

Cheers,
Thorben

[testhelper1...@gmail.com]

Hello, Thorben...

Im a bit confused...after trying to repeat the error (10 times), all i get is the following chain of exceptions (which should be ok as i can handle the ProcessEngineException):

org.apache.jasper.JasperException
root
org.camunda.bpm.engine.ProcessEngineException
root
org.apache.ibatis.exceptions.PersistenceException
root
org.h2.jdbc.JdbcSQLException

I am quite sure that before i got an exception directly from the database in one case and an OptimisticLockingException in the other (which i now do not see at all). Here is a complete trace:


type Exception report

message An exception occurred processing JSP page /HelperCallbackReceiver.jsp at line 19

description The server encountered an internal error that prevented it from fulfilling this request.

exception

org.apache.jasper.JasperException: An exception occurred processing JSP page /HelperCallbackReceiver.jsp at line 19

16: Long helperId = Long.parseLong(request.getParameter("helperId"));
17: HelperCallback callback = HelperCallback.valueOf(request.getParameter("callbackResult"));
18: // render action result
19: out.println(HelperInteraction.processReminderCallback(eventId, helperId, callback, null));
20: %>
21: </body>
22: </html>


Stacktrace:
org.apache.jasper.servlet.JspServletWrapper.handleJspException(JspServletWrapper.java:574)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:476)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

org.camunda.bpm.engine.ProcessEngineException: ENGINE-03004 Exception while executing Database Operation 'INSERT ExecutionEntity[4c8f28d6-b92f-11e5-b7ac-e0187702fffa]' with message '
### Error updating database. Cause: org.h2.jdbc.JdbcSQLException: Referentielle Integrität verletzt: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"
Referential integrity constraint violation: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"; SQL statement:
insert into ACT_RU_EXECUTION
(
ID_,
PROC_INST_ID_,
BUSINESS_KEY_,
PROC_DEF_ID_,
ACT_ID_,
ACT_INST_ID_,
IS_ACTIVE_,
IS_CONCURRENT_,
IS_SCOPE_,
IS_EVENT_SCOPE_,
PARENT_ID_,
SUPER_EXEC_,
SUPER_CASE_EXEC_,
CASE_INST_ID_,
SUSPENSION_STATE_,
CACHED_ENT_STATE_,
SEQUENCE_COUNTER_,
REV_
)
values
(
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
1
) [23506-168]
### The error may involve org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.insertExecution-Inline
### The error occurred while setting parameters
### SQL: insert into ACT_RU_EXECUTION ( ID_, PROC_INST_ID_, BUSINESS_KEY_, PROC_DEF_ID_, ACT_ID_, ACT_INST_ID_, IS_ACTIVE_, IS_CONCURRENT_, IS_SCOPE_, IS_EVENT_SCOPE_, PARENT_ID_, SUPER_EXEC_, SUPER_CASE_EXEC_, CASE_INST_ID_, SUSPENSION_STATE_, CACHED_ENT_STATE_, SEQUENCE_COUNTER_, REV_ ) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
### Cause: org.h2.jdbc.JdbcSQLException: Referentielle Integrität verletzt: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"
Referential integrity constraint violation: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"; SQL statement:
insert into ACT_RU_EXECUTION
(
ID_,
PROC_INST_ID_,
BUSINESS_KEY_,
PROC_DEF_ID_,
ACT_ID_,
ACT_INST_ID_,
IS_ACTIVE_,
IS_CONCURRENT_,
IS_SCOPE_,
IS_EVENT_SCOPE_,
PARENT_ID_,
SUPER_EXEC_,
SUPER_CASE_EXEC_,
CASE_INST_ID_,
SUSPENSION_STATE_,
CACHED_ENT_STATE_,
SEQUENCE_COUNTER_,
REV_
)
values
(
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
1
) [23506-168]'. Flush summary:
[
INSERT HistoricVariableInstanceEntity[3ffdd7f6-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricVariableInstanceEntity[4004198f-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricJobLogEventEntity[3ffdff0a-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricVariableUpdateEventEntity[3ffdd7f8-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricVariableUpdateEventEntity[4004198e-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricVariableUpdateEventEntity[40041990-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[3ffdff0b-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[EventBasedGateway_2:4c8f4fe9-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[ExclusiveGateway_02izwmg:40041991-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[ExclusiveGateway_0dk385k:3ffe261c-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[SendTask_1sq5cwh:4006d8b4-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[ServiceTask_16f9cl7:40041992-b92f-11e5-b7ac-e0187702fffa]
INSERT HistoricActivityInstanceEventEntity[ServiceTask_3:3ffe261d-b92f-11e5-b7ac-e0187702fffa]
INSERT ExecutionEntity[4c8f28d6-b92f-11e5-b7ac-e0187702fffa]
INSERT ByteArrayEntity[3ffdd7f5-b92f-11e5-b7ac-e0187702fffa]
INSERT ByteArrayEntity[3ffdd7f7-b92f-11e5-b7ac-e0187702fffa]
INSERT ByteArrayEntity[3ffdd7f9-b92f-11e5-b7ac-e0187702fffa]
INSERT VariableInstanceEntity[3ffdd7f6-b92f-11e5-b7ac-e0187702fffa]
INSERT VariableInstanceEntity[4004198f-b92f-11e5-b7ac-e0187702fffa]
INSERT SignalEventSubscriptionEntity[4c8f4fe7-b92f-11e5-b7ac-e0187702fffa]
INSERT MessageEventSubscriptionEntity[4c8f4fe8-b92f-11e5-b7ac-e0187702fffa]
INSERT CompensateEventSubscriptionEntity[4006d8b3-b92f-11e5-b7ac-e0187702fffa]
DELETE MessageEventSubscriptionEntity[f9471461-b92d-11e5-b7ac-e0187702fffa]
DELETE TimerEntity[f9473b73-b92d-11e5-b7ac-e0187702fffa]
UPDATE VariableInstanceEntity[f938e38a-b92d-11e5-b7ac-e0187702fffa]
UPDATE ExecutionEntity[f92b75fc-b92d-11e5-b7ac-e0187702fffa]
DELETE ExecutionEntity[f9471460-b92d-11e5-b7ac-e0187702fffa]
UPDATE HistoricActivityInstanceEventEntity[EventBasedGateway_1kzg3ch:f9473b72-b92d-11e5-b7ac-e0187702fffa]
]
org.camunda.bpm.engine.impl.db.EnginePersistenceLogger.flushDbOperationException(EnginePersistenceLogger.java:113)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:296)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:282)
org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:315)
org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:243)
org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:104)
org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
org.camunda.bpm.engine.impl.RuntimeServiceImpl.correlateMessage(RuntimeServiceImpl.java:399)
de.trispeedys.resourceplanning.interaction.HelperInteraction.processReminderCallback(HelperInteraction.java:64)
org.apache.jsp.HelperCallbackReceiver_jsp._jspService(HelperCallbackReceiver_jsp.java:115)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:438)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

org.apache.ibatis.exceptions.PersistenceException:
### Error updating database. Cause: org.h2.jdbc.JdbcSQLException: Referentielle Integrität verletzt: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"
Referential integrity constraint violation: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"; SQL statement:
insert into ACT_RU_EXECUTION
(
ID_,
PROC_INST_ID_,
BUSINESS_KEY_,
PROC_DEF_ID_,
ACT_ID_,
ACT_INST_ID_,
IS_ACTIVE_,
IS_CONCURRENT_,
IS_SCOPE_,
IS_EVENT_SCOPE_,
PARENT_ID_,
SUPER_EXEC_,
SUPER_CASE_EXEC_,
CASE_INST_ID_,
SUSPENSION_STATE_,
CACHED_ENT_STATE_,
SEQUENCE_COUNTER_,
REV_
)
values
(
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
1
) [23506-168]
### The error may involve org.camunda.bpm.engine.impl.persistence.entity.ExecutionEntity.insertExecution-Inline
### The error occurred while setting parameters
### SQL: insert into ACT_RU_EXECUTION ( ID_, PROC_INST_ID_, BUSINESS_KEY_, PROC_DEF_ID_, ACT_ID_, ACT_INST_ID_, IS_ACTIVE_, IS_CONCURRENT_, IS_SCOPE_, IS_EVENT_SCOPE_, PARENT_ID_, SUPER_EXEC_, SUPER_CASE_EXEC_, CASE_INST_ID_, SUSPENSION_STATE_, CACHED_ENT_STATE_, SEQUENCE_COUNTER_, REV_ ) values ( ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, 1 )
### Cause: org.h2.jdbc.JdbcSQLException: Referentielle Integrität verletzt: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"
Referential integrity constraint violation: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"; SQL statement:
insert into ACT_RU_EXECUTION
(
ID_,
PROC_INST_ID_,
BUSINESS_KEY_,
PROC_DEF_ID_,
ACT_ID_,
ACT_INST_ID_,
IS_ACTIVE_,
IS_CONCURRENT_,
IS_SCOPE_,
IS_EVENT_SCOPE_,
PARENT_ID_,
SUPER_EXEC_,
SUPER_CASE_EXEC_,
CASE_INST_ID_,
SUSPENSION_STATE_,
CACHED_ENT_STATE_,
SEQUENCE_COUNTER_,
REV_
)
values
(
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
1
) [23506-168]
org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:26)
org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:154)
org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:141)
org.camunda.bpm.engine.impl.db.sql.DbSqlSession.executeInsertEntity(DbSqlSession.java:145)
org.camunda.bpm.engine.impl.db.sql.DbSqlSession.insertEntity(DbSqlSession.java:137)
org.camunda.bpm.engine.impl.db.AbstractPersistenceSession.executeDbOperation(AbstractPersistenceSession.java:41)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:293)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:282)
org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:315)
org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:243)
org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:104)
org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
org.camunda.bpm.engine.impl.RuntimeServiceImpl.correlateMessage(RuntimeServiceImpl.java:399)
de.trispeedys.resourceplanning.interaction.HelperInteraction.processReminderCallback(HelperInteraction.java:64)
org.apache.jsp.HelperCallbackReceiver_jsp._jspService(HelperCallbackReceiver_jsp.java:115)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:438)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
root cause

org.h2.jdbc.JdbcSQLException: Referentielle Integrität verletzt: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"
Referential integrity constraint violation: "ACT_FK_EXE_PROCINST: PUBLIC.ACT_RU_EXECUTION FOREIGN KEY(PROC_INST_ID_) REFERENCES PUBLIC.ACT_RU_EXECUTION(ID_) ('f92b75fc-b92d-11e5-b7ac-e0187702fffa')"; SQL statement:
insert into ACT_RU_EXECUTION
(
ID_,
PROC_INST_ID_,
BUSINESS_KEY_,
PROC_DEF_ID_,
ACT_ID_,
ACT_INST_ID_,
IS_ACTIVE_,
IS_CONCURRENT_,
IS_SCOPE_,
IS_EVENT_SCOPE_,
PARENT_ID_,
SUPER_EXEC_,
SUPER_CASE_EXEC_,
CASE_INST_ID_,
SUSPENSION_STATE_,
CACHED_ENT_STATE_,
SEQUENCE_COUNTER_,
REV_
)
values
(
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
?,
1
) [23506-168]
org.h2.message.DbException.getJdbcSQLException(DbException.java:329)
org.h2.message.DbException.get(DbException.java:169)
org.h2.message.DbException.get(DbException.java:146)
org.h2.constraint.ConstraintReferential.checkRowOwnTable(ConstraintReferential.java:361)
org.h2.constraint.ConstraintReferential.checkRow(ConstraintReferential.java:303)
org.h2.table.Table.fireConstraints(Table.java:871)
org.h2.table.Table.fireAfterRow(Table.java:888)
org.h2.command.dml.Insert.insertRows(Insert.java:126)
org.h2.command.dml.Insert.update(Insert.java:84)
org.h2.command.CommandContainer.update(CommandContainer.java:75)
org.h2.command.Command.executeUpdate(Command.java:230)
org.h2.jdbc.JdbcPreparedStatement.execute(JdbcPreparedStatement.java:194)
org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:44)
org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:69)
org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:48)
org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:105)
org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:71)
org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:152)
org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:141)
org.camunda.bpm.engine.impl.db.sql.DbSqlSession.executeInsertEntity(DbSqlSession.java:145)
org.camunda.bpm.engine.impl.db.sql.DbSqlSession.insertEntity(DbSqlSession.java:137)
org.camunda.bpm.engine.impl.db.AbstractPersistenceSession.executeDbOperation(AbstractPersistenceSession.java:41)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flushDbOperationManager(DbEntityManager.java:293)
org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.flush(DbEntityManager.java:282)
org.camunda.bpm.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:315)
org.camunda.bpm.engine.impl.interceptor.CommandContext.close(CommandContext.java:243)
org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:104)
org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
org.camunda.bpm.engine.impl.RuntimeServiceImpl.correlateMessage(RuntimeServiceImpl.java:399)
de.trispeedys.resourceplanning.interaction.HelperInteraction.processReminderCallback(HelperInteraction.java:64)
org.apache.jsp.HelperCallbackReceiver_jsp._jspService(HelperCallbackReceiver_jsp.java:115)
org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:438)
org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:396)
org.apache.jasper.servlet.JspServlet.service(JspServlet.java:340)
javax.servlet.http.HttpServlet.service(HttpServlet.java:729)
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)

Thanks,
Stefan

[thorben....@camunda.com]

Hi Stefan,

In certain scenarios, exceptions due to referential integrity violations are expected (e.g. a process instance is deleted while in parallel a new execution is inserted that references the process instance). So it should be ok to see this exception and you write that you can deal with it. If you should see the other exception you were mentioning before again, feel free to post a follow-up. If you can, please try to extract it into a test case. That makes it easier to understand the problem.

Cheers,
Thorben