一次mysql死锁错误的分析与解决

2,794 阅读18分钟

mysql死锁错误:1213 Deadlock found when trying to get lock解决

问题发生

今天龚总发邮件,说处理预约单发生死锁日志,赶紧看看。迅速打开邮件附件的日志,主要的关键内容如下:

2020-05-01 03:30:01.278 WARN [$_NIOREACTOR-43-RW] (io.mycat.backend.mysql.nio.handler.SingleNodeHandler.backConnectionErr(SingleNodeHandler.java:267)) - execute sql err : errno:1213 Deadlock found when trying to get lock; try restarting transaction con:MySQLConnection [id=123, lastTime=1588275001179, user=uop_iom, schema=iom, old shema=iom, borrowed=true, fromSlaveDB=false, threadId=318, charset=utf8, txIsolation=3, autocommit=true, attachment=dn1_10{update to_b_olcomwork update to_b_olcomwork set olcom_state = '2', WOGET_TIME = '2020-05-01 03:30:01.238', remark3 = 'being in sendqueue' where serial_number = '17607524621' and olcom_work_id = '3020050100615544'}, respHandler=SingleNodeHandler [node=dn1_10{update to_b_olcomwork set olcom_state = '2', WOGET_TIME = '2020-05-01 03:30:01.238', remark3 = 'being in sendqueue' where serial_number = '17607524621' and olcom_work_id = '3020050100615544'}, packetId=1], host=

更新其中一张表的时候死锁了。

问题分析

什么是死锁

死锁这个名词在java多线程里经常看到,在mysql里,含义也是类似,死锁一般是事务相互等待对方资源,最后形成环路造成的。

举例:两个事务A、B。A要更新x和y两行,B要更新y和x两行,当A更新了x准备更新y时,刚好B也更新了y准备更新x,就会互相等待,大家都不释放锁,形成死锁。

对于死锁,数据库处理方法:牺牲一个连接,保证另外一个连接成功执行。 发生死锁会返回ERROR:1213 错误提示,大部分的死锁InnoDB存储引擎本身可以侦测到,不需要人为进行干预。

注意:InnoDB存储引擎并不会回滚大部分的错误异常,像阻塞章节里面的例子,但是死锁例外,发现死锁后,InnoDB存储引擎会马上回滚一个事务,会返回1213错误。

代码核查

接着查找这个表涉及到更新的操作,尤其是有事务的dml操作。

结果发现大部分都无事务,其中找到了一个有事务的引起了注意。

  @Transactional(rollbackFor = Exception.class, propagation = Propagation.REQUIRES_NEW)
  public void insertSelective(List<ToBOlcomwork> toBOlcomworkList) {
    for (ToBOlcomwork toBOlcomwork : toBOlcomworkList) {
      log.debug("order->work  olcom_work_id = {}, order_id = {}, switch_id = {} , servlist = {}",
          toBOlcomwork.getOlcomWorkId()
          , toBOlcomwork.getOrderId(), toBOlcomwork.getSwitchId(), toBOlcomwork.getServlist());
      int iNum = toBOlcomworkMapper.insertSelective(toBOlcomwork);
      log.info(
          "order->work  olcom_work_id = {}, order_id = {}, switch_id = {} , servlist = {} , iNum = {}",
          toBOlcomwork.getOlcomWorkId(), toBOlcomwork.getOrderId(), toBOlcomwork.getSwitchId(),
          toBOlcomwork.getServlist(), iNum);
    }
  }

spring事务传播

  1. 在声明式的事务处理中,要配置一个切面,其中就用到了propagation,表示打算对这些方法怎么使用事务,是用还是不用,其中propagation有七种配置,REQUIRED、SUPPORTS、MANDATORY、REQUIRES_NEW、NOT_SUPPORTED、NEVER、NESTED。默认是REQUIRED。
  2. Spring中七种Propagation类的事务属性详解:
  • REQUIRED:支持当前事务,如果当前没有事务,就新建一个事务。这是最常见的选择。
  • SUPPORTS:支持当前事务,如果当前没有事务,就以非事务方式执行。
  • MANDATORY:支持当前事务,如果当前没有事务,就抛出异常。
  • REQUIRES_NEW:新建事务,如果当前存在事务,把当前事务挂起。
  • NOT_SUPPORTED:以非事务方式执行操作,如果当前存在事务,就把当前事务挂起。
  • NEVER:以非事务方式执行,如果当前存在事务,则抛出异常。
  • NESTED:支持当前事务,如果当前事务存在,则执行一个嵌套事务,如果当前没有事务,就新建一个事务。

官网:docs.spring.io/spring/docs…

查看引擎

show create  table to_b_olcomwork;
...
  PRIMARY KEY (`OLCOM_WORK_ID`,`EXEC_MONTH`),
  KEY `idx_to_b_olcomwork_sn` (`SERIAL_NUMBER`),
  KEY `idx_to_b_olcomwork_ti` (`TRADE_ID`),
  KEY `idx_to_b_olcomwork_os` (`OLCOM_STATE`),
  KEY `idx_to_b_olcomwork_et` (`EXEC_TIME`),
  KEY `idx_to_b_olcomwork_oi` (`ORDER_ID`)
) /*!50100 TABLESPACE `iomwork` */ ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_bin

