Error after parallel async tasks

[fconrady]

Hi,

I tried to create a minimal example where two async service tasks run in parallel. For this I used the async job executor and I made the parallel gateway async and exclusive, as instructed in Tijs' blog entry:
http://bpmn20inaction.blogspot.ca/2014/07/activiti-516-feature-preview.html

The code is in the attached parallel.txt zip file.

I run Main.java as a Java application in Eclipse. The two tasks are executed, but then the process ends up printing the following message and hangs.
SEVERE: activitiy or FailedJobRetryTimerCycleValue is null in job 14'. only decrementing retries.

What am I missing?

Thanks
Florian

Started example.
Jul 24, 2015 4:14:36 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions
INFO: Loading XML bean definitions from class path resource [activiti.cfg.xml]
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on engine with resource org/activiti/db/create/activiti.h2.create.engine.sql
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on history with resource org/activiti/db/create/activiti.h2.create.history.sql
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource
INFO: performing create on identity with resource org/activiti/db/create/activiti.h2.create.identity.sql
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.ProcessEngineImpl <init>
INFO: ProcessEngine default created
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor start
INFO: Starting up the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs
INFO: Creating thread pool queue of size 100
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs
INFO: Creating executor service with corePoolSize 2, maxPoolSize 10 and keepAliveTime 5000
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run
INFO: {} starting to acquire async jobs due
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run
INFO: {} starting to acquire async jobs due
Jul 24, 2015 4:14:40 PM org.activiti.engine.impl.bpmn.deployer.BpmnDeployer deploy
INFO: Processing resource Parallel.bpmn
Finished example.
Parallel strand 1
Parallel strand 2
Jul 24, 2015 4:14:43 PM org.activiti.engine.impl.cmd.JobRetryCmd execute
SEVERE: activitiy or FailedJobRetryTimerCycleValue is null in job 14'. only decrementing retries.

[jbarrez]

That message can be ignored. It has actually been lowered to debug in the current release.

Thanks for the good maven example, that helps a lot.
The process instance does not hang.

Adding following code to your example fixes it:

<code>
while (processEngine.getRuntimeService().createProcessInstanceQuery().count() > 0) {
   System.out.println("Process still running");
   Thread.sleep(1000L);
  }
  System.out.println("Process instance completed");
  processEngine.close();
</code>

[fconrady]

Thanks, I added the code snippet, but it does not behave the way I would like. To make this more explicit I added timestamps to the parallel tasks and I added a third task that depends on the first two parallel ones (see the attached zip file parallel2.txt).

After the first two tasks are executed, the process waits for about 20 seconds, printing "Process still running" and then it executes the third one.

You say that the error is lowered to debug in the current release. As far as I understand, 5.17.0 is the current release and this is the version specified in pom.xml. Is there a more recent release that I should use?

Thanks
Florian

Started example.

Jul 29, 2015 2:18:31 PM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions

INFO: Loading XML bean definitions from class path resource [activiti.cfg.xml]

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on engine with resource org/activiti/db/create/activiti.h2.create.engine.sql

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on history with resource org/activiti/db/create/activiti.h2.create.history.sql

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on identity with resource org/activiti/db/create/activiti.h2.create.identity.sql

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.ProcessEngineImpl <init>

INFO: ProcessEngine default created

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor start

INFO: Starting up the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs

INFO: Creating thread pool queue of size 100

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs

INFO: Creating executor service with corePoolSize 2, maxPoolSize 10 and keepAliveTime 5000

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run

INFO: {} starting to acquire async jobs due

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run

INFO: {} starting to acquire async jobs due

Jul 29, 2015 2:18:34 PM org.activiti.engine.impl.bpmn.deployer.BpmnDeployer deploy

INFO: Processing resource Parallel.bpmn

Process still running

Parallel strand 1 at 20150729-14:18:36.468

Parallel strand 2 at 20150729-14:18:36.469

Jul 29, 2015 2:18:36 PM org.activiti.engine.impl.cmd.JobRetryCmd execute

SEVERE: activitiy or FailedJobRetryTimerCycleValue is null in job 15'. only decrementing retries.

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Process still running

Serial strand at 20150729-14:18:54.474

Process instance completed

Jul 29, 2015 2:18:54 PM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor shutdown

INFO: Shutting down the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].

Jul 29, 2015 2:18:54 PM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run

INFO: {} stopped async job due acquisition

Jul 29, 2015 2:18:54 PM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run

INFO: {} stopped async job due acquisition

Finished example.

[grahamjohnson80]

That log level was lowered in these commits:

https://github.com/Activiti/Activiti/commit/e10fb4a2fa797c81b9ab8052793527a3cb80cd73
https://github.com/Activiti/Activiti/commit/806ac390a63a561759a5995ed24283391e6e8d4d

Which will be in 5.18.0, which (according to comment http://forums.activiti.org/comment/30678#comment-30678) will be released in the next couple of days.

It would be nice if the typo in that message ("activitiy" were fixed too )

[fconrady]

Thanks, I updated to 5.18.0 and now the example works as intended. It is attached as parallel3.txt.

Florian


Started example.

Aug 04, 2015 9:54:45 AM org.springframework.beans.factory.xml.XmlBeanDefinitionReader loadBeanDefinitions

INFO: Loading XML bean definitions from class path resource [activiti.cfg.xml]

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on engine with resource org/activiti/db/create/activiti.h2.create.engine.sql

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on history with resource org/activiti/db/create/activiti.h2.create.history.sql

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.db.DbSqlSession executeSchemaResource

INFO: performing create on identity with resource org/activiti/db/create/activiti.h2.create.identity.sql

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.ProcessEngineImpl <init>

INFO: ProcessEngine default created

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor start

INFO: Starting up the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs

INFO: Creating thread pool queue of size 100

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor startExecutingAsyncJobs

INFO: Creating executor service with corePoolSize 2, maxPoolSize 10 and keepAliveTime 5000

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run

INFO: {} starting to acquire async jobs due

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run

INFO: {} starting to acquire async jobs due

Aug 04, 2015 9:54:49 AM org.activiti.engine.impl.bpmn.deployer.BpmnDeployer deploy

INFO: Processing resource Parallel.bpmn

Process still running

Parallel task 1 started at 20150804-09:54:52.014

Parallel task 2 started at 20150804-09:54:52.018

Process still running

Parallel task 1 finished at 20150804-09:54:53.076

Parallel task 2 finished at 20150804-09:54:53.080

Process still running

Serial task at 20150804-09:54:53.631

Process instance completedAug 04, 2015 9:54:54 AM org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor shutdown

INFO: Shutting down the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].



Aug 04, 2015 9:54:54 AM org.activiti.engine.impl.asyncexecutor.AcquireTimerJobsRunnable run

INFO: {} stopped async job due acquisition

Aug 04, 2015 9:54:54 AM org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable run

INFO: {} stopped async job due acquisition

Finished example.