MySQL一次死锁排查过程分析(双update)

Posted suminem

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了MySQL一次死锁排查过程分析(双update)相关的知识,希望对你有一定的参考价值。

1.环境

mysql5.7.26,事务隔离级别为RR

2.表结构

+------------------+------------------+------+-----+---------------------+----------------+
| Field            | Type             | Null | Key | Default             | Extra          |
+------------------+------------------+------+-----+---------------------+----------------+
| id               | int(11) unsigned | NO   | PRI | NULL                | auto_increment |
| config_id        | int(11)          | NO   |     | NULL                |                |
| place_code       | varchar(16)      | NO   |     |                     |                |
| stock_date       | date             | NO   |     | NULL                |                |
| start_time       | time             | NO   |     | NULL                |                |
| end_time         | time             | NO   |     | NULL                |                |
| a_amount         | int(11)          | NO   |     | 0                   |                |
| t_amount         | int(11)          | NO   |     | 0                   |                |
| show_apps        | varchar(512)     | YES  |     | NULL                |                |
| update_time      | timestamp        | YES  |     | NULL                |                |
| create_time      | timestamp        | NO   |     | 0000-00-00 00:00:00 |                |
+------------------+------------------+------+-----+---------------------+----------------+

3.死锁日志分析

3.1 死锁日志如下

技术图片
2020-07-07T23:36:18.057866Z 2210220 [Note] InnoDB: Transactions deadlock detected, dumping detailed information.
2020-07-07T23:36:18.057932Z 2210220 [Note] InnoDB: 
*** (1) TRANSACTION:

TRANSACTION 182336318, ACTIVE 1 sec fetching rows
mysql tables in use 1, locked 1
LOCK WAIT 133 lock struct(s), heap size 24784, 32399 row lock(s), undo log entries 1
MySQL thread id 2210217, OS thread handle 139920667432704, query id 420859658 10.11.100.12 tc updating
UPDATE c_place_time_stock SET a_amount=(c_place_time_stock.a_amount - 2), update_time=now() WHERE c_place_time_stock.place_code = A02 AND c_place_time_stock.stock_date = 2020-07-08 AND c_place_time_stock.start_time <= 08:00:00 AND c_place_time_stock.end_time > 08:00:00
2020-07-07T23:36:18.058022Z 2210220 [Note] InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 207 page no 239 n bits 344 index PRIMARY of table `tcenter`.`c_place_time_stock` trx id 182336318 lock_mode X waiting
Record lock, heap no 228 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 0000a188; asc     ;;
 1: len 6; hex 00000ade3b3d; asc     ;=;;
 2: len 7; hex 76000018b80612; asc v      ;;
 3: len 4; hex 800002b4; asc     ;;
 4: len 3; hex 413237; asc A27;;
 5: len 3; hex 8fc8e8; asc    ;;
 6: len 3; hex 808780; asc    ;;
 7: len 3; hex 80f780; asc    ;;
 8: len 4; hex 800026b0; asc   & ;;
 9: len 4; hex 80002710; asc    ;;
 10: len 30; hex 3631303136332c3630303031362c3631303136382c3634303036382c3631; asc 610163,600016,610168,640068,61; (total 48 bytes);
 11: len 4; hex 5f0506f1; asc _   ;;
 12: len 4; hex 5efe174a; asc ^  J;;

2020-07-07T23:36:18.059281Z 2210220 [Note] InnoDB: *** (2) TRANSACTION:

TRANSACTION 182336317, ACTIVE 1 sec starting index read
mysql tables in use 1, locked 1
9 lock struct(s), heap size 1136, 28 row lock(s), undo log entries 16
MySQL thread id 2210220, OS thread handle 139920666892032, query id 420859667 10.11.100.12 tc updating
UPDATE c_place_time_stock SET a_amount=2168, update_time=now() WHERE c_place_time_stock.id = 41334
2020-07-07T23:36:18.059373Z 2210220 [Note] InnoDB: *** (2) HOLDS THE LOCK(S):

