Integrity Constraint Violation updating ACT_RU_VARIABLE

[mindcrime]

Hey gang, we're getting the following error using Activiti 5.10.  This seems to be happening when we try to update / insert variables in a service task, after returning from a web service call.   The only real clue I have right now, that might point to the cause, is this stacktrace, and word from the development team that the web-service in question takes a LONG time to return… on the order of 3-4 minutes (I know, I know). 

Any thoughts on what, exactly, would be going on here?

### Error updating database.  Cause: com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: The insert or update value of the FOREIGN KEY "ACTDB01_UCB.ACT_RU_VARIABLE.ACT_FK_VAR_PROCINST" is not equal to any value of the parent key of the parent table.. SQLCODE=-530, SQLSTATE=23503, DRIVER=3.64.82
### The error may involve org.activiti.engine.impl.persistence.entity.VariableInstanceEntity.insertVariableInstance-Inline
### The error occurred while setting parameters
### SQL: insert into ACT_RU_VARIABLE (ID_, REV_, TYPE_, NAME_, PROC_INST_ID_, EXECUTION_ID_, TASK_ID_, BYTEARRAY_ID_, DOUBLE_, LONG_ , TEXT_, TEXT2_)     values (      ?,      1,      ?,      ?,       ?,      ?,       ?,      ?,      ?,      ?,      ?,      ?     )
### Cause: com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: The insert or update value of the FOREIGN KEY "ACTDB01_UCB.ACT_RU_VARIABLE.ACT_FK_VAR_PROCINST" is not equal to any value of the parent key of the parent table.. SQLCODE=-530, SQLSTATE=23503, DRIVER=3.64.82
        at org.apache.ibatis.exceptions.ExceptionFactory.wrapException(ExceptionFactory.java:23)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:147)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.insert(DefaultSqlSession.java:134)
        at org.activiti.engine.impl.db.DbSqlSession.flushInserts(DbSqlSession.java:459)
        at org.activiti.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:369)
        at org.activiti.engine.impl.interceptor.CommandContext.flushSessions(CommandContext.java:157)
        at org.activiti.engine.impl.interceptor.CommandContext.close(CommandContext.java:109)
        at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:49)
        at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:42)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
        at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:40)
        at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33)
        at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:46)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:736)
Caused by: com.ibm.db2.jcc.am.SqlIntegrityConstraintViolationException: The insert or update value of the FOREIGN KEY "ACTDB01_UCB.ACT_RU_VARIABLE.ACT_FK_VAR_PROCINST" is not equal to any value of the parent key of the parent table.. SQLCODE=-530, SQLSTATE=23503, DRIVER=3.64.82
        at com.ibm.db2.jcc.am.bd.a(bd.java:675)
        at com.ibm.db2.jcc.am.bd.a(bd.java:60)
        at com.ibm.db2.jcc.am.bd.a(bd.java:127)
        at com.ibm.db2.jcc.am.io.b(io.java:2371)
        at com.ibm.db2.jcc.am.io.c(io.java:2354)
        at com.ibm.db2.jcc.t4.ab.l(ab.java:370)
        at com.ibm.db2.jcc.t4.ab.a(ab.java:62)
        at com.ibm.db2.jcc.t4.p.a(p.java:50)
        at com.ibm.db2.jcc.t4.rb.b(rb.java:220)
        at com.ibm.db2.jcc.am.jo.mc(jo.java:3377)
        at com.ibm.db2.jcc.am.jo.b(jo.java:4335)
        at com.ibm.db2.jcc.am.jo.gc(jo.java:2721)
        at com.ibm.db2.jcc.am.jo.execute(jo.java:2704)
        at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.pmiExecute(WSJdbcPreparedStatement.java:938)
        at com.ibm.ws.rsadapter.jdbc.WSJdbcPreparedStatement.execute(WSJdbcPreparedStatement.java:614)
        at org.apache.ibatis.executor.statement.PreparedStatementHandler.update(PreparedStatementHandler.java:41)
        at org.apache.ibatis.executor.statement.RoutingStatementHandler.update(RoutingStatementHandler.java:66)
        at org.apache.ibatis.executor.SimpleExecutor.doUpdate(SimpleExecutor.java:45)
        at org.apache.ibatis.executor.BaseExecutor.update(BaseExecutor.java:108)
        at org.apache.ibatis.executor.CachingExecutor.update(CachingExecutor.java:75)
        at org.apache.ibatis.session.defaults.DefaultSqlSession.update(DefaultSqlSession.java:145)
        … 14 more 
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

