我们项目的 Websocket Server 使用的 Swoole,最近在搭建 beta 环境的时候发现 Websocket 协议虽然升级成功了,但是会出现定时重连,心跳、数据也一直没有发送。项目的生产环境和 beta 一致,但是生产环境确没有这个问题。
定位问题
为了方便调试 Swoole,以下测试是在本地环境下进行。
查看 PHP 日志
在 PHP 日志里,发现一条错误日志: ErrorException: Swoole\WebSocket\Server::push(): the connected client of connection[47] is not a websocket client or closed,说明 Websocket 连接已经 close 了。
抓包
既然连接被 close 掉了,那我们来看看是谁主动关闭的连接。Swoole 监听的端口是 1215,通过 tcpdump -nni lo0 -X port 1215 可以看到,Swoole 在发出协议升级的响应报文后,又发出了 Fin 报文段,即 Swoole 主动断开了连接,所以才会出现浏览器显示 WebSocket 连接建立成功,但是又定时重连的问题。
10:22:58.060810 IP 127.0.0.1.1215 > 127.0.0.1.53823: Flags [P.], seq 1:185, ack 1372, win 6358, options [nop,nop,TS val 1981911666 ecr 1981911665], length 184
0x0000: 4500 00ec 0000 4000 4006 0000 7f00 0001 E.....@.@.......
0x0010: 7f00 0001 04bf d23f 9377 304a 6d2f 9604 .......?.w0Jm/..
0x0020: 8018 18d6 fee0 0000 0101 080a 7621 9272 ............v!.r
0x0030: 7621 9271 4854 5450 2f31 2e31 2031 3031 v!.qHTTP/1.1.101
0x0040: 2053 7769 7463 6869 6e67 2050 726f 746f .Switching.Proto
0x0050: 636f 6c73 0d0a 5570 6772 6164 653a 2077 cols..Upgrade:.w
0x0060: 6562 736f 636b 6574 0d0a 436f 6e6e 6563 ebsocket..Connec
0x0070: 7469 6f6e 3a20 5570 6772 6164 650d 0a53 tion:.Upgrade..S
0x0080: 6563 2d57 6562 536f 636b 6574 2d41 6363 ec-WebSocket-Acc
0x0090: 6570 743a 2052 6370 3851 6663 446c 3146 ept:.Rcp8QfcDl1F
0x00a0: 776e 666a 6377 3862 4933 6971 7176 4551 wnfjcw8bI3iqqvEQ
0x00b0: 3d0d 0a53 6563 2d57 6562 536f 636b 6574 =..Sec-WebSocket
0x00c0: 2d56 6572 7369 6f6e 3a20 3133 0d0a 5365 -Version:.13..Se
0x00d0: 7276 6572 3a20 7377 6f6f 6c65 2d68 7474 rver:.swoole-htt
0x00e0: 702d 7365 7276 6572 0d0a 0d0a p-server....
10:22:58.060906 IP 127.0.0.1.53823 > 127.0.0.1.1215: Flags [.], ack 185, win 6376, options [nop,nop,TS val 1981911666 ecr 1981911666], length 0
0x0000: 4500 0034 0000 4000 4006 0000 7f00 0001 E..4..@.@.......
0x0010: 7f00 0001 d23f 04bf 6d2f 9604 9377 3102 .....?..m/...w1.
0x0020: 8010 18e8 fe28 0000 0101 080a 7621 9272 .....(......v!.r
0x0030: 7621 9272 v!.r
10:22:58.061467 IP 127.0.0.1.1215 > 127.0.0.1.53823: Flags [F.], seq 185, ack 1372, win 6358, options [nop,nop,TS val 1981911667 ecr 1981911666], length 0
0x0000: 4500 0034 0000 4000 4006 0000 7f00 0001 E..4..@.@.......
0x0010: 7f00 0001 04bf d23f 9377 3102 6d2f 9604 .......?.w1.m/..
0x0020: 8011 18d6 fe28 0000 0101 080a 7621 9273 .....(......v!.s
0x0030: 7621 9272 v!.r
追踪 Swoole 源码
我们现在知道了是 Swoole 主动断开了连接,但它是在什么时候断开的,又为什么要断开呢?就让我们从源码一探究竟。
从抓包结果看,发出响应报文到 close 连接的时间很短,所以猜测是握手阶段出了问题。从响应报文可以看出,Websocket 连接是建立成功的,推测 swoole_websocket_handshake() 的结果应该是 true,那么连接应该是在 swoole_websocket_handshake() 里 close 的。
// // swoole_websocket_server.cc int swoole_websocket_onHandshake(swServer *serv, swListenPort *port, http_context *ctx) { int fd = ctx->fd; bool success = swoole_websocket_handshake(ctx); if (success) { swoole_websocket_onOpen(serv, ctx); } else { serv->close(serv, fd, 1); } if (!ctx->end) { swoole_http_context_free(ctx); } return SW_OK; }