RECORD LOCKS space id 207 page no 239 n bits 344 index PRIMARY of table `tcenter`.`c_place_time_stock` trx id 182336317 lock_mode X locks rec but not gap
Record lock, heap no 228 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 0000a188; asc     ;;
 1: len 6; hex 00000ade3b3d; asc     ;=;;
 2: len 7; hex 76000018b80612; asc v      ;;
 3: len 4; hex 800002b4; asc     ;;
 4: len 3; hex 413237; asc A27;;
 5: len 3; hex 8fc8e8; asc    ;;
 6: len 3; hex 808780; asc    ;;
 7: len 3; hex 80f780; asc    ;;
 8: len 4; hex 800026b0; asc   & ;;
 9: len 4; hex 80002710; asc    ;;
 10: len 30; hex 3631303136332c3630303031362c3631303136382c3634303036382c3631; asc 610163,600016,610168,640068,61; (total 48 bytes);
 11: len 4; hex 5f0506f1; asc _   ;;
 12: len 4; hex 5efe174a; asc ^  J;;

2020-07-07T23:36:18.060674Z 2210220 [Note] InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:

RECORD LOCKS space id 207 page no 239 n bits 344 index PRIMARY of table `tcenter`.`c_place_time_stock` trx id 182336317 lock_mode X locks rec but not gap waiting
Record lock, heap no 214 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
 0: len 4; hex 0000a176; asc    v;;
 1: len 6; hex 00000ade3afa; asc     : ;;
 2: len 7; hex 50000017711ef0; asc P   q  ;;
 3: len 4; hex 80000257; asc    W;;
 4: len 3; hex 413031; asc A01;;
 5: len 3; hex 8fc8e8; asc    ;;
 6: len 3; hex 80d780; asc    ;;
 7: len 3; hex 80e780; asc    ;;
 8: len 4; hex 80000877; asc    w;;
 9: len 4; hex 80000823; asc    #;;
 10: len 30; hex 3631303136332c3630303031362c3631303136382c3634303036382c3631; asc 610163,600016,610168,640068,61; (total 62 bytes);
 11: len 4; hex 5f0506d5; asc _   ;;
 12: len 4; hex 5efe1749; asc ^  I;;

2020-07-07T23:36:18.061845Z 2210220 [Note] InnoDB: *** WE ROLL BACK TRANSACTION (2)
View Code

 

3.2 事务分析:将编号小的视为事务一(TRANSACTION 182336317);编号大的视为事务二(TRANSACTION 182336318)

事务一的信息

事务一的SQL语句:
        UPDATE c_place_time_stock SET a_amount=2168, update_time=now() WHERE c_place_time_stock.id = 41334

持有的锁信息(InnoDB: *** (2) HOLDS THE LOCK(S):)
        --表示持有哪些锁,相关信息展示在下边
        index PRIMARY of table `tcenter`.`c_place_time_stock`  --表示锁是加在表c_place_time_stock的索引PRIMARY上
        lock_mode X locks    --表示锁的类型为X排他锁
        n_fields 13;    --表示这个记录是13列
        0: len 4; hex 0000a188; asc     ;;     --第一个字段,也就是主键字段ID,从十六进制转换为10进制,得到的值为41352,可知该事务持有的行锁的行ID为41352 
        ......
        每行均可通过进制转换得到对应的值
    
RECORD LOCKS space id 207 page no 239 n bits 344 index PRIMARY of table `tcenter`.`c_place_time_stock` trx id 182336317 lock_mode X locks rec but not gap waiting
    Record lock, heap no 214 PHYSICAL RECORD: n_fields 13; compact format; info bits 0
      -
-结合起来表示在主键上的page num=239上已经持有一个X锁(not gap waiting),ID=41352
        结合前边的28 row lock(s)  ,可以知道现有28行记录锁      
    
在等待的锁信息(InnoDB: *** (2) WAITING FOR THIS LOCK TO BE GRANTED:)
     --表示等待锁的信息展示在下边 index PRIMARY of table `tcenter`.`c_place_time_stock` --表示在等待的是表c_place_time_stock的索引PRIMARY上面的锁 lock_mode X locks rec but not gap waiting --表示需要加一个排他锁(写锁),当前的状态是等待中 Record lock --表示这是一个记录行锁 n_fields 13 --表示索引PRIMYRAY的记录是13列, 根据表的结构,依次为id、config_id、place_code ...... 0: len 4; hex 0000a176; asc v;; --进制转换后得到id值为41334,可知该事务等待在
主键上加一个ID=41334的X锁(语句可以通过开启genaral日志获取) ......

所以在等待事务二的:PRIMARY: record lock: (id=
41334)

 事务二的信息

 

事务二的SQL语句
 
UPDATE c_place_time_stock SET a_amount=(c_place_time_stock.a_amount - 2), update_time=now() WHERE c_place_time_stock.place_code = A02 AND c_place_time_stock.stock_date = 2020-07-08 AND c_place_time_stock.start_time <= 08:00:00 AND c_place_time_stock.end_time > 08:00:00
  
