AnsweredAssumed Answered

Activiti Processes disappearing, requiring a server restart

Question asked by ob2wr on Aug 2, 2017
Latest reply on Aug 2, 2017 by ob2wr

Hello,

We are using Activiti (5.21.0) connected to MySql (15.1). Activiti (web application ) is deployed on Tomcat (8.0.43). Within a gap of 5-7 days we get an issue. All the processes, except for the default Demo Process & Demo Reports  , get un-deployed.  That is we cannot see the processes in Deployments tab or under ‘Deployed process definitions’ tab.  However if we check the ACT_RE_DEPLOYMENT table records are present for each of our BPMN processes.  On restarting tomcat things return to normal.

This is generally happening at the time of Auto-restart of Tomcat for rolling over the logs. But seems that this restart causes memory issues. Please see the log below.

 

29-Jul-2017 14:42:59.065 INFO [main] org.apache.catalina.core.StandardServer.await A valid shutdown command was received via the shutdown port. Stopping the Server instance.

29-Jul-2017 14:42:59.066 INFO [main] org.apache.coyote.AbstractProtocol.pause Pausing ProtocolHandler ["http-nio-8080"]

29-Jul-2017 14:42:59.117 INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service Catalina

02:42:59,121 [localhost-startStop-2] INFO  org.springframework.web.context.support.AnnotationConfigWebApplicationContext  - Closing WebApplicationContext for namespace 'dispatcher-servlet': startup date [Fri Jul 28 17:56:51 BST 2017]; parent: Root WebApplicationContext

02:42:59,141 [localhost-startStop-2] INFO  org.activiti.rest.servlet.WebConfigurer  - Destroying Web application

02:42:59,142 [localhost-startStop-2] INFO  org.springframework.web.context.support.AnnotationConfigWebApplicationContext  - Closing Root WebApplicationContext: startup date [Fri Jul 28 17:56:47 BST 2017]; root of context hierarchy

02:42:59,143 [localhost-startStop-2] INFO  org.activiti.engine.impl.asyncexecutor.AbstractAsyncJobExecutor  - Shutting down the default async job executor [org.activiti.engine.impl.asyncexecutor.DefaultAsyncJobExecutor].

02:42:59,145 [Thread-5] INFO  org.activiti.engine.impl.asyncexecutor.AcquireAsyncJobsDueRunnable  - stopped async job due acquisition

29-Jul-2017 14:42:59.160 WARNING [localhost-startStop-2] org.apache.catalina.loader.WebappClassLoaderBase.clearReferencesThreads The web application [activiti-rest] appears to have started a thread named [Abandoned connection cleanup thread] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:

java.lang.Object.wait(Native Method)

java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143)

com.mysql.jdbc.AbandonedConnectionCleanupThread.run(AbandonedConnectionCleanupThread.java:43)

 

Below is the observation from MySql DB, not sure if this is also causing the issue.

