一次现网问题定位-websocket断连问题

背景

本系统为客服系统，客服侧通过websocket推送消费者发送的消息，并上屏。本来前端有设计断连重连的，但是断断续续有客服反馈消息不上屏，这个已经持续了好几年了，因为发生概率概率很低，客服作业时又没办法拉着一直等着复现。因此该问题一直未得到有效定位和解决。最近有个网点的客服复现概率较高，加上他们服务的对象是2B的，答复速度相对宽松，可以边跟用户沟通，边让我们捣鼓，因此对此问题做了一次深入的定位。

代码说明

本系统前端使用的是sockjs，后端用的spring-websocket，同时配置成了sockjs（sockjs可以通过降级模拟websocket，适用范围更广更可靠）。

初步的定位思路

实际上任何问题定位都是通过各种渠道，去了解现场；在结合源码分析，基本上就能知道大概是什么原因了。但是面对非业务代码问题时，很多时候很难获取足够的现场信息，加之也不能快速掌握代码，定位都比较困难。
对于本问题在定位前就有以下疑问：

1. websocket为什么会断？
   一般来说tcp协议是可靠的，除非网络质量非常差，导致重传多次后仍得不到ack，按说应该是小概率事件，但是这个站点却比较容易出现，几个小时会产生一次。也不可能是应用层的超时配置导致，因为双向都有心跳保活，间隔小于30s。这里需要通过抓包确定网络层到底发生了什么问题。
2. websocket为什么重连机制失效了？这个需要用户打开chrome的调试工具（F12），等待问题复现时，观察network看板，到底是代码有bug导致没有重连，还是服务端有问题重连不上？

各种渠道获取的信息分析

浏览器信息分析

从上图可以观察到，重连机制是ok的，但是可疑的是，网络如此不稳定，多次websocket重连失败？另外为什么降级成xhr_streaming报错？
上面有2个比较重要的信息时，websocket重连时，浏览器里面有报“websocket is closed before the connection is established”;另外降级成xhr_streaming后，请求显示cancel。
对于第一个需要通过抓包，确认tcp创建过程中发生了什么错误。对于第二个需要确认到底浏览器因为什么原因取消（主动中断）了此次请求，是浏览器的行为，还是代码的行为？

抓包分析

抓包的数据就不在这展示了，从里面获取到如下信息：

1. 上面websocket协议的连接请求，在抓包中没有出现，可见浏览器没发出请求(至于有没有发起tcp连接无法确认，单纯的tcp三次握手没有特异性)
2. 降级后xhr_streaming请求有发送，但服务端并没有响应，然后客户端（浏览器）主动发起了关闭连接的请求。

到此，我仍不清确定“websocket is closed before the connection is established”是因为什么导致的。不过我隐约感觉，像是什么超时，导致请求被取消，因为xhr_streaming请求持续的时间都差不多，大约600多ms。这个不可能是网络不稳定，要是因为网络原因，大面积的请求失败，用户其他功能也一定会有问题。
接下来决定先研究一下xhr_streaming降级请求为啥也失败了，因为我可以修改sockjs的配置，强制使用该降级协议，在测试环境进行调试，确认问题。

测试环境问题重现分析

通过强制sockjs使用xhr_streaming，复现问题并调试服务端

constoptions={transports:['xhr-streaming']};

本地测试结果如下：

1. 请求会到后台，能够触发后台websocket的afterConnectionEstablished回调。
2. 前端onopen回调无法触发
3. 浏览器F12观察到的现象与生产一致，xhr_streaming的请求没有响应，timing里面也未显示Request/Response相关时间信息

