目前手里的一个项目,测试人员提交了几次存在页面无响应的问题,但是每次出现页面无响应的时候,开发者工具都不能通过性能监视器、内存监视器查看异常的情况,而我又从来没有在开发环境中捕获到这个问题。
一般来说,一个问题一定对应着一个代码上的缺陷,但是这个问题却始终找不到直观的、可捕获的代码异常,终于今天在我的环境中,这个问题复现了,而且我正好开着开发者工具。不过现象很吊诡,控制台没有任何错误信息输出,网络里面的资源请求页都正常,但是当我排查到了websocket资源时,发现了一个问题:对同一个地址存在两个正保持连接中的websocket请求。由于使用nginx作为网关,ws需要定时发送一个keeplive的字串,这个字串在新链接中迟迟没有被发送,而老的链接中,这个字串最后一次发送时间也远远超过了定期器的执行间隔,大概率就是这里不正常了。
运气好的是,通过网络找到发起程序栈,定位到了具体的代码位置,此时在ws.open的for循环上打了一个断点,竟然捕获到了,确实页面被阻塞在了这里,此时ws.readyState的状态为2(Closing)!也就是说上一个ws连接一直处于Clsoing中,readyState一直切换到到Closed的状态,这就很奇怪了,一般来说,Closing到Closed的状态切换是非常快的,极少可能会出现一直保持在Closing的问题,但新的ws连接已经被建立,那么也就是说onclose其实已经被触发了,注意的是,当websocket的onclose被触发时,readyState不一定就是Closed,而有可能是Closing。
大致的问题到这里就很清楚,也明白为什么是个偶发现象了。因为前一个连接关闭的时候(此时onclose回调还没有执行完成),正好遇到了onopen回调中的for循环里的sleep执行完毕,因为js单线程的原因,任务又切换到了for循环这里,ws.readyState此时又正好为Closing,就一直在这里阻塞,onclose回调也无法正常执行完成,此时就形成了竞争关系,导致了readyState一直无法切换到Closed,从而导致了for循环永远处于循环中,这也是此次问题的根本原因。因为这个问题不涉及到前端的交互操作,而且也是只个极小概率才能复现的问题,导致这么久都没有排查到。
代码如下:
const connector = () => {
console.warn("event connection connecting")
const ws = new WebSocket(url)
ws.onerror = (evt) => {
console.warn("event connection error", evt)
}
ws.onclose = async (evt) => {
console.warn("event connection close", evt)
if (closed) {
return
}
await sleep(3 * 1000)
setTimeout(connector)
}
ws.onopen = async (evt) => {
for (; ws?.readyState !== ws?.CLOSED;) {
if (ws?.readyState === ws?.OPEN) {
ws?.send("keeplive")
await sleep(16 * 1000)
}
}
}
ws.onmessage = (evt) => {
try {
const message = JSON.parse(evt.data)
callback(message)
} catch (e) {
console.info(evt.data)
}
}
}
connector()
找到问题后,解决方案也很简单,因为只是用于定时发送一个keeplive防止nginx网关给ws链接异常关闭掉,因此使用setInterval改造onopen的回调即可。
ws.onopen = async (evt) => {
const interval = setInterval(() => {
if (ws?.readyState === ws?.OPEN) {
ws?.send("keeplive")
} else {
clearInterval(interval)
}
}, 16 * 1000)
}
虽然使用for循环的初衷在与判断readyState的状态,而且是每16秒才执行一次,不存在for循环一直执行的问题,但是忽略了readyState状态的变化问题。
总结
- 慎重使用for循环用于状态检测;
- websocket的Closing状态并不是很快就能从Closing切换到Closed,如果onclose回调阻塞、未收到服务器的关闭响应、网络问题或超时、客户端未正确处理关闭、ws连接处于某种未知的异常。都有可能导致Closing状态无法正确切换到Closed;
后续
2025年1月23日更新
由业务系统登录慢引发的问题。
业务后端使用了nginx进行代理,由nginx统一对服务接口进行代理。在业务的nginx配置中,存在两个websocket的代理,一个提供本文所讲的事件服务,另一个用于提供业务的通信服务。
在业务系统登录后,会连接通信服务,然后会去连接事件服务。在测试的时候,事件服务其实大部分时候都是离线的。这时就出现了一个非常奇怪的问题,同一计算机,第一个用户登录以后,第二个用户再登陆就非常的慢,等待登录的时间最长可以到32秒左右。目前版本的通信服务没有加密链接处理,所以肯定不会存在加密导致的链接慢的问题,在细致排查通信服务的问题后,发现通信服务业务从连接到建立的速度非常快,但是排查网络请求后,发现执行通信服务的WebSocket代码逻辑的同时,网络请求却卡住了,请求处于已经请求,但又未建立(未收到服务器响应)的阶段,通信源服务日志也没有收到WebSocket的连接日志,直到事件服务的WebSokcet抛出连接异常后,通信服务的WebSocket服务开始正式建立连接,通信源服务也收到了连接建立请求。
于是在开发者控制台中,写了两段测试业务逻辑。一段是通过代理服务地址去建立通信服务的WebSocket连接,一段是直接访问通信服务地址建立WebSocket连接。在业务系统没有登录的情况,两个都非常快,但在业务系统登录且退出系统后(此时没有刷新网页),通过代理服务地址访问的WebSocket不出意外的阻塞了,而直接访问的WebSokcet依然很顺畅,直到控制台中事件服务出现了连接异常的错误提示后,代理服务地址的WebSocket终于建立好了连接。
这也就说明阻塞发生在了nginx上,这也就能解释上文为什么websocket的readyState会一直处于Closing的原因,nginx阻塞了。
通过了解,一个nginx的server,是在CPU的某1个核上跑,如果websocket的源服务挂了,访问nginx的代理地址后,nginx会一直尝试去连接这个原服务,直到超时发生,然后才继续后面的请求(不清楚是不是只发生在websocket的反代场景下),因此,只需要调整反向代理的代理连接超时的配置项,将proxy_connection_timeout调到3s。因为被代理的服务都位于同一主机上,通过127.0.0.1的地址去访问,如果超过3s都还访问不到那肯定是服务崩溃了。这个参数根据实际的业务场景进行调整。
DISCUSSION
评论
还没有公开评论,欢迎留下想法。