是innodb,支持行级锁。

哪些会锁表?

在innodb下:

  • select不会锁表
  • select for update会锁行/表
  • update会锁行/表
  • insert不会锁表(但会锁insert的行)

innodb,update锁表:

  • where里走了主键,行级锁
  • where里走了索引,行级锁
  • 否则是表级锁
  • 具体有没有走主键或者索引,不是看where里是否写了,而是看执行计划是否真的走了

重要命令

上面未能找出原因。

出大招: SHOW ENGINE INNODB STATUS;

innodb的命令,这个命令有点奇怪,所有信息都在一个字段的值里。

展示的信息:

  • background thread
  • semaphores
  • LATEST FOREIGN KEY ERROR
  • Latest detected Deadlock
  • transactions
  • file i/o
  • insert buffer and adaptive hash index
  • log
  • buffer pool and memory
  • individual buffer pool info
  • Row operations

《高性能mysql第三版》的最后附录里有详细的介绍。

引用: innodb存储引擎在show engine innodb status(老版本对应的是show innodb status)输出中,显示除了大量的内部信息,它输出就是一个单独的字符串,没有行和列,内容分为很多小段,每一段对应innodb存储引擎不同部分的信息,其中有一些信息对于innodb开发者来说非常有用,但是,许多信息,如果你尝试去理解,并且应用到高性能innodb调优的时候,你会发现它们非常有趣,甚至是非常有必要的。

输出内容中包含了一些平均值的统计信息,这些平均值是自上次输出结果生成以来的统计数,因此,如果你正在检查这些值,那就要确保已经等待了至少30s的时间,使两次采样之间的积累足够长的统计时间并多次采样,检查计数器变化从而弄清其行为,并不是所有的输出都会在一个时间点上生成,因而也不是所有的显示出来的平均值会在同一时间间隔里重新再计算。而且,innodb有一个内部复位间隔,而它是不可预知的,各个版本也不一样。

这些输出信息足够提供给手工计算出大多数你想要的统计信息,有一款监控工具innotop可以帮你计算出增量差值和平均值。

LATEST DETECTED DEADLOCK

幸运,几天前的死锁日志还在,没有被覆盖,证明之后这台mysql都没死锁了。

