udp2raw icon indicating copy to clipboard operation
udp2raw copied to clipboard
verified publisher icon wangyu-

经常出现10到20秒左右的断流，附日志和wireshark截图

Open teevor opened this issue 5 years ago • 8 comments

基本信息

客户端（PC） 服务器
系统 Parrot 4.10 (debian发行版) Debian 10
网络 联通200M光纤 Vultr日本
执行用户 非root root
udp2raw 版本 20200715.0 -
连接方式 v2ray(mkcp模式) + udp2raw -

配置文件

  • 服务器
-s
-l 0.0.0.0:8000
-r 127.0.0.1:53
-k XXXXXX
--raw-mode faketcp
--cipher-mode xor
--fix-gro
-a
  • 客户端
-c
-l 127.0.0.1:53000
-r server_ip:8000
-k XXXXXX
--raw-mode faketcp
--cipher-mode xor
--fix-gro

问题描述

流量大时经常出现10到20秒左右的网络中断，大约几分钟或几十秒就会出现一次，尤其是打开多个直播视频时，流量越大越会频繁复现，这里流量大一般指5MByte/s以上（其实也不算太大），比如打开多个Twitch直播页面；而油管和Netflix这类有长时间缓冲的视频相对较少出现断流使用体验。

一般断流可在一二十秒后恢复，但大约两三次里有一次会造成电脑WIFI链接的中断，出现可能性应该也和当时的流量大小程正相关，同时弹出弹出让我输入WIFI密码的窗口，实际并不用重输密码，几秒钟后可以重新手动连接，这还一度让我怀疑是网卡驱动出了问题，不过因为只有mkcp+udp2raw会出现这种情况，而只用v2ray的tcp模式哪怕到20MByte/s的下载速度也不会断WIFI，所以我暂时不太敢换网卡驱动，由此也怀疑跟同时处理的udp数量过多有关，但我不知道这怎么测

尝试

  • 最近没敢试去掉udp2raw两端mkcp模式直连，几个月前开始会被ban，但去年这么用不会出现断流的情况
  • 参考2017年的#43，两边添加--seq-mode 0，没效果

流量示意图

Untitled Diagram (1)

断流时客户端的抓包情况（-> 代表流量方向）

  1. Client v2ray -> Client udp2raw 大量udp包 Client v2ray - Client udp2raw
  2. Client udp2raw -> Client v2ray 没数据，不知道为什么会搜出一条无关的包，打码处是服务器地址 Client udp2raw - Client v2ray
  3. Client udp2raw -> Server udp2raw 没有数据，还是不知道为什么会搜出这几条来，打码处是服务器地址 Client udp2raw - Server udp2raw
  4. Server udp2raw -> Client udp2raw 大量TCP Out_Of_Order和TCP Retransmission，打码处是服务器地址 Server udp2raw - Client udp2raw

断流时的日志

  • 服务器，好像没发现什么异常
Jul 19 15:20:23 user udp2raw_amd64[12309]: [2020-07-19 15:20:23][INFO][101.19.138.220:3092]new conv conv_id=683c1d35, assigned fd=563
Jul 19 15:20:27 user udp2raw_amd64[12309]: [2020-07-19 15:20:27][INFO][101.19.138.220:3092]new conv conv_id=7f85501f, assigned fd=564
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]received syn,sent syn ack back
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]got packet from a new ip
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]created new conn,state: server_handshake1,my_id is 4f81fa42
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]changed state to server_handshake1,my_id is 4f81fa42
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]received handshake oppsite_id:164a3563  my_id:4f81fa42
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]oppsite const_id:54f32c41
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]grabbed a connection
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]new conv conv_id=1f1b5e3a, assigned fd=565
Jul 19 15:20:41 user udp2raw_amd64[12309]: [2020-07-19 15:20:41][INFO][101.19.138.220:3223]new conv conv_id=f2100c42, assigned fd=566
  • 客户端，里面标注了两个点，断流和断WIFI大概出现在那里
