一则MySQL deadlock问题的解决

用户反馈服务器日志中出现大量：Deadlock found when trying to get lock; Try restarting transaction message from server: "Lock wait timeout exceeded; try restarting transaction"；

进行了一段时间loadrunner并发测试并在网上找了很多先行者的文章，之后终于找到了解决的方法：

 

基本条件：

服务器存在两个进程(线程)均需要对同一个table进行插入动作：
表xxshistory(id2,id1,row1,row2)，主键(id2,id1,row1),外键FK_1(id2,id1)
表zzequip主键(id2,id1),含字段netstat

线程1：
    对xxshistory表插入当天数据，如：
    insert into xxshistory(id2,id1,row1,row2)values(?,?,?,?);
线程2：
    对xxshistory表插入当天数据，sql例：
INSERT INTO xxshistory (id1,row1,row2,id2)  SELECT * FROM (SELECT h.id1,'2016-11-30','3 ' , h.id2 FROM xxshistory h LEFT JOIN zzequip s ON h.id1=s.AID AND h.id2=s.id2 AND s.netstat='1' GROUP BY h.id1,h.id2 HAVING MAX(h.row1)<'2016-11-30' ) AS b

-----------------然后就是deadlock
Deadlock found when trying to get lock; Try restarting transaction message from server: "Lock wait timeout exceeded; try restarting transaction"

 

原因：

根据MYSQL EXPLAIN语句的执行结果 线程2的sql在操作中用到了外键索引，而显然线程1的操作是根据主键操作的；

线程1：插入过程，获得主键锁(s锁)，仍需要外键锁，等待对外键FK_1索引加锁(x锁)，

线程2：插入过程，获得外键索引锁(x锁)，仍需申请主键锁，等待对主键加锁(s锁)，

(备注：INSERT可能产生的锁包括检查dup key时的s锁lock mode S locks rec but not gap waiting,
插入意向锁lock_mode X locks gap before rec insert intention waiting)
并发形成死锁； (主键索引锁与非聚簇索引锁冲突)

解决办法：
避免主键索引锁与非聚簇索引锁冲突，在插入操作时都先得到需要操作的记录主键，根据主键插入。
线程2把查询和插入操作拆分，先查询得到对应主键信息：
 " SELECT h.id1,'' ,'' ,h.id2 FROM statushistory h LEFT JOIN zzequip  s ON h.id1=s.AID AND h.id2=s.id2 AND s.netstat='1' "+ "GROUP BY h.id1,h.id2 HAVING MAX(h.row1)<'' ；
在逐条根据主键信息插入。
上述改进解决了deadlock问题，但是会产生主键冲突异常，解决办法是线程1、线程2在插入新记录时均增加ignore关键字以避免主键冲突；

deadlock日志：

=====================================
161130  0:02:54 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 38 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2451 1_second, 2451 sleeps, 228 10_second, 750 background, 750 flush
srv_master_thread log flush and writes: 2663
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 205002, signal count 170785
Mutex spin waits 2454690, rounds 11657610, OS waits 127717
RW-shared spins 55583, rounds 971864, OS waits 20354
RW-excl spins 62517, rounds 1832253, OS waits 40305
Spin rounds per wait: 4.75 mutex, 17.48 RW-shared, 29.31 RW-excl
------------------------
LATEST DETECTED DEADLOCK
------------------------
161130  0:00:01
*** (1) TRANSACTION:
TRANSACTION 15B43CE, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 5 lock struct(s), heap size 1024, 3 row lock(s), undo log entries 1
MySQL thread id 21650, OS thread handle 0x347c, query id 6211894 localhost 127.0.0.1 usrer1 update
insert into xxshistory(id2,id1,row1,row2) values ('-1', 'X83','2016-11-30' ,'7 '  )
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 55130 n bits 672 index `FK_xxshistory` of table `db1`.`xxshistory` trx id 15B43CE lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 288 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 3; hex 583834; asc X84;;
 1: len 2; hex 2d31; asc -1;;
 2: len 3; hex 8fc16e; asc   n;;

