Question about some operations in a executionListener

[jonlee]

I have a service bean through transaction proxy, there is a method like this:

   @Transactional
   @Component("myServiceBean")
   public MyServiceBean{
   
   }

‍‍‍‍‍‍‍‍

   public void doSomething() throws RuntimeException{
      taskService.complete("101");
   }
‍‍‍‍‍

My process definition has a executionListener, when some tasks complete, it will be fired, My listener like this:

   
   @Transactional
   @Component("CaseAcceptEndListener")
   public class CaseAcceptEndListener implements ExecutionListener{
    
        @Override
   public void notify(DelegateExecution delegateexecution) throws Exception {
           ProcessInstance processInstance = runtimeService.startProcessInstanceByKey("myKey");

           HistoricProcessInstance hp = 
         historyService.createHistoricProcessInstanceQuery().processInstanceId(processInstance.getId())
         .singleResult();
           
        }

   }

‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

In my listener, at first I start a another process, and then I query a historicProcessInstance by the process id just happended. but something is wrong, because I can't find the historyProcess. it seems like the codes  in different transaction.


use the same code(notify code) in my unit test, I can find the historyProcess, like this:

   @Test
   public void test(){
      ProcessInstance processInstance = runtimeService.startProcessInstanceByKey("myKey");

       HistoricProcessInstance hp = 
         historyService.createHistoricProcessInstanceQuery().processInstanceId(processInstance.getId())
         .singleResult();
   }
‍‍‍‍‍‍‍‍‍‍

so, can you give me some advices?  thanks very much

[jbarrez]

How do you call the executionListener in your process xml? Do you inject it from Spring?

[jonlee]

yes, I inject my listener from spring, my process definition fragment like this:
<code>
    <extensionElements>
      <activiti:executionListener event="end" delegateExpression="${myListener}"></activiti:executionListener>
    </extensionElements>
</code>

[jonlee]

I don't know the explict reason, but I guess it's about the transaction probably,  I debug it for 2 day, but I didn't fix it, thanks for your concern

[jbarrez]

The setup looks correct, transaction wise.

Could it be the historic process instance simply isn't flushed to the database yet? Activiti only flushes at the end of the transaction.
Wehere in the process is this execution listener firing?

[jonlee]

In my listener, the database has no records when I start my process instance, and then I can't find the historic process instance by id. but using the same mechanism in the unit test, I can get it, the records are not generated in the database yet(already debug it). I don't know why, the code can run rightly everywhere except in the listener. my transaction manager is JTA, and activiti version is 5.15

[jonlee]

is there any method about flushing activiti record to database initiatively ? thanks

[jbarrez]

> is there any method about flushing activiti record to database initiatively ? thanks


There is (dbSqlSession.flush), but it's still at the end of the transaction that it's committed. But it might work.

It does sounds strange the unit test can find it. Do you also use JTA in the unit test?

[jonlee]

I debugged last night, discovered that dbSqlSession didn't flush data in the listener, but do flush in the unit test.
when it stepped over the code of the unit test at the line below:
<java>
String processInstanceId = runtimeService.startProcessInstanceByKey("t").getId();
</java>
it will flush:
<java>
//invode dbSqlSession's flush method
</java>
but if in the listener, it didn't happen.

[jonlee]

