Problem with Timer Intermediate Catching Event

[mindcrime]

Hi all, we're seeing some weird behavior using a Timer event.  We've reduced this to a very simple BPMN that does no more than this:

Begin with a None Start Event, transition to a Timer Intermediate Catching Event (specified with a duration, like, say, "PT2M" for 2 minutes), then flow out to a Task of some sort (more on that in a minute) and then flow to an End Event.

Running against a local PostgreSQL database, this works exactly as expected, with a Script Task, Service Task or User Task after the time.  But here's where it gets weird… if the backing database is our DEV instance of DB/2, this go wonky.  In that scenario, if you put a Service or Script task after the Timer, then execution never proceeds to that Task at all.  But if you put a User Task there, the User Task is created almost immediately after the process starts, and not after the 2 minute delay.

This is with Activiti 5.10, FWIW.

Has anybody seen anything like this before?  Any ideas what might be happening?

[jbarrez]

No, never seen it. And it sounds very, very (very) strange!.

Doe you have the exact same setup on DB2? I find it hard to imagine the behaviour is so different. Do you use the exact same activiti config (with different jdbc params ofc)?

[mindcrime]

Yep, same code, same Activiti config, same BPMN, all I do is edit the jdbc params to switch over, and the behavior changes.  Now, to be fair, the DEV database was originally installed as an older version and has been upgraded and futzed with, while my Postgres instance is pristine 5.10.  But, I have a hard time seeing what could cause the discrepancy.

The only even vague inclination that comes to mind is that it might involve the handling of date/time fields, and something may be weird about that with DB/2.

[frederikherema1]

Yes, you might want to double-check the values in the ACT_RU_JOB table for due date of a job… However, date-issies still don't explain why it works with a user-task right after it.

Does the ACT_RU_JOB have an "retriesCount" of zero an an exception filled in? Maybe an error occurred while executing the service-task when the timer fires. After 3 retries, by default, the job is "parked"…

[mindcrime]

A little more detail…  When I start this process (bpmn below), we see the behavior where the User Task is created immediately.  However, what we don't see, is *any* entry in the ACT_RU_JOB table with a PROC_INST_ID_ corresponding to the PROC_INST_ID_ of the User Task.  It's almost like the Timer is never being invoke or used at all.

Here's the XML representation of the BPMN in question:



<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:activiti="http://activiti.org/bpmn" xmlns:bpmndi="http://www.omg.org/spec/BPMN/20100524/DI" xmlns:smileysurprised:mgdc="http://www.omg.org/spec/DD/20100524/DC" xmlns:smileysurprised:mgdi="http://www.omg.org/spec/DD/20100524/DI" typeLanguage="http://www.w3.org/2001/XMLSchema" expressionLanguage="http://www.w3.org/1999/XPath" targetNamespace="http://www.activiti.org/test">
  <process id="pendProcess" name="pendProcess">
    <endEvent id="endevent1" name="End"></endEvent>
    <startEvent id="startevent1" name="Start"></startEvent>
    <intermediateCatchEvent id="timerintermediatecatchevent1" name="TimerCatchEvent">
      <timerEventDefinition>
        <timeDuration>PT2M</timeDuration>
      </timerEventDefinition>
    </intermediateCatchEvent>
    <userTask id="usertask1" name="FOOBAR" activiti:candidateUsers="phil" activiti:candidateGroups="enrollment"></userTask>
    <sequenceFlow id="flow4" name="" sourceRef="startevent1" targetRef="timerintermediatecatchevent1"></sequenceFlow>
    <sequenceFlow id="flow5" name="" sourceRef="timerintermediatecatchevent1" targetRef="usertask1"></sequenceFlow>
    <sequenceFlow id="flow6" name="" sourceRef="usertask1" targetRef="endevent1"></sequenceFlow>
  </process>
</definitions>


Any thoughts on what might explain this? 

[mindcrime]

Also, here is the debug logging from the time I start the program to after I've started the process in question, and then a few seconds afterwards.  This doesn't reflect waiting the full 30 seconds, because it would be pages and pages of output at this level.  But what we see is that the User Task gets created (actually, maybe that it gets *created* isn't actually a problem?) but no entry ever seems to be created in the Job table, so it never actually proceeds to the subsequent task (which is particularly notable when the Task is a script or service task that spits out some logging)

The code we're using to launch the process looks like this:


public static void main(String[] args) {
 
 
  org.apache.log4j.BasicConfigurator.configure();
 
  ClassPathXmlApplicationContext applicationContext = new ClassPathXmlApplicationContext(
    "classpath:*wfcoreContext.xml");
  TaskService tskService = (TaskService) applicationContext
    .getBean("taskService");
  HistoryService hisService = (HistoryService) applicationContext
    .getBean("historyService");

  ProcessEngine processEngine = ProcessEngines.getDefaultProcessEngine();
 
  RepositoryService repositoryService = processEngine.getRepositoryService();
  RuntimeService runtimeService = processEngine.getRuntimeService();
  Map<String, Object> variableMap = new HashMap<String, Object>();
 
  ProcessInstance processInstance = runtimeService.startProcessInstanceByKey("pendProcess",variableMap);
 
  System.out.println("Process Inst ID : "+processInstance.getProcessInstanceId());
  }
}



[mindcrime]

OK, a little update.  This isn't behaving *quite* the way we thought it was (at least not today).  What we're seeing is this:

On DB/2 (but not on Postgres)