------------------------
LATEST DETECTED DEADLOCK
------------------------
2020-05-01 12:02:03 0x7fbfa35d9700
*** (1) TRANSACTION:
TRANSACTION 50598312, ACTIVE 2 sec starting index read
mysql tables in use 1, locked 1
LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
MySQL thread id 477, OS thread handle 140460629157632, query id 6073371 iomapp01 132.121.26.30 uop_iom Searching rows for update
update to_b_olcomwork
   set olcom_state = '0'
 where remark3 like '%Result/ResultDesc=GDVOLTETAS%-͸�����ݵ����кŲ���ȷ%'
   and exec_time > date_sub(now(), interval 12 hour)
   and olcom_state = '6'

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 4 page no 150548 n bits 640 index idx_to_b_olcomwork_os of table `iom`.`to_b_olcomwork` trx id 50598312 lock_mode X
Record lock, heap no 5 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 1; hex 36; asc 6;;
 1: len 16; hex 33303230303232353030303030353930; asc 3020022500000590;;
 2: len 4; hex 80000002; asc     ;;


*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 4 page no 21 n bits 88 index PRIMARY of table `iom`.`to_b_olcomwork` trx id 50598312 lock_mode X locks rec but not gap waiting
Record lock, heap no 7 PHYSICAL RECORD: n_fields 59; compact format; info bits 128
 0: len 16; hex 33303230303232353030303030353930; asc 3020022500000590;;
 1: len 4; hex 80000002; asc     ;;
 2: len 6; hex 0000014babf8; asc    K  ;;
 3: len 7; hex 01000001730ddf; asc     s  ;;
 4: len 19; hex 43524d37303230303232353032333239333738; asc CRM7020022502329378;;
 5: len 1; hex 36; asc 6;;
 6: len 1; hex 34; asc 4;;
 7: len 6; hex 484153323031; asc HAS201;;
 8: len 4; hex 8000000a; asc     ;;
 9: SQL NULL;
 10: SQL NULL;
 11: len 11; hex 3133323635333139383231; asc 13265319821;;
 ...(省略)

*** (2) TRANSACTION:
TRANSACTION 50598310, ACTIVE 6 sec updating or deleting
mysql tables in use 1, locked 1
LOCK WAIT 118458 lock struct(s), heap size 12443856, 1922747 row lock(s), undo log entries 1
MySQL thread id 483, OS thread handle 140451657475840, query id 6073341 iomapp02 132.121.26.31 uop_iom updating
update to_b_olcomwork
    set olcom_state = '0'
	 where exec_time >= str_to_date('2020-04-26 00:00:00','%Y-%m-%d %H:%i:%s')
 and remark3 like '%null%'

*** (2) HOLDS THE LOCK(S):
RECORD LOCKS space id 4 page no 21 n bits 88 index PRIMARY of table `iom`.`to_b_olcomwork` trx id 50598310 lock_mode X
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 59; compact format; info bits 128
 0: len 16; hex 33303230303232353030303030353835; asc 3020022500000585;;
 1: len 4; hex 80000002; asc     ;;
 2: len 6; hex 0000014b9972; asc    K r;;
 ...(较长,省略)

...(这里还有heap no 3~18,很长,省略)

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 4 page no 150548 n bits 640 index idx_to_b_olcomwork_os of table `iom`.`to_b_olcomwork` trx id 50598310 lock_mode X locks gap before rec insert intention waiting
Record lock, heap no 5 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 1; hex 36; asc 6;;
 1: len 16; hex 33303230303232353030303030353930; asc 3020022500000590;;
 2: len 4; hex 80000002; asc     ;;

死锁日志分析

总体结构:

LATEST DETECTED DEADLOCK

  • (1) TRANSACTION:
  • (1) HOLDS THE LOCK(S):
  • (1) WAITING FOR THIS LOCK TO BE GRANTED:
  • (2) TRANSACTION:
  • (2) HOLDS THE LOCK(S):
  • (2) WAITING FOR THIS LOCK TO BE GRANTED:
------------------------
LATEST DETECTED DEADLOCK
------------------------
2020-05-01 12:02:03 0x7fbfa35d9700 #这里显示了最近一次发生死锁的日期和时间