when stepped over the start process instance code, it didn't flush data, and the debug log below:
<code>
2014-06-05 10:40 main DEBUG- — starting StartProcessInstanceCmd ——————————————————–
2014-06-05 10:40 main DEBUG- Running command with propagation REQUIRED
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- Participating in existing transaction
2014-06-05 10:40 main DEBUG- Valid context found. Reusing it for the current command 'org.activiti.engine.impl.cmd.StartProcessInstanceCmd'
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main INFO- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: calling toString…
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: toString returning com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011
2014-06-05 10:40 main DEBUG- ooo Using Connection [Transaction-aware proxy for target Connection [com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011]]
2014-06-05 10:40 main DEBUG- ==>  Preparing: select * from ACT_RE_PROCDEF where KEY_ = ? and (TENANT_ID_ = '' or TENANT_ID_ is null) and VERSION_ = (select max(VERSION_) from ACT_RE_PROCDEF where KEY_ = ? and (TENANT_ID_ = '' or TENANT_ID_ is null))
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: notifyBeforeUse a SessionHandleState with 1 context(s)
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@f632fc7d
2014-06-05 10:40 main DEBUG- a TransactionContext: changing to state null
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: detected transaction com.atomikos.icatch.imp.CompositeTransactionImp@f632fc7d
2014-06-05 10:40 main DEBUG- Coordinator 192.168.0.121.tm0001100119 entering state: ACTIVE
2014-06-05 10:40 main INFO- registerSynchronization ( com.atomikos.jdbc.AtomikosConnectionProxy$JdbcRequeueSynchronization@f632fc7d ) for transaction 192.168.0.121.tm0001100119
2014-06-05 10:40 main INFO- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: calling prepareStatement…
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: prepareStatement returning com.mysql.jdbc.jdbc2.optional.JDBC4PreparedStatementWrapper@18169e8
2014-06-05 10:40 main DEBUG- ==> Parameters: t(String), t(String)
2014-06-05 10:40 main DEBUG- <==      Total: 1
2014-06-05 10:40 main DEBUG- initializing ProcessInstance[3802]
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: ACTIVITY
2014-06-05 10:40 main DEBUG- ProcessInstance[3802] executes Activity(startevent1): org.activiti.engine.impl.bpmn.behavior.NoneStartEventActivityBehavior
2014-06-05 10:40 main DEBUG- Leaving activity 'startevent1'
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: ACTIVITY
2014-06-05 10:40 main DEBUG- ProcessInstance[3802] takes transition (startevent1)–flow1–>(usertask1)
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: ACTIVITY
2014-06-05 10:40 main DEBUG- ProcessInstance[3802] executes Activity(usertask1): org.activiti.engine.impl.bpmn.behavior.UserTaskActivityBehavior
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main INFO- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: calling toString…
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: toString returning com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011
2014-06-05 10:40 main DEBUG- ooo Using Connection [Transaction-aware proxy for target Connection [com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011]]
2014-06-05 10:40 main DEBUG- ==>  Preparing: select * from ACT_RU_IDENTITYLINK where PROC_INST_ID_ = ?
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: notifyBeforeUse a SessionHandleState with 1 context(s)
2014-06-05 10:40 main DEBUG- getCompositeTransaction()  returning instance with id 192.168.0.121.tm0001100119
2014-06-05 10:40 main DEBUG- a SessionHandleState with 1 context(s): checking XA context for transaction com.atomikos.icatch.imp.CompositeTransactionImp@f632fc7d
2014-06-05 10:40 main DEBUG- a TransactionContext: changing to state null
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: detected transaction com.atomikos.icatch.imp.CompositeTransactionImp@f632fc7d
2014-06-05 10:40 main DEBUG- Coordinator 192.168.0.121.tm0001100119 entering state: ACTIVE
2014-06-05 10:40 main INFO- registerSynchronization ( com.atomikos.jdbc.AtomikosConnectionProxy$JdbcRequeueSynchronization@f632fc7d ) for transaction 192.168.0.121.tm0001100119
2014-06-05 10:40 main INFO- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: calling prepareStatement…
2014-06-05 10:40 main DEBUG- atomikos connection proxy for com.mysql.jdbc.jdbc2.optional.JDBC4ConnectionWrapper@4b5011: prepareStatement returning com.mysql.jdbc.jdbc2.optional.JDBC4PreparedStatementWrapper@9eddf9
2014-06-05 10:40 main DEBUG- ==> Parameters: 3802(String)
2014-06-05 10:40 main DEBUG- <==      Total: 0
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: AUDIT
2014-06-05 10:40 main DEBUG- Current history level: AUDIT, level required: ACTIVITY
2014-06-05 10:40 main DEBUG- — StartProcessInstanceCmd finished ——————————————————–
<code>