查询死锁日志
查询死锁日志
登录MySQL，执行
show engine innodb status \G;
可以看到以下日志
LATEST DETECTED DEADLOCK ------------------------ 2019-07-29 11:40:16 0x2b05f879d700 *** (1) TRANSACTION: TRANSACTION 58675337, ACTIVE 0 sec fetching rows mysql tables in use 3, locked 3 LOCK WAIT 54 lock struct(s), heap size 8400, 4 row lock(s) MySQL thread id 5540968, OS thread handle 47304462178048, query id 2483784685 10.4.69.107 aaa_admin Searching rows for update update reimburse_expense set status = 'CLOSED', updated_at = CURRENT_TIMESTAMP(6), updated_by = 'UI181102VQXJFVG' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725WY1I2V4' *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 2268 page no 9219 n bits 96 index PRIMARY of table `maycur-pro`.`reimburse_expense` trx id 58675337 lock_mode X locks rec but not gap waiting Record lock, heap no 29 PHYSICAL RECORD: n_fields 68; compact format; info bits 0 0: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** (2) TRANSACTION: TRANSACTION 58675341, ACTIVE 0 sec fetching rows mysql tables in use 3, locked 3 52 lock struct(s), heap size 8400, 3 row lock(s) MySQL thread id 5542239, OS thread handle 47304643565312, query id 2483784712 10.4.69.107 cur_admin Searching rows for update update reimburse_expense set status = 'CLOSED', updated_at = CURRENT_TIMESTAMP(6), updated_by = 'UI181102VQXJFVG' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725XGELH4W' *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 2268 page no 9219 n bits 96 index PRIMARY of table `xxx-pro`.`reimburse_expense` trx id 58675341 lock_mode X locks rec but not gap Record lock, heap no 29 PHYSICAL RECORD: n_fields 68; compact format; info bits 0 0: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 2268 page no 15201 n bits 328 index idx_reimburse_expense_status of table `maycur-pro`.`reimburse_expense` trx id 58675341 lock_mode X locks rec but not gap waiting Record lock, heap no 191 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 0: len 18; hex 445445433138303931373155354950514652; asc DTEC1809171U5IPQFR;; 1: len 10; hex 50524f43455353494e47; asc PROCESSING;; 2: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** WE ROLL BACK TRANSACTION (2) ------------
MySQL记录的日志不完整，缺少部分可以推断出。
日志所示，
事务一（TRANSACTION 58675337）
等待RECORD LOCKS space id 2268 page no 9219 n bits 96 index PRIMARY of table xxx-pro.reimburse_expense trx id 58675337 lock_mode X locks rec but not gap waiting
Record lock, heap no 29 PHYSICAL RECORD: n_fields 68; compact format; info bits 0
事务二（TRANSACTION 58675341）
持有RECORD LOCKS space id 2268 page no 9219 n bits 96 index PRIMARY of table xxx-pro.reimburse_expensetrx id 58675341 lock_mode X locks rec but not gap Record lock
等待RECORD LOCKS space id 2268 page no 15201 n bits 328 index idx_reimburse_expense_status of table xxx-pro.reimburse_expensetrx id 58675341 lock_mode X locks rec but not gap waiting Record lock
根据据死锁条件可知，
事务一（TRANSACTION 58675337）
持有RECORD LOCKS space id 2268 page no 15201 n bits 328 index idx_reimburse_expense_status of table xxx-pro.reimburse_expensetrx id 58675341 lock_mode X locks rec but not gap waiting Record lock
以上信息表示
事务一持有idx_reimburse_expense_status锁，等了主键锁。
事务二持有主键锁，等待idx_reimburse_expense_status锁。
分析
表reimburse_expense信息，省略了无关字段和索引
create table reimburse_expense_mock ( ent_code varchar(25) not null, code varchar(25) not null, reimburse_data_code varchar(25) null, deleted tinyint(1) default 0 not null, status varchar(16) default 'OPEN' not null, primary key (code), index fee_data_idx03(reimburse_data_code), index idx_reimburse_expense_status(ent_code, status) );
引起死锁的SQL
# update1 update reimburse_expense set status = 'CLOSED', updated_at = CURRENT_TIMESTAMP(6), updated_by = 'UI181102VQXJFVG' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725WY1I2V4' # update2 update reimburse_expense set status = 'CLOSED', updated_at = CURRENT_TIMESTAMP(6), updated_by = 'UI181102VQXJFVG' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725XGELH4W'
理论
RC隔离级别update执行过程
rc级别下，当update中使用了二级索引，执行过程：
- 扫描二级索引，在二级索引上加X锁
- 根据二级索引查询到的主键索引查询行数据，在主键索引上加X锁。验证
- 当行数据不符合查询条件，释放锁；符合，则更新。
- 当二级索引更新，会在未更新和更新后的索引上加X锁。验证
复现
猜测死锁产生的过程如下：
update执行过程：
第一步：update1扫描idx_reimburse_expense_status
第二步：update2扫描fee_data_idx03，这时update1和update2使用的是不同索引，不会阻塞。
第三步：update2使用第二步中扫描到的主键查询行，这个过程使用的是当前读，在主键上加X锁。
第四步：update1扫描的主键恰好是update2锁住的主键，update1使用该主键进行当前读就会发生阻塞。
第五步：update2使用主键更新status，status是二级索引idx_reimburse_expense_status一部分，二级索引发生更新，修改前后的索引都要加锁，而idx_reimburse_expense_status已经在第一步被update1加锁，update2阻塞，产生死锁。
具体步骤
模拟update，复现死锁。
Session1 |
Session2 |
start transaction; |
start transaction; |
1.1 select * from reimburse_expense_mock force index(idx_reimburse_expense_status) where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725WY1I2V4' for update ; |
|
2.1 select from reimburse_expense_mock force index(fee_data_idx03) where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725XGELH4W' for update; |
|
1.2 select * from reimburse_expense_mock where code = 'FD190723XWQE2YO' for update;(阻塞) |
|
2.2 update reimburse_expense_mock force index (idx_reimburse_expense_status) set status = 'closing' where code='FD190723XWQE2YO';（死锁） |
mysql死锁日志。如下
*** (1) TRANSACTION: TRANSACTION 12235990, ACTIVE 30 sec starting index read mysql tables in use 1, locked 1 LOCK WAIT 4 lock struct(s), heap size 1136, 38 row lock(s) MySQL thread id 227, OS thread handle 123145414512640, query id 38609 localhost 127.0.0.1 root statistics /* ApplicationName=IntelliJ IDEA 2019.1.2 */ select * from reimburse_expense_mock where code = 'FD190723XWQE2YO' for update *** (1) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 912 page no 3 n bits 104 index PRIMARY of table `eblank`.`reimburse_expense_mock` trx id 12235990 lock_mode X locks rec but not gap waiting Record lock, heap no 31 PHYSICAL RECORD: n_fields 69; compact format; info bits 0 0: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** (2) TRANSACTION: TRANSACTION 12235991, ACTIVE 27 sec starting index read mysql tables in use 1, locked 1 3 lock struct(s), heap size 1136, 2 row lock(s) MySQL thread id 228, OS thread handle 123145414234112, query id 38619 localhost 127.0.0.1 root Searching rows for update /* ApplicationName=IntelliJ IDEA 2019.1.2 */ update reimburse_expense_mock force index (idx_reimburse_expense_status) set status = 'closing' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and code='FD190723XWQE2YO' *** (2) HOLDS THE LOCK(S): RECORD LOCKS space id 912 page no 3 n bits 104 index PRIMARY of table `eblank`.`reimburse_expense_mock` trx id 12235991 lock_mode X locks rec but not gap Record lock, heap no 31 PHYSICAL RECORD: n_fields 69; compact format; info bits 0 0: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** (2) WAITING FOR THIS LOCK TO BE GRANTED: RECORD LOCKS space id 912 page no 9 n bits 112 index idx_reimburse_expense_status of table `eblank`.`reimburse_expense_mock` trx id 12235991 lock_mode X locks rec but not gap waiting Record lock, heap no 20 PHYSICAL RECORD: n_fields 3; compact format; info bits 0 0: len 18; hex 445445433138303931373155354950514652; asc DTEC1809171U5IPQFR;; 1: len 10; hex 50524f43455353494e47; asc PROCESSING;; 2: len 15; hex 46443139303732335857514532594f; asc FD190723XWQE2YO;; *** WE ROLL BACK TRANSACTION (2)
和生产上的日志相比，加锁方式一致。
验证
二级索引查询
rc级别下update，会对二级索引加锁，再使用二级索引对应的主键进行当前读，锁住主键，读取后如果不符合查询条件，会释放。
使用以下方式证明。SQL1使用了二级索引idx_reimburse_expense_status，SQL2使用主键索引idx_fee_data_code。
# SQL1 update reimburse_expense_mock force index(idx_reimburse_expense_status) set status = 'CLOSED', updated_at = CURRENT_TIMESTAMP(6), updated_by = 'UI181102VQXJFVG' where ent_code = 'DTEC1809171U5IPQFR' and status = 'PROCESSING' and deleted = false and reimburse_data_code = 'BX190725WY1I2V4'; # SQL2 select * from reimburse_expense_mock where code = 'FD190723XWQE2YO' lock in share mode ;
- 先在事务一中执行SQL1，再在事务二中执行SQL2，不会发生阻塞。
- 先在事务一中执行SQL2，再在事务二中执行SQL1，SQL1发生阻塞。
二级索引更新
当二级索引更新，会在未更新和更新后的索引上加X锁。
# SQL1 update reimburse_expense_mock set status = 'closing' where code='FD190723XWQE2YO'; # SQL2 select * from reimburse_expense_mock force index(idx_reimburse_expense_status) where ent_code = 'DTEC1809171U5IPQFR' and status = 'processing' for update; # SQL3 select * from reimburse_expense_mock force index(idx_reimburse_expense_status) where ent_code = 'DTEC1809171U5IPQFR' and status = 'closing' for update;
二级索引更新时，未更新的索引上会加锁。
Session1 |
Session2 |
update reimburse_expense_mock |
|
select * |
查看lock状态。
select lock_mode, lock_type, lock_table,lock_index, lock_data from information_schema.INNODB_LOCKS;
可以看出锁住了未更新的数据。
二级索引更新时，更新后的索引上会加锁。
Session1 |
Session2 |
update reimburse_expense_mock |
|
select * from reimburse_expense_mock force index(idx_reimburse_expense_status) where ent_code = 'DTEC1809171U5IPQFR' and status = 'closing' for update;（阻塞） |
lock状态
