一次线上死锁复盘

最新推荐文章于 2023-12-11 11:40:19 发布

HeiheiChihiro

最新推荐文章于 2023-12-11 11:40:19 发布

阅读量794

点赞数 2

分类专栏： mysql 文章标签： dba 数据库 sql

本文链接：https://blog.csdn.net/HeiheiChihiro/article/details/123535730

版权

mysql 专栏收录该内容

3 篇文章 0 订阅

订阅专栏

背景

这几日38线上大促，公司wms系统频繁出现死锁，经过和dba的共同排查，定位到了一条update语句，这是我第一次参与线上死锁问题的排查，确实学到了不少知识

知识回顾

首先我们来回顾下mysql中关于锁的知识～

S锁

S锁，即Shared Lock,可以理解为读写锁中的读锁，当我们在sql中使用in shared model的时候，就会给代码加上S锁。被S锁锁住的行记录只能被另外的读sql（不带for update）访问，而不能被其他sql更新，因为更新sql会带X锁

X锁

X锁，即排他锁，写锁，当读sql使用for update或者是是update delete语句时，就会给行记录加上X锁，此时该行记录不能被其他需要加S、X锁的记录访问

Record 锁

记录锁，可以理解为行锁，它锁得是数据行的聚簇索引

gap锁

gap锁即间隙锁，它会在索引之间加上x锁，防止幻读。
比如有如下的联合索引结构

id | code | num
—|--- | num
1 | 1| 10
2 | 1| 12
3 | 2| 13
4 | 2| 15

这时候我们执行如下DQL语句
给查询加x锁

select * from test where num = 15 for update;

在RR级别下，该sql会给num=13的索引加锁外,还会给所有code=x（任意值），但是num=13的索引加间隙锁，因此只要是num=13的update、insert或delete语句都会被阻塞。

insert into test(code,num) values(1,13);

从图中看到下面这句sql迟迟没有执行完成被阻塞了，此时就是gap锁在作祟

insert into test(code,num) values(1,15);

解析过程

解决死锁可以从死锁日志，入手，但要注意死锁日志也只会显示最近一次死锁的死锁日志

我们在控制台输入以下sql，显示最近的一次死锁日志

show engine innodb status


=====================================
2022-03-09 09:47:11 0x7f933caff700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 38 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 7710017 srv_active, 0 srv_shutdown, 9102639 srv_idle
srv_master_thread log flush and writes: 16812656
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 1358602
OS WAIT ARRAY INFO: signal count 361113732
RW-shared spins 0, rounds 194509727, OS waits 942245
RW-excl spins 0, rounds 116470292, OS waits 253641
RW-sx spins 4230179, rounds 21655984, OS waits 118848
Spin rounds per wait: 194509727.00 RW-shared, 116470292.00 RW-excl, 5.12 RW-sx
------------------------
LATEST DETECTED DEADLOCK
------------------------
2022-03-09 09:15:47 0x7f9349477700
*** TRANSACTION:
# 事务id 57468539，活跃了44秒去查找行数据
# fetching rows 表示事务状态在row_search_for_mysql中被设置，表示正在查找记录。
# starting index read 表示事务状态为根据索引读取数据。
# updating or deleting 表示事务已经真正进入了Update/delete的函数逻辑(row_update_for_mysql)
TRANSACTION 57468539, ACTIVE 44 sec fetching rows
# 事务使用了3张表，在其中1张表上发生了死锁
mysql tables in use 3, locked 1
# 锁链表长度为15800，占用堆内存1417424 bit，锁了13254条行记录，生成了4888条聚簇索引undo log（只有聚簇索引会产生行记录，二级索引不会）
15800 lock struct(s), heap size 1417424, 13254 row lock(s), undo log entries 4888
# 描述了执行线程的id和，和机器ip等信息
MySQL thread id 22991287, OS thread handle 140270566340352, query id 1310129155 10.100.129.49 wms updating
# 死锁的其中一条sql
update pas_header dh set dh.no_Stock_Flag = 0, VERSION = VERSION + 1, UPDATE_TIME = '2022-03-09 09:15:45.481', UPDATE_BY = 'xxx' where dh.warehouse_id = 1111 and dh.no_Stock_Flag = 1 and not exists (select 1 from pas_detail dd where dd.no_Stock_Flag = 1 and dd.do_header_id = dh.id and dd.warehouse_id = dh.warehouse_id) and exists (select 1 from pas_detail dd1 where dh.id = dd1.do_header_id and dh.warehouse_id = dd1.warehouse_id and dd1.sku_id in (280))  AND IS_DELETED = 0
# 获取🔒的相关信息
*** HOLDS THE LOCK:
# RECORD LOCKS表示行记录锁，其space id为671，页号为17756，该页还剩下112bits
# 其使用的是wms库的pas_detail表，加锁的事务id为57468539，加的锁是S锁并且没有间隙锁
RECORD LOCKS space id 571 page no 17756 n bits 112 index PRIMARY of table `wms`.`pas_detail` trx id 57468539 lock mode S locks rec but not gap
Record lock, heap no 7 PHYSICAL RECORD: n_fields 78; compact format; info bits 0

