
我是通过主路由 nft 分流国外流量->sing-box 这样的方案,sing-box 之前一直用的 1.10 版本,最近升级到 1.12.12 ,然后日常操作系统 macos ,翻墙协议 hy2 ,最近想试试 anytls ,就搭了个节点试了下,日常使用中发现有个问题,关闭某个需要翻墙的网页但不关闭浏览器,过一段时间重新打开这个网站,会卡 10s 左右,查看浏览器 timing ,发现会卡在 stalled 状态 10+秒,然后换 reality 一样有这个问题,hy2 就没这个问题。
记录浏览器日志分析一下,发现 h2.ping_failed 错误,底层报 network-error ,耗时 10 秒
h2.ping_failed { "attempts": 0, "body": { "elapsed_time": 9273, "method": "GET", "phase": "application", "protocol": "h2", "referrer": "", "sampling_fraction": 1, "server_ip": "fc00::3e", "status_code": 0, "type": "h2.ping_failed" }, "depth": 0, "group": "cf-nel", "network_anonymization_key": "https://nodeseek.com same_site", "queued": "19011117", "status": "pending", "type": "network-error", "url": "https://www.nodeseek.com/" } 继续抓 tcp ,发现 tcp_keep_alive 都有正常返回,但是发送 tls 数据包立即收到 ack 但是没有任何应用层数据返回,等了 10 秒,本地主动关闭了这个连接。
57935 2005.830332 local fc00::e TCP 74 [TCP Keep-Alive] 56747 → 443 [ACK] Seq=30879 Ack=353231 Win=131072 Len=0 57936 2005.830710 fc00::e local TCP 86 [TCP Keep-Alive ACK] 443 → 56747 [ACK] Seq=353231 Ack=30880 Win=60416 Len=0 TSval=378749083 TSecr=3110960712 58772 2016.221237 local fc00::e TLSv1.3 341 Application Data 58773 2016.221246 local fc00::e TLSv1.3 125 Application Data 58774 2016.221601 fc00::e local TCP 86 443 → 56747 [ACK] Seq=353231 Ack=31135 Win=60416 Len=0 TSval=378759474 TSecr=3111331241 58775 2016.221608 fc00::e local TCP 86 443 → 56747 [ACK] Seq=353231 Ack=31174 Win=60416 Len=0 TSval=378759474 TSecr=3111331241 58805 2017.168143 local fc00::e TLSv1.3 121 Application Data 58806 2017.168586 fc00::e local TCP 86 443 → 56747 [ACK] Seq=353231 Ack=31209 Win=60416 Len=0 TSval=378760420 TSecr=3111332188 58810 2017.182453 local fc00::e TLSv1.3 841 Application Data 58811 2017.182926 fc00::e local TCP 86 443 → 56747 [ACK] Seq=353231 Ack=31964 Win=60416 Len=0 TSval=378760435 TSecr=3111332203 59351 2026.123200 local fc00::e TLSv1.3 137 Application Data 59352 2026.123327 local fc00::e TCP 86 56747 → 443 [FIN, ACK] Seq=32015 Ack=353231 Win=131072 Len=0 TSval=3111341246 TSecr=378760435 59353 2026.123579 fc00::e local TCP 86 443 → 56747 [ACK] Seq=353231 Ack=32015 Win=60416 Len=0 TSval=378769479 TSecr=3111341246 59356 2026.124104 fc00::e local TCP 86 443 → 56747 [FIN, ACK] Seq=353231 Ack=32016 Win=60416 Len=0 TSval=378769480 TSecr=3111341246 59357 2026.124213 local fc00::e TCP 86 56747 → 443 [ACK] Seq=32016 Ack=353232 Win=131072 Len=0 TSval=3111341248 TSecr=378769480 看到这里,大概猜测是本地->sing-box 的连接是存活的,但是 sing-box 到代理服务器的连接已经挂掉了,而且 sing-box 并没有清理掉这个连接。
开启 sing-box 的 debug 日志看一下,但是发现被卡住的请求的时间点有 dns-in 请求的日志,但是却一直没有 tcp-in 的日志和 outbound 的路由日志,等到 10 秒之后才出现 outbound 日志,日志太长这里就不贴了。
观察 yacd 面板活动链接,一个活动链接在关闭页面之后可以存活 13 分钟以上,但是实际在关闭页面 5 分钟之后,打开该网站就会卡 10 秒,并且该活动链接被关闭,浏览器新开了一个链接才能正常访问。
查看 sing-box 所在路由器的 keepalive 参数
net.ipv4.tcp_keepalive_intvl = 75 net.ipv4.tcp_keepalive_probes = 9 net.ipv4.tcp_keepalive_time = 120 链接空闲 2 分钟开始发 keepalive 包,得不到回复会重试 9 次,尝试修改重试次数为 1 次,现象依旧。
翻一翻 sing-box 的代码,发现问题出在 /constant/timeout.go
TCPKeepAliveInitial = 10 * time.Minute TCPKeepAliveInterval = 75 * time.Second 这里将 tcpkeepalive 的空闲时间设置为 10 分钟 在客户端默认 tcp 请求类构造中确实用到了这个参数 /common/dialer/default.go
看了下官方 dialer 包的 tcpkeepalive 默认空闲时间是 15 秒,不知道这里为啥设置 10 分钟。
尝试修改 TCPKeepAliveInitial 为 2 分钟重新打包测试,问题修复。
再次抓包 chrome ,可以看到 chrome 在页面关闭后会每隔 45s 左右发送 tcpkeepalive 包保活以便后续复用,由于中间有代理,所以这个实际上是和路由器的链接,从 ack 的响应时间也看得出来,服务器在 400s 左右发送 http 的 GOAWAY 标志关闭本连接,这是应用层的返回了,说明直到服务器主动关闭,代理到目标网站服务器的连接是正常的。
18099 272.552947 local fc00::1c HTTP2 121 RST_STREAM[209] 18100 272.553314 fc00::1c local TCP 86 443 → 49196 [ACK] Seq=1397977 Ack=14892 Win=64512 Len=0 TSval=442426090 TSecr=3576262906 19028 317.554963 local fc00::1c TCP 74 [TCP Keep-Alive] 49196 → 443 [ACK] Seq=14891 Ack=1397977 Win=131072 Len=0 19029 317.555459 fc00::1c local TCP 86 [TCP Keep-Alive ACK] 443 → 49196 [ACK] Seq=1397977 Ack=14892 Win=64512 Len=0 TSval=442471091 TSecr=3576262906 ...... 20636 637.695578 fc00::1c local TCP 86 [TCP Keep-Alive] 443 → 49196 [ACK] Seq=1397976 Ack=14892 Win=64512 Len=0 TSval=442791228 TSecr=3576505164 20637 637.695735 local fc00::1c TCP 86 [TCP Keep-Alive ACK] 49196 → 443 [ACK] Seq=14892 Ack=1397977 Win=131072 Len=0 TSval=3576628043 TSecr=442758351 20712 672.557774 fc00::1c local HTTP2 125 GOAWAY[0] 20713 672.557940 local fc00::1c TCP 86 49196 → 443 [ACK] Seq=14892 Ack=1398016 Win=131072 Len=0 TSval=3576662905 TSecr=442826089 20714 672.558192 local fc00::1c TCP 86 49196 → 443 [FIN, ACK] Seq=14892 Ack=1398016 Win=131072 Len=0 TSval=3576662905 TSecr=442826089 20715 672.558920 fc00::1c local TCP 86 443 → 49196 [FIN, ACK] Seq=1398016 Ack=14893 Win=64512 Len=0 TSval=442826090 TSecr=3576662905 20716 672.559025 local fc00::1c TCP 86 49196 → 443 [ACK] Seq=14893 Ack=1398017 Win=131072 Len=0 TSval=3576662906 TSecr=442826090 之前没试过 safari ,再抓下 safari 试试看,发现 safari 完全不会主动保活,对端发回来的保活信息也无视掉,过了 250s 直接给 rst 了。查了下 mac 的系统参数,tcpkeepalive 确实是关闭的。说明之前如果用 safari 反而不会有问题。
32182 955.580181 198.18.0.25 192.168.1.144 TLSv1.3 720 Application Data, Application Data, Application Data 32183 955.580780 192.168.1.144 198.18.0.25 TCP 66 56737 → 443 [ACK] Seq=22625 Ack=3804785 Win=130560 Len=0 TSval=3062114973 TSecr=1951439236 32910 1077.884854 198.18.0.25 192.168.1.144 TCP 66 [TCP Keep-Alive] 443 → 56737 [ACK] Seq=3804784 Ack=22625 Win=65536 Len=0 TSval=1951561540 TSecr=3062114973 32911 1077.885054 192.168.1.144 198.18.0.25 TCP 66 [TCP Window Update] 56737 → 443 [ACK] Seq=22625 Ack=3804785 Win=131072 Len=0 TSval=3062237276 TSecr=1951439236 33232 1195.831135 192.168.1.144 198.18.0.25 TCP 54 56737 → 443 [RST, ACK] Seq=22625 Ack=3804785 Win=131072 Len=0 再抓下路由器,发现会正常发送保活信息了,时间也正好是之前改的 2 分钟
2083 8.117003 local proxy TLSv1.3 103 Application Data 2110 8.302440 proxy local TCP 68 443 → 55336 [ACK] Seq=1338702 Ack=14854 Win=43008 Len=0 TSval=2009101644 TSecr=2466027398 3398 128.639991 local proxy TCP 68 [TCP Keep-Alive] 55336 → 443 [ACK] Seq=14853 Ack=1338702 Win=2267136 Len=0 TSval=2466147921 TSecr=2009101644 3399 128.826529 proxy local TCP 68 [TCP Keep-Alive ACK] 443 → 55336 [ACK] Seq=1338702 Ack=14854 Win=43008 Len=0 TSval=2009222157 TSecr=2466027398 3812 250.879981 local proxy TCP 68 [TCP Keep-Alive] 55336 → 443 [ACK] Seq=14853 Ack=1338702 Win=2267136 Len=0 TSval=2466270161 TSecr=2009222157 3816 251.066285 proxy local TCP 68 [TCP Keep-Alive ACK] 443 → 55336 [ACK] Seq=1338702 Ack=14854 Win=43008 Len=0 TSval=2009344385 TSecr=2466027398 4539 373.759985 local proxy TCP 68 [TCP Keep-Alive] 55336 → 443 [ACK] Seq=14853 Ack=1338702 Win=2267136 Len=0 TSval=2466393041 TSecr=2009344385 4541 373.946893 proxy local TCP 68 [TCP Keep-Alive ACK] 443 → 55336 [ACK] Seq=1338702 Ack=14854 Win=43008 Len=0 TSval=2009467253 TSecr=2466027398 4582 408.114641 proxy local TLSv1.3 107 Application Data 4583 408.115025 proxy local TLSv1.3 92 Application Data 4584 408.115121 local proxy TCP 68 55336 → 443 [ACK] Seq=14854 Ack=1338765 Win=2267136 Len=0 TSval=2466427396 TSecr=2009501418 4585 408.115260 proxy local TCP 68 443 → 55336 [FIN, ACK] Seq=1338765 Ack=14854 Win=43008 Len=0 TSval=2009501419 TSecr=2466027398 4586 408.115824 local proxy TLSv1.3 92 Application Data 4587 408.115909 local proxy TCP 68 55336 → 443 [FIN, ACK] Seq=14878 Ack=1338766 Win=2267136 Len=0 TSval=2466427396 TSecr=2009501419 4588 408.301673 proxy local TCP 56 443 → 55336 [RST] Seq=1338766 Win=0 Len=0 本次是由于 sing-box 的 tcpkeepalive 连接空闲时间设置过长,导致 sing-box 和代理服务器之间的空闲连接已经被清理了(估计是运营商干的),但是 sing-ox 并不知道,直到 10 分钟之后才会探测,探测 9*15 秒之后才会释放该连接。chrome 一直积极保活该连接,使用的时候发现请求超时没有回复才主动断掉重新建立连接。
sing-box 后续估计会把 tcpkeepalive 参数做成可修改的配置,不过这个默认 10 分钟也不太合适。
1 nilai 1 小时 56 分钟前 不错,你分析的这个过程值得学习 |