# 下面这部分显示的是死锁的第一个事务的信息
*** (1) TRANSACTION:
TRANSACTION 50598312, ACTIVE 2 sec starting index read
# 这行表示事务50598312,ACTIVE 2 sec表示事务处于活跃状态2秒,starting index read表示正在使用索引读取数据行

mysql tables in use 1, locked 1
#这行表示事务 50598312 正在使用1个表,且涉及锁的表有1个

LOCK WAIT 3 lock struct(s), heap size 1136, 2 row lock(s)
# 这行表示在等待3把锁,占用内存1136字节,涉及2行记录,
# 如果事务已经锁定了几行数据,这里将会有一行信息显示出锁定结构的数目(注意,这跟行锁是两回事)和堆大小,堆的大小指的是为了持有这些行锁而占用的内存大小,
# Innodb是用一种特殊的位图表来实现行锁的,从理论上讲,它可将每一个锁定的行表示为一个比特,经测试显示,每个锁通常不超过4比特

MySQL thread id 477, OS thread handle 140460629157632, query id 6073371 iomapp01 132.121.26.30 uop_iom Searching rows for update
# 这行表示该事务的线程ID信息,操作系统句柄信息,连接来源、用户

update to_b_olcomwork
   set olcom_state = '0'
 where remark3 like '%Result/ResultDesc=GDVOLTETAS%-͸�����ݵ����кŲ���ȷ%'
   and exec_time > date_sub(now(), interval 12 hour)
   and olcom_state = '6'
# 这行表示事务涉及的SQL

*** (1) HOLDS THE LOCK(S):
RECORD LOCKS space id 4 page no 150548 n bits 640 index idx_to_b_olcomwork_os of table `iom`.`to_b_olcomwork` trx id 50598312 lock_mode X
Record lock, heap no 5 PHYSICAL RECORD: n_fields 3; compact format; info bits 0
 0: len 1; hex 36; asc 6;;
 1: len 16; hex 33303230303232353030303030353930; asc 3020022500000590;;
 2: len 4; hex 80000002; asc     ;;

# 下面这一部分显示的是当死锁发生时,第一个事务正在等待的锁等信息
*** (1) WAITING FOR THIS LOCK TO BE GRANTED:
# 这行信息表示第一个事务正在等待锁被授予

RECORD LOCKS space id 4 page no 21 n bits 88 index PRIMARY of table `iom`.`to_b_olcomwork` trx id 50598312 lock_mode X locks rec but not gap waiting
# 这行信息表示等待的锁是一个record lock,空间id是4,页编号为21,大概位置在页的88位处,锁发生在表iom.to_b_olcomwork的主键上,是一个X锁(排他锁,详细见下),但是不是gap lock。 waiting表示正在等待锁

Record lock, heap no 7 PHYSICAL RECORD: n_fields 59; compact format; info bits 128
# 这行表示record lock的heap no 位置

 0: len 16; hex 33303230303232353030303030353930; asc 3020022500000590;;
 1: len 4; hex 80000002; asc     ;;
 2: len 6; hex 0000014babf8; asc    K  ;;
 ...
# 这部分剩下的内容只对调试才有用。

# 下面这部分是事务二的状态:
*** (2) TRANSACTION:
TRANSACTION 50598310, ACTIVE 6 sec updating or deleting
# 这行表示事务 50598310(第一个事务是50598312),ACTIVE 6 sec表示事务处于活跃状态6秒(第一个是2秒),
# 可能的事务有 inserting、updating、deleting、fetching rows、starting index read等(第一个是starting index read)

mysql tables in use 1, locked 1

LOCK WAIT 118458 lock struct(s), heap size 12443856, 1922747 row lock(s), undo log entries 1
# 118458 lock struct(s)表示该事务的锁链表长度为 118458(刚才说是几把锁不太对),每个链表节点代表该事务持有的一个锁结构,包括表锁,记录锁以及 autoinc 锁等。
# heap size 12443856 为事务分配的锁堆内存大小,这里有12M了!
# 1922747 row lock(s) 表示当前事务持有的行锁个数, 通过遍历上边的118458个锁结构、找到其中类型为LOCK_REC的记录数
# undo log entries 1表示当前事务有1个undo log记录、因为二级索引不记undo log、表示该事务更新了1个聚簇索引