LATEST DETECTED DEADLOCK

 ------------------------

 2017-07-28 16:57:11 2b5721f44700

 *** (1) TRANSACTION:

 TRANSACTION 3186592, ACTIVE 0 sec starting index read

 mysql tables in use 1, locked 1

 LOCK WAIT 11 lock struct(s), heap size 1184, 4 row lock(s), undo log entries 6

 MySQL thread id 351405, OS thread handle 0x2b5721ec2700, query id 10900155 10.95.104.93 opsbank updating

 update ACT_HI_TASKINST set

       PROC_DEF_ID_ = 'escalationExample:1:32515',

       EXECUTION_ID_ = '38254',

       NAME_ = 'First line support',

       PARENT_TASK_ID_ = null,

       DESCRIPTION_ = 'Fix issue raised by customer',

       OWNER_ = null,

       ASSIGNEE_ = 'kermit',

       CLAIM_TIME_ = null,

       END_TIME_ = '2017-07-28 17:57:11.185',

       DURATION_ = 583211182,

       DELETE_REASON_ = 'deleted',

       TASK_DEF_KEY_ = 'firstLineSupport',

       FORM_KEY_ = null,

       PRIORITY_ = 50,

       DUE_DATE_ = null,

       CATEGORY_ = null

     where ID_ = '38257'

 *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

 RECORD LOCKS space id 300 page no 10 n bits 184 index `PRIMARY` of table `activitiopen`.`ACT_HI_TASKINST` trx id 3186592 lock_mode X locks rec but not gap waiting

 Record lock, heap no 112 PHYSICAL RECORD: n_fields 22; compact format; info bits 0

  0: len 5; hex 3338323537; asc 38257;;

  1: len 6; hex 000000309f9f; asc    0  ;;

  2: len 7; hex 600000024a1c02; asc `   J  ;;

  3: len 25; hex 657363616c6174696f6e4578616d706c653a313a3332353135; asc escalationExample:1:32515;;

  4: len 16; hex 66697273744c696e65537570706f7274; asc firstLineSupport;;

  5: len 5; hex 3338323531; asc 38251;;

  6: len 5; hex 3338323534; asc 38254;;

7: len 18; hex 4669727374206c696e6520737570706f7274; asc First line support;;

  8: SQL NULL;

  9: len 28; hex 4669782069737375652072616973656420627920637573746f6d6572; asc Fix issue raised by customer;;

  10: SQL NULL;

  11: len 6; hex 6b65726d6974; asc kermit;;

  12: len 7; hex 999d2b7e40001e; asc   +~@  ;;

  13: SQL NULL;

  14: len 7; hex 999d2c0c621784; asc   , b  ;;

  15: len 8; hex 80000000003022a7; asc      0" ;;

  16: len 9; hex 636f6d706c65746564; asc completed;;

  17: len 4; hex 80000032; asc    2;;

  18: SQL NULL;

  19: SQL NULL;

  20: SQL NULL;

  21: len 0; hex ; asc ;;

 

 *** (2) TRANSACTION:

 TRANSACTION 3186591, ACTIVE 0 sec starting index read

 mysql tables in use 1, locked 1

 30 lock struct(s), heap size 6544, 20 row lock(s), undo log entries 8

 MySQL thread id 351404, OS thread handle 0x2b5721f44700, query id 10900172 10.95.104.93 opsbank updating

 delete from ACT_RU_EXECUTION where ID_ = '38251' and REV_ = 1

 *** (2) HOLDS THE LOCK(S):

 RECORD LOCKS space id 300 page no 10 n bits 184 index `PRIMARY` of table `activitiopen`.`ACT_HI_TASKINST` trx id 3186591 lock_mode X locks rec but not gap

 Record lock, heap no 112 PHYSICAL RECORD: n_fields 22; compact format; info bits 0

  0: len 5; hex 3338323537; asc 38257;;

  1: len 6; hex 000000309f9f; asc    0  ;;

  2: len 7; hex 600000024a1c02; asc `   J  ;;

  3: len 25; hex 657363616c6174696f6e4578616d706c653a313a3332353135; asc escalationExample:1:32515;;

  4: len 16; hex 66697273744c696e65537570706f7274; asc firstLineSupport;;

  5: len 5; hex 3338323531; asc 38251;;

  6: len 5; hex 3338323534; asc 38254;;

  7: len 18; hex 4669727374206c696e6520737570706f7274; asc First line support;;

  8: SQL NULL;

  9: len 28; hex 4669782069737375652072616973656420627920637573746f6d6572; asc Fix issue raised by customer;;

  10: SQL NULL;

  11: len 6; hex 6b65726d6974; asc kermit;;

  12: len 7; hex 999d2b7e40001e; asc   +~@  ;;

  13: SQL NULL;

  14: len 7; hex 999d2c0c621784; asc   , b  ;;

  15: len 8; hex 80000000003022a7; asc      0" ;;

  16: len 9; hex 636f6d706c65746564; asc completed;;

  17: len 4; hex 80000032; asc    2;;

  18: SQL NULL;

  19: SQL NULL;

  20: SQL NULL;

  21: len 0; hex ; asc ;;

 

 *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

 RECORD LOCKS space id 281 page no 3 n bits 248 index `PRIMARY` of table `activitiopen`.`ACT_RU_EXECUTION` trx id 3186591 lock_mode X locks rec but not gap waiting

 Record lock, heap no 175 PHYSICAL RECORD: n_fields 19; compact format; info bits 0

  0: len 5; hex 3338323531; asc 38251;;

  1: len 6; hex 000000309f98; asc    0  ;;

  2: len 7; hex 5c000001d82b76; asc \    +v;;

  3: len 4; hex 80000001; asc     ;;

  4: len 5; hex 3338323531; asc 38251;;

  5: SQL NULL;

  6: SQL NULL;

  7: len 25; hex 657363616c6174696f6e4578616d706c653a313a3332353135; asc escalationExample:1:32515;;

  8: SQL NULL;

  9: SQL NULL;

  10: len 1; hex 80; asc  ;;

  11: len 1; hex 80; asc  ;;

  12: len 1; hex 81; asc  ;;

  13: len 1; hex 80; asc  ;;

  14: len 4; hex 80000001; asc     ;;

  15: len 4; hex 80000002; asc     ;;

  16: len 0; hex ; asc ;;

  17: SQL NULL;

  18: len 6; hex 597b7c230528; asc Y{|# (;;

 

 *** WE ROLL BACK TRANSACTION (1)

 ------------

 TRANSACTIONS

 ------------

 Trx id counter 3228847

 Purge done for trx's n:o < 3228832 undo n:o < 0 state: running but idle

 History list length 2288

 LIST OF TRANSACTIONS FOR EACH SESSION:

 ---TRANSACTION 0, not started

 MySQL thread id 367358, OS thread handle 0x2b57076be700, query id 11230443 10.48.66.88 opsbank init

 SHOW ENGINE INNODB STATUS

 ---TRANSACTION 3228846, not started

 MySQL thread id 30464, OS thread handle 0x2b57076ff700, query id 11230437 localhost 127.0.0.1 rdsadmin cleaning up

 --------

 FILE I/O

 --------

 I/O thread 0 state: waiting for completed aio requests (insert buffer thread)

 I/O thread 1 state: waiting for completed aio requests (log thread)

 I/O thread 2 state: waiting for completed aio requests (read thread)

 I/O thread 3 state: waiting for completed aio requests (read thread)

 I/O thread 4 state: waiting for completed aio requests (read thread)

 I/O thread 5 state: waiting for completed aio requests (read thread)

 I/O thread 6 state: waiting for completed aio requests (write thread)

 I/O thread 7 state: waiting for completed aio requests (write thread)

 I/O thread 8 state: waiting for completed aio requests (write thread)

 I/O thread 9 state: waiting for completed aio requests (write thread)

 Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,

  ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0

 Pending flushes (fsync) log: 0; buffer pool: 0

 1092 OS file reads, 395704 OS file writes, 372957 OS fsyncs

 0.00 reads/s, 0 avg bytes/read, 0.00 writes/s, 0.00 fsyncs/s

 -------------------------------------

 INSERT BUFFER AND ADAPTIVE HASH INDEX

 -------------------------------------

 Ibuf: size 1, free list len 0, seg size 2, 0 merges

 merged operations:

  insert 0, delete mark 0, delete 0

 discarded operations:

  insert 0, delete mark 0, delete 0

 Hash table size 5843809, node heap has 15 buffer(s)

 0.00 hash searches/s, 0.00 non-hash searches/s

 ---

 LOG

 ---

 Log sequence number 58534483

 Log flushed up to   58534483

 Pages flushed up to 58534483

 Last checkpoint at  58534483

 0 pending log writes, 0 pending chkp writes

 118354 log i/o's done, 0.00 log i/o's/second

 ----------------------

 BUFFER POOL AND MEMORY

 ----------------------

 Total memory allocated 3021996032; in additional pool allocated 0

 Dictionary memory allocated 268428

 Buffer pool size   180224

 Free buffers       178654

 Database pages     1555

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 951, created 604, written 152095

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 1555, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ----------------------

 INDIVIDUAL BUFFER POOL INFO

 ----------------------

 ---BUFFER POOL 0

 Buffer pool size   22528

 Free buffers       22326

 Database pages     201

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 164, created 37, written 55513

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 201, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 1

 Buffer pool size   22528

 Free buffers       22324

 Database pages     203

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 75, created 128, written 2027

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 203, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 2

 Buffer pool size   22528

 Free buffers       22397

 Database pages     128

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 62, created 66, written 515

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 128, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 3

 Buffer pool size   22528

 Free buffers       22284

 Database pages     241

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 151, created 90, written 18624

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 241, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 4

 Buffer pool size   22528

 Free buffers       22307

 Database pages     220

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 136, created 84, written 15435

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 220, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 5

 Buffer pool size   22528

 Free buffers       22332

 Database pages     194

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 112, created 82, written 9345

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 194, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 6

 Buffer pool size   22528

 Free buffers       22330

 Database pages     197

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 128, created 69, written 38249

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 197, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 ---BUFFER POOL 7

 Buffer pool size   22528

 Free buffers       22354

 Database pages     171

 Old database pages 0

 Modified db pages  0

 Pending reads 0

 Pending writes: LRU 0, flush list 0, single page 0

 Pages made young 0, not young 0

 0.00 youngs/s, 0.00 non-youngs/s

 Pages read 123, created 48, written 12387

 0.00 reads/s, 0.00 creates/s, 0.00 writes/s

 No buffer pool page gets since the last printout

 Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s

 LRU len: 171, unzip_LRU len: 0

 I/O sum[0]:cur[0], unzip sum[0]:cur[0]

 --------------

 ROW OPERATIONS

 --------------

 0 queries inside InnoDB, 0 queries in queue

 0 read views open inside InnoDB

 Main thread process no. 12056, id 47656132937472, state: sleeping

 Number of rows inserted 20459, updated 41529, deleted 16824, read 4309439

 0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.07 reads/s

 ----------------------------

 END OF INNODB MONITOR OUTPUT

 ============================

 

 

Outcomes