问题初现
二线反馈近期有用户反馈,在小程序和微信公众号内,websocket 连接经常会有连接超时,并且等了一分多钟后才发起重连的问题。 在我们内部测试,并没有发现类似情况,所以猜测是用户的网络环境问题。让用户切换网络环境后,并没有解决。
内部排查
- 由于近期新发布了几个版本,第一时间怀疑是代码修改问题,所以先进行了代码review,分析了一遍连接这一块的逻辑,没有发现什么问题。
- 刚开始我们本地无法复现,所以需要用户配合,一起抓包分析网络请求,发现出现问题时,有些 TCP 包发出去没有返回。怀疑是用户当时的 CDN 节点有问题。
- 刚开始只是在微信的环境里复现,所以怀疑是微信内部的 websocket 机制问题,然后去查了微信小程序中websocket 相关的文档,试图找出一些端倪,然而并没有解决。
- 反馈该问题的用户越来越多。
- 经过频繁测试连接 -> 调用接口 -> 断开,偶尔可能会复现一次,浏览器和小程序都会复现。通过打印日志和抓包分析,发现出现问题时 ping 消息发出去后没有返回 pong,两次之后 SDK 就会主动断开 websocket,但是在调用了 websocket.close() 方法后,1分钟后才收到websocket.onclose() 回调,所以导致一分钟后才发起重连。
- 分析 TCP 抓包日志后得到结果是有发送消息,但是没有返回响应消息。
- 因为一分钟后才收到 onclose() 回调感到很奇怪,也无法定位是 SDK 内部实现机制问题,还是服务端问题,然后通过修改和删减SDK代码,连接外部 socket,经过上百次重复测试没有发现问题。
- 这时基本可以确定不是前端 SDK 问题了。
服务端协助排查
- 服务端在收到 ping 后并没有做任何逻辑处理,直接返回 pong。
- 因为线上服务器有几十台机器,不好查看日志,所以尝试在测试环境复现一下,好抓包看日志分析,但是在测试环境经过大量测试也没有复现。
- 这是就基本可以排除是代码bug了,怀疑是客户端到服务端中间环境问题。
运维协助排查
- 运维通过抓服务器的 TCP 包发现,出现问题时确实是收到消息但是没有发出。
- 通过大量测试、复现,分析规律发现当请求落到某一台负载上的时候就会发不出消息。
- 在下掉这台负载后,经过上百次重复测试,问题不再复现。
总结
这次问题从刚开始暴露到最终解决总历时超过35天,时间拖的有点久了,原因是:1. 刚开始不容易复现,需要客户配合抓包测试,过于繁琐;2. 个人对网络这块功力尚浅,前期分析日志到排除前端问题耗费大量时间。
反思,刚开始当有多个用户反馈的时候就应该尽快进行内部大量测试,复现问题。当无法定位问题出在哪里时,应该尽早进行不同环境的交叉测试,分析测试结果找规律。
收获
通过这次排查问题收获还是挺多的,学会了抓包分析TCP日志,阅读了大量TCP、HTTP、Websocket 相关的文章,对其内部机制和协议有了一定的了解,下一步的计划是读两本书:图解TCP/IP 和 图解HTTP,对网络这块的知识做个系统化的学习和巩固。 当遇到问题时才知道学习相关知识的重要性,这是也是去学习的最佳时机,因为这时印象最深刻。当然遇到问题之前就已经学会了更好。