Innodb并发写入死锁

• 最近遇到两个线程同时消费两地kafka数据，并将数据写入Mysql库，出现死锁。两地kafka数据来自上游同一数据源。
• 通过一番查阅后，原来是插入数据包含主键，会先获取主键的S锁检查主键重复性，再获取X锁写入数据。两个线程可能同时写相同数据，就可能会同时持有S锁，然后申请X锁，出现死锁
• 通过本地多次模拟，概率性出现1次死锁场景，报错信息：Deadlock found when trying to get lock; Try restarting transaction

mysql> show engine innodb status \G;
*************************** 1. row ***************************
  Type: InnoDB
  Name:
Status:
=====================================
2019-01-20 21:38:03 0xde8 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 40 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 2671 srv_active, 0 srv_shutdown, 25375 srv_idle
srv_master_thread log flush and writes: 0
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 7675
OS WAIT ARRAY INFO: signal count 9298
RW-shared spins 541923, rounds 544051, OS waits 2496
RW-excl spins 150026, rounds 443360, OS waits 3456
RW-sx spins 22, rounds 526, OS waits 15
Spin rounds per wait: 1.00 RW-shared, 2.96 RW-excl, 23.91 RW-sx
------------------------
LATEST DETECTED DEADLOCK #最近死锁信息
------------------------
2019-01-20 18:42:56 0x13f0
*** (1) TRANSACTION:  #第一个事务
TRANSACTION 62632, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 70, OS thread handle 4816, query id 92010 localhost 127.0.0.1 ro
ot update
insert ignore into qua_result(qua_id,qua_result,qua_grp_id,doc_nbr,db_tim,source
)
        values

            (
            '0',
            '0',
            'Y',
            '0',
            '2019-01-19 20:01:00.0',
            'a'
            )
         ,
            (

*** (1) WAITING FOR THIS LOCK TO BE GRANTED: #第一个事务等待X锁,由于死锁信息只打印部分，这里隐含了事务1持有S锁（使用索引都会用到S锁），数据含有索引那么锁在索引上，如果无索引则锁在表上
RECORD LOCKS space id 9 page no 4 n bits 216 index PRIMARY of table `test`.`qua_
result` trx id 62632 lock_mode X locks rec but not gap waiting
Record lock, heap no 56 PHYSICAL RECORD: n_fields 8; compact format; info bits 1
60
 0: len 1; hex 30; asc 0;;
 1: len 1; hex 30; asc 0;;
 2: len 1; hex 59; asc Y;;
 3: len 1; hex 30; asc 0;;
 4: len 6; hex 00000000f4a4; asc       ;;
 5: len 7; hex 020000013b0110; asc     ;  ;;
 6: len 5; hex 99a2274040; asc   '@@;;
 7: len 10; hex 61202020202020202020; asc a         ;;

*** (2) TRANSACTION: #第二个事务
TRANSACTION 62631, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 69, OS thread handle 5104, query id 92008 localhost 127.0.0.1 ro
ot update
insert ignore into qua_result(qua_id,qua_result,qua_grp_id,doc_nbr,db_tim,source
)
        values

            (
            '0',
            '0',
            'Y',
            '0',
            '2019-01-19 20:01:00.0',
            'b'
            )
			,
            (

*** (2) HOLDS THE LOCK(S): #第二个事务持有S锁
RECORD LOCKS space id 9 page no 4 n bits 216 index PRIMARY of table `test`.`qua_
result` trx id 62631 lock mode S
Record lock, heap no 56 PHYSICAL RECORD: n_fields 8; compact format; info bits 1
60
 0: len 1; hex 30; asc 0;;
 1: len 1; hex 30; asc 0;;
 2: len 1; hex 59; asc Y;;
 3: len 1; hex 30; asc 0;;
 4: len 6; hex 00000000f4a4; asc       ;;
 5: len 7; hex 020000013b0110; asc     ;  ;;
 6: len 5; hex 99a2274040; asc   '@@;;
 7: len 10; hex 61202020202020202020; asc a         ;;

*** (2) WAITING FOR THIS LOCK TO BE GRANTED: #第二个事务等待X锁
RECORD LOCKS space id 9 page no 4 n bits 216 index PRIMARY of table `test`.`qua_
result` trx id 62631 lock_mode X locks rec but not gap waiting
Record lock, heap no 56 PHYSICAL RECORD: n_fields 8; compact format; info bits 1
60
 0: len 1; hex 30; asc 0;;
 1: len 1; hex 30; asc 0;;
 2: len 1; hex 59; asc Y;;
 3: len 1; hex 30; asc 0;;
 4: len 6; hex 00000000f4a4; asc       ;;
 5: len 7; hex 020000013b0110; asc     ;  ;;
 6: len 5; hex 99a2274040; asc   '@@;;
 7: len 10; hex 61202020202020202020; asc a         ;;

*** WE ROLL BACK TRANSACTION (2)
------------
TRANSACTIONS
------------
Trx id counter 241180
Purge done for trx's n:o < 240109 undo n:o < 0 state: running but idle
History list length 40
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 281475324249920, not started
0 lock struct(s), heap size 1136, 0 row lock(s)
--------
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] , aio writes: [0, 0, 0, 0] ,
 ibuf aio reads:, log i/o's:, sync i/o's:
Pending flushes (fsync) log: 0; buffer pool: 0
914 OS file reads, 12234 OS file writes, 1673 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 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 2 buffer(s)
Hash table size 34679, node heap has 3 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 3 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
Hash table size 34679, node heap has 0 buffer(s)
0.00 hash searches/s, 0.00 non-hash searches/s
---
LOG
---
Log sequence number          30753854
Log buffer assigned up to    30753854
Log buffer completed up to   30753854
Log written up to            30753854
Log flushed up to            30753854
Added dirty pages up to      30753854
Pages flushed up to          30753854
Last checkpoint at           30753854
10499 log i/o's done, 0.00 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 137363456
Dictionary memory allocated 379876
Buffer pool size   8192
Free buffers       6933
Database pages     1251
Old database pages 441
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 873, created 378, written 1483
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: 1251, 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
Process ID=2084, Main thread ID=0000000000000D64 , state=sleeping
Number of rows inserted 35320, updated 313, deleted 34420, read 53230
0.00 inserts/s, 0.00 updates/s, 0.00 deletes/s, 0.00 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================

1 row in set (0.00 sec)

ERROR:
No query specified

mysql>

转载于:https://my.oschina.net/u/3960369/blog/3003846