从上面可以发现网络是正常的，服务端能够正常收到请求。但是前端onopen没有触发，我对sockjs这个库有一定的了解，该库专门定义几个事件o(open事件)，h（心跳事件），现在既然前端onopen的回调没有触发，那应该是open事件的数据没有给到前端（抓包可以证明该点）。
本来我想通过源码确认该事件是何时发送的，这个太耗时了，所以搜索了AI，“SockJS 配置xhr_streaming模式，无法收到open事件”，AI答复是，nginx会缓存数据（开启proxy_buffering），不会立即给前端。
我并未通过抓包验证上述回答，该答案能够很好的解释当前现象，而且只有该种场景，能够支撑我怀疑是代码中有超时取消请求的逻辑，因此通过调试工具中看到接口调用的堆栈，逐个去分析可疑代码。并得到一下信息：

1. sockjs有连接超时机制，如果超时时间内，没触发状态转换，则close此次连接。详细见后面sockjs源码。
2. 超时时间由应用层的超时配置、/info接口的响应时间、默认5s共同决定。默认取/info接口的响应时间:Math.max(this._timeout, (this._rto * Transport.roundTrips) || 5000)

代码可以直接看sockjs的main.js

SockJS.prototype._connect=function(){for(varTransport=this._transports.shift();Transport;Transport=this._transports.shift()){# 不重要的代码有省略// calculate timeout based on RTO and round trips. Default to 5svartimeoutMs=Math.max(this._timeout,(this._rto*Transport.roundTrips)||5000);# 该方法重点关注，用于设置超时关闭连接this._transportTimeoutId=setTimeout(this._transportTimeout.bind(this),timeoutMs);varoptions=this._transportOptions[Transport.transportName];vartransportObj=newTransport(transportUrl,this._transUrl,options);transportObj.on('message',this._transportMessage.bind(this));transportObj.once('close',this._transportClose.bind(this));}this._close(2000,'All transports failed',false);};SockJS.prototype._transportTimeout=function(){debug('_transportTimeout');if(this.readyState===SockJS.CONNECTING){if(this._transport){this._transport.close();}this._transportClose(2007,'Transport timed out');}};

从上述分析，xhr_streaming请求的取消，是因为连接超时了，超时时间是info接口的响应时间，单次请求的时间肯定是有波动的，所以触发该超时还是有一定概率的，因此前面websocket连接失败，并显示“websocket is closed before the connection is established”，应该也是超时，然后被sockjs取消了请求。为此，我修改了sockjs的源码，将超时时间设置成10ms，并将协议改回websocket，测试结果与生产一致。
应用层代码修改

constoptions={transports:['websocket']timeout:10};

sockjs源码修改（Math.max改成了Math.min）

vartimeoutMs=Math.min(this._timeout,(this._rto*Transport.roundTrips)||5000);

至此websocket重连失败的问题已经定位结束。

对于开头问题1的说明

最近版本前端引入了一个问题，前端对重连进行了加固，除了监听框架的close事件进行重试外，也增加了主动探测webosocket是否工作正常。探测原理就是不断检查服务端发的心跳，一旦长时间（75s）无法获取心跳，则判定websocket不可靠，需要进行重连。
问题是，sockjs并不是固定频率发送心跳。它的机制是，设定了30秒的定时器不断发送心跳，不过正常的消息会重置这个定时器，所以客服工作过程中，与消费者不断发消息时，会不断重置定制器，导致心跳一直不发，从而前端判定websocket不稳定而重连。重连又有可能重连不成功（前面分析的原因），该期间消息丢失。

上述问题解决后，未碰到业务保障消息不上屏的问题。因此没办法通过抓包确认，因为网络原因导致的websocket断连，问题定位到此告一段落。

后记

sockjs对连接超时的设计，我个人觉得并不合理，网络是复杂的，不能保证相同的请求，总是有相同的延时，因此默认的超时时间如果以info接口的延时为参考，应该在他的基础上，在加一点冗余。
另外前面关于nginx开启proxy_buffering后，响应会被缓存，导致xhr_streaming不能及时收到open事件，这个我也经过了验证。
我在服务的响应头中增加了“X-Accel-Buffering: no;”，xhr_streaming协议就能正常工作了。