一次怪异的业务卡顿排查过程

标签：rabbit   number   time   tail   shadow   拨打电话   seq   ofo   ext   

• 故障现象
  ????客服人员使用该系统的其中几个功能模块的时候，弹出的沟通窗口会卡顿，并且关闭当前弹窗，返回首页也会卡顿，卡顿时间1分钟左右。
  

• 排查流程

  1，系统排查
  根据现场IT同事反馈异常出现比较集中到时段，进行系统状态查看：
  A，pinpoint查看后端应用GC和内存使用均正常；
  B，nginx日志中没有大量超时异常请求（ELK日志中没请求超时情况）;
  C，不存在大量请求在同一台服务器，造成单台服务器负载过高情况；

  2，网络排查
  A，发生异常时，IT 现场进行ping 正常;访问其他网站正常；访问公司其他网站正常；
  B，发生异常时，traceroute正常；
  C，IT 统计办公区网络设备连接数，并未发现异常(担心网络终端网络连接数被耗尽)；

D，IT增加一个公网出口IP，卡顿依旧;

3，浏览器debug
A，指导用户使用浏览器debug，进行请求分析并未发现异常；
B，拿到测试账号，登陆后台进行debug,没有发现耗时长的资源请求；

4，再次收集问题
通过上面到排查，排出了应用，网络问题，开始怀疑用户客户端问题。
A，it通过资源管理监控，异常情况时，用户电脑资源并未有明显波动；

5，IP电话问题
?????到目前为止，可能原因和故障点都进行了排查和验证，但是都未发现异常原因，感觉走入了死胡同。
之前的问题故障现象都是测试或者产品反馈，于是直接找IT和使用人员重新了解故障发生前后操作以及故障现象。同IT了解过程，收集到一个奇怪到现象：拨打IP电话和挂断IP电话打时候会出现卡顿现象。
A，该现象每次毕现；于此同时IP电话打不通和中途断线情况；
B，让it咨询IP电话服务商，确认IP电话是否会对网络有影响；

??感觉像是找到了“背锅”的对象， 由于涉及到外部协调排查IP电话，比较费时，同时使用IP电话系统的另外一个系统没有出现卡顿现象（虽然IP电话使用数量上少很多），于是怀疑IP电话和这个关联性不太高，属于巧合。

6，wireshark 抓包

A，通过之前分析，服务是OK，由于没法办法追踪到具体用户请求，所有不方便排查用户请求是否到达服务器；
B，故障属于随机发生和离现场较远，没法现场待命随时进行浏览器debug分析；
C，traceroute 排除了网络层的问题，浏览器debug基本排出应用层问题；
??????由于拨打电话毕现，因此让IT同事找个用户电脑进行安装抓包软件，并让他进行电话拨打，对这个时间段对抓包结果进行分析。

• 抓包分析

  根据IT抓包结果，发现有大量对虚假重传：
  

  搜索 “tcp spurious retransmission”，网上给出以下可能出现的原因
  tcp虚假重传
  指实际上并没有超时，但看起来超时了，导致虚假超时重传的原因有很多种：
  （1）对于部分移动网络，当网络发生切换时会导致网络延时突增
  （2）当网络的可用带宽突然变小时，网络rtt会出现突增的情况，这会导致虚假超时重
  （3）网络丢包（原始和重传的包都有可能丢包）会导致虚假重传超时。
  但是都没有关于该问题的解决方法。
  由于对wireshark这个软件不是太熟悉，对分析结果不是太确定，于是搜索关键词"wireshark spurious retransmission" ，学习wireshard的基本用法。
  https://blog.csdn.net/faithc/article/details/52832617?locationNum=1&fps=1
  这个博客中提到一个关于 “tcp dump ack”的解释：

  当网络中存在乱序或者丢包时，将会导致接收端接收到的seq number不连续。此时接收端会向发送端回复重复ack，ack值为期望收到的下一个seq number。重复ack数大于等于3次将会触发快速重传

  根据我之前的排查，应该不存在网络丢包的问题，于是搜索tcp乱序问题，找到了 timestamp和顺序有关。

• 尝试方案

  文章https://blog.csdn.net/happyrabbit456/article/details/45694631?locationNum=9&fps=1
  文章http://blog.sina.com.cn/s/blog_781b0c850100znjd.html ----lvs 大神
  提及到故障现象和我们遇到类似，于是修改内核参数tcp_tw_recycle=0，并观察（周日修改）

• 故障复现

  周日修改后，周一天告知it注意观察；到下班时候，确认一天内没有用户反馈卡顿现象；
  为了验证该问题，确认不是由于其他操作（更新，网络改善）解决该问题，于是周一晚上把该参数调整回去；周二上午上班到10:30 收到5-6个卡顿到问题，于是修改回参数，到下班未收到类似反馈。

• 问题原因

  同时开启tcp_timestamp和tcp_tw_recycle会启用TCP/IP协议栈的per-host的PAWS机制; 经过同一NAT转换后的来自不同真实client的数据流，在服务端看来是于同一host打交道;但由于不同真实client会携带各自的timestamp值;因而无法保证整过NAT转化后的数据包携带的timestamp值严格递增; 当服务器的per-host PAWS机制被触发后，会丢弃timestamp值不符合递增条件的数据包

  参考文献 http://perthcharles.github.io/2015/08/27/timestamp-NAT/

• 解决方案
  net.ipv4.tcp_tw_recycle = 0 (所有直接对外提供服务到服务器关闭）

一次怪异的业务卡顿排查过程

标签：rabbit   number   time   tail   shadow   拨打电话   seq   ofo   ext   

原文地址：http://blog.51cto.com/emulator/2172744