Jul 19 22:31:06 user udp2raw_amd64[149902]: [2020-07-19 22:31:06][INFO]new packet from 127.0.0.1:52643,conv_id=859dee25
Jul 19 22:31:14 user udp2raw_amd64[149902]: [2020-07-19 22:31:14][INFO]new packet from 127.0.0.1:56208,conv_id=f10a92e9

> 注：从这开始断流
> Jul 19 22:31:14 user udp2raw_amd64[149902]: [2020-07-19 22:31:14][INFO]state back to client_idle from  client_ready bc of client-->server direction timeout

Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]source_addr is now 10.0.0.3
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]using port 13924
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]state changed from client_idle to client_tcp_handshake
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO](re)sent tcp syn
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]new packet from 127.0.0.1:39040,conv_id=ca7cc381
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]new packet from 127.0.0.1:42194,conv_id=de3822ee
Jul 19 22:31:15 user udp2raw_amd64[149902]: [2020-07-19 22:31:15][INFO]new packet from 127.0.0.1:40783,conv_id=7a71b707
Jul 19 22:31:16 user udp2raw_amd64[149902]: [2020-07-19 22:31:16][INFO](re)sent tcp syn
Jul 19 22:31:17 user udp2raw_amd64[149902]: [2020-07-19 22:31:17][INFO](re)sent tcp syn
Jul 19 22:31:18 user udp2raw_amd64[149902]: [2020-07-19 22:31:18][INFO]new packet from 127.0.0.1:34856,conv_id=60d1afcf
Jul 19 22:31:18 user udp2raw_amd64[149902]: [2020-07-19 22:31:18][INFO](re)sent tcp syn
Jul 19 22:31:19 user udp2raw_amd64[149902]: [2020-07-19 22:31:19][INFO](re)sent tcp syn
Jul 19 22:31:20 user udp2raw_amd64[149902]: [2020-07-19 22:31:20][INFO]state back to client_idle from client_tcp_handshake
Jul 19 22:31:20 user udp2raw_amd64[149902]: [2020-07-19 22:31:20][INFO]source_addr is now 10.0.0.3
Jul 19 22:31:20 user udp2raw_amd64[149902]: [2020-07-19 22:31:20][INFO]using port 14054
Jul 19 22:31:20 user udp2raw_amd64[149902]: [2020-07-19 22:31:20][INFO]state changed from client_idle to client_tcp_handshake
Jul 19 22:31:20 user udp2raw_amd64[149902]: [2020-07-19 22:31:20][INFO](re)sent tcp syn
Jul 19 22:31:21 user udp2raw_amd64[149902]: [2020-07-19 22:31:21][INFO]new packet from 127.0.0.1:46745,conv_id=12b48155
Jul 19 22:31:21 user udp2raw_amd64[149902]: [2020-07-19 22:31:21][INFO](re)sent tcp syn
Jul 19 22:31:23 user udp2raw_amd64[149902]: [2020-07-19 22:31:23][INFO](re)sent tcp syn
Jul 19 22:31:23 user udp2raw_amd64[149902]: [2020-07-19 22:31:23][INFO]new packet from 127.0.0.1:44606,conv_id=baf854d1
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:58472,conv_id=bec76a0b
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:42698,conv_id=7c0fd8fb
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:42315,conv_id=3bf1ffb2
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:40074,conv_id=dec0d678
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:59815,conv_id=12f81d83
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO](re)sent tcp syn
Jul 19 22:31:24 user udp2raw_amd64[149902]: [2020-07-19 22:31:24][INFO]new packet from 127.0.0.1:52888,conv_id=5fb03424
Jul 19 22:31:25 user udp2raw_amd64[149902]: [2020-07-19 22:31:25][INFO]new packet from 127.0.0.1:32960,conv_id=af5e8cbe
Jul 19 22:31:25 user udp2raw_amd64[149902]: [2020-07-19 22:31:25][INFO]new packet from 127.0.0.1:55471,conv_id=5e17d549
Jul 19 22:31:25 user udp2raw_amd64[149902]: [2020-07-19 22:31:25][INFO](re)sent tcp syn
Jul 19 22:31:25 user udp2raw_amd64[149902]: [2020-07-19 22:31:25][INFO]new packet from 127.0.0.1:35050,conv_id=b1f6e336 
Jul 19 22:31:25 user udp2raw_amd64[149902]: [2020-07-19 22:31:25][INFO]state back to client_idle from client_tcp_handshake
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO]source_addr is now 10.0.0.3
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO]using port 38879
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO]state changed from client_idle to client_tcp_handshake
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO](re)sent tcp syn
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO]new packet from 127.0.0.1:54071,conv_id=90e084e9
Jul 19 22:31:26 user udp2raw_amd64[149902]: [2020-07-19 22:31:26][INFO]new packet from 127.0.0.1:36800,conv_id=eff00bc8
Jul 19 22:31:27 user udp2raw_amd64[149902]: [2020-07-19 22:31:27][INFO]new packet from 127.0.0.1:53391,conv_id=77383958
Jul 19 22:31:27 user udp2raw_amd64[149902]: [2020-07-19 22:31:27][INFO](re)sent tcp syn
Jul 19 22:31:28 user udp2raw_amd64[149902]: [2020-07-19 22:31:28][INFO](re)sent tcp syn
Jul 19 22:31:29 user udp2raw_amd64[149902]: [2020-07-19 22:31:29][INFO](re)sent tcp syn
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO]new packet from 127.0.0.1:35354,conv_id=3d5698b2
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO]new packet from 127.0.0.1:58570,conv_id=f4898d07
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO]state changed from client_tcp_handshake to client_handshake1
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO](re)sent handshake1
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO]changed state from to client_handshake1 to client_handshake2,my_id is 9e25310d,oppsite id is 3ed8b2b5
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO](re)sent handshake2
Jul 19 22:31:30 user udp2raw_amd64[149902]: [2020-07-19 22:31:30][INFO]changed state from to client_handshake2 to client_ready
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:48309,conv_id=ea75a6c7
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:58038,conv_id=67133af3
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:57475,conv_id=b06d3e05
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:45697,conv_id=f38bb51c
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:37225,conv_id=dae2b517
Jul 19 22:31:31 user udp2raw_amd64[149902]: [2020-07-19 22:31:31][INFO]new packet from 127.0.0.1:60354,conv_id=2156ec66
Jul 19 22:31:33 user udp2raw_amd64[149902]: [2020-07-19 22:31:33][INFO]new packet from 127.0.0.1:42342,conv_id=9c83b696
Jul 19 22:32:04 user udp2raw_amd64[149902]: [2020-07-19 22:32:04][INFO]state back to client_idle from  client_ready bc of server-->client direction timeout
Jul 19 22:32:04 user udp2raw_amd64[149902]: [2020-07-19 22:32:04][INFO]source_addr is now 10.0.0.3
Jul 19 22:32:04 user udp2raw_amd64[149902]: [2020-07-19 22:32:04][INFO]using port 12489
Jul 19 22:32:04 user udp2raw_amd64[149902]: [2020-07-19 22:32:04][INFO]state changed from client_idle to client_tcp_handshake
Jul 19 22:32:04 user udp2raw_amd64[149902]: [2020-07-19 22:32:04][INFO](re)sent tcp syn
Jul 19 22:32:05 user udp2raw_amd64[149902]: [2020-07-19 22:32:05][INFO](re)sent tcp syn
Jul 19 22:32:07 user udp2raw_amd64[149902]: [2020-07-19 22:32:07][INFO](re)sent tcp syn
Jul 19 22:32:08 user udp2raw_amd64[149902]: [2020-07-19 22:32:08][INFO](re)sent tcp syn
Jul 19 22:32:09 user udp2raw_amd64[149902]: [2020-07-19 22:32:09][INFO](re)sent tcp syn
Jul 19 22:32:09 user udp2raw_amd64[149902]: [2020-07-19 22:32:09][INFO]state back to client_idle from client_tcp_handshake

