近日服务器经常出现访问缓慢,有时甚至出现503服务不可用问题。
SESSION临时文件
针对该问题的引发原因,首先是基于以前的经验对php的session文件夹进行排查,发现生成的session临时文件有80多万, 针对该问题先对session文件夹过期session进行了清理,同时计划后期用redis来存储session.
应用程序池
原以为,清理完后,不会再出问题,结果仍然会出现有时候间隙性的访问缓慢,由于平台是基于IIS7,在登录windows 后发现访问缓慢时,CPU与内存并未饱和,于是重启了应用程序池,临时的解决问题,但依旧未根治。
系统重启
正好最近系统更新的了补丁,但未重启,于是在凌晨对服务器进行了重启,结果第二天中午仍然有客户反馈访问不了。
PHP错误日志
出现503后,查看了PHP的错误日志,PHP程序执行超时,排序死循环,大体预估可能存在MYSQL慢查询:
[11-Nov-2018 08:59:01] PHP Fatal error: Maximum execution time of 60 seconds exceeded in xxx.php on line 6
[11-Nov-2018 08:59:01] PHP Fatal error: Maximum execution time of 60 seconds exceeded in xxx.php on line 6
[11-Nov-2018 08:59:01] PHP Fatal error: Maximum execution time of 60 seconds exceeded in xxx.php on line 6
[11-Nov-2018 08:59:01] PHP Fatal error: Maximum execution time of 60 seconds exceeded in xxx.php on line 6
MYSQL慢日志
通过SQL慢日志分析,发现确实存在一条慢日志查询,而且触发机率非常高,几乎几秒一次,没有索引,未做缓存:
select
sum(phone_province='北京') as 北京,
sum(phone_province='天津') as 天津,
sum(phone_province='上海') as 上海,
sum(phone_province='重庆') as 重庆,
sum(phone_province='河北') as 河北,
sum(phone_province='河南') as 河南,
sum(phone_province='云南') as 云南,
sum(phone_province='辽宁') as 辽宁,
sum(phone_province='黑龙江') as 黑龙江,
sum(phone_province='湖南') as 湖南,
sum(phone_province='安徽') as 安徽,
sum(phone_province='山东') as 山东,
sum(phone_province='新疆') as 新疆,
sum(phone_province='江苏') as 江苏,
sum(phone_province='浙江') as 浙江,
sum(phone_province='江西') as 江西,
sum(phone_province='湖北') as 湖北,
sum(phone_province='广西') as 广西,
sum(phone_province='甘肃') as 甘肃,
sum(phone_province='山西') as 山西,
sum(phone_province='内蒙古') as 内蒙古,
sum(phone_province='陕西') as 陕西,
sum(phone_province='吉林') as 吉林,
sum(phone_province='福建') as 福建,
sum(phone_province='贵州') as 贵州,
sum(phone_province='广东') as 广东,
sum(phone_province='青海') as 青海,
sum(phone_province='西藏') as 西藏,
sum(phone_province='四川') as 四川,
sum(phone_province='宁夏') as 宁夏,
sum(phone_province='海南') as 海南,
sum(phone_province='台湾') as 台湾,
sum(phone_province='香港') as 香港,
sum(phone_province='澳门') as 澳门
from `user_xxx` where phone_province != ''
对于这条SQL,感觉非常奇怪,SQL的调用自于平台的信息披露,这应该是冷门页面,除非是有人在恶意采集数据, 我开始怀疑,有人在恶意的进行平台数据挖掘,由于该接口的数据并未要求实时性,将该接口进行缓存处理。
IIS访问日志
对于上面的结果,我开始着手分析IIS的访问日志,我不得不将日志文件转到linux进行分析,先是对日志中访问状态进行了排序:
awk '{a[$9]+=1}END {for(i in a){print a[i]" "i}}' u_ex181109.log|sort -k1 -rn
总访问量PV在用20万左右,500错误的接近3000。
接着对,访问频率最高的URL进行统计
awk '{a[substr($5,0,40)]+=1}END {for(i in a){print a[i]" "i}}' u_ex181111.log|sort -k1 -rn|less
发现注册页访问量大概500左右,但判断手机号码是否存在的接口却调用了50000多次,由于加了阿里的WAF,没有获取到精准的IP访问来源, 暂且没有判定是否存在手机号码恶意探测,和开发人员沟通后,先做注册流程的调整。
IIS连接数
做完了以上工作,原以为不会再有问题,没想到问题还是会发生,于是对IIS的连接数进行监控,
cmd -> perfmon.msc
在监视工具》性能监视器》添加》计数器》Current Connections, 添加完成后,可以在工具栏中的属性进度其它的调整。
当再次发生访问缓慢时,显示当前连接数接近900多,而平时网站能正常访问时,连接数大概在50左右, 因此问题的根本原因应该就是连接数过大。
打开IIS,找到网站对应的应用程序池,选择高级设置》队列长度,发现默认为100,改为65535。
调整IIS的appConcurrentRequestLimit设置:
c:\windows\system32\inetsrv\appcmd.exe set config /section:serverRuntime /appConcurrentRequestLimit:50000
网上很多教程说设置为100000,当我设置完成时,发现报500错误了,于是通过以上命令改回50000才正常,配置文件位于:
%systemroot%\System32\inetsrv\config\applicationHost.config <serverRuntime appConcurrentRequestLimit="50000" />
该文件不能直接修改,如果不能通过以上命令进行修改,可以将该文件复制出来,修改完成后再张贴到原处。
调整
machine.config
中的processModel>requestQueueLimit
的设置 由原来的默认5000改为100000,该文件在Windows目录下C:\Windows\Microsoft.NET\Framework\v2.0.50727\CONFIG
:<configuration> <system.web> <processModel autoConfig="true"/> 改为 <processModel requestQueueLimit="100000"/>
改完会立即生效
修改注册表,调整IIS 7支持的同时TCPIP连接数 由原来的默认5000改为100000。
reg add HKLM\System\CurrentControlSet\Services\HTTP\Parameteris /v MaxConnections /t REG_DWORD /d 100000
修改完成后,持续监控IIS连接数。
应用程序
通过对IIS的并发调整后,进行AB测试静态文件,并发在1000以上没有出现访问异常,但访问PHP文件时,出现加载缓慢。 再次对日志文件进行分析,对时间段的并发数进行统计:
awk '{a[substr($2,0,5)]+=1}END {for(i in a){print a[i]" "i}}' u_ex181113.log|sort -k1 -rn|less
根据并发高的时间段,去查找对应的访问地址,发现每一次出现并发高的时候,都会出现以下访问连接:
2018-11-13 00:00:21 POST / xxx 120.27.173.40 Mozilla/5.0+(Windows+NT+6.1;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/70.0.3538.77+Safari/537.36 www.example.com 200 0 64
2018-11-13 00:00:22 POST / xxx 121.43.18.19 Mozilla/5.0+(Windows+NT+6.1;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/70.0.3538.77+Safari/537.36 www.example.com 200 0 64
2018-11-13 00:00:22 POST / xxx 121.43.18.19 Mozilla/5.0+(Windows+NT+6.1;+Win64;+x64)+AppleWebKit/537.36+(KHTML,+like+Gecko)+Chrome/70.0.3538.77+Safari/537.36 www.example.com 200 0 64