MySQL thread id 483, OS thread handle 140451657475840, query id 6073341 iomapp02 132.121.26.31 uop_iom updating
update to_b_olcomwork
    set olcom_state = '0'
	 where exec_time >= str_to_date('2020-04-26 00:00:00','%Y-%m-%d %H:%i:%s')
 and remark3 like '%null%'
# 事务涉及的SQL

*** (2) WAITING FOR THIS LOCK TO BE GRANTED:
RECORD LOCKS space id 4 page no 150548 n bits 640 index idx_to_b_olcomwork_os of table `iom`.`to_b_olcomwork` trx id 50598310 lock_mode X locks gap before rec insert intention waiting
# lock_mode X 表示改记录锁为排他锁
# RECORD LOCKS 表示正在等待的是记录锁
# gap before rec insert intention waiting,在事务插入数据过程中,为防止其他事务向索引上该位置插入数据,会在插入之前先申请插入意向范围锁,而如果申请插入意向范围锁被阻塞,则事务处于gap before rec insert intention waiting的等待状态。

共享锁(S锁)和排它锁(X锁)

共享锁【S锁】: 又称读锁,若事务T对数据对象A加上S锁,则事务T可以读A但不能修改A,其他事务只能再对A加S锁,而不能加X锁,直到T释放A上的S锁。这保证了其他事务可以读A,但在T释放A上的S锁之前不能对A做任何修改。

排他锁【X锁】: 又称写锁。若事务T对数据对象A加上X锁,事务T可以读A也可以修改A,其他事务不能再对A加任何锁,直到T释放A上的锁。这保证了其他事务在T释放A上的锁之前不能再读取和修改A。

死锁代码

其实这么多信息,最重要的是下面两个update语句。

  1. update
update to_b_olcomwork
   set olcom_state = '0'
 where remark3 like '%Result/ResultDesc=GDVOLTETAS%-͸�����ݵ����кŲ���ȷ%'
   and exec_time > date_sub(now(), interval 12 hour)
   and olcom_state = '6'
  1. update
update to_b_olcomwork
    set olcom_state = '0'
	 where exec_time >= str_to_date('2020-04-26 00:00:00','%Y-%m-%d %H:%i:%s')
 and remark3 like '%null%’

继续核查:

  1. 这两条语句是在代码的哪里
  2. 还是说当时手工跑

分析: exec_time这个是索引,所以可以走行级锁。但是感觉两个sql是行级锁的范围是有重合的,因此就有可能发生死锁。 从锁的行看,第二条sql基本把全表的记录都锁了。这个表全表也就一百多万行。

执行计划

第二条sql走了全表,表级锁,会死锁。 第一条是range,其实也不算太好。

复习explain

expain出来的信息有10列,分别是id、select_type、table、type、possible_keys、key、key_len、ref、rows、Extra

概要描述:

  • id:选择标识符
  • select_type:表示查询的类型。
  • table:输出结果集的表
  • partitions:匹配的分区
  • type:表示表的连接类型
  • possible_keys:表示查询时,可能使用的索引
  • key:表示实际使用的索引
  • key_len:索引字段的长度
  • ref:列与索引的比较
  • rows:扫描出的行数(估算的行数)
  • filtered:按表条件过滤的行百分比
  • Extra:执行情况的描述和说明

比较关键的select_tyep、type、Extra。

