Job Executor in shared Environment not adquiring Jobs

Hi All,

Apologies if I repeat my question but I can’t figure out the solution in all the topics I’ve read.

I’m having a issue with job executors. I’ve followed many topics and Camunda Documentation but my system doesn’t work as I expected.

I have 2 tomcat servers installed in my laptop from the Tomcat distribution. These servers share the database and they have the same configuration in bpm-platform.xml (but the hostname):

  <job-executor>
    <job-acquisition name="default">
      <properties>
        <property name="maxJobsPerAcquisition">5</property>
        <property name="waitTimeInMillis">8000</property>
        <property name="lockTimeInMillis">400000</property>
      </properties>
    </job-acquisition>
    <properties>
      <!-- Note: the following properties only take effect in a Tomcat environment -->
      <property name="queueSize">3</property>
      <property name="corePoolSize">5</property>
      <property name="maxPoolSize">10</property>
      <property name="keepAliveTime">0</property>
    </properties>
  </job-executor>

  <process-engine name="default">
    <job-acquisition>default</job-acquisition>
    <configuration>org.camunda.bpm.engine.impl.cfg.StandaloneProcessEngineConfiguration</configuration>
    <datasource>java:jdbc/ProcessEngine</datasource>

    <properties>
      <property name="history">none</property>
      <property name="databaseSchemaUpdate">false</property>
      <property name="authorizationEnabled">true</property>
      **<property name="jobExecutorDeploymentAware">false</property>**
      <property name="historyCleanupBatchWindowStartTime">00:01</property>
      <property name="jobExecutorActivate">true</property>
      <property name="hostname">server-1</property>
    </properties>

Besides, I have an application that invokes one of the server’s REST API to create a process instance. This process have a multi instance parallel subprocess with an asyncBefore=true in the start event.

My issue is that only one job-executor is executed (where the REST API is invoked).

I have logged the jobexecutor and I can see that both of them are running:

Server 1:

04-Jun-2021 17:46:17.093 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
**04-Jun-2021 17:46:17.093 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job**
04-Jun-2021 17:46:17.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 5 jobs for process engine 'default': [[ffce9662-c54b-11eb-9848-366d7d8a56fc, ffcebd77-c54b-11eb-9848-366d7d8a56fc, ffcee48c-c54b-11eb-9848-366d7d8a56fc, ffcee491-c54b-11eb-9848-366d7d8a56fc, ffcf0ba6-c54b-11eb-9848-366d7d8a56fc]]
04-Jun-2021 17:46:17.099 DETALLADO [Thread-5] **org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14023 Execute jobs for process engine 'default': [ffce9662-c54b-11eb-9848-366d7d8a56fc, ffcebd77-c54b-11eb-9848-366d7d8a56fc, ffcee48c-c54b-11eb-9848-366d7d8a56fc, ffcee491-c54b-11eb-9848-366d7d8a56fc, ffcf0ba6-c54b-11eb-9848-366d7d8a56fc]**

Server 2:

04-Jun-2021 17:45:27.525 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:45:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:45:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59997 millis
04-Jun-**2021 17:46:27.526 DE**TALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:46:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:46:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis
04-Jun-2021 17:47:27.526 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:47:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:47:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis

I suppose my problem is for invoking only one of the servers via REST and the other job executor don’t notice about those new jobs.

Ho can I deal with these issue? Shall I persist the jobs in other way?

Thank you very much for your help.

Are you creating enough jobs in your test? There aren’t quite enough logs there for me to tell. Is it as simple as there were only 5 jobs and the first acquisition thread to check picked up those jobs?

It might help to upload a full set of logs from each engine and generate enough data that both have a chance to pick up jobs.

Hi @jgigliotti.

Thank you very much for your answer.

I’m sorry, I didn’t share the whole log because of length, There are a lot of traces in the process that are mixed with job-executor’s. I’ve removed them to share with you.

Server 1

