Problem with Timer events.

[shreekant]

I have been facing problems with timer boundary events as well as timer intermediate delays. Hence, I created a simple workflow to test things out and streamline the problem.

I have a subworkflow, which has a user task, and it has a timer boundary event, which leads to a user task.

Problem:
When I start the workflow, the user task inside the workflow, and the escalation task both start at the same time, in spite of having 5 minutes on the timer event. When I look into the 'my instance', it says 'user task' was started moments ago, but finished 6 hours ago (because the escalation task cancels that one), and escalation task was started 6 hours ago.
There is some sort of time zone issue, because of which activiti engine thinks that the workflow was started 6 hours ago. I am not sure about this. But if this is the case, where can I configure the time zones? Any other ideas?

Thank you for your help!
Shreekant.

[martin_grofcik]

Hi Shreekant,

Could you create jUnit test for it please?
Time is driven by org.activiti.engine.runtime.Clock interface implementations (e.g. org.activiti.engine.impl.util.DefaultClockImpl).
In the  version < 5.15 there was TimeUtil class.

Regards
Martin

[shreekant]

Thanx for the reply.

In Junit as well it gives the same problem.
I tried the same workflow in the standalone instance that Activiti org provides, and things work fine there. We have our own independent environment, with LDAP integration, and the problems occur here.

The problem is that, in a running process, when a task is created, it says it was created '6 hours ago'. When that gets 'completed', the creation time becomes 'moments ago', with completion at '6 hours ago'. When the next task is completed the previous '6 hours ago' turns to 'moments ago'.

There seems to be time zone issue. If someone points me to the code where the time of creation and time of completion is set, I can look into activiti code, to see what I'm doing wrong.

Thank you.

[shreekant]

Update to black-box debugging:

If the process does not have any timer events, the creation and completion times are correct. Whenever I add a timer boundary even to a subprocess, then all the times of creation and completion of the inner tasks start getting messed up.

Thank you,
Shreekant

[martin_grofcik]

Hi Shreekant.

I have created simple jUnit test (you can find the core of this test in the activiti sources)

  @Deployment
  public void testSimpleSubProcessWithTimer() {
   
    Date startTime = new Date();
   
    // After staring the process, the task in the subprocess should be active
    ProcessInstance pi = runtimeService.startProcessInstanceByKey("simpleSubProcess");
    Task subProcessTask = taskService.createTaskQuery()
                                                   .processInstanceId(pi.getId())
                                                   .singleResult();
    assertEquals("Task in subprocess", subProcessTask.getName());
   
    // Setting the clock forward 2 hours 1 second (timer fires in 2 hours) and fire up the job executor
    Date escalationTime = new Date(startTime.getTime() + (2 * 60 * 60 * 1000) + 1000);
    processEngineConfiguration.getClock().setCurrentTime(escalationTime);
    waitForJobExecutorToProcessAllJobs(5000L, 50L);

    // The subprocess should be left, and the escalated task should be active
    Task escalationTask = taskService.createTaskQuery()
                                                   .processInstanceId(pi.getId())
                                                   .singleResult();
    assertEquals("Fix escalated problem", escalationTask.getName());

    // test history
    HistoricTaskInstance historicSubProcessTask = historyService.createHistoricTaskInstanceQuery().
            taskDefinitionKey("subProcessTask").
            singleResult();
    assertTrue(historicSubProcessTask.getStartTime().before(new Date(startTime.getTime() + 1000)));
    assertTrue(historicSubProcessTask.getEndTime().equals(escalationTime));

    HistoricTaskInstance historicEscalationProcessTask = historyService.createHistoricTaskInstanceQuery().
      taskDefinitionKey("subProcessTask").
      singleResult();
    assertTrue(historicEscalationProcessTask.getStartTime().equals(escalationTime));
    assertNull(historicSubProcessTask.getEndTime());

  }

and it is passing.
Regards
Martin

[shreekant]

Thanx for your reply again!

Yes, similar unit test succeeds in standalone activiti provided by the org, but not in the one that I have set up where I've added LDAP and MySql database.