*** (2) TRANSACTION:
TRANSACTION 15B352B, ACTIVE 1 sec inserting, thread declared inside InnoDB 500
mysql tables in use 3, locked 3
288 lock struct(s), heap size 44352, 73483 row lock(s), undo log entries 947
MySQL thread id 21608, OS thread handle 0x2c20, query id 6204529 localhost 127.0.0.1 usrer1 Sending data
INSERT INTO xxshistory (id1,row1,row2,id2)  SELECT * FROM (SELECT h.id1,'2016-11-30','3 ' , h.id2 FROM xxshistory h LEFT JOIN zzequiprow2 s ON h.id1=s.AID AND h.id2=s.id2 AND s.netstat='1' GROUP BY h.id1,h.id2 HAVING MAX(h.row1)<'2016-11-30' ) AS b
*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 0 page no 55130 n bits 672 index `FK_xxshistory` of table `db1`.`xxshistory` trx id 15B352B lock mode S
Record lock, heap no 1 PHYSICAL RECORD: n_fields 1; compact format; info bits 0
 0: len 8; hex 73757072656d756d; asc supremum;;

Record lock, heap no 2 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 3; hex 583634; asc X64;;
 1: len 2; hex 2d31; asc -1;;
 2: len 3; hex 8fc176; asc   v;;

 1: len 2; hex 2d31; asc -1;;
 2: len 3; hex 8fc16e; asc   n;;

Record lock, heap no 236 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 3; hex 583830; asc X80;;
 1: len 2; hex 2d31; asc -1;;
 2: len 3; hex 8fc16f; asc   o;;


------------------------中间省略

Record lock, heap no 600 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 3; hex 583732; asc X72;;
 1: len 2; hex 2d31; asc -1;;
 2: len 3; hex 8fc17e; asc   ~;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 0 page no 56536 n bits 200 index `PRIMARY` of table `db1`.`xxshistory` trx id 15B352B lock mode S locks rec but not gap waiting
Record lock, heap no 122 PHYSICAL RECORD: n_fields 6; compact format; info bits 0
 0: len 3; hex 583833; asc X83;;
 1: len 3; hex 8fc17e; asc   ~;;
 2: len 2; hex 2d31; asc -1;;
 3: len 6; hex 0000015b43ce; asc    [C ;;
 4: len 7; hex d70000d9d20110; asc        ;;
 5: len 30; hex 374e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e4e; asc 7NNNNNNNNNNNNNNNNNNNNNNNNNNNNN; (total 96 bytes);

*** WE ROLL BACK TRANSACTION (1)
------------
TRANSACTIONS
------------
Trx id counter 15E0036
Purge done for trx's n:o < 15E0034 undo n:o < 0
History list length 1198
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 22260, OS thread handle 0x1ce0, query id 6544403 localhost 127.0.0.1 root
show engine innodb row2
--------
FILE I/O
--------
I/O thread 0 state: wait Windows aio (insert buffer thread)
I/O thread 1 state: wait Windows aio (log thread)
I/O thread 2 state: wait Windows aio (read thread)
I/O thread 3 state: wait Windows aio (read thread)
I/O thread 4 state: wait Windows aio (read thread)
I/O thread 5 state: wait Windows aio (read thread)
I/O thread 6 state: wait Windows aio (write thread)
I/O thread 7 state: wait Windows aio (write thread)
I/O thread 8 state: wait Windows aio (write thread)
I/O thread 9 state: wait Windows aio (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
8881 OS file reads, 280945 OS file writes, 157745 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 3, seg size 5, 0 merges
merged operations:
 insert 0, delete mark 0, delete 0
discarded operations:
 insert 0, delete mark 0, delete 0
Hash table size 1365571, node heap has 79 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number 3238511178
Log flushed up to   3238511178
Last checkpoint at  3238511178
0 pending log writes, 0 pending chkp writes
153570 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 349536256; in additional pool allocated 0
Dictionary memory allocated 5236825
Buffer pool size   21056
Free buffers       11046
Database pages     9931
Old database pages 3653
Modified db pages  0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 16, not young 0
0.00 youngs/s, 0.00 non-youngs/s
Pages read 8870, created 1061, written 124154
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: 9931, 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
1 read views open inside InnoDB
Main thread id 2792, state: waiting for server activity
Number of rows inserted 363271, updated 1551713, deleted 349439, read 872878012
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================