web常见问题排查

发表于 | 分类于

一般排查方法

  • 检查error_log
  • 检查access_log
  • 检查slow_log
  • linux命令工具
  • tcpdump分析网络状况
  • 程序的gdb调试

error_log

error_log提供了有关异常的丰富信:

  • 网络超时：connect,write,read timeout
  • File not found
  • HTTP状态码

     举例来讲，更新nginx后，http请求不能返回完整数据，返回部分数据后请求就结束了，每次都能复现。这时候查看error_log,看到有Permission denied错误，即查实为nginx的临时写目录没有权限所造成。

slow_log

    php-fpm慢日志slowl_og设置可以让开发者很好的查找哪些php进程速度过慢而导致的网站问题，让开发者方便的找到问题的所在。该方法同样适用于排查nginx的500、502问题根源，当nginx收到如上错误码时，可以确定后端php-fpm解析php出了某种问题，比如，执行错误，执行超时等。

access_log

对access_log进行统计分析，可以很好地展示与监控web服务的状态。包括200请求次数的变化，流量大小，后端响应时间等

1
2
3
1. 统计HTTP状态码的比例，可以知道nginx服务健康状况；
2. 统计响应时间，判断超时请求。
3. 统计QPS，对比负载是否均衡。

linux工具命令

strace 跟踪进程中的系统调用

使用strace命令工具可跟踪系统调用并打印出丰富的信息，如系统调用发生的时间，调用耗时，传送的参数，调用返回结果等等。

1
2
3
4
5
常用参数有：
-tt 打印系统调用发生的时间
-T 打印系统调用耗时
-e <name> 跟踪特定系统调用，比如-e open,read,write,close来追踪文件相关调用
-s <size> 指定打印的最大长度

strace只能追踪系统调用，普通函数是无法追踪的。CPU很高，说明程序一直在跑，但strace没有异常，说明是用户状代码在消耗CPU。问题必定出现在自己程序逻辑上。

tcpdump

tcpdump是linux本身得供的一款强大的网络抓包工具。对于两台设备之间传输的数据是否正常，为何响应慢等网络问题，都可以使用tcpdump来抓包排查。
windows下面有一款具有同样功能的工具软件–wireshark,也很好用。

还记得刚才示例中提到的慢连接吧，Nginx的access_log显示请求响应时间为3s多，而后端是毫秒计，这种慢就可以使用tcpdump来抓包查看了

可以看到后端响应ack花了3s.这种慢连接，我们线上会经常碰到。通常nginx做反向代量连接后端时、php程序在访问后端资源时、以及php用curl请求其他接口时，经常出现慢连接的情况。这些慢连接产生的根本原因在于：
–服务端listen时，设置的backlog太小，导致连接队列很小；
–连接队列满时，对于新的连接请求，服务端会直接丢弃SYN包；
–SYN包初始重传时间为3s；

再举一下综合案例：PHP升级后，开始运行正常，但几天后，系统负载突然上升，达到200-400左右，CPU使用不高，内存使用不高，netstat发现大量的PHP进程处于CLOSE_WAIT状态。
排查：error_log与access_log都没有问题；
nginx与PHP不在同一台机器，暂时无法查看其error_log；
CPU、内存都不高，为何负载这么高？
CLOSE_WAIT是怎么造成的

我们先从CLOSE_WAIT入手，TCP关闭连接过程中，被动关闭的一方，在接收到对方的FIN后，发送自己的FIN前，这个状态就是CLOSE_WAIT。
系统调用close，关闭连接，发送FIN

从CLOSE_WAIT的状态看，PHP应该是没有调用close函数，程序可能因为某种原因堵塞，而无法调用close。
启用strace追踪PHP进程到底堵塞在哪里。
strace追踪结果来看，PHP进程没有堵塞，但write函数调用失败，Broken pipe说明连接已经关闭，调用close了。

继续strace分析，连接为什么关闭，是后端PHP处理太慢导致nginx超时么？从strace看到，PHP从accept到close，总共耗时1ms，nginx不可能超时。

我们启动tcpdump抓包（windows下使用wireshark查看）

发现3个异常：
–3次握手nginx发送的SYN，PHP响应是ACK，而不是SYN+ACK
–Nginx发送FIN关闭连接后，PHP没有发送FIN
–第二个连接的SYN，PHP同样只返回ACK，但ACK序列号却是确认上一个连接的。

结合strace与tcpdump来看，accept调用比接收到SYN晚了2分钟

这里可以看到：SYN三次握手完成后，socket放到了连接队列里，accept从连接队列获取socket，如果队列过大，等到accept消费到这个socket，可能已经超时关闭连接。队列中关闭的连接处于CLOSE_WAIT状态。若PHP一个关闭的连接，就会出现Broken Pipe报错现象。
这其实就是backlog设置过大引起。

总结一下，web问题排障很复杂，找到正确的方向很重要。学会看log与系统状态，学会使用统计数据（常用的一些awk,grep命令)，熟悉一些常用的工具。
问题一定是有原因的，要找到root cause(真正的根本原因)