04-Jun-2021 17:46:17.088 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.088 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:46:17.088 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.089 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.090 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.091 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.092 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.093 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.093 DETALLADO [http-nio-8081-exec-3] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14017 Notifying Job Executor of new job notifying job executor of new job
04-Jun-2021 17:46:17.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 5 jobs for process engine 'default': [[ffce9662-c54b-11eb-9848-366d7d8a56fc, ffcebd77-c54b-11eb-9848-366d7d8a56fc, ffcee48c-c54b-11eb-9848-366d7d8a56fc, ffcee491-c54b-11eb-9848-366d7d8a56fc, ffcf0ba6-c54b-11eb-9848-366d7d8a56fc]]
04-Jun-2021 17:46:17.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14023 Execute jobs for process engine 'default': [ffce9662-c54b-11eb-9848-366d7d8a56fc, ffcebd77-c54b-11eb-9848-366d7d8a56fc, ffcee48c-c54b-11eb-9848-366d7d8a56fc, ffcee491-c54b-11eb-9848-366d7d8a56fc, ffcf0ba6-c54b-11eb-9848-366d7d8a56fc]
04-Jun-2021 17:46:17.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:46:17.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 7998 millis
04-Jun-2021 17:46:25.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:46:25.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:46:25.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 15998 millis
04-Jun-2021 17:46:41.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:46:41.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:46:41.101 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 31998 millis
04-Jun-2021 17:47:00.772 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:47:00.779 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 5 jobs for process engine 'default': [[ffcf0bab-c54b-11eb-9848-366d7d8a56fc, ffcf0bb0-c54b-11eb-9848-366d7d8a56fc, ffcf32c5-c54b-11eb-9848-366d7d8a56fc, ffcf32ca-c54b-11eb-9848-366d7d8a56fc, ffcf32cf-c54b-11eb-9848-366d7d8a56fc]]
04-Jun-2021 17:47:00.779 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14023 Execute jobs for process engine 'default': [ffcf0bab-c54b-11eb-9848-366d7d8a56fc, ffcf0bb0-c54b-11eb-9848-366d7d8a56fc, ffcf32c5-c54b-11eb-9848-366d7d8a56fc, ffcf32ca-c54b-11eb-9848-366d7d8a56fc, ffcf32cf-c54b-11eb-9848-366d7d8a56fc]
04-Jun-2021 17:47:00.781 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:47:00.781 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 7998 millis
04-Jun-2021 17:47:08.779 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:47:08.780 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:47:08.780 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 15999 millis
....

Server 2 (at the same time)

04-Jun-2021 17:45:27.525 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:45:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:45:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59997 millis
04-Jun-2021 17:46:27.526 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:46:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:46:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis
04-Jun-2021 17:47:27.526 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:47:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:47:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis
04-Jun-2021 17:48:27.526 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:48:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:48:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis
04-Jun-2021 17:49:27.526 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:49:27.540 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:49:27.540 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59987 millis
04-Jun-2021 17:50:27.527 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:50:27.531 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:50:27.531 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59996 millis
04-Jun-2021 17:51:27.527 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:51:27.530 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:51:27.530 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59998 millis
04-Jun-2021 17:52:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:52:27.532 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:52:27.532 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59996 millis
04-Jun-2021 17:53:27.528 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14012 Job acquisition thread woke up
04-Jun-2021 17:53:27.532 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 0 jobs for process engine 'default': []
04-Jun-2021 17:53:27.532 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14011 Job acquisition thread sleeping for 59996 millis

As you can see, both job executors are running but only one executed the jobs (ther server where I invoked POST /process-definition/key/KEY/start).

Also, I can see more than 5 jobs persisted in ACT_RU_JOBS table but only 5 locked by the same owner.

In both servers, an StandaloneProcessEngineConfiguration is configured:

 <process-engine name="default">
    <job-acquisition>default</job-acquisition>
    <configuration>org.camunda.bpm.engine.impl.cfg.StandaloneProcessEngineConfiguration</configuration>
    <datasource>java:jdbc/ProcessEngine</datasource>

Is it right? Can this configuration be the problem?

Thank you so much

Based just on the data you have here, this looks fine. You’re only generating 5 jobs, so the first acquisition thread is going to grab all 5 and complete them (notice there are 0 before and 0 after). Looking at the timestamps, the acquisition threads on each engine are offset by a full 30 seconds, so they’re not really even competing, one will always win and take all 5.

To have a more complete picture, you need to either generate more jobs (10, 15, 20 – start many new instances of that KEY with your POST). You could probably also drop the maxJobsPerAcquisition config down to 1 (for testing purposes). But still, you might find that one thread zips through all 5 before the other engine’s thread gets to the next polling cycle.

Hi @jgigliotti ,

If I’m not confused, there are more than 5 jobs created. If I review the server1’s log, I can see 5 jobs acquired at 17:46:17 and 5 jobs acquired at 17:47:00 (they have different ids)

