### Error querying database. Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
### The error may exist in URL [jar:file:/D:/maven/repo/com/xquant/platform/component/xquant-platform-component-quota/1.3.10.15/xquant-platform-component-quota-1.3.10.15.jar!/sqlMapper/QuotaInstMapper.xml]
### The error may involve defaultParameterMap
### The error occurred while setting parameters
### SQL: SELECT QUOTA_INST_ID,PARENT_QUOTA_INST_ID,BATCH_ID,DOC_NO,DOC_TYPE,PARENT_DOC_NO,PARENT_DOC_TYPE,TRD_TYPE, BIZ_TYPE,I_CODE,A_TYPE,M_TYPE,H_I_CODE,H_M_TYPE,H_A_TYPE,PARTY_ID,ISSUER_ID,P_CLASS,P_TYPE, CASH_ACCT_ID,EXT_CASH_ACCT_ID,SECU_ACCT_ID,EXT_SECU_ACCT_ID,VOLUME,REMAIN_VOLUME,CANCEL_VOLUME, NET_PRICE,NET_PRICE_AMOUNT,REMAIN_NET_PRICE_AMOUNT,FULL_PRICE,FULL_PRICE_AMOUNT,REMAIN_FULL_PRICE_AMOUNT, END_YTM,STRIKE_YTM,TOTAL_AI,REMAIN_TOTAL_AI,SETTLE_AMOUNT,REMAIN_SETTLE_AMOUNT,CANCEL_SETTLE_AMOUNT,ORD_DATE, CASH_SET_DATE,SECU_SET_DATE,SET_DAYS,SET_TYPE,DIRECTION,LIMIT_STATUS,CL_STATUS,SPV_ID,QUOTA_STATUS,CURRENCY, REMAIN_FREEZE_VOLUME,REMAIN_FREEZE_SETTLE_AMOUNT,BEG_VOLUME FROM TTRD_XCC_QUOTA_INST WHERE BATCH_ID = ? FOR UPDATE
### Cause: com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
; SQL []; Lock wait timeout exceeded; try restarting transaction; nested exception is com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction
at java.util.concurrent.FutureTask.report(FutureTask.java:122)
at java.util.concurrent.FutureTask.get(FutureTask.java:192)
at com.xquant.platform.test.util.ExecutorServiceUtil.lambda$submitAll$3(ExecutorServiceUtil.java:48)
... 65 more
Caused by: org.springframework.dao.CannotAcquireLockException:
执行如下命令查询数据库：show engine innodb status
=====================================
2020-03-28 12:10:47 7fe563df7700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 25 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 19584 srv_active, 0 srv_shutdown, 2643084 srv_idle
srv_master_thread log flush and writes: 2662667
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 58793
OS WAIT ARRAY INFO: signal count 60054
Mutex spin waits 97460, rounds 1105782, OS waits 27314
RW-shared spins 37346, rounds 1075708, OS waits 30033
RW-excl spins 353, rounds 34594, OS waits 671
Spin rounds per wait: 11.35 mutex, 28.80 RW-shared, 98.00 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
2020-03-28 09:52:05 7fe551de9700
*** (1) TRANSACTION:
TRANSACTION 3303283, ACTIVE 0 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1184, 12 row lock(s)
MySQL thread id 2489, OS thread handle 0x7fe56a1b8700, query id 12707252 192.168.7.201 xir_trdj Sending data
SELECT
QUOTA_INST_ID,PARENT_QUOTA_INST_ID,BATCH_ID,DOC_NO,DOC_TYPE,PARENT_DOC_NO,PARENT_DOC_TYPE,TRD_TYPE,
BIZ_TYPE,I_CODE,A_TYPE,M_TYPE,H_I_CODE,H_M_TYPE,H_A_TYPE,PARTY_ID,ISSUER_ID,P_CLASS,P_TYPE,
CASH_ACCT_ID,EXT_CASH_ACCT_ID,SECU_ACCT_ID,EXT_SECU_ACCT_ID,VOLUME,REMAIN_VOLUME,CANCEL_VOLUME,
NET_PRICE,NET_PRICE_AMOUNT,REMAIN_NET_PRICE_AMOUNT,FULL_PRICE,FULL_PRICE_AMOUNT,REMAIN_FULL_PRICE_AMOUNT,
END_YTM,STRIKE_YTM,TOTAL_AI,REMAIN_TOTAL_AI,SETTLE_AMOUNT,REMAIN_SETTLE_AMOUNT,CANCEL_SETTLE_AMOUNT,ORD_DATE,
CASH_SET_DATE,SECU_SET_DATE,SET_DAYS,SET_TYPE,DIRECTION,LIMIT_STATUS,CL_STATUS,SPV_ID,QUOTA_STATUS,CURRENCY,
REMAIN_FREEZE_VOLUME,REMAIN_FREEZE_SETTLE_AMOUNT,BEG_VOLUME
FROM
TTRD_XCC_QUOTA_INST
WHERE
BATCH_ID = 327670
FOR UPDATE
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1176 page no 3 n bits 80 index `PRIMARY` of table `trdj`.`TTRD_XCC_QUOTA_INST` trx table locks 1 total table locks 2 trx id 3303283 lock_mode X locks rec but not gap waiting lock hold time 0 wait time before grant 0
*** (2) TRANSACTION:
TRANSACTION 3303282, ACTIVE 0 sec starting index read
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1184, 7 row lock(s)
MySQL thread id 2488, OS thread handle 0x7fe551de9700, query id 12707255 192.168.7.201 xir_trdj Sending data
SELECT
QUOTA_INST_ID,PARENT_QUOTA_INST_ID,BATCH_ID,DOC_NO,DOC_TYPE,PARENT_DOC_NO,PARENT_DOC_TYPE,TRD_TYPE,
BIZ_TYPE,I_CODE,A_TYPE,M_TYPE,H_I_CODE,H_M_TYPE,H_A_TYPE,PARTY_ID,ISSUER_ID,P_CLASS,P_TYPE,
CASH_ACCT_ID,EXT_CASH_ACCT_ID,SECU_ACCT_ID,EXT_SECU_ACCT_ID,VOLUME,REMAIN_VOLUME,CANCEL_VOLUME,
NET_PRICE,NET_PRICE_AMOUNT,REMAIN_NET_PRICE_AMOUNT,FULL_PRICE,FULL_PRICE_AMOUNT,REMAIN_FULL_PRICE_AMOUNT,
END_YTM,STRIKE_YTM,TOTAL_AI,REMAIN_TOTAL_AI,SETTLE_AMOUNT,REMAIN_SETTLE_AMOUNT,CANCEL_SETTLE_AMOUNT,ORD_DATE,
CASH_SET_DATE,SECU_SET_DATE,SET_DAYS,SET_TYPE,DIRECTION,LIMIT_STATUS,CL_STATUS,SPV_ID,QUOTA_STATUS,CURRENCY,
REMAIN_FREEZE_VOLUME,REMAIN_FREEZE_SETTLE_AMOUNT,BEG_VOLUME
FROM
TTRD_XCC_QUOTA_INST
WHERE
BATCH_ID = 327670
FOR UPDATE
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 1176 page no 3 n bits 80 index `PRIMARY` of table `trdj`.`TTRD_XCC_QUOTA_INST` trx table locks 1 total table locks 2 trx id 3303282 lock_mode X locks rec but not gap lock hold time 0 wait time before grant 0
*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 1176 page no 3 n bits 80 index `PRIMARY` of table `trdj`.`TTRD_XCC_QUOTA_INST` trx table locks 1 total table locks 2 trx id 3303282 lock_mode X locks rec but not gap waiting lock hold time 0 wait time before grant 0
*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 3303663
Purge done for trx's n:o < 3303661 undo n:o < 0 state: running but idle
History list length 8
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 2520, OS thread handle 0x7fe563df7700, query id 12708423 192.168.7.201 xir_trdj init
show engine innodb status
---TRANSACTION 3302903, not started
MySQL thread id 2472, OS thread handle 0x7fe56a203700, query id 12706574 192.168.7.201 xir_trdj
---TRANSACTION 1955587, not started
MySQL thread id 1, OS thread handle 0x7fe56a24e700, query id 0 Waiting for requests
---TRANSACTION 3303662, ACTIVE 2991 sec
1 lock struct(s), heap size 360, 0 row lock(s)
MySQL thread id 2516, OS thread handle 0x7fe551de9700, query id 12708392 192.168.7.201 xir_trdj
Trx #rec lock waits 2 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 3303661, ACTIVE 2999 sec
1 lock struct(s), heap size 1184, 0 row lock(s)
MySQL thread id 2518, OS thread handle 0x7fe56a1b8700, query id 12708396 192.168.7.201 xir_trdj
Trx #rec lock waits 3 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
---TRANSACTION 3303622, ACTIVE 4166 sec
3 lock struct(s), heap size 1184, 12 row lock(s), undo log entries 63
MySQL thread id 2493, OS thread handle 0x7fe563d61700, query id 12708363 192.168.7.201 xir_trdj
Trx #rec lock waits 0 #table lock waits 0
Trx total rec lock wait time 0 SEC
Trx total table lock wait time 0 SEC
--------
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
129050 OS file reads, 647935 OS file writes, 375993 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, 5 merges
merged operations:
insert 0, delete mark 5, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 5093042961
Log flushed up to 5093042961
Pages flushed up to 5093042961
Last checkpoint at 5093042961
Max checkpoint age 80826164
Checkpoint age target 78300347
Modified age 0
Checkpoint age 0
0 pending log writes, 0 pending chkp writes
299073 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 140574720; in additional pool allocated 0
Total memory allocated by read views 376
Internal hash tables (constant factor + variable factor)
Adaptive hash index 2397792 (2213368 + 184424)
Page hash 139112 (buffer pool 0 only)
Dictionary cache 3586512 (554768 + 3031744)
File system 1725312 (812272 + 913040)
Lock system 336680 (332872 + 3808)
Recovery system 0 (0 + 0)
Dictionary memory allocated 3031744
Buffer pool size 8191
Buffer pool size, bytes 134201344
Free buffers 1024
Database pages 7156
Old database pages 2621
Modified db pages 0
Percent of dirty pages(LRU & free pages): 0.000
Max dirty pages percent: 75.000
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 8226, not young 971523
0.00 youngs/s, 0.00 non-youngs/s
Pages read 128007, created 1084, written 324202
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: 7156, 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
3 RW transactions active inside InnoDB
0 RO transactions active inside InnoDB
3 out of 1000 descriptors used
Main thread process no. 1793, id 140622585378560, state: sleeping
Number of rows inserted 2679680, updated 777771, deleted 2668140, read 50093492
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
Number of system rows inserted 0, updated 0, deleted 0, read 0
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
从日志中可以看出分析出导致死锁的SQL语句和锁定的数据条数。
TRANSACTION 3303283
mysql tables in use 1, locked 1
LOCK WAIT 4 lock struct(s), heap size 1184, 12 row lock(s)
TRANSACTION 3303282
mysql tables in use 1, locked 1
4 lock struct(s), heap size 1184, 7 row lock(s)
当前数据库中该表一共有数据条数：
本来只想锁定前五条记录，结果将整个表都锁定了，那么什么情况下会导致行锁升级为表锁呢？
- 未给对应的字段添加索引（BATCH_ID）
- 普通索引而且属性值重复率高
参考博客：https://msd.misuland.com/pd/3053059875815820666
扫一扫
220
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
