How to unit test boundary event Timers

Hi Guys,

I am trying to write a unit test (junit4) to test a boundary timer will take me to the next expected task following the time reached. I have used the ProcessEngineConfig to set the process engine clock forward so that timer should fire. However, the timer does not seem to fire. I assume that the job has not fired when I test to see if next task has been reached. So is there support for testing timers.

Thanks for any advice.

Brian

Hi Brian,

When you want to have full control over the execution of the timer job it’s best to do something like is done is this test:

If you want to use the job executor to handle it, then you can use the JobTestHelper for example:

Hope this helps.

Best regards,

Tijs

Hi Tijs,

Thanks for that pointer. I have it working now.

Regards

Brian

Hey, I’m also trying to test a BPMN with a timer in it. So I tried to use suggestion above.
The timer is fired and the service task following the timer is executed on calling

job = managementService.moveTimerToExecutableJob(job.getId());

but the job execution method throws OptimisticLockingException

managementService.executeJob(jobAway.getId());

When I remove the last call I guess the test is not thread safe anymore because sometimes the asserts I wrote for the process state fail.

I tried to use the PluggableFlowableTestCase but I’m testing in a Spring Boot environment and I did not manage to get the test case working together with @SpringBootTest.

Can somebody help me?

Thanks in advance!

Hi Schuettec,

Sorry, been away for a while. I wrote a blog on how I tested the timer. It can be found here https://www.seedbpm.com/615/testing-timers-in-flowable/

Have you tried making the timer exclusive as well.

I hope it helps.

Regards

Brian

Thanks for sharing that Brian, very useful!

Hi there,

the mentioned solution does not work in our Spring Boot context. As soon as we execute the timer job manually

    Job timer = managementService.createTimerJobQuery().singleResult();
    managementService.moveTimerToExecutableJob(timer.getId());
    managementService.executeJob(timer.getId());

we get an FlowableOptimisticLockingException. We added an event listener to find out what is happing. It seems that the call of executeJob(…) will execute the job twice: in the main thread and in the executor thread - followed by the FlowableOptimisticLockingException.

Process definition:

<?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:xsd="http://www.w3.org/2001/XMLSchema" xmlns:flowable="http://flowable.org/bpmn" xmlns:bpmndi="http://www.omg.org/spec/BPMN/20100524/DI" xmlns:omgdc="http://www.omg.org/spec/DD/20100524/DC" xmlns:omgdi="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.flowable.org/processdef">
  <process id="longRunningTimerProcess" name="longRunningTimerProcess" isExecutable="true">
    <startEvent id="startEvent1"></startEvent>
    <scriptTask id="printTimeBefore" name="printTimeBefore" scriptFormat="groovy" flowable:autoStoreVariables="false">
      <script><![CDATA[String date = processEngine.getProcessEngineConfiguration().getClock().getCurrentTime().toString();
println("Current date and time: " + date);]]></script>
    </scriptTask>
    <intermediateCatchEvent id="waitTimer" name="waitTimer">
      <timerEventDefinition>
        <timeDuration>PT5S</timeDuration>
      </timerEventDefinition>
    </intermediateCatchEvent>
    <scriptTask id="printTimeAfter" name="printTimeAfter" scriptFormat="groovy" flowable:autoStoreVariables="false">
      <script><![CDATA[String date = processEngine.getProcessEngineConfiguration().getClock().getCurrentTime().toString();
println("Date and time after timer: " + date);]]></script>
    </scriptTask>
    <sequenceFlow id="sid-589E06DD-ADE0-407B-8AAE-33CCF24C17AC" sourceRef="startEvent1" targetRef="printTimeBefore"></sequenceFlow>
    <sequenceFlow id="sid-6BED58FA-0D97-4126-B07B-70CCD82B2F08" sourceRef="waitTimer" targetRef="printTimeAfter"></sequenceFlow>
    <endEvent id="endevent1" name="End"></endEvent>
    <sequenceFlow id="flow1" sourceRef="printTimeAfter" targetRef="endevent1"></sequenceFlow>
    <sequenceFlow id="sid-DDADF96E-3CB7-4731-B585-24BC278F73A2" sourceRef="printTimeBefore" targetRef="waitTimer"></sequenceFlow>
  </process>
  <bpmndi:BPMNDiagram id="BPMNDiagram_longRunningTimerProcess">
    <bpmndi:BPMNPlane bpmnElement="longRunningTimerProcess" id="BPMNPlane_longRunningTimerProcess">
      <bpmndi:BPMNShape bpmnElement="startEvent1" id="BPMNShape_startEvent1">
        <omgdc:Bounds height="30.0" width="30.0" x="60.0" y="150.0"></omgdc:Bounds>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNShape bpmnElement="printTimeBefore" id="BPMNShape_printTimeBefore">
        <omgdc:Bounds height="80.0" width="100.0" x="165.0" y="125.0"></omgdc:Bounds>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNShape bpmnElement="waitTimer" id="BPMNShape_waitTimer">
        <omgdc:Bounds height="31.0" width="31.0" x="345.0" y="149.0"></omgdc:Bounds>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNShape bpmnElement="printTimeAfter" id="BPMNShape_printTimeAfter">
        <omgdc:Bounds height="80.0" width="100.0" x="450.0" y="125.0"></omgdc:Bounds>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNShape bpmnElement="endevent1" id="BPMNShape_endevent1">
        <omgdc:Bounds height="28.0" width="28.0" x="600.0" y="148.0"></omgdc:Bounds>
      </bpmndi:BPMNShape>
      <bpmndi:BPMNEdge bpmnElement="sid-589E06DD-ADE0-407B-8AAE-33CCF24C17AC" id="BPMNEdge_sid-589E06DD-ADE0-407B-8AAE-33CCF24C17AC">
        <omgdi:waypoint x="89.94999906759469" y="165.0"></omgdi:waypoint>
        <omgdi:waypoint x="165.0" y="165.0"></omgdi:waypoint>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNEdge bpmnElement="flow1" id="BPMNEdge_flow1">
        <omgdi:waypoint x="549.9499999999998" y="163.68421052631578"></omgdi:waypoint>
        <omgdi:waypoint x="600.0047468824858" y="162.3669807816862"></omgdi:waypoint>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNEdge bpmnElement="sid-DDADF96E-3CB7-4731-B585-24BC278F73A2" id="BPMNEdge_sid-DDADF96E-3CB7-4731-B585-24BC278F73A2">
        <omgdi:waypoint x="264.9499999999939" y="164.82817869415805"></omgdi:waypoint>
        <omgdi:waypoint x="345.00008708167013" y="164.55309260007016"></omgdi:waypoint>
      </bpmndi:BPMNEdge>
      <bpmndi:BPMNEdge bpmnElement="sid-6BED58FA-0D97-4126-B07B-70CCD82B2F08" id="BPMNEdge_sid-6BED58FA-0D97-4126-B07B-70CCD82B2F08">
        <omgdi:waypoint x="375.94988254463453" y="164.55537621708532"></omgdi:waypoint>
        <omgdi:waypoint x="450.0" y="164.82078853046596"></omgdi:waypoint>
      </bpmndi:BPMNEdge>
    </bpmndi:BPMNPlane>
  </bpmndi:BPMNDiagram>
</definitions>

The unit test:

@Test
@Deployment(resources = {"test/longRunningTimerProcess.bpmn"})
public void testSkipTimer() {
    processEngine.getRuntimeService().addEventListener(createFlowableEventListener());
    processEngine.getRuntimeService().startProcessInstanceByKey(LONG_RUNNING_PROCESS);

    ManagementService managementService = processEngine.getManagementService();

    Job timer = managementService.createTimerJobQuery().singleResult();
    managementService.moveTimerToExecutableJob(timer.getId());
    managementService.executeJob(timer.getId());

    assertTimeoutPreemptively(Duration.ofMillis(10000), () -> {
        while (true) {
            if (runtimeService.createProcessInstanceQuery().active().singleResult() == null) {
                return;
            }

            Thread.sleep(100);
        }
    });
}

And the log output:

