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
< 3228832 undo n < 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
============================