# 中间部分省略

# 等待锁释放，锁被事务57469354被持有
***  WAITING FOR THIS LOCK TO BE GRANTED, WHICH CONFLICTS WITH THE LOCK HELD BY TRANSACTION 57469354:
# 关注最后一句话，它是说57468539给pas_header加了x锁（非间隙锁）
RECORD LOCKS space id 1070 page no 26539 n bits 96 index PRIMARY of table `wms`.`pas_header` trx id 57468539 lock_mode X locks rec but not gap waiting
Record lock, heap no 12 PHYSICAL RECORD: n_fields 141; compact format; info bits 0
 0: len 8; hex 80000000001e978d; asc         ;;
 1: len 6; hex 0000036ce9aa; asc    l  ;;
 2: len 7; hex 3000001105117c; asc 0     |;;
 3: len 28; hex 50323230333038323335313330343230303030303333363634333638; asc P220308235130420000033664368;;
 4: len 2; hex 3030; asc 00;;
 
 # 中间部分省略
 
 *** TRANSACTION:
 # 事务57469354，活跃了2s，此时处于读取索引的状态
TRANSACTION 57469354, ACTIVE 2 sec starting index read
# 事务用了1张表，死锁发生在一张表上
mysql tables in use 1, locked 1
# 不加赘述了...
LOCK WAIT 4 lock struct(s), heap size 1136, 2 row lock(s), undo log entries 1
MySQL thread id 22991006, OS thread handle 140271031367424, query id 1310129167 10.100.129.188 wms updating

# 死锁的另一条sql语句
update pas_detail  set UPDATE_TIME='2021-03-09 09:15:45.501', VERSION=1, NEED_REPL_QTY=1, need_repl_qty_pcs=1 where ID=1111111 and VERSION=0
*** HOLDS THE LOCK:
# 事务57469354给pas_header加了x锁（非间隙锁）
RECORD LOCKS space id 1070 page no 26539 n bits 96 index PRIMARY of table `wms`.`pas_header` trx id 57469354 lock_mode X locks rec but not gap
Record lock, heap no 12 PHYSICAL RECORD: n_fields 141; compact format; info bits 0

# 中间部分省略

# 等待锁释放，此时锁被事务57468539hold住
***  WAITING FOR THIS LOCK TO BE GRANTED, WHICH CONFLICTS WITH THE LOCK HELD BY TRANSACTION 57468539:
# 记录锁
RECORD LOCKS space id 571 page no 17756 n bits 112 index PRIMARY of table `wms`.`pas_detail` trx id 57469354 lock_mode X locks rec but not gap waiting
Record lock, heap no 25 PHYSICAL RECORD: n_fields 78; compact format; info bits 0

tips：为了保护公司数据安全，对上面sql语句和数据做了改动

从上面的死锁日志我们可以得知，发生死锁的其中两个sql是

在事务57469354中

update pas_detail  set UPDATE_TIME='2022-03-09 09:15:45.501', VERSION=1, NEED_REPL_QTY=1, need_repl_qty_pcs=1 where ID=3202196 and VERSION=0

和

在事务57468539中