AFTER the Timer event fires (you see the entry disappear from the ACT_RU_JOB table)

A UserTask which comes after the Timer is created successfully.

But

A ServiceTask which comes after the Timer does *not* appear to fire at all. (no logging output is observed)

But, again, when we did this on Postgres everything behaved exactly as expected.

Any thoughts, tips or suggestions are greatly appreciated.

[jbarrez]

It sounds really really weird. It does sounds like a config difference between the two … you are sure it is excatly the same process you run?

Could you post your process?

[mindcrime]

Yep, exactly the same process.  I have a trivial little Java program that programmatically deploys the BPMN, and it's using the same configuration and settings as the program that kicks off the process.   The version of the BPMN configured for a User Task is above, and here's the same thing but set to call a Service Task.   The Service class is a simple class that does nothing but a println() call in the execute() method.


<?xml version="1.0" encoding="UTF-8"?>
<definitions xmlns="http://www.omg.org/spec/BPMN/20100524/MODEL" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns:activiti="http://activiti.org/bpmn" xmlns:bpmndi="http://www.omg.org/spec/BPMN/20100524/DI" xmlns:smileysurprised:mgdc="http://www.omg.org/spec/DD/20100524/DC" xmlns:smileysurprised:mgdi="http://www.omg.org/spec/DD/20100524/DI" typeLanguage="http://www.w3.org/2001/XMLSchema" expressionLanguage="http://www.w3.org/1999/XPath" targetNamespace="http://www.activiti.org/test">
  <process id="pendProcess" name="pendProcess">
    <endEvent id="endevent1" name="End"></endEvent>
    <startEvent id="startevent1" name="Start"></startEvent>
    <intermediateCatchEvent id="timerintermediatecatchevent1" name="TimerCatchEvent">
      <timerEventDefinition>
        <timeDuration>PT4M</timeDuration>
      </timerEventDefinition>
    </intermediateCatchEvent>
    <sequenceFlow id="flow4" name="" sourceRef="startevent1" targetRef="timerintermediatecatchevent1"></sequenceFlow>
    <serviceTask id="servicetask1" name="Service Task" activiti:class="com.act.TimerService"></serviceTask>
    <sequenceFlow id="flow5" name="" sourceRef="timerintermediatecatchevent1" targetRef="servicetask1"></sequenceFlow>
    <sequenceFlow id="flow6" name="" sourceRef="servicetask1" targetRef="endevent1"></sequenceFlow>
  </process>
</definitions>

The Activiti config looks like this:


<beans xmlns="http://www.springframework.org/schema/beans"
xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
xsi:schemaLocation="http://www.springframework.org/schema/beans   http://www.springframework.org/schema/beans/spring-beans-3.0.xsd">

<bean id="activitiTransManager"
  class="org.springframework.jdbc.datasource.DataSourceTransactionManager">
  <property name="dataSource" ref="activitiDataSource" />
</bean>

<bean id="processEngineConfiguration" class="org.activiti.spring.SpringProcessEngineConfiguration">
  <property name="databaseType" value="db2" />
  <property name="dataSource" ref="activitiDataSource" />
  <property name="transactionManager" ref="activitiTransManager" />
  <property name="databaseSchemaUpdate" value="false" />
  <property name="jobExecutorActivate" value="true" />
  <property name="historyLevel" value="2" />
</bean>

<bean id="processEngine" class="org.activiti.spring.ProcessEngineFactoryBean">
  <property name="processEngineConfiguration" ref="processEngineConfiguration" />
</bean>

<bean id="repositoryService" factory-bean="processEngine"
  factory-method="getRepositoryService" />
<bean id="runtimeService" factory-bean="processEngine"
  factory-method="getRuntimeService" />
<bean id="taskService" factory-bean="processEngine"
  factory-method="getTaskService" />
<bean id="historyService" factory-bean="processEngine"
  factory-method="getHistoryService" />
<bean id="managementService" factory-bean="processEngine"
  factory-method="getManagementService" />
<bean id="identityService" factory-bean="processEngine"
  factory-method="getIdentityService" />


<bean id="dbProperties"
  class="org.springframework.beans.factory.config.PropertyPlaceholderConfigurer">
  <property name="location" value="classpath:db.properties" />
  <property name="ignoreUnresolvablePlaceholders" value="true" />
</bean>

<bean id="activitiDataSource"
  class="org.springframework.jdbc.datasource.DriverManagerDataSource">
  <description>Configuration for a development DB2 data source.
  </description>
  <property name="driverClassName" value="${jdbc.driver}" />
  <property name="url" value="${jdbc.url.activiti}" />
  <property name="username" value="${jdbc.username}" />
  <property name="password" value="${jdbc.password}" />
</bean>


</beans>


As you can see, we read in the jdbc properties from a file, and I literally just comment out one set of lines and uncomment another, to switch between db2 and postgres (along with changing the "databaseType" value in the processEngineConfiguration bean).

[frederikherema1]

Do you have history enabled? Can you check if the ACT_HI_ACTINST contains an entry (on DB2) for the service-task? AFAIK, there is no reason why the service-task won't be executed depending on the database that is used. The engine internals (taking flows and execution activities) won't be affected by the underlying database. Can you check the ACT_RU_JOB table has the right due-date on DB2, based on the time-duration.

To see if this is a intermediate-event only issue, can you alter the process and add a user-task (or receive task) right after the start-event instead of the intermediate-event. Add a country-timer event to that new user/recieve task and assert if the timer-trigger works as expected?