[
https://issues.apache.org/jira/browse/AMQ-9307?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Bharath Kumar CM updated AMQ-9307:
----------------------------------
Component/s: JDBC
Affects Version/s: 5.17.2
Issue Type: Bug (was: Dependency upgrade)
Priority: Blocker (was: Major)
> Error while closing connection: Deadlock found when trying to get lock; try
> restarting transaction
> --------------------------------------------------------------------------------------------------
>
> Key: AMQ-9307
> URL: https://issues.apache.org/jira/browse/AMQ-9307
> Project: ActiveMQ
> Issue Type: Bug
> Components: JDBC
> Affects Versions: 5.17.2
> Reporter: Bharath Kumar CM
> Priority: Blocker
>
> Getting below error on ActiveMQ log, looking for some solution to find the
> root cause and fix for this issue.
> {code:java}
> Sep 6 16:10:46 SERVER activemq_db8159[1168628]: WARN | Error while closing
> connection: Deadlock found when trying to get lock; try restarting transaction
> Sep 6 16:10:46 SERVER activemq_db8159[1168628]:
> java.sql.BatchUpdateException: Deadlock found when trying to get lock; try
> restarting transaction{code}
> later ActiveMQ service is being restarting due to restart of the service
> messages are getting stuck for continuous client messages.
>
> {code:java}
> 2023-09-06 16:10:46,332 | INFO | Stopping BrokerService[dbaas_broker] due to
> exception, java.io.IOException: Deadlock found when trying to get lock; try
> restarting transaction | org.apache.activemq.util.DefaultIOExceptionHandler |
> ActiveMQ Transport: ssl:///10.67.13.199:54970
>
> {code}
> JDBC connection:
> {code:java}
> <jdbcPersistenceAdapter dataSource="#mysql-ds" lockKeepAlivePeriod="10000">
> <bean class="org.apache.commons.dbcp2.BasicDataSource" destroy-method="close"
> id="mysql-ds">
> <property name="driverClassName" value="com.mysql.jdbc.Driver" />
> <property name="url"
> value="jdbc:mysql://mysqldb.com:3307/8159_activemq?useSSL=true&requireSSL=true&socketTimeout=10000&connectTimeout=5000&autoReconnect=true&maxReconnects=60"
> />{code}
> version details
> ActiveMQ Version - 5.17.2
> MySQL connector version - mysql-connector-j-8.0.31.jar:8.0.31
> INNODB status:
>
> {code:java}
> MariaDB [(none)]> SHOW ENGINE INNODB STATUS \G;
> *************************** 1. row ***************************
> Type: InnoDB
> Name:
> Status:
> =====================================
> 2023-09-08 05:44:03 0x7fc5ddd00700 INNODB MONITOR OUTPUT
> =====================================
> Per second averages calculated from the last 55 seconds
> -----------------
> BACKGROUND THREAD
> -----------------
> srv_master_thread loops: 658347 srv_active, 0 srv_shutdown, 3052597 srv_idle
> srv_master_thread log flush and writes: 3710151
> ----------
> SEMAPHORES
> ----------
> OS WAIT ARRAY INFO: reservation count 13196031
> OS WAIT ARRAY INFO: signal count 7507305
> RW-shared spins 3175113, rounds 52954335, OS waits 1496241
> RW-excl spins 1004776, rounds 5875228, OS waits 14950
> RW-sx spins 3900, rounds 714889, OS waits 23471
> Spin rounds per wait: 16.68 RW-shared, 5.85 RW-excl, 183.30 RW-sx
> ------------------------
> LATEST DETECTED DEADLOCK
> ------------------------
> 2023-09-07 11:30:08 0x7fc5ec0f5700
> *** (1) TRANSACTION:
> TRANSACTION 59108994, ACTIVE 22 sec fetching rows
> mysql tables in use 2, locked 2
> LOCK WAIT 10 lock struct(s), heap size 1128, 2 row lock(s)
> MySQL thread id 965528, OS thread handle 140488046327552, query id 18506205
> 10.4.28.55 8159_activemq_rw Sending data
> DELETE FROM ACTIVEMQ_MSGS WHERE (PRIORITY=0 AND ID <= ( SELECT
> min(ACTIVEMQ_ACKS.LAST_ACKED_ID) FROM ACTIVEMQ_ACKS WHERE
> ACTIVEMQ_ACKS.CONTAINER=ACTIVEMQ_MSGS.CONTAINER AND
> ACTIVEMQ_ACKS.PRIORITY=0) )
> *** (1) WAITING FOR THIS LOCK TO BE GRANTED:
> RECORD LOCKS space id 62 page no 22720 n bits 96 index PRIMARY of table
> `8159_activemq`.`ACTIVEMQ_MSGS` trx id 59108994 lock_mode X locks rec but not
> gap waiting
> Record lock, heap no 8 PHYSICAL RECORD: n_fields 10; compact format; info
> bits 32
> 0: len 8; hex 800000000000c2db; asc ;;
> 1: len 6; hex 00000385ef32; asc 2;;
> 2: len 7; hex 77000039360733; asc w 96 3;;
> 3: len 20; hex 71756575653a2f2f544f504841545f494e565f46; asc
> queue://TOPHAT_INV_F;;
> 4: len 30; hex 49443a464d5341503331302d34393933362d313639343038303939383932;
> asc ID:FMSAP310-49936-169408099892; (total 41 bytes);
> 5: len 8; hex 8000000000000006; asc ;;
> 6: len 8; hex 8000000000000000; asc ;;
> 7: len 30; hex 000001c91c0000008e00017b01002549443a464d5341503331302d343939;
> asc { %ID:FMSAP310-499; (total 461 bytes);
> 8: len 8; hex 8000000000000000; asc ;;
> 9: SQL NULL;
>
> *** (2) TRANSACTION:
> TRANSACTION 59109170, ACTIVE 1 sec updating or deleting
> mysql tables in use 1, locked 1
> 3 lock struct(s), heap size 1128, 2 row lock(s), undo log entries 1
> MySQL thread id 965524, OS thread handle 140488045713152, query id 18506329
> 10.4.28.55 8159_activemq_rw Updating
> DELETE FROM ACTIVEMQ_MSGS WHERE ID=49883
> *** (2) HOLDS THE LOCK(S):
> RECORD LOCKS space id 62 page no 22720 n bits 96 index PRIMARY of table
> `8159_activemq`.`ACTIVEMQ_MSGS` trx id 59109170 lock_mode X locks rec but not
> gap
> Record lock, heap no 8 PHYSICAL RECORD: n_fields 10; compact format; info
> bits 32
> 0: len 8; hex 800000000000c2db; asc ;;
> 1: len 6; hex 00000385ef32; asc 2;;
> 2: len 7; hex 77000039360733; asc w 96 3;;
> 3: len 20; hex 71756575653a2f2f544f504841545f494e565f46; asc
> queue://TOPHAT_INV_F;;
> 4: len 30; hex 49443a464d5341503331302d34393933362d313639343038303939383932;
> asc ID:FMSAP310-49936-169408099892; (total 41 bytes);
> 5: len 8; hex 8000000000000006; asc ;;
> 6: len 8; hex 8000000000000000; asc ;;
> 7: len 30; hex 000001c91c0000008e00017b01002549443a464d5341503331302d343939;
> asc { %ID:FMSAP310-499; (total 461 bytes);
> 8: len 8; hex 8000000000000000; asc ;;
> 9: SQL NULL;
>
> *** (2) WAITING FOR THIS LOCK TO BE GRANTED:
> RECORD LOCKS space id 62 page no 7 n bits 792 index ACTIVEMQ_MSGS_PIDX of
> table `8159_activemq`.`ACTIVEMQ_MSGS` trx id 59109170 lock_mode X locks rec
> but not gap waiting
> Record lock, heap no 558 PHYSICAL RECORD: n_fields 2; compact format; info
> bits 0
> 0: len 8; hex 8000000000000000; asc ;;
> 1: len 8; hex 800000000000c2db; asc ;;
>
> *** WE ROLL BACK TRANSACTION (2)
> ------------
> TRANSACTIONS
> ------------
> Trx id counter 59338587
> Purge done for trx's n:o < 59338587 undo n:o < 0 state: running but idle
> History list length 0
> LIST OF TRANSACTIONS FOR EACH SESSION:
> ---TRANSACTION 421962821473120, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821456256, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821481552, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821468904, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821477336, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821464688, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821460472, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821452040, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> ---TRANSACTION 421962821447824, not started
> 0 lock struct(s), heap size 1128, 0 row lock(s)
> --------
> FILE I/O
> --------
> I/O thread 0 state: waiting for i/o request (insert buffer thread)
> I/O thread 1 state: waiting for i/o request (log thread)
> I/O thread 2 state: waiting for i/o request (read thread)
> I/O thread 3 state: waiting for i/o request (read thread)
> I/O thread 4 state: waiting for i/o request (read thread)
> I/O thread 5 state: waiting for i/o request (read thread)
> I/O thread 6 state: waiting for i/o request (read thread)
> I/O thread 7 state: waiting for i/o request (read thread)
> I/O thread 8 state: waiting for i/o request (read thread)
> I/O thread 9 state: waiting for i/o request (read thread)
> I/O thread 10 state: waiting for i/o request (read thread)
> I/O thread 11 state: waiting for i/o request (read thread)
> I/O thread 12 state: waiting for i/o request (read thread)
> I/O thread 13 state: waiting for i/o request (read thread)
> I/O thread 14 state: waiting for i/o request (read thread)
> I/O thread 15 state: waiting for i/o request (read thread)
> I/O thread 16 state: waiting for i/o request (read thread)
> I/O thread 17 state: waiting for i/o request (read thread)
> I/O thread 18 state: waiting for i/o request (read thread)
> I/O thread 19 state: waiting for i/o request (read thread)
> I/O thread 20 state: waiting for i/o request (read thread)
> I/O thread 21 state: waiting for i/o request (read thread)
> I/O thread 22 state: waiting for i/o request (read thread)
> I/O thread 23 state: waiting for i/o request (read thread)
> I/O thread 24 state: waiting for i/o request (read thread)
> I/O thread 25 state: waiting for i/o request (read thread)
> I/O thread 26 state: waiting for i/o request (read thread)
> I/O thread 27 state: waiting for i/o request (read thread)
> I/O thread 28 state: waiting for i/o request (read thread)
> I/O thread 29 state: waiting for i/o request (read thread)
> I/O thread 30 state: waiting for i/o request (read thread)
> I/O thread 31 state: waiting for i/o request (read thread)
> I/O thread 32 state: waiting for i/o request (read thread)
> I/O thread 33 state: waiting for i/o request (read thread)
> I/O thread 34 state: waiting for i/o request (read thread)
> I/O thread 35 state: waiting for i/o request (read thread)
> I/O thread 36 state: waiting for i/o request (read thread)
> I/O thread 37 state: waiting for i/o request (read thread)
> I/O thread 38 state: waiting for i/o request (read thread)
> I/O thread 39 state: waiting for i/o request (read thread)
> I/O thread 40 state: waiting for i/o request (read thread)
> I/O thread 41 state: waiting for i/o request (read thread)
> I/O thread 42 state: waiting for i/o request (read thread)
> I/O thread 43 state: waiting for i/o request (read thread)
> I/O thread 44 state: waiting for i/o request (read thread)
> I/O thread 45 state: waiting for i/o request (read thread)
> I/O thread 46 state: waiting for i/o request (read thread)
> I/O thread 47 state: waiting for i/o request (read thread)
> I/O thread 48 state: waiting for i/o request (read thread)
> I/O thread 49 state: waiting for i/o request (read thread)
> I/O thread 50 state: waiting for i/o request (read thread)
> I/O thread 51 state: waiting for i/o request (read thread)
> I/O thread 52 state: waiting for i/o request (read thread)
> I/O thread 53 state: waiting for i/o request (read thread)
> I/O thread 54 state: waiting for i/o request (read thread)
> I/O thread 55 state: waiting for i/o request (read thread)
> I/O thread 56 state: waiting for i/o request (read thread)
> I/O thread 57 state: waiting for i/o request (read thread)
> I/O thread 58 state: waiting for i/o request (read thread)
> I/O thread 59 state: waiting for i/o request (read thread)
> I/O thread 60 state: waiting for i/o request (read thread)
> I/O thread 61 state: waiting for i/o request (read thread)
> I/O thread 62 state: waiting for i/o request (read thread)
> I/O thread 63 state: waiting for i/o request (read thread)
> I/O thread 64 state: waiting for i/o request (read thread)
> I/O thread 65 state: waiting for i/o request (read thread)
> I/O thread 66 state: waiting for i/o request (write thread)
> I/O thread 67 state: waiting for i/o request (write thread)
> I/O thread 68 state: waiting for i/o request (write thread)
> I/O thread 69 state: waiting for i/o request (write thread)
> I/O thread 70 state: waiting for i/o request (write thread)
> I/O thread 71 state: waiting for i/o request (write thread)
> I/O thread 72 state: waiting for i/o request (write thread)
> I/O thread 73 state: waiting for i/o request (write thread)
> I/O thread 74 state: waiting for i/o request (write thread)
> I/O thread 75 state: waiting for i/o request (write thread)
> I/O thread 76 state: waiting for i/o request (write thread)
> I/O thread 77 state: waiting for i/o request (write thread)
> I/O thread 78 state: waiting for i/o request (write thread)
> I/O thread 79 state: waiting for i/o request (write thread)
> I/O thread 80 state: waiting for i/o request (write thread)
> I/O thread 81 state: waiting for i/o request (write thread)
> I/O thread 82 state: waiting for i/o request (write thread)
> I/O thread 83 state: waiting for i/o request (write thread)
> I/O thread 84 state: waiting for i/o request (write thread)
> I/O thread 85 state: waiting for i/o request (write thread)
> I/O thread 86 state: waiting for i/o request (write thread)
> I/O thread 87 state: waiting for i/o request (write thread)
> I/O thread 88 state: waiting for i/o request (write thread)
> I/O thread 89 state: waiting for i/o request (write thread)
> I/O thread 90 state: waiting for i/o request (write thread)
> I/O thread 91 state: waiting for i/o request (write thread)
> I/O thread 92 state: waiting for i/o request (write thread)
> I/O thread 93 state: waiting for i/o request (write thread)
> I/O thread 94 state: waiting for i/o request (write thread)
> I/O thread 95 state: waiting for i/o request (write thread)
> I/O thread 96 state: waiting for i/o request (write thread)
> I/O thread 97 state: waiting for i/o request (write thread)
> Pending normal aio reads: [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0,
> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0,
> 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0] , aio writes:
> [0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0,
> 0, 0, 0, 0, 0, 0, 0] ,
> ibuf aio reads:, log i/o's:, sync i/o's:
> Pending flushes (fsync) log: 0; buffer pool: 0
> 84348099 OS file reads, 45353143 OS file writes, 7813858 OS fsyncs
> 0.00 reads/s, 0 avg bytes/read, 5.60 writes/s, 2.58 fsyncs/s
> -------------------------------------
> INSERT BUFFER AND ADAPTIVE HASH INDEX
> -------------------------------------
> Ibuf: size 1, free list len 0, seg size 2, 326 merges
> merged operations:
> insert 150, delete mark 267, delete 22
> discarded operations:
> insert 0, delete mark 0, delete 0
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> Hash table size 69257, node heap has 1 buffer(s)
> 3.85 hash searches/s, 0.25 non-hash searches/s
> ---
> LOG
> ---
> Log sequence number 2500024278373
> Log flushed up to 2500024276737
> Pages flushed up to 2500024276737
> Last checkpoint at 2500024276128
> 0 pending log flushes, 0 pending chkp writes
> 6087092 log i/o's done, 2.31 log i/o's/second
> ----------------------
> BUFFER POOL AND MEMORY
> ----------------------
> Total large memory allocated 301989888
> Dictionary memory allocated 43920
> Buffer pool size 16054
> Free buffers 1024
> Database pages 15022
> Old database pages 5525
> Modified db pages 50
> Percent of dirty pages(LRU & free pages): 0.312
> Max dirty pages percent: 75.000
> Pending reads 0
> Pending writes: LRU 0, flush list 0, single page 0
> Pages made young 7648268, not young 94650352
> 0.00 youngs/s, 0.00 non-youngs/s
> Pages read 84348078, created 11140151, written 37578055
> 0.00 reads/s, 0.00 creates/s, 2.96 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: 15022, unzip_LRU len: 0
> I/O sum[157]:cur[0], unzip sum[0]:cur[0]
> --------------
> ROW OPERATIONS
> --------------
> 0 queries inside InnoDB, 0 queries in queue
> 0 read views open inside InnoDB
> Process ID=1, Main thread ID=140484596745984, state: sleeping
> Number of rows inserted 55948, updated 665215, deleted 55946, read 8771119
> 0.00 inserts/s, 0.33 updates/s, 0.00 deletes/s, 2.35 reads/s
> Number of system rows inserted 824726, updated 0, deleted 824703, read 824744
> 0.33 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
> ----------------------------
> END OF INNODB MONITOR OUTPUT
> ============================
>
> 1 row in set (0.001 sec)
>
> ERROR: No query specified
>
> MariaDB [(none)]>
> {code}
>
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
