Hyland Connect

markv · ‎06-16-2015

Hi…

I'm seeing a consistent issue with Time Cycles and TimerStartEvents in v5.17.0. The manifestation is that for a fixed repeat count (i.e. R5/PT1M) roughly the first half of the repeats will occur on the expected interval (1 minute in this example) and the remainder will occur in a very short time. This behavior is reproduceable for testing I've done with R10/PT5M, R5/PT1M, and other time cycle values, and I've got a unit test case that reproduces it. Here's the log for one run, with the Time cycle set to R10/PT1M. In this case, the first 6 iterations occur at the expected intervals, and the remainder (5 rather than the expected 4 iterations) occur within a second. Should I log an issue in Jira for this?


10:03:28,519 [main] INFO  org.springframework.beans.factory.xml.XmlBeanDefinitionReader  - Loading XML bean definitions from class path resource [activiti.cfg.xml]
10:03:34,780 [main] INFO  org.activiti.engine.impl.db.DbSqlSession  - performing create on engine with resource org/activiti/db/create/activiti.h2.create.engine.sql
10:03:35,040 [main] INFO  org.activiti.engine.impl.db.DbSqlSession  - performing create on history with resource org/activiti/db/create/activiti.h2.create.history.sql
10:03:35,152 [main] INFO  org.activiti.engine.impl.db.DbSqlSession  - performing create on identity with resource org/activiti/db/create/activiti.h2.create.identity.sql
10:03:35,182 [main] INFO  org.activiti.engine.impl.ProcessEngineImpl  - ProcessEngine default created
10:03:35,247 [main] INFO  org.activiti.engine.impl.jobexecutor.JobExecutor  - Starting up the JobExecutor[org.activiti.engine.impl.jobexecutor.DefaultJobExecutor].
10:03:35,286 [Thread-1] INFO  org.activiti.engine.impl.jobexecutor.AcquireJobsRunnableImpl  - JobExecutor[org.activiti.engine.impl.jobexecutor.DefaultJobExecutor] starting to acquire jobs
10:03:35,384 [main] INFO  org.activiti.engine.impl.bpmn.deployer.BpmnDeployer  - Processing resource org/activiti/test/ServiceTaskTimerTest.bpmn
10:03:39,852 [main] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:03:39.5770
10:03:39,857 [main] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:03:39.8560
10:04:40,438 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:04:40.4380
10:04:40,439 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:04:40.4390
10:05:40,449 [pool-1-thread-2] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:05:40.4490
10:05:40,450 [pool-1-thread-2] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:05:40.4500
10:06:40,471 [pool-1-thread-3] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:06:40.4710
10:06:40,472 [pool-1-thread-3] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:06:40.4720
10:07:40,501 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:07:40.5010
10:07:40,507 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:07:40.5070
10:08:40,529 [pool-1-thread-2] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.5290
10:08:40,530 [pool-1-thread-2] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.5300
10:08:40,549 [pool-1-thread-3] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.5490
10:08:40,552 [pool-1-thread-3] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.5520
10:08:40,568 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.5680
10:08:40,569 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.5690
10:08:40,588 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.5880
10:08:40,589 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.5890
10:08:40,618 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.6180
10:08:40,625 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.6250
10:08:40,849 [pool-1-thread-1] INFO  org.activiti.ServiceTaskOne  - ServiceTaskOne.execute(): Starting at: 16-Jun-2015 10:08:40.8490
10:08:40,851 [pool-1-thread-1] INFO  org.activiti.ServiceTaskTwo  - ServiceTaskTwo.execute(): Executing at: 16-Jun-2015 10:08:40.8510
‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍‍

martin_grofcik · ‎06-17-2015

Hi Mark,
Interesting.
Create jUnit test on github.
http://forums.activiti.org/content/sticky-how-write-unit-test

Regards
Martin

jbarrez · ‎06-17-2015

We did some changes on the 5.18 master branch recently, when we saw something similar as you

Would be good to have a unit test so we can verify it on 5.18

markv · ‎06-17-2015

Gentlemen, thanks for your prompt attention to this. We are currently investigating using Activiti for use in a two year Java development effort, and plan on using much of the timer functionality. I've created ACT-4022 for this issue, and attached a unit test zip with the log listed above enclosed.

martin_grofcik · ‎06-17-2015

5.18.0-SNAPSHOT fixes the issue.
see https://activiti.atlassian.net/browse/ACT-4022?focusedCommentId=10605&page=com.atlassian.jira.plugin...

Regards
Martin

markv · ‎06-17-2015

Excellent. Thanks for your prompt action, again, Martin.

Hyland Connect

TimerStartEvent Time Cycle Interval Issue