记一次 websocket 连接问题排查记录

1,645 阅读4分钟

问题初现

二线反馈近期有用户反馈,在小程序和微信公众号内,websocket 连接经常会有连接超时,并且等了一分多钟后才发起重连的问题。 在我们内部测试,并没有发现类似情况,所以猜测是用户的网络环境问题。让用户切换网络环境后,并没有解决。

内部排查

  1. 由于近期新发布了几个版本,第一时间怀疑是代码修改问题,所以先进行了代码review,分析了一遍连接这一块的逻辑,没有发现什么问题。
  2. 刚开始我们本地无法复现,所以需要用户配合,一起抓包分析网络请求,发现出现问题时,有些 TCP 包发出去没有返回。怀疑是用户当时的 CDN 节点有问题。
  3. 刚开始只是在微信的环境里复现,所以怀疑是微信内部的 websocket 机制问题,然后去查了微信小程序中websocket 相关的文档,试图找出一些端倪,然而并没有解决。
  4. 反馈该问题的用户越来越多。
  5. 经过频繁测试连接 -> 调用接口 -> 断开,偶尔可能会复现一次,浏览器和小程序都会复现。通过打印日志和抓包分析,发现出现问题时 ping 消息发出去后没有返回 pong,两次之后 SDK 就会主动断开 websocket,但是在调用了 websocket.close() 方法后,1分钟后才收到websocket.onclose() 回调,所以导致一分钟后才发起重连。
  6. 分析 TCP 抓包日志后得到结果是有发送消息,但是没有返回响应消息。
  7. 因为一分钟后才收到 onclose() 回调感到很奇怪,也无法定位是 SDK 内部实现机制问题,还是服务端问题,然后通过修改和删减SDK代码,连接外部 socket,经过上百次重复测试没有发现问题。
  8. 这时基本可以确定不是前端 SDK 问题了。

服务端协助排查

  1. 服务端在收到 ping 后并没有做任何逻辑处理,直接返回 pong。
  2. 因为线上服务器有几十台机器,不好查看日志,所以尝试在测试环境复现一下,好抓包看日志分析,但是在测试环境经过大量测试也没有复现。
  3. 这是就基本可以排除是代码bug了,怀疑是客户端到服务端中间环境问题。

运维协助排查

  1. 运维通过抓服务器的 TCP 包发现,出现问题时确实是收到消息但是没有发出。
  2. 通过大量测试、复现,分析规律发现当请求落到某一台负载上的时候就会发不出消息。
  3. 在下掉这台负载后,经过上百次重复测试,问题不再复现。

总结

这次问题从刚开始暴露到最终解决总历时超过35天,时间拖的有点久了,原因是:1. 刚开始不容易复现,需要客户配合抓包测试,过于繁琐;2. 个人对网络这块功力尚浅,前期分析日志到排除前端问题耗费大量时间。

反思,刚开始当有多个用户反馈的时候就应该尽快进行内部大量测试,复现问题。当无法定位问题出在哪里时,应该尽早进行不同环境的交叉测试,分析测试结果找规律。

收获

通过这次排查问题收获还是挺多的,学会了抓包分析TCP日志,阅读了大量TCP、HTTP、Websocket 相关的文章,对其内部机制和协议有了一定的了解,下一步的计划是读两本书:图解TCP/IP 和 图解HTTP,对网络这块的知识做个系统化的学习和巩固。 当遇到问题时才知道学习相关知识的重要性,这是也是去学习的最佳时机,因为这时印象最深刻。当然遇到问题之前就已经学会了更好。