排查Mysql突然变慢的一次过程

本文源地址：排查Mysql突然变慢的一次过程

上周客户说系统突然变得很慢，而且时不时的蹦出一个 404 和 500，弄得真的是很没面子，而恰巧出问题的时候正在深圳出差，所以一直没有时间 看问题，一直到今天，才算是把问题原因找到。

定位问题

刚开始得到是系统慢的反馈，没有将问题点定位到数据库上，查了半天服务是否正常（因为之前有一次Dubbo内存泄漏）。

在将应用服务日志查看了一遍后，没有发现任何异常，只是打了几个警告的日志。

于是又查看了业务运行时的日志，看到日志都提示了一个 Lock wait timeout exceeded; try restarting transaction 的异常。

这时还是没有将重心放到数据库上，认为是代码的原因，导致事务一直没有提交。

重新将代码审阅了一遍，觉得应该不是代码逻辑的问题，而这个时候， Lock wait timeout exceeded; try restarting transaction 这个异常的日志越来越多。

认为是数据库层面出了问题，开始排查数据库。

寻找原因

由于我们的数据库不是用的 云RDS版本，是在一台8核32G的AWS上的安装版本。

使用 top 命令，查看到 Mysql 占用的 CPU 使用率高达 90% 左右。

心里一慌，感觉不妙，这样子高负载的CPU使用率，搞不好服务器都要宕掉。

于是拿出了仅有的一点Mysql基本知识，基本上这次只使用到了下面几个语句：

• 查看当前Mysql所有的进程

show processlist;

• 查看Mysql的最大缓存

show global variables like "global max_allowed_packet"

• 查看当前正在进行的事务

select * from information_schema.INNODB_TRX

• 查看当前Mysql的连接数

show status like "thread%"

解决

按照上面的几个语句，一步一步跟踪定位下来。

show processlist; 下来，我们就可以查看出当前所有的进程，并且得到最耗时的进程。

在当前数据库中，看到处于 Sleep 状态的SQL非常多，而这也是占用CPU过高的重大原因，休眠线程太多，于是配置了一个 wait_time_out 为 600 秒的一个解决方案。

为什么配置600秒，因为我们应用超时时间配置的最大时间就是 600秒，10分钟，这里的配置需要根据业务来具体配置。

select * from information_schema.INNODB_TRX

执行这个语句，看到Mysql中大部分处于 Lock 的SQL是一条 update 的SQL，而且还有一个单条件的SQL，查询居然耗时4分钟，很是惊讶。

于是查看了这张表。

刚一打开结构，差点没忍住口吐芬芳，居然一个索引都没有，数据量超过300W，没有索引查询基本上都要4分钟往上走。

于是准备加上索引，在一阵漫长的等待中，索引终于加上去了。

show status like "thread%"

索引加上去了之后，查看了一下当前Mysql的连接数，似乎没有之前那么高了，估计是挤压的太多。

然后又查看了下服务器的CPU占用率，这次好了一点，从1%到80%来回跳动，没有出现90&那么高的频率。

总结

Mysql作为使用频率非常高的数据库，对于它的SQL调优真的是一门技术活，而且项目中的一些SQL看的也是想吐，这种调优起来真的难上加难。

其实 information_schema 这个数据库，里面的Mysql日志看起来比业务日志顺眼的很多。