有效解决 MySQL 行锁等待超时问题

一、有效背景

#### 20191219 10:10:10,解决234 | com.alibaba.druid.filter.logging.Log4jFilter.statementLogError(Log4jFilter.java:152) | ERROR |  { conn-10593, pstmt-38675} execute error. update operation_service set offlinemark = ? , resourcestatus = ?  where RowGuid = ? com.mysql.jdbc.exceptions.jdbc4.MySQLTransactionRollbackException: Lock wait timeout exceeded; try restarting transaction

上述这个错误，接触 MySQL 的锁等时问同学或多或少应该都遇到过，专业一点来说，待超这个报错我们称之为锁等待超时。有效根据锁的解决类型主要细分为：

行锁等待超时

当 SQL 因为等待行锁而超时，那么就为行锁等待超时，锁等时问常在多并发事务场景下出现。待超

元数据锁等待超时

当 SQL 因为等待元数据锁而超时，有效那么就为元数据锁等待超时，解决常在 DDL 操作期间出现。锁等时问

本文仅介绍如何有效解决行锁等待超时，待超因为大多数项目都是有效此类错误，元数据锁等待超时则不涉及讲解。解决

二、锁等时问行锁的等待

在介绍如何解决行锁等待问题前，先简单介绍下这类问题产生的原因。产生原因简述：当多个事务同时去操作(增删改)某一行数据的时候，MySQL 为了维护 ACID 特性，就会用锁的形式来防止多个事务同时操作某一行数据，避免数据不一致。只有分配到行锁的事务才有权力操作该数据行，直到该事务结束，才释放行锁，而其他没有分配到行锁的事务就会产生行锁等待。服务器租用如果等待时间超过了配置值(也就是 innodb_lock_wait_timeout 参数的值，个人习惯配置成 5s，MySQL 官方默认为 50s)，则会抛出行锁等待超时错误。

如上图所示，事务 A 与事务 B 同时会去 Insert 一条主键值为 1 的数据，由于事务 A 首先获取了主键值为 1 的行锁，导致事务 B 因无法获取行锁而产生等待，等到事务 A 提交后，事务 B 才获取该行锁，完成提交。这里强调的是行锁的概念，虽然事务 B 重复插入了主键，但是在获取行锁之前，事务一直是处于行锁等待的状态，只有获取行锁后，才会报主键冲突的错误。当然这种 Insert 行锁冲突的问题比较少见，只有在大量并发插入场景下才会出现，项目上真正常见的是站群服务器 update&delete 之间行锁等待，这里只是用于示例，原理都是相同的。

三、产生的原因

根据我之前接触到的此类问题，大致可以分为以下几种原因：

1. 程序中非数据库交互操作导致事务挂起

将接口调用或者文件操作等这一类非数据库交互操作嵌入在 SQL 事务代码之中，那么整个事务很有可能因此挂起(接口不通等待超时或是上传下载大附件)。

2. 事务中包含性能较差的查询SQL

事务中存在慢查询，导致同一个事务中的其他 DML 无法及时释放占用的行锁，引起行锁等待。

3. 单个事务中包含大量 SQL

通常是由于在事务代码中加入 for 循环导致，虽然单个 SQL 运行很快，但是 SQL 数量一大，事务就会很慢。

4. 级联更新 SQL 执行时间较久

这类 SQL 容易让人产生错觉，例如：update A set ... where ...in (select B) 这类级联更新，不仅会占用 A 表上的行锁，也会占用 B 表上的行锁，当 SQL 执行较久时，很容易引起 B 表上的源码下载行锁等待。

5. 磁盘问题导致的事务挂起

极少出现的情形，比如存储突然离线，SQL 执行会卡在内核调用磁盘的步骤上，一直等待，事务无法提交。综上可以看出，如果事务长时间未提交，且事务中包含了 DML 操作，那么就有可能产生行锁等待，引起报错。

四、定位难点当

web 日志中出现行锁超时错误后，很多开发都会找我来排查问题，这里说下问题定位的难点!

1. MySQL 本身不会主动记录行锁等待的相关信息，所以无法有效的进行事后分析。

2. 锁争用原因有多种，很难在事后判断到底是哪一类问题场景，尤其是事后无法复现问题的时候。

3. 找到问题 SQL 后，开发无法有效从代码中挖掘出完整的事务，这也和公司框架-产品-项目的架构有关，需要靠 DBA 事后采集完整的事务 SQL 才可以进行分析。

五、常用方法

先介绍下个人通常是如何解决此类问题的， 这里问题解决的前提是问题可以复现，只要不是突然出现一次，之后再也不出现，一般都是可以找到问题源头的。

这里问题复现分为两种情景：

1. 手动复现

只要按照一定的操作，就可以复现报错，这种场景较简单!

2. 随机复现

不知道何时会突然报错，无法手动复现，这种场景较难!

下面先写下统一的模拟场景，用于复现行锁超时问题，便于大家理解：

--表结构 CREATE TABLE `emp` (   `id` int(11) NOT NULL,   KEY `idx_id` (`id`) ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 从1~100w插入100w行记录。 --测试过程： 事务1： start transaction; delete from emp where id = 1; select * from emp where id in (select id from emp);   -->模拟慢查询，执行时间很久，事务因此一直不提交，行锁也不释放. commit; 事务2： start transaction; delete from emp where id < 10;   --> 处于等待id=1的行锁状态，当达到行锁超时时间（这里我配置了超时时间为 5s）后，返回行锁超时报错 rollback;

5.1 手动复现场景

这个场景通常只需要通过 innodb 行锁等待脚本就可以知道当前 MySQL 的 innodb 行锁等待情况，例如我们一边模拟上述报错场景(模拟页面操作)，另一边使用脚本查询(需要在超时之前查询，否则超时报错后就看不到了)。

/*innodb 行锁等待脚本*/ SELECT r.trx_mysql_thread_id waiting_thread,r.trx_query waiting_query, concat(timestampdiff(SECOND,r.trx_wait_started,CURRENT_TIMESTAMP()),s) AS duration, b.trx_mysql_thread_id blocking_thread,t.processlist_command state,b.trx_query blocking_current_query,e.sql_text blocking_last_query FROM information_schema.innodb_lock_waits w JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id JOIN performance_schema.threads t on t.processlist_id = b.trx_mysql_thread_id JOIN performance_schema.events_statements_current e USING(thread_id)

如上我们可以看到事务 2 的线程 id 为 76，已经被事务 1，也就是线程 id 为 75 的事务阻塞了 3s，并且可以看到事务 1 当前执行的 SQL 为一个 SELECT。这里也解释了很多开发经常问我的，为什么 SELECT 也会阻塞其他会话?如果遇到这种情况，那么处理其实非常简单。需要优化这个 SELECT 就好了，实在优化不了，把这个查询扔到事务外就可以了，甚至都不需要挖掘出整个事务。上述这个问题模拟，其实就是对应第三节问题产生原因中的第二点(事务中包含性能较差的查询 SQL)，下面我们把第一点(程序中非数据库交互操作导致事务挂起)也模拟下，对比下现象。我们只需要将事务 1 的过程改成如下即可。

事务1： start transaction; delete from emp where id = 1; select * from emp where id in (select id from emp); 等待60s(什么都不要做)             --> 模拟接口调用超时，事务夯住，随后再执行commit。 commit;

再次用脚本查看，可以看到现象是有所不同的，不同点在于，阻塞事务处于 sleep 状态，即事务当前并不在跑 SQL。从 DBA 的角度看，这类现象八成就可以断定是代码在事务中嵌入了其他的交互操作导致的事务挂起(另外也有可能是网络问题导致的事务僵死)，因为程序并不像人，它不会偷懒，不会出现事务执行到一半，休息一会再提交一说。

如果是这类现象的问题，因为本质并不是由于 SQL 慢导致的事务挂起，所以必须要到代码里去找到对应的点，看下到底是在做什么交互操作卡住了。

这里就需要开发去排查代码才可以找到源头，但是唯一可用的信息就是该事务最后执行的一条 SQL，也就是上图中最后一列，从我之前的经验来看(绝大时候)，开发很难单从这一条 SQL 就可以找到代码里具体位置，尤其是当这条 SQL 是一条很常见的 SQL，就更为困难!

当面对这种情况，就需要 DBA 去挖掘出这个事务执行过的所有 SQL，然后再让开发去排查代码，这样难度应该就小多了。这里就需要用到 MySQL 的 general_log，该日志用于记录 MySQL 中所有运行过的 SQL。

--查看general_log是否开启，及文件名 mysql> show variables like %general_log%; +------------------+--------------------------------------+ | Variable_name    | Value                                | +------------------+--------------------------------------+ | general_log      | OFF                                  | | general_log_file | /data/mysql_data/192-168-188-155.log | +------------------+--------------------------------------+ --暂时开启general_log mysql> set global general_log = 1; Query OK, 0 rows affected (0.00 sec) --暂时关闭general_log mysql> set global general_log = 0; Query OK, 0 rows affected (0.00 sec)

开启 general_log 后，手动复现的时候通过 innodb 行锁等待脚本查询结果中的线程 ID，去 general_log 找到对应的事务分析即可，如下：

根据线程 ID 可以很轻易的从 general_log 中找到对应时间点的事务操作(实际场景下可能需要通过管道命令过滤)。如上图所示，事务 1 与事务 2 的全部 SQL 都可以找到，再通过这些 SQL 去代码中找到对应的位置即可，比如上图中线程 ID 为 111 的事务，执行 select * from emp where id in (select id from emp) 后到真正提交，过了 1min 左右，原因要么就是这条 SQL 查询慢，要么就是代码在执行其他交互操作。

PS：general_log 由于会记录所有 SQL，所以对 MySQL 性能影响较大，且容易暴涨，所以只在问题排查时暂时开启，问题排查后，请及时关闭!

5.2 随机复现场景

相较于手动复现场景，这种场景因为具有随机性，所以无法一边模拟报错，一边通过脚本查询到具体的阻塞情况，因此需要通过其他方式来监控 MySQL 的阻塞情况。我一般是通过在 Linux 上后台跑监控脚本(innodb_lock_monitor.sh)来记录 MySQL 阻塞情况，脚本如下：

#!/bin/bash #账号、密码、监控日志 user="root" password="Gepoint" logfile="/root/innodb_lock_monitor.log" while true do         num=`mysql -u${ user} -p${ password} -e "select count(*) from information_schema.innodb_lock_waits" |grep -v count`         if [[ $num -gt 0 ]];then             date  >> /root/innodb_lock_monitor.log             mysql -u${ user} -p${ password} -e  "SELECT r.trx_mysql_thread_id waiting_thread,r.trx_query waiting_query, \ concat(timestampdiff(SECOND,r.trx_wait_started,CURRENT_TIMESTAMP()),s) AS duration,\ b.trx_mysql_thread_id blocking_thread,t.processlist_command state,b.trx_query blocking_query,e.sql_text \ FROM information_schema.innodb_lock_waits w \ JOIN information_schema.innodb_trx b ON b.trx_id = w.blocking_trx_id \ JOIN information_schema.innodb_trx r ON r.trx_id = w.requesting_trx_id \ JOIN performance_schema.threads t on t.processlist_id = b.trx_mysql_thread_id \ JOIN performance_schema.events_statements_current e USING(thread_id) \G " >> ${ logfile}         fi         sleep 5 done

再次查看

--使用 nohup 命令后台运行监控脚本 [root@192-168-188-155 ~]# nohup sh innodb_lock_monitor.sh  & [2] 31464 nohup: ignoring input and appending output to ‘nohup.out’ --查看 nohup.out 是否出现报错 [root@192-168-188-155 ~]# tail -f nohup.out mysql: [Warning] Using a password on the command line interface can be insecure. mysql: [Warning] Using a password on the command line interface can be insecure. mysql: [Warning] Using a password on the command line interface can be insecure. --定时查看监控日志是否有输出(没有输出的话，这个日志也不会生成哦！) [root@192-168-188-155 ~]# tail -f innodb_lock_monitor.log Wed Feb  5 11:30:11 CST 2020