记一次Nginx服务器报502 Connection timed out的排查历程
一个风和日丽的下午,测试小妹妹心急火燎地突然跑过来说,同样的脚本,同样的压测参数,但在持续压测2min左右后开始报502错误,重要功能平均响应时间严重超标。
重现
从测试小妹妹那要来Jmeter脚本,300并发持续5分钟进行压测。不出意外,果然2分钟左右Jmeter就出现502 Bad Gateway错误。
伴随着502报错的,还有急剧升高的响应时长。
监测Docker容器负载
容器的CPU负载在刚开始并发请求时很高,属于正常状态,不过持续观察发现,当Jmeter收到报错提示时,此时的CPU负载突然降到很低,持续一段时间才缓慢回升。
监测带宽
我这里使用的是nload,它是一个命令行工具,让用户可以分开来监控入站流量和出站流量。
# fedora或centos
yum install nload -y
# ubuntu/debian
sudo apt-get install nload
如果只需要快速查看总带宽使用情况,无需每个进程的详细情况,那么nload用起来很方便。
nload
经过观察发现,跟CPU负载一样,同一时间段,带宽使用也突然降低,持续一段时间才缓慢回升。
查看Tomcat日志
catalina.out中没看到有报错日志
localhost_access_log.txt中看到有异常现象
这个时间段2019-07-09 17:59:05——2019-07-09 17:59:14,也就是Jmeter第一次出现502异常的时间段,并没有请求进到Tomcat中
查看Nginx日志
同一时间段error.log中出现超时日志
初步推断
一般出现超时问题,第一反应就是应用服务存在性能问题,没法及时处理并发请求,导致响应时长超过等待时间。这时候就考虑找出慢SQL,优化SQL,优化索引,引入缓存,优化业务,调优Nginx、Tomcat配置等。
通过日志分析,暂时可以判定无法响应请求应该来自应用服务链路的前一节点,也就是Nginx。
但假设Nginx出了问题,导致超时,那Tomcat那头肯定是有访问日志的,现在是压根就没请求进入Tomcat。
这种情况,很像很久之前系统第一次压测时遇到的TCP连接问题,服务器资源设置过小,导致过多的连接无法进入队列,直接被服务器端拒绝,但很早就已经进行过内核参数调优了,姑且再核查一遍内核参数吧
内核参数排查
cat /etc/sysctl.conf
恩…内核参数看起来没什么问题,但有时候最好不要太相信自己的眼睛
执行命令:
sysctl -p
如果系统没有错误提示,就表明系统对内核参数应用成功。
额,出现了错误提示,根据错误提示重新设定了key值,重新执行命令,没有报错
重新300并发,持续压测了1个小时,未看到异常,并且响应时长已恢复到正常水平
总结
- 根据日志分析错误出现在哪一环
- 眼见不一定为实