select_type:查询中每个select子句的类型

  • (1) SIMPLE(简单SELECT,不使用UNION或子查询等)
  • (2) PRIMARY(子查询中最外层查询,查询中若包含任何复杂的子部分,最外层的select被标记为PRIMARY)
  • (3) UNION(UNION中的第二个或后面的SELECT语句)
  • (4) DEPENDENT UNION(UNION中的第二个或后面的SELECT语句,取决于外面的查询)
  • (5) UNION RESULT(UNION的结果,union语句中第二个select开始后面所有select)
  • (6) SUBQUERY(子查询中的第一个SELECT,结果不依赖于外部查询)
  • (7) DEPENDENT SUBQUERY(子查询中的第一个SELECT,依赖于外部查询)
  • (8) DERIVED(派生表的SELECT, FROM子句的子查询)
  • (9) UNCACHEABLE SUBQUERY(一个子查询的结果不能被缓存,必须重新评估外链接的第一行)

type:对表访问方式,表示MySQL在表中找到所需行的方式,又称“访问类型”。 常用的类型有: ALL、index、range、 ref、eq_ref、const、system、NULL(从左到右,性能从差到好)

  • ALL:Full Table Scan, MySQL将遍历全表以找到匹配的行
  • index: Full Index Scan,index与ALL区别为index类型只遍历索引树
  • range:只检索给定范围的行,使用一个索引来选择行
  • ref: 表示上述表的连接匹配条件,即哪些列或常量被用于查找索引列上的值
  • eq_ref: 类似ref,区别就在使用的索引是唯一索引,对于每个索引键值,表中只有一条记录匹配,简单来说,就是多表连接中使用primary key或者 unique key作为关联条件
  • const、system: 当MySQL对查询某部分进行优化,并转换为一个常量时,使用这些类型访问。如将主键置于where列表中,MySQL就能将该查询转换为一个常量,system是const类型的特例,当查询的表只有一行的情况下,使用system
  • NULL: MySQL在优化过程中分解语句,执行时甚至不用访问表或索引,例如从一个索引列里选取最小值可以通过单独索引查找完成。

Extra:该列包含MySQL解决查询的详细信息,有以下几种情况:

  • Using where:不用读取表中所有信息,仅通过索引就可以获取所需数据,这发生在对表的全部的请求列都是同一个索引的部分的时候,表示mysql服务器将在存储引擎检索行后再进行过滤
  • Using temporary:表示MySQL需要使用临时表来存储结果集,常见于排序和分组查询,常见 group by ; order by
  • Using filesort:当Query中包含 order by 操作,而且无法利用索引完成的排序操作称为“文件排序”
  • Using join buffer:改值强调了在获取连接条件时没有使用索引,并且需要连接缓冲区来存储中间结果。如果出现了这个值,那应该注意,根据查询的具体情况可能需要添加索引来改进能。
  • Impossible where:这个值强调了where语句会导致没有符合条件的行(通过收集统计信息不可能存在结果)。
  • Select tables optimized away:这个值意味着仅通过使用索引,优化器可能仅从聚合函数结果中返回一行
  • No tables used:Query语句中使用from dual 或不含任何from子句

问题原因

问了唐MM,原来这两个sql都是他手工跑的。那就找到源头了。至少不用修改源代码了。暂时代码没有bug。

如何改进

  1. 优化手工跑的sql(用explain验证)
  2. 手工跑时不要并行跑(防止死锁)
  3. 尽可能拆成小sql,一秒内跑完(比如用循环,每次limit一个数量)
  4. 尽可能自动化跑,记录跑的结果(防止事后说都执行成功了,死无对证)

参考读到的一些文章

mysql explain www.cnblogs.com/tufujie/p/9…

《高性能mysql》的show engine innodb status blog.csdn.net/github_2667…

死锁日志分析 www.jianshu.com/p/f8bd1edcf…

MySQL Lock--gap before rec insert intention waiting www.cnblogs.com/gaogao67/p/…

X锁和S锁 www.cnblogs.com/panxuejun/p…

本文Danni3首发掘金。转载请注明出处。 juejin.cn/post/684490…

2020.5.8