vlambda博客
学习文章列表

数据库慢查询导致laravel任务调度线程剧增

现象
突然间系统访问变得异常缓慢,登录都需要很多秒时间,甚至有时登录不上,系统日志也没有显示错误,感觉很诡异。
1、系统首页以前一秒以内就可以显示出来,然而现在却超时的比较严重
2、系统ssh登录也变得异常的缓慢。

问题的思考

1、被其他网络所攻击

2、系统遇到了性能瓶颈

3、数据库连接过多
查看了网络访问,tailf /var/log/nginx/access.log,网络访问的流量正常。

系统是nginx +php-fpm (php) + mysql,查看php-fpm 是否创建了太多

ps -aux | grep 'php-fpm' | wc -l# 显示只有23个,随着时间的增加,也没有出现增

php-fpm的处理链接也是正常的


我修改了查询语句 grep php 而不是 grep php-fpm

ps -aux | grep 'php' | wc -l# 显示只有369个,随着时间的增加,也没有出现增

这下发现有 php artisan run:schedule 有巨多,且状态出现都是S或者Ss,表示睡眠状态。

此时系统任然是超时的厉害
然后我决定把这些进程全部杀死

ps -aux | grep 'php artisan' | awk '{print $2}' | xargs kill -9

删掉所有的这些进程,访问系统,系统就变得完全的正常了

原因:是laravel的任务调度出现了问题

问题重现

crontab -u nginx -e

注释了任务调度后,执行命令如下命令,睡眠S状态的进程不再增加

ps -aux | grep 'php artisan' 

打开任务调度后,睡眠S状态的php artisan 进程不断的在增长
锁定了问题是由任务调度导致的。

分析

任务调度主要是对数据库的数据进行了处理,那就有可能与数据库有关系
查看了数据库的安装目录,错误日志里面没有数据,查看了一下slow_query.log,整体的大小有183M,这个就不正常了,于是查看了该日志文件,发现对一张表的查询出现了几十万次的慢查询记录。

cat slow_query.log | grep '表' | wc -l

查询到了多达40万条对该表的慢查询,那这个表的查询一定是出现了问题。
分析后,对该表查询的条件新增了一个索引

alter table xxx add index idx_xxx(`column_name`);

顺带查询了链接情况

show status like 'Theads%';

发现Theads_created 数值一致在增加,链接创建数
Theads_cached 一直为0,说明没有缓存链接

查看了mysql wait_timeout 链接超时时间为8个小时

show variables like '%timeout';
threads_cached=50wait_timeout=600interactive_timeout=600

重启数据库

查看任务调度进程,等一段时间,不在出现睡眠等待进程了。数据库的链接数也保持一个比较低的稳定点的数据,解决问题。