[trademak]

It seems like the process instance is not there anymore. Are you experiencing this issue in a unit test or while running on an application server? Is there any asynchronous functionality in your process definition or is the service task executed synchronously?

Best regards,

[mindcrime]

By and large, it's all synchronous.  There aren't any parallel gateways in front of this or anything.   The only element of async here, is that the first Activity in the flow is marked async.  We did this so that at the startProcessInstanceByKey() call would return and give us the process instance ID immediately. (They want to capture that and store it in their own schema for correlation with other things).  But once the process instance is running, we aren't - to the best of my knowledge - doing anything else through the API that would affect the process instance.

This is running on a server, in the dev environment, not in a unit test.

The one thought I had, was that it might be failing to find the procInstId if the process instance were persisted in another, as of yet uncommitted, transaction.  So I had them change the service task to async which should, if I understand this bit correctly, mean that any previous transaction will be committed before we go into the service task.  Doing that resulted in a different error, unfortunately.  😞

That other error looks like this:


[4/30/13 17:17:12:287 CDT] 000000f8 CommandContex E   Error while closing command context
                                 org.activiti.engine.ActivitiException: No job found with id 'b152b65b-b1de-11e2-a683-005056bc7e51'
        at org.activiti.engine.impl.cmd.ExecuteJobsCmd.execute(ExecuteJobsCmd.java:58)
        at org.activiti.engine.impl.interceptor.CommandExecutorImpl.execute(CommandExecutorImpl.java:24)
        at org.activiti.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:42)
        at org.activiti.spring.SpringTransactionInterceptor$1.doInTransaction(SpringTransactionInterceptor.java:42)
        at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:130)
        at org.activiti.spring.SpringTransactionInterceptor.execute(SpringTransactionInterceptor.java:40)
        at org.activiti.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:33)
        at org.activiti.engine.impl.jobexecutor.ExecuteJobsRunnable.run(ExecuteJobsRunnable.java:46)
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:736)


[jbarrez]

I could follow the reasoing you have that the execution didnt yet commit and thats why the process instance isn't there yet.

Your argumentation is correct, putting async in front of the service task makes the transaction commit.

But the second one seems really odd. It is an exception from the internals of the jib executors and for some reason the job isn't there.
Is there any way you can inspect the contents of the database (the job table to be precise)?  It's very hard to understand what might be wrong here wihtout more insight into what is actually happening

[mindcrime]

I have an idea what may be happening now.  Going back to the fact that they are calling a web service that takes 3-4 minutes to return (yeah, I know, I know…) I wrote a trivial BPMN with a couple of service tasks, and in one of the service classes, I threw in a Thread.sleep() to cause it to wait 4 minutes.  And lo and behold, I see Activiti throwing Exceptions from the underlying database complaining that the Connection ins't valid.  

So I suspect that the Connection is getting timed out, out from underneath us, during that long pause.  If that's happening, then I suspect that may be the root cause of the "job not found" error.   But I don't know enough about the Activiti internals to be sure.  But *something* is definitely failing at the db level due to this long wait.   I'm having them bump up the connection timeout settings on the Datasource for now, to see if that changes anything.

Of course, long-term, we need to get rid of, or fix, this 4 minute long WS call.  😞

[jbarrez]

Yes, that doesn't sound a very healthy way of working. I actually don't have much experience with 'inavlid connections' and how it messes up with the application logic. But I can imagine something like what you are seeing there …

Did the increase of the timeout help?

Another route which might be better, it to fire of some event to some queue when you need to do the ws call. At that point the process goes into a receive task. That queue is being monitored, and work is taken off it (ie executing the call). When the call is done, the process instance can be triggered to continued, thus eliminating the need for a transaction of 4 minutes.

> Of course, long-term, we need to get rid of, or fix, this 4 minute long WS call.

Yes!