持有的锁信息
      根据事务一在等待事务二上表c_place_time_stock的PRIMARY上的锁,且ID=41334,所以推导出事务二持有表c_place_time_stock 上PRIMARY的锁
 
 所以事务二正在申请持有(ID=41334)的X锁: PRIMAEY : record lock: (ID=41334)
 
 
 在等待的锁信息(InnoDB: *** (1) WAITING FOR THIS LOCK TO BE GRANTED:)
 
      index PRIMARY of table `sbtest`.`t1` --表示在等的是表t1 的主键索引 上面的锁
      lock_mode X locks rec but not gap waiting --表示需要加一个排他锁(写锁),当前的状态是等待中
      Record lock --是一个记录锁
 
      0: len 4; hex 0000a188; asc     ;; --是第一个字段,也就是主键字段 ID, 值为41352
      ......(13条记录与事务一持有锁描述相同)
      所以在事务二在等待事务一的: PRIMARY: record lock:(ID=41352) 。    

3.2 加锁规则和死锁成因

时间点 事务一 事务二
T1 持有主键索引ID=41352的记录锁,模式为排他锁  
T2   申请主键为ID=41334的记录锁,模式为排他锁
T3   在等待主键索引ID=41352的记录锁
T4 申请并等待主键索引为ID=41334的记录锁  
T3被T1阻塞,T4被T2阻塞

业务逻辑:

时间点 事务一 事务二
 

查阅general_log,可以发现在事务一的业务逻辑中,有多个UPDATE,每个都是先select出ID,然后运算后进行UPDATE,在多个UPDATE完成后统一commit;先执行的update如下:

UPDATE c_place_time_stock SET a_amount=9902, update_time=now() WHERE c_place_time_stock.id = 41352

 
T1 持有主键索引ID=41352的X锁  
    UPDATE c_place_time_stock SET a_amount=(c_place_time_stock.a_amount - 2), update_time=now() WHERE c_place_time_stock.place_code = ‘A02‘ AND c_place_time_stock.stock_date = ‘2020-07-08‘ AND c_place_time_stock.start_time <= ‘08:00:00‘ AND c_place_time_stock.end_time > ‘08:00:00‘
T2   申请范围包括ID=41334和41352的记录锁,模式为排他锁
T3   等待主键索引ID=41352的记录锁释放,进入等待队列
  UPDATE c_place_time_stock SET a_amount=2168, update_time=now() WHERE c_place_time_stock.id = 41334  
T4 本身持有主键索引ID=41352的X锁,改为申请ID=41334的X锁,进入等待队列,等待T3的释放申请。  

T3被T1阻塞,T4被T3阻塞,同时T4所在事务未完成,无法释放T1,行程死锁环路。最终回归了代价最小的事务一

 4.解决方式

事务一的逻辑中每次update均commit;

5. 日志说明

锁的几种属性

LOCK_REC_NOT_GAP        (锁记录)
LOCK_GAP                         (锁记录前的GAP)
LOCK_ORDINARY              (同时锁记录+记录前的GAP ,也就是Next Key锁)
LOCK_INSERT_INTENTION(插入意向锁,其实是特殊的GAP锁)

锁的属性可以与锁模式任意组合

lock->type_mode       可以是Lock_X 或者Lock_S 
locks gap before rec  表示为gap锁:lock->type_mode & LOCK_GAP
locks rec but not gap 表示为记录锁,非gap锁:lock->type_mode & LOCK_REC_NOT_GAP
insert intention           表示为插入意向锁:lock->type_mode & LOCK_INSERT_INTENTION
waiting                       表示锁等待:lock->type_mode & LOCK_WAIT

 

参考1:https://mp.weixin.qq.com/s?__biz=MzI4NjExMDA4NQ==&mid=2648450273&idx=1&sn=2836db9eb1086a9fca91748dd233a234&chksm=f3c97c0bc4bef51d6c92e9a79b959c7f7e41367d5429ec80b5881d165978f311a4d8f0452634&scene=21#wechat_redirect

参考2:https://cloud.tencent.com/developer/article/1650865

以上是关于MySQL一次死锁排查过程分析(双update)的主要内容,如果未能解决你的问题,请参考以下文章

记录一次 Mysql 死锁排查过程

记录一次Mysql死锁排查过程

记录一次Mysql死锁排查过程

记录一次MySQL死锁排查过程

讲讲insert on duplicate key update 的死锁坑

Mysql 死锁排查过程