线上「5XX」之时间都去哪儿了
线上服务稳定性，是研发&运维同学都百分百关心的事情，哪怕就是线上的一次小波动、小报警，我们都必须知道问题发生的原因是「为什么」？本文就是通过一个线上PHP机器规律性抛出5XX错误而展开的问题追查过程。
一、问题
通过监控系统观察发现，线上业务PHP机器每隔两小时必然出现一批5XX错误，虽然线上服务并未因此受到明显影响，但这个问题不查出来，在后续可能有别的隐患。
二、现象
2.1 诡异的现象
- 时间相对规律，机器不固定，同时伴随有大量的
iowait - web-43（服务器代号）发起请求的时间远早于service-25接收到请求的时间，而当请求快超时时service-25才接到请求
- 查看业务日志，web-43服务器正常发起了请求，一直等到超时后断开请求，从service-25的日志看，service-25接到请求时就已经到达超时时间了
- 查看此时的听云监控，php进程在
写日志文件时耗时比较长，和iowait飙升相匹配
2.2 初步诊断
- 时间非常有规律：「定时任务」导致？
- 发生在服务之间：「网络情况」导致？
- iowait会飙升：「磁盘IO」导致？
三、细节排查
3.1 定时任务
疑问：时间点固定、且伴随有大量的iowait，首先想到了定时任务，是不是机器上跑有定时任务、或外部系统定时对service服务发起调用？
把所有相关的定时任务排查了一遍，发现没有吻合上的定时任务； 对服务的请求也做了相关的统计，流量没有发现明显的差异。
初步可以排除定时任务、业务流量变化。
3.2 网络情况
疑问：该现象是在两个服务之间交互的时间产生的，会不会是网络原因，在web和servce之间还有一层负载均衡，负载均衡对我们而言是黑盒的？
联系到阿里云的技术协同排查一下SLB，通过抓包看了一下请求包的情况，阿里云反馈是service服务慢，可以优先排查service的原因， service的确有慢的情况，怀疑刚才的情况正好是service慢的情况，这样排查的确有太多因素影响，于是先处理service慢的原因， 把php 和 nginx 都耗时长的请求单独拿出来，发现阿里云的健康检查也会有超时，这么简单的请求怎么会超时呢？
诡异，是不是 nginx 和 php 有问题？
同时在多台service上进行抓包，捕捉上面现象所对应的网络数据包发送情况，发现有大量的RST，追查了一个具体的tcp流，
发现service收到请求后并没有及时响应, 随后web主动断开了请求，为什么service的处理能力会下降呢，这一时刻service上做了什么操作呢？
3.3 Nginx、PHP服务
从线上摘下一台出现频率比较高的机器，只接受简单的健康检查请求，和业务流量隔离开，观察是否会复现，结果仍会有超时的情况，初步可以排除了业务的影响，
此时找到了个可以复现的点，给问题排查带来了一些方便。
排查业务后，还剩 nginx + php + ecs实例 + 物理机。
接着最想知道的就是nginx 和 php 此时都做了什么操作，时间都消耗到什么地方去了，用strace工具跟踪了nginx、php系统调用过程， 观察系统调用过程的耗时情况，发现很多都是在磁盘IO的时间耗时较长，这和上面看到iowait飙升可以匹配上了， 不让人理解的是为什么会iowait上升，此时只剩正常的监控检查，磁盘IO操作也不会那么大？
3.4 磁盘IO
是不是物理环境有问题，让阿里云技术做了更换ECS实例所在物理机的测试，然而没什么卵用，通过iotop工具查看磁盘IO比较高的进程， 没发现异常的进程，nginx、php进程占用的磁盘IO确实比较高，是iowait上升引起nginx、php响应慢，还是nginx、php进程造成iowait上升， 因果傻傻分不清楚，只能通过测试来一步步排查了：
- 测试一：停掉php、nginx服务，iowait没有上升，此时似乎也没什么磁盘IO操作了；
- 测试二：停掉php服务，nginx指向静态页面，iowait会有上升，排除php影响；
- 测试三：模拟nginx的磁盘写入，看看是不是会引起iowait上升， 准备用磁盘IO测试工具来模拟，结果把服务玩坏了，真是祸不单行，找OP重启机器去，磁盘被玩坏了，要从快照里恢复，发现了快照的生成时间和上诉现象的时间点吻合，是不是快照的原因引起的呢？
- 测试四：停止机器的快照功能，观察请求时间，一切正常，初步断定了是快照功能带来的影响，同时也
找阿里云的技术进行了核实，快照的确会对磁盘的IO有一定影响
四、总结
- 问题的排查是个抽丝剥茧的过程，通过一步步的测试排除可疑点；
- 每个排查点相应的工具会对排查效率有很大的提高；
- 思路要开阔，不要局限于眼前看到的；如果不用到快照功能，什么时候才能排查到是快照的影响？
