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

mysql.jpg

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

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


定位问题

刚开始得到是系统慢的反馈,没有将问题点定位到数据库上,查了半天服务是否正常(因为之前有一次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日志看起来比业务日志顺眼的很多。


严阵以待
10 声望0 粉丝