04-Jun-2021 17:46:17.099 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 5 jobs for process engine 'default': [[ffce9662-c54b-11eb-9848-366d7d8a56fc, ffcebd77-c54b-11eb-9848-366d7d8a56fc, ffcee48c-c54b-11eb-9848-366d7d8a56fc, ffcee491-c54b-11eb-9848-366d7d8a56fc, ffcf0ba6-c54b-11eb-9848-366d7d8a56fc]]
04-Jun-2021 17:47:00.779 DETALLADO [Thread-5] org.camunda.commons.logging.BaseLogger.logDebug ENGINE-14022 Acquired 5 jobs for process engine 'default': [[ffcf0bab-c54b-11eb-9848-366d7d8a56fc, ffcf0bb0-c54b-11eb-9848-366d7d8a56fc, ffcf32c5-c54b-11eb-9848-366d7d8a56fc, ffcf32ca-c54b-11eb-9848-366d7d8a56fc, ffcf32cf-c54b-11eb-9848-366d7d8a56fc]]

However, in the other server I never see this acquisition.

I’m going to try with a lower number of maxJobPerAcquisition.

Thanks

Using that parametrization doesn’t work as expected (only server1 executes)

ACT_RU_JOBS table:

e4c78d66-c5ce-11eb-beb8-761da56fa0d6	2	message	2021-06-05 09:30:54	761fb202-390e-49fc-be8d-90a221147983	1	e4c76652-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c7b47b-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c78d67-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c7b480-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c7b47c-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c7db95-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c7b481-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c7db9a-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c7db96-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c802af-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c7db9b-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c802b4-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c802b0-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c829c9-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c802b5-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c829ce-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c829ca-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c850e3-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c829cf-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c877f8-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c850e4-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c877fd-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c877f9-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c89f12-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c89f0e-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c8c627-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c89f13-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c8ed3c-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c8c628-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c8ed41-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c8ed3d-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c91456-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c8ed42-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c93b6b-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c91457-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c96280-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c93b6c-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c98995-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c96281-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c9899a-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c98996-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c9b0af-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c9899b-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c9b0b4-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c9b0b0-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c9d7c9-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c9b0b5-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15
e4c9d7ce-c5ce-11eb-beb8-761da56fa0d6	1	message			1	e4c9d7ca-c5ce-11eb-beb8-761da56fa0d6	e4bf0230-c5ce-11eb-beb8-761da56fa0d6	KEY:161:b7529c51-c542-11eb-bab2-366d7d8a56fc	KEY	     3						0	async-continuation	activity-start-create-scope	b74c34af-c542-11eb-bab2-366d7d8a56fc	1	0	5a5877f9-c543-11eb-9093-366d7d8a56fc	1		2021-06-05 09:23:15```

Hi,

I’ve been doing different tests but I don’t achieve both job-executors execute in parallel.

The only way I can see both servers executing their job-executors is unchecking the “Exclusive” checkbox in the asyncBefore start event.

Is this the expected behaviour? Can’t both job-executors excute in parallel on exclusive jobs?

Thanks

More on exclusive jobs here.

I’m still not seeing anything that jumps out as being wrong. In your logs for server 1, I see 5 jobs picked up at 17:46:17.099 and 5 jobs picked up at 17:47:00.779. There are several polls in between that come up with 0 jobs, so you don’t have a steady stream of jobs, it’s just a burst of 5 then a burst of 5.

The relevant timestamps for server 2 are 17:46:27.528 and 17:47:27.528. In both cases, the thread comes in late after server 1 has already grabbed the only available jobs.

I can’t say for certain that nothing is wrong here, I’m just saying there isn’t enough data. If server 1 was consistently pulling 5 jobs for every single run, indicating a steady stream of jobs and server 2 still had none, I’d say something wasn’t right. The fact that your test with the exclusive attribute divides up the work different tells me that server 2 is connected correctly and with sufficient load, you’d see a better distribution of jobs across both servers.

1 Like

Hi @jgigliotti,

Thank you for your answer.

What I don’t understand is the next quote:

Why isn’t the first execution you mention about server2 (at 17:46:27.528) grabbing the jobs of the second acquisiton of server1 (at 17:47:00.779)? I tkink, they should be “available” for the server 2 in that momment.

Thank you again.

My assumption (maybe wrongly?) was that jobs just hadn’t been created yet. It may be helpful to run another test where you let it log for a bit and watch that both servers are acquiring 0 jobs. Then periodically start a new instance that creates more jobs (maybe several instances to increase the number of jobs).

It might also be useful to turn the job executor off on server 1, that way you can re-verify that server 2 is processing jobs from that database and the active deployments (I say re-verify because you’ve already seen them execute on both servers with your exclusive=false test).

To me it still looks like server 1 happened to win, but some of these cases it’s just a matter of overlooking a small detail or missing info.