update pas_header dh set dh.no_Stock_Flag = 0, VERSION = VERSION + 1, UPDATE_TIME = '2022-03-09 09:15:45.481', UPDATE_BY = 'xxxx' where dh.warehouse_id = 1111 and dh.no_Stock_Flag = 1 and not exists (select 1 from pas_detail dd where dd.no_Stock_Flag = 1 and dd.do_header_id = dh.id and dd.warehouse_id = dh.warehouse_id) and exists (select 1 from pas_detail dd1 where dh.id = dd1.do_header_id and dh.warehouse_id = dd1.warehouse_id and dd1.sku_id in (381))  AND IS_DELETED = 0

在下面的解析我用354表示第一句sql，539表示第二句sql
看下两句sql分别获得了什么锁

锁信息

mysql tables in use 3, locked 1
15800 lock struct(s), heap size 1417424, 13254 row lock(s), undo log entries 488

锁记录

RECORD LOCKS space id 571 page no 17756 n bits 112 index PRIMARY of table `wms`.`pas_detail` trx id 57468539 lock mode S locks rec but not gap

可以看到539给13254条行记录加了S锁（共享锁）,S锁允许持有S锁的事务继续访问，但是会阻塞想给记录加X锁的事务。
问题来了为什么是S锁呢，注意看539这条sql，它在update的where条件里使用了子查询

update pas_header dh set dh.no_Stock_Flag = 0, VERSION = VERSION + 1, UPDATE_TIME = '2022-03-09 09:15:45.481', UPDATE_BY = 'zhanglian' where dh.warehouse_id = 5416 and dh.no_Stock_Flag = 1 and not exists (select 1 from pas_detail dd where dd.no_Stock_Flag = 1 and dd.do_header_id = dh.id and dd.warehouse_id = dh.warehouse_id) and exists (select 1 from pas_detail dd1 where dh.id = dd1.do_header_id and dh.warehouse_id = dd1.warehouse_id and dd1.sku_id in (280))  AND IS_DELETED = 0

当我们在update中使用子查询时，mysql并不会走mvcc，而是会给索引和聚簇索引加上S锁，来保证数据的准确性。注意这里有一个tip：mysql会给命中的行记录的聚簇索引和非聚簇索引都加上锁，顺序取决于索引怎么命中，此时的顺序是先给命中的二级索引加上S锁，再给聚簇索引加上S锁。
此时被命中的行记录就无法再执行其他事务的DML操作。
从上面的日志中我们可以清楚的看到，这两个子查询锁定了13254行记录
同一时刻，sql354也在执行

update pas_detail  set UPDATE_TIME='2022-03-09 09:15:45.501', VERSION=1, NEED_REPL_QTY=1, need_repl_qty_pcs=1 where ID=3202196 and VERSION=0

这句sql很直接，用了主键id，因此mysql在加锁时是先给聚簇索引加X锁，再去给关联的非聚簇索引加X锁，但由于该二级索引已经被539上了S锁，所以想加X锁的354就一直等待，日志记录如下所示

***  WAITING FOR THIS LOCK TO BE GRANTED, WHICH CONFLICTS WITH THE LOCK HELD BY TRANSACTION 57468539:

记录锁

RECORD LOCKS space id 571 page no 17756 n bits 112 index PRIMARY of table `wms`.`pas_detail` trx id 57469354 lock_mode X locks rec but not gap waiting
Record lock, heap no 25 PHYSICAL RECORD: n_fields 78; compact format; info bits 0

结果就是539在等待354释放聚簇索引的X锁，
354等待539加在二级索引上的S锁，造成了死锁。

解决思路

由于不可能再去线上把这条update手动执行一遍，于是我把update中的两条子查询sql提取出来，使用explain看看执行情况
在这里插入图片描述
发现它走某些情况下几乎是使用了全表扫描，这也不难理解为什么线上会频繁死锁

于是将它改成等价的update join语句，索引生效了，只扫描了42行
在这里插入图片描述
但为什么会update join能够走索引，两个exists缺不行呢，理论上关联的字段全都有索引。这我想和sql优化器有关系了，但不论如何，还是要经历避免update里使用子查询的的写法，一旦全表扫描或者锁表，会严重影响业务的运行。