2019-04-23 08:33:31.139  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [startEvent1]
2019-04-23 08:33:31.141  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [sid-589E06DD-ADE0-407B-8AAE-33CCF24C17AC]
Current date and time: Tue Apr 23 08:33:31 CEST 2019
2019-04-23 08:33:31.455  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [printTimeBefore]
2019-04-23 08:33:31.455  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [sid-DDADF96E-3CB7-4731-B585-24BC278F73A2]
2019-04-23 08:33:31.519  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [waitTimer]
2019-04-23 08:33:31.519  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [sid-6BED58FA-0D97-4126-B07B-70CCD82B2F08]
2019-04-23 08:33:31.520  INFO H --- [ecutor-thread-1] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [waitTimer]
2019-04-23 08:33:31.520  INFO H --- [ecutor-thread-1] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [sid-6BED58FA-0D97-4126-B07B-70CCD82B2F08]
Date and time after timer: Tue Apr 23 08:33:31 CEST 2019
2019-04-23 08:33:31.532  INFO H --- [ecutor-thread-1] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [printTimeAfter]
2019-04-23 08:33:31.532  INFO H --- [ecutor-thread-1] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [flow1]
2019-04-23 08:33:31.533  INFO H --- [ecutor-thread-1] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [endevent1]
Date and time after timer: Tue Apr 23 08:33:31 CEST 2019
2019-04-23 08:33:31.537  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [printTimeAfter]
2019-04-23 08:33:31.537  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [flow1]
2019-04-23 08:33:31.538  INFO H --- [           main] c.a.s.p.t.t.TriggerTimerTest             - {} : [5] [longRunningTimerProcess:1:4] [endevent1]

org.flowable.common.engine.api.FlowableOptimisticLockingException: Execution[ id '6' ] - activity 'endevent1' - parent '5' was updated by another transaction concurrently

	at org.flowable.common.engine.impl.db.DbSqlSession.flushUpdates(DbSqlSession.java:505)
	at org.flowable.common.engine.impl.db.DbSqlSession.flush(DbSqlSession.java:292)

Different combinations of async and exclusive did not change the behaviour. If the test just waits for the one second, everything works fine. If we remove the executeJob(…) call, also no exception.

Is it intendend that the timer job is picked up twice?

Best regards

Hi,

When calling the moveTimerToExecutableJob method you get back a job instance which should be used to call the executeJob method instead of the original timer job id.

Best regards,

Tijs

Hi tijs,

using the returned job does not solve the problem…

The adapted unit test:

	@Test
@Deployment(resources = {"test/longRunningTimerProcess.bpmn"})
public void testSkipTimer() {
	processEngine.getRuntimeService().addEventListener(createFlowableEventListener());
	processEngine.getRuntimeService().startProcessInstanceByKey(LONG_RUNNING_PROCESS);

	ManagementService managementService = processEngine.getManagementService();

	Job timer = managementService.createTimerJobQuery().singleResult();
	Job executableJob = managementService.moveTimerToExecutableJob(timer.getId());
	managementService.executeJob(executableJob.getId());

	assertTimeoutPreemptively(Duration.ofMillis(10000), () -> {
		while (true) {
			if (runtimeService.createProcessInstanceQuery().active().singleResult() == null) {
				return;
			}

			Thread.sleep(100);
		}
	});
}

Ok thanks, did you disable the async executor in your process engine configuration? Because otherwise that async executor will try to execute the job after calling the moveTimerToExecutableJob method as well as your manual call to executeJob.

Best regards,

Tijs

As we want to test our processes like in production environment, changing the config is not the best approach as the asyncExecutor will be needed. Furthermore, not every timer should be triggered manually. Sometimes timers should be triggered just by running into the defined due date.

Maybe you could mention the coincidence of asyncExecutor and executeJob(…) somewhere.

What is the consequence of using just moveTimerToExecutableJob(…) without calling executeJob(…)?

We solved this problem by setting the date/time of the whole process engine later than the expected due date.

Job timer = managementService.createTimerJobQuery().singleResult();
Clock clock = processEngine.getProcessEngineConfiguration().getClock();
clock.setCurrentTime(timer.getDuedate());
processEngine.getProcessEngineConfiguration().setClock(clock);

Yes I understand. Moving the clock can be used to trick the async executor to not pick up the job yet, which is fine for a unit test. Another solution would be to indeed only call the moveTimerToExecutableJob method and then do a thread sleep for 5 seconds or so. Then the async executor should have fetched the job and executed it as well.

Best regards,

Tijs

1 Like