I don't know how to paste a workflow png here, so I ll just explain one simple test workflow. I have a "User Task 1" and then a subprocess, which has a boundary timer of 5 minutes "PT5M". Subprocess has one task. Timer fires an "Escalation task". So, when I start this process at 2 o'clock in the afternoon, the first user task runs fine. But when it hits the subprocess, the timer immediately fires and cancels the "subprocess Task" and fires the "Escalation Task". The creation time of Escalation task is 6 hours in the future.

The data in the database looks like this:

<code>
mysql> select * from ACT_HI_TASKINST where PROC_INST_ID_ = "8603"\G
*************************** 1. row ***************************
            ID_: 7944
   PROC_DEF_ID_: process:21:8602
  TASK_DEF_KEY_: sid-1B4F6B85-09B7-4C97-B158-42B2ECD3956C
  PROC_INST_ID_: 8603
  EXECUTION_ID_: 8603
          NAME_: Escalation 1
PARENT_TASK_ID_: NULL
   DESCRIPTION_: NULL
         OWNER_: NULL
      ASSIGNEE_: waphares
      DURATION_: NULL
DELETE_REASON_: NULL
      PRIORITY_: 50
      FORM_KEY_: NULL
      CATEGORY_: NULL
     TENANT_ID_:
    START_TIME_: 2014-06-04 21:25:13.759
    CLAIM_TIME_: NULL
      END_TIME_: NULL
      DUE_DATE_: NULL
*************************** 2. row ***************************
            ID_: 8608
   PROC_DEF_ID_: process:21:8602
  TASK_DEF_KEY_: sid-B7FE083E-8550-4535-91CF-285C8F1BB113
  PROC_INST_ID_: 8603
  EXECUTION_ID_: 8603
          NAME_: User Task 1
PARENT_TASK_ID_: NULL
   DESCRIPTION_: NULL
         OWNER_: waphares
      ASSIGNEE_: waphares
      DURATION_: 10680
DELETE_REASON_: completed
      PRIORITY_: 50
      FORM_KEY_: NULL
      CATEGORY_: NULL
     TENANT_ID_:
    START_TIME_: 2014-06-04 14:25:01.669
    CLAIM_TIME_: NULL
      END_TIME_: 2014-06-04 14:25:12.349
      DUE_DATE_: NULL
*************************** 3. row ***************************
            ID_: 8614
   PROC_DEF_ID_: process:21:8602
  TASK_DEF_KEY_: sid-E1468CA1-D74C-4ADD-8706-1B6C6BA7AF4A
  PROC_INST_ID_: 8603
  EXECUTION_ID_: 8610
          NAME_: SubProcess Task 1
PARENT_TASK_ID_: NULL
   DESCRIPTION_: NULL
         OWNER_: NULL
      ASSIGNEE_: waphares
      DURATION_: 25201254
DELETE_REASON_: deleted
      PRIORITY_: 50
      FORM_KEY_: NULL
      CATEGORY_: NULL
     TENANT_ID_:
    START_TIME_: 2014-06-04 14:25:12.446
    CLAIM_TIME_: NULL
      END_TIME_: 2014-06-04 21:25:13.700
      DUE_DATE_: NULL
3 rows in set (0.01 sec)
</code>
Could you please point me in the right direction? Looks like noone else has faced similar problem.

[martin_grofcik]

Hi Shreekant,
I was not able to reproduce this issue. It does not mean it that it does not exist. 🙂
My recommendation is: debug it. Place breakpoint to org.activiti.engine.impl.util.DefaultClockImpl#getCurrentTime[code] - this is the place from where time is taken by default.

Regards
Martin

[arekp]

Hello activiti team,
is it advisable to overwrite the DefaultClockImpl by own implementation and configuring it accordingly in activiti.cfg.xml like this:
<code>
<bean id="processEngineConfiguration"
      class="org.activiti.engine.impl.cfg.StandaloneProcessEngineConfiguration">
  <property name="clock">
    <bean class="MyClockImpl" />
  </property>
</bean>
</code>

?

[martin_grofcik]

Hi,

There are situations in which you can provide your own clock implementation. (see org.activiti.crystalball.simulator.impl.clock.ThreadLocalClock)

Regards
Martin