High CPU Usage when Idle (Camunda V7.4)

Camunda 7 Topics Discussion & Questions
1

I am having an issue with High CPU Usage persisting even after all the jobs are completed. I use a layer above Camunda to schedule 200 Process Instances to run. Once all 200 instances finish the CPU Usage stays high until I shutdown Camunda. And after I restart Camunda the CPU Usage stays low.

When I look at the CPU Usage on my Mac, I can see the majority of the load is in mysqld and Bootstrap.

I am using Camunda version 7.4. Hopefully this is an issue fixed in a later version of Camunda.

Here is a Thread Dump to maybe help understand this more:

“Thread-7” prio=10 tid=0x00002ac060760800 nid=0x6a3c runnable [0x00002ac05d832000]
java.lang.Thread.State: RUNNABLE
at java.util.HashMap.getEntry(HashMap.java:465)
at java.util.HashMap.get(HashMap.java:417)
at org.apache.ibatis.reflection.Reflector.getGetterType(Reflector.java:406)
at org.apache.ibatis.reflection.MetaClass.getGetterType(MetaClass.java:103)
at org.apache.ibatis.reflection.MetaClass.metaClassForProperty(MetaClass.java:98)
at org.apache.ibatis.reflection.MetaClass.hasGetter(MetaClass.java:159)
at org.apache.ibatis.builder.SqlSourceBuilder$ParameterMappingTokenHandler.buildParameterMapping(SqlSourceBuilder.java:82)
at org.apache.ibatis.builder.SqlSourceBuilder$ParameterMappingTokenHandler.handleToken(SqlSourceBuilder.java:66)
at org.apache.ibatis.parsing.GenericTokenParser.parse(GenericTokenParser.java:53)
at org.apache.ibatis.builder.SqlSourceBuilder.parse(SqlSourceBuilder.java:45)
at org.apache.ibatis.scripting.xmltags.DynamicSqlSource.getBoundSql(DynamicSqlSource.java:43)
at org.apache.ibatis.mapping.MappedStatement.getBoundSql(MappedStatement.java:278)
at org.apache.ibatis.executor.CachingExecutor.query(CachingExecutor.java:75)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:108)
at org.apache.ibatis.session.defaults.DefaultSqlSession.selectList(DefaultSqlSession.java:102)
at org.camunda.bpm.engine.impl.db.sql.DbSqlSession.selectList(DbSqlSession.java:87)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.selectListWithRawParameter(DbEntityManager.java:170)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.selectList(DbEntityManager.java:162)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.selectList(DbEntityManager.java:158)
at org.camunda.bpm.engine.impl.db.entitymanager.DbEntityManager.selectList(DbEntityManager.java:147)
at org.camunda.bpm.engine.impl.persistence.entity.JobManager.findNextJobsToExecute(JobManager.java:171)
at org.camunda.bpm.engine.impl.cmd.AcquireJobsCmd.execute(AcquireJobsCmd.java:60)
at org.camunda.bpm.engine.impl.cmd.AcquireJobsCmd.execute(AcquireJobsCmd.java:37)
at org.camunda.bpm.engine.impl.interceptor.CommandExecutorImpl.execute(CommandExecutorImpl.java:24)
at org.camunda.bpm.engine.impl.interceptor.CommandContextInterceptor.execute(CommandContextInterceptor.java:95)
at org.camunda.bpm.engine.impl.interceptor.LogInterceptor.execute(LogInterceptor.java:30)
at org.camunda.bpm.engine.impl.jobexecutor.SequentialJobAcquisitionRunnable.acquireJobs(SequentialJobAcquisitionRunnable.java:131)
at org.camunda.bpm.engine.impl.jobexecutor.SequentialJobAcquisitionRunnable.run(SequentialJobAcquisitionRunnable.java:58)
locked <0x0000000781e14b58> (a org.camunda.bpm.engine.impl.jobexecutor.SequentialJobAcquisitionRunnable)
at java.lang.Thread.run(Thread.java:745)
“Thread-7” prio=10 tid=0x00002ac060760800 nid=0x6a3c runnable [0x00002ac05d832000]
java.lang.Thread.State: RUNNABLE
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)

Any help or insight on this will be greatly appreciated.

Thank you!

Jim

2

CPU usage could be high because Camunda hasn’t finished flushing out the job history or something. If you suspect that MySQL is consuming the resources, turn on the “general_log” option in MySQL and see what statements it is executing. You can also log into MySQL and execute ‘SHOW PROCESSLIST;’ To see what is currently executing.

Which Java application server are you using (Tomcat, WildFly)?

3

I think there was a bug that the job executor would constantly try to acquire jobs, even when none are present. Could you check if it is better with 7.6?

4

I will investigate that now. Thanks.

I’m using Tomcat.

5

Thanks for the mysql logging suggestion. Here is my log that repeats very frequently. Probably a few hundred times per second. Was this fixed in V7.6?

2017-05-08 12:15:37.121743 user[user]@ localhost [127.0.0.1] 324 0 Query SET autocommit=0
2017-05-08 12:15:37.121739 user[user]@ localhost [127.0.0.1] 307 0 Query SET autocommit=0
2017-05-08 12:15:37.121483 user[user]@ localhost [127.0.0.1] 324 0 Query SET autocommit=1
2017-05-08 12:15:37.121478 user[user]@ localhost [127.0.0.1] 307 0 Query SET autocommit=1
2017-05-08 12:15:37.121174 user[user]@ localhost [127.0.0.1] 307 0 Query select
RES.*
from ACT_RU_JOB RES

where (RES.RETRIES_ > 0)
  and (RES.DUEDATE_ is null or RES.DUEDATE_ <= '2017-05-08 12:15:37.12')
  and (RES.LOCK_OWNER_ is null or RES.LOCK_EXP_TIME_ < '2017-05-08 12:15:37.12')
  and RES.SUSPENSION_STATE_ = 1

   
    and (RES.DEPLOYMENT_ID_ is null
     
      or
      RES.DEPLOYMENT_ID_ in
         (  
          '956d22d9-341e-11e7-aae5-10ddb1f387ea'
         ) 
     
    )
   
 
LIMIT 3 OFFSET 0

2017-05-08 12:15:37.121101 user[user]@ localhost [127.0.0.1] 324 0 Query select
RES.*
from ACT_RU_JOB RES

where (RES.RETRIES_ > 0)
  and (RES.DUEDATE_ is null or RES.DUEDATE_ <= '2017-05-08 12:15:37.12')
  and (RES.LOCK_OWNER_ is null or RES.LOCK_EXP_TIME_ < '2017-05-08 12:15:37.12')
  and RES.SUSPENSION_STATE_ = 1

   
    and (RES.DEPLOYMENT_ID_ is null
     
      or
      RES.DEPLOYMENT_ID_ in
         (  
          '956d22d9-341e-11e7-aae5-10ddb1f387ea'
         ) 
     
    )
   
 
LIMIT 3 OFFSET 0

2017-05-08 12:15:37.120858 user[user]@ localhost [127.0.0.1] 324 0 Query select @@session.tx_read_only
2017-05-08 12:15:37.120821 user[user]@ localhost [127.0.0.1] 307 0 Query select @@session.tx_read_only
2017-05-08 12:15:37.120618 user[user]@ localhost [127.0.0.1] 324 0 Query SET autocommit=0
2017-05-08 12:15:37.120612 user[user]@ localhost [127.0.0.1] 307 0 Query SET autocommit=0
2017-05-08 12:15:37.120391 user[user]@ localhost [127.0.0.1] 324 0 Query SET autocommit=1
2017-05-08 12:15:37.120292 user[user]@ localhost [127.0.0.1] 307 0 Query SET autocommit=1

6

Firstly, Camunda is an incredibly chatty application with its back end database. Don’t read the volume of queries as being a problem, it’s normal. Moreover, examining the Camunda queries can be difficult because they use an abstraction layer called MyBatis. This means it’s easy for them to create the complicated queries they use, but doesn’t help if you’re examining those queries. I’ve looked at some of them and they are extremely large.

You should migrate to 7.6 first and test again. There’s no point in using that older version and as Thorben suggests, it was probably fixed.

7

Hi @jamesfwood,

This looks like this bug mentioned by Thorben.
You have to upgrade to get rid of it.

Cheers,
Christian