> 注：从这开始电脑WIFI连接自动中断
> Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]udp fd connect fail -1 Network is unreachable

Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]create udp_fd error
Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]get_src_adress() failed
Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]udp fd connect fail -1 Network is unreachable
Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]create udp_fd error
Jul 19 22:32:10 user udp2raw_amd64[149902]: [2020-07-19 22:32:10][WARN]get_src_adress() failed
Jul 19 22:32:11 user udp2raw_amd64[149902]: [2020-07-19 22:32:11][WARN]udp fd connect fail -1 Network is unreachable
Jul 19 22:32:11 user udp2raw_amd64[149902]: [2020-07-19 22:32:11][WARN]create udp_fd error
Jul 19 22:32:11 user udp2raw_amd64[149902]: [2020-07-19 22:32:11][WARN]get_src_adress() failed

疑问

在断流发生时，客户端日志里记录了很多(re)sent tcp syn，但Wireshark里用ip.dst == server_ip却没查到对应请求，反倒查出一些本地到本地的Unreachable ICMP，我实在是搞不清哪里出的问题了，麻烦大佬看看我这有救吗

teevor avatar Jul 19 '20 17:07 teevor

突然发现Linux Google Chrome会时不时的连续发送3个随机http请求，只打开Chrome不开网页、禁用所有插件还是会往外发，贴一下我v2ray客户端的日志，请求都是这种随机字符的假域名，~~也不知道是怎么来的~~

本来还以为是被挂马了，没想到是Chrome的正常操作：https://serverfault.com/questions/235307/unusual-head-requests-to-nonsense-urls-from-chrome

2020/07/20 04:40:32 127.0.0.1:56620 accepted http://tpnigauyyxmq/ [kcp] 
2020/07/20 04:40:32 127.0.0.1:56624 accepted http://elglzumthrucaa/ [kcp] 
2020/07/20 04:40:32 127.0.0.1:56622 accepted http://wttltewrznfhkm/ [kcp]

观察了一下，之前网络占用高的时候，断流和WIFI断连经常伴随着Chrome突然发了三个这种请求，怀疑是因为服务器解析这三个域名等待的时间里，mkcp以为对方没收到又做了大量重发，挤占网络资源，我换Firefox以后没有了这种打劫式的请求，网络比用Chrome时稳定多了，但还是遇到过10秒左右的断流和WIFI断连，看着还是和网络占用成正相关

现在问题Chrome一浪我就断网，只要打开Chrome就没完没了的发，哪怕用Firefox也不完全稳定

teevor avatar Jul 19 '20 21:07 teevor

打游戲一會兒斷一會兒斷，chrome不能開？

Handsome1080P avatar Jul 20 '20 12:07 Handsome1080P

打游戲一會兒斷一會兒斷，chrome不能開？

我倒是不用这个线路打游戏，只是目前看起来有时断流跟Chrome发的三个链接有关，但不是它直接导致的

teevor avatar Jul 20 '20 12:07 teevor

一般断流可在一二十秒后恢复，但大约两三次里有一次会造成电脑WIFI链接的中断，出现可能性应该也和当时的流量大小程正相关，同时弹出弹出让我输入WIFI密码的窗口，实际并不用重输密码，几秒钟后可以重新手动连接，这还一度让我怀疑是网卡驱动出了问题，不过因为只有mkcp+udp2raw会出现这种情况，而只用v2ray的tcp模式哪怕到20MByte/s的下载速度也不会断WIFI，所以我暂时不太敢换网卡驱动，由此也怀疑跟同时处理的udp数量过多有关，但我不知道这怎么测

udp2raw使用的raw socket本身没有能力让wifi断开。如果wifi断开了，可能原因：

  1. 驱动有问题

  2. 发送的数据包太多了(超过了网卡处理能力)，网卡驱动处理不过来，造成了类似假死的现象。

不论原因是1还是2， tcp模式因为流控比较温和/保守，用tcp不会出现问题只有udp会出问题，也不奇怪。

观察了一下，之前网络占用高的时候，断流和WIFI断连经常伴随着Chrome突然发了三个这种请求，怀疑是因为服务器解析这三个域名等待的时间里，mkcp以为对方没收到又做了大量重发，挤占网络资源，我换Firefox以后没有了这种打劫式的请求，网络比用Chrome时稳定多了，但还是遇到过10秒左右的断流和WIFI断连，看着还是和网络占用成正相关

不理解为啥几个解析不出来的域名会造成大量重发挤占网络。不确定断流是不是和这种3个请求有关。

不过我觉得你的kcp发送窗口和接受窗口配的可能有问题，导致有时候会发出超过网卡处理能力的巨量数据包。 网上很多教程推荐的参数都不分青红皂白上来就开一个超大窗口，很容易造成类似问题。 如果你的参数不是自己配的，建议结合自己的带宽和rtt自己配一下。

wangyu- avatar Jul 23 '20 16:07 wangyu-

mark

fbion avatar Jul 27 '20 14:07 fbion

您是否编写了systemctl作为后台运行解决方案？我也出现了类似状况，经过排除是编写的systemctl的问题。 目前也不知道编写的systemctl问题具体出在哪里，无法进行排查。

zhihuiyuze avatar Aug 12 '21 15:08 zhihuiyuze

使用 https://gist.github.com/tanpengsccd/41a7ba56f31a9b58bfa1177e9228b239的systemctl经常出现断流现象，不知道问题具体出在哪里。

[Unit]
Description=udp2raw-tunnel client service
ConditionFileIsExecutable=/usr/local/bin/udp2raw
ConditionPathExists=/etc/udp2raw/home-1-vpn-server.conf

BindsTo=network-online.target
After=network-online.target

[Service]
Type=simple
User=root
Group=nogroup
#LimitNOFILE=32768
PIDFile=/run/udp2raw-home-1-vpn-server.pid
AmbientCapabilities=CAP_NET_RAW CAP_NET_ADMIN
ExecStart=/usr/local/bin/udp2raw --conf-file /etc/udp2raw/home-1-vpn-server.conf
Restart=on-failure

[Install]
WantedBy=network-online.target

这是我目前使用的systemctl，断流情况现在是每天一次，比上面的每分钟断流好多了。我不知道是否是systemctl对资源限制有什么规则，可能存在资源限制吧。

zhihuiyuze avatar Aug 12 '21 15:08 zhihuiyuze

使用 https://gist.github.com/tanpengsccd/41a7ba56f31a9b58bfa1177e9228b239的systemctl经常出现断流现象，不知道问题具体出在哪里。

[Unit]
Description=udp2raw-tunnel client service
ConditionFileIsExecutable=/usr/local/bin/udp2raw
ConditionPathExists=/etc/udp2raw/home-1-vpn-server.conf

BindsTo=network-online.target
After=network-online.target

[Service]
Type=simple
User=root
Group=nogroup
#LimitNOFILE=32768
PIDFile=/run/udp2raw-home-1-vpn-server.pid
AmbientCapabilities=CAP_NET_RAW CAP_NET_ADMIN
ExecStart=/usr/local/bin/udp2raw --conf-file /etc/udp2raw/home-1-vpn-server.conf
Restart=on-failure

[Install]
WantedBy=network-online.target

这是我目前使用的systemctl，断流情况现在是每天一次，比上面的每分钟断流好多了。我不知道是否是systemctl对资源限制有什么规则，可能存在资源限制吧。

Supervisor is working,no any issues

Handsome1080P avatar Aug 13 '21 02:08 Handsome1080P