Timer repetition issue

[martin_grofcik]

Hi.

(I almost forgot how can I create forum topic 🙂 ).
the question is:
Current (5.18.0-SNAPSHOT) timer implementation does not guarantee that:

• repetition timer is executed n times
• repetition timer period will be constant for all repetitions.

jUnit test:

org.activiti.engine.test.bpmn.event.timer.StartTimerEventTest#testCycleWithLimitStartTimerEvent_failing‍

https://github.com/martin-grofcik/Activiti/tree/timer-issue

Thank you in advance for the answer,
Regards
Martin

[martin_grofcik]

Is it intended behaviour?

[jbarrez]

I looked at the unit test, but i'm not sure I'm following yet.

> repetition timer is executed n times

So you're saying it isn't executed 2 times

> repetition timer period will be constant for all repetitions.

There is always the delay of the polling interval of the job executor of course. Or are you meaning something else?


It would be good if you can described what you expect when that process is executed vs what is happening on 5.18 snapshot right now.

[martin_grofcik]

Hi,

I was wrong with my first issue

repetition timer is executed n times

that's not true, there is guarantee of n times execution.

Another point is that

repetition timer period will be constant for all repetitions.

There is still issue in it. I updated source code in my branch:

  @Deployment(resources = {"org/activiti/engine/test/bpmn/event/timer/StartTimerEventTest.testCycleWithLimitStartTimerEvent.bpmn20.xml"})
  public void testCycleWithLimitStartTimerEvent_keepTimerPeriod() throws Exception {
    processEngineConfiguration.getClock().setCurrentTime(new Date());

    final ProcessInstanceQuery piq = runtimeService.createProcessInstanceQuery().processDefinitionKey("startTimerEventExampleCycle");

    // move to 15 mins forward - e.g. server was down and it was started again
    moveByMinutes(15);
    waitForJobExecutorOnCondition(10000, 500, new Callable<Boolean>() {
      public Boolean call() throws Exception {
        // one process instance should be started - because time is after start date
        return 1 == piq.count();
      }
    });

    moveByMinutes(1);
    waitForJobExecutorOnCondition(10000, 500, new Callable<Boolean>() {
      public Boolean call() throws Exception {
        // we have moved the time 1 minute forward. Process start period is 5 mins. => No other process instance
        // should be started
        // @FIXME: 5.18-SNAPSHOT - there are 2 process instances running because of org.activiti.engine.impl.calendar.DurationHelper.getDateAfterRepeat
        return 1 == piq.count();
      }
    });

    // +4 mins -> new process instance should be started because time period was reached since the last timer execution
    moveByMinutes(4);
    waitForJobExecutorOnCondition(10000, 500, new Callable<Boolean>() {
      public Boolean call() throws Exception {
        return 2 == piq.count();
      }
    });
  }

The real use case is: timer with R100/PT99S (100x repeat with 99 sec period). Let's say that each iteration is executed with 1 sec delay. It means that the last repetition will be scheduled right after the previous one (timer period is omitted). I think that's wrong, we should keep period for the last repetition too.

Regards
Martin

[jbarrez]

Hi Martin,

Looked at your unit test, but I believe it's correct:

* In a normal situation, the timer would be scheduled to fire after 5 mins and after 10 mins.

* You move by 15 minutes. In that case, the R2/PT5M 'valid' period has already passed. The best effort is now to use the current time. if you check the due date, you see the due date is equal to the Clock + 15 mins

* If you change the moveByMinutes(15) to 5 and print out the duedate, you see the next job is nicely set to (start + 10 minutes).

As such, the results are correct according to me. Also the 99 -> 100 case is not shown, taking in account the above remarks.

[martin_grofcik]

Hi Joram,

at first thanks for your help.
I created new jUnit testrg.activiti.engine.test.bpmn.event.timer.StartTimerEventTest#testCycleWithLimitStartTimerEvent_keepPeriod
[table]
[tr] [td]CREATE_TIME_  [/td][/tr]
[tr][td]2015-07-02 12:25:27.102[/td][/tr]
[tr][td]2015-07-02 12:26:42.102[/td][/tr]
[tr][td]2015-07-02 12:27:57.102[/td][/tr]
[tr][td]2015-07-02 12:29:12.102[/td][/tr]
[tr][td]2015-07-02 12:29:18.102[/td][/tr]
[/table]

as you can see process 5 is created only 6 seconds after the process 4 => timer period is not kept.
I would expect that timer period will persist.
(I think that I can create fix for that. Is it a bug?)

Thank you for your answer,
Regards
Martin

[jbarrez]

No I think it's correct. I have put sysouts after each moveBySeconds() and saw the following.

The process instance is started. I will use the timings i have here.

* The process was started at 11:07:03

Iteration 1:
* The timer is moved by 64 seconds. Time is now 11:08:12
* The timer is moved 1 second. Time was now 11:08:18 (remember, the job executor polls every x seconds (5 I believe), hence why these times aren't exact)

Iteration 2:
* The timer is moved by 64 seconds. Time is now 11:09:27
* The timer is moved 1 second. Time was now 11:09:31

Iteration 3:
* The timer is moved by 64 seconds. Time is now 11:10:42
* The timer is moved 1 second. Time was now 11:10:48

Iteration 4:
* The timer is moved by 64 seconds. Time is now 11:11:57
* The timer is moved 1 second. Time was now 11:12:03

Oh-oh. That is exact T + (4 * 1minute). The job executor inspects the start time and sees it should fire NOW.
So what is happening is correct.

It also explains why your timings of 'create time' go up. Each iteration, we're already passed the :03 mark, and the job executor simple takes the current time.

[martin_grofcik]

Hi Joram,

* The timer is moved by 64 seconds. Time is now 11:11:57
* The timer is moved 1 second. Time was now 11:12:03

Oh-oh. That is exact T + (4 * 1minute). The job executor inspects the start time and sees it should fire NOW.

the 1 minute period between 11:11:57 and 11:12:03 period was not kept.  it means that when period is 1 minute it can be still executed earlier.

Regards
Marti

[jbarrez]

> the 1 minute period between 11:11:57 and 11:12:03 period was not kept. it means that when period is 1 minute it can be still executed
> earlier.

No, the due date calculate has changed to take in account the start time, and calculates repetitions from that point on.  I get what you are saying ('no interval of one minute), hoewever, the duedate calculation has been changed to take in account the job start time, and counts intervals from that starting point.


The problem here that in this test, the moveByMinutes + the variable polling of the job executor influences the measurements here. It would be a total different outcome, if the the job executor just keeps running as-is.