排查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日志看起来比业务日志顺眼的很多。