MySQL死锁排查

之前一直没有机会碰到与MySQL相关的问题，缺乏一些对于线上环境排错的经验，今天刚好碰到这个一个例子，以此来做一些记录。

问题起因

某数据库中一张business表，当尝试update某一条记录时，会卡住一段时间，然后报一个获取锁错误。

问题初步确定

遇到这个问题第一反应是这个记录被加锁了，首先update了一下同一张表的其他数据，确定可以执行，因此初步确定是行锁引起的。

那么最直接的想法就是执行show full processlist;，看一下能否找到蛛丝马迹。

然而结果并不乐观，上面命令告诉我当前这个数据库没有任何连接在执行SQL，唯一看到的就是我这条命令本身了。

但虽说没有执行SQL，但是有很多Sleep中的连接，这种情况下，在此尝试update被锁死的数据，依然处于锁死状态。

进一步排查

这时想到了SHOW ENGINE INNODB STATUS;查看一下InnoDB引擎的情况，可以看到我刚才执行的语句在尝试加锁的时候超时了，更印证了之前的推测。

首先考虑是不是出现了死锁，现在的MySQL基本比较智能了，如果一般的简单死锁会自动回滚一个事务。通过show status like '%lock%';查看了一下，当前等待的锁数目为0，当我尝试update时数量变为1，说明只有当前一个锁在等待，并不是简单的一个死锁问题。

那么看一下SELECT * FROM information_schema.INNODB_TRX;当前trx的结果，发现了令人卧槽的结果。

居然有一个事务运行了几个小时……并且加锁居然加了200多个行锁。这显然就是罪魁祸首了。

后续排查

那么原因很明了了，找到这个事务的线程，直接kill掉可以强行回滚释放掉锁，但是究竟是什么业务导致的这个问题，还需要细致排查。

首先看调用方，根据show full processlist;的结果可以找到调用方，是一台Java服务，但这个很难知道究竟是什么业务引起的超长时间事务。

一开始想到去看binlog，但是谷歌过发现binlog并不会记录事务的操作，只有事务提交后才会被写入，然而我们这个超长时间没有提交的事务就无法看到内容了。

最后找到了general_log，这个日志文件会将事务中的动作也记录下来。

然而执行一下show variables like '%general%';后发现居然是OFF状态，也就是没有在记录general_log（后来我反应过来，这是很正常的，开启了这个选项会在短时间内用这个日志把你的磁盘爆掉…）

那么此处我们set global general_log=1;后，之后产生的动作便会被记录了。

最终解决

首先当前第一要务是把对应的线程kill掉，先释放行锁，恢复业务。

其次是打开general_log的记录，随时观察数据库，当数据库复现这个问题时，使用thread_id到general_log中搜索便可以一目了然了。

最后一定要记得观察一下general_log的情况，毕竟详细记录所有操作，日志量也是巨大的，用完之后要将开关关掉。