[Bug] VLESSs fallback到vless时连不上目标地址

[HeXis-YS]

Describe the bug【描述 bug】
当VLESS TCP经过fallback后，无法通过代理访问网络。
经测试，使用trojan时不存在此问题。

To Reproduce【如何复现该bug】
按给定的配置文件运行服务端与客户端，然后使用代理访问网络。
下方提供的日志是运行curl https://google.com --proxy socks5://127.0.0.1:1080得到的。

Expected behavior【预期的行为】
应该能够使用代理正常访问

Envs (please complete the following information):【系统环境】
客户端：Windows 10 专业版 22H2 19045.2311, verysimple v1.2.5-beta.2
服务端：Clear Linux 37860, verysimple v1.2.5-beta.2

Config file 【配置文件，客户端服务端配置都提供】
client.toml

[app]
loglevel = 0

[[listen]]
tag = "my_socks5"
protocol = "socks5"
host = "127.0.0.1"
port = 1080

[[dial]]
tag = "my_vlesss1"
protocol = "vlesss"
uuid = "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx"
host = "my.domain.com"
ip = "199.xx.xxx.xxx" 

port = 443
version = 0
insecure = true
utls = true

server.toml

[app]
loglevel = 0
logfile = "/var/log/verysimple/vs_log"

[[listen]]
tag = "vless-tls-in"
protocol = "vlesss"
uuid = "yyyyyyyy-yyyy-yyyy-yyyy-yyyyyyyyyyyy"
ip = "0.0.0.0"
host = "my.domain.com"
port = 443
version = 0
fallback = "/dev/shm/tcp.sock"
cert = "/usr/local/etc/xray/cert.pem"
key = "/usr/local/etc/xray/cert.key"
fullcone = true

[[listen]]
tag = "vless-tcp-in"
protocol = "vless"
uuid = "xxxxxxxx-xxxx-xxxx-xxxx-xxxxxxxxxxxx"
network = "unix"
host = "/dev/shm/tcp.sock"
version = 0
fullcone = true

Debug Log 【Debug日志, 客户端 和 服务端 的 日志 都提供】
客户端

===============================
verysimple v1.2.5-beta.2, go1.19.4 windows amd64, with advLayer packages: [quic grpcSimple ws]
===============================
A very simple app
===============================
2022-12-24 21:57:30.817 INFO   Program started
2022-12-24 21:57:30.817 INFO   zap log init complete.  {"logfile": "C:\\Users\\Lenovo\\Desktop\\vs\\vs_log"}
2022-12-24 21:57:30.818 INFO   verysimple v1.2.5-beta.2, go1.19.4 windows amd64, with advLayer packages: [quic grpcSimple ws]

2022-12-24 21:57:30.818 INFO   Working at      {"dir": "C:\\Users\\Lenovo\\Desktop\\vs"}
2022-12-24 21:57:30.818 DEBUG  All Given Flags {"flags": {"c":"my string representation"}}
Log Level:0 debug
2022-12-24 21:57:30.819 INFO   Options {"Log Level": "debug", "UseReadv": true}
2022-12-24 21:57:30.819 INFO   Using uTls and Chrome fingerprint for   {"host": "my.domain.com"}
2022-12-24 21:57:30.820 INFO   Starting...
2022-12-24 21:57:30.820 INFO   Listening       {"tag": "my_socks5", "protocol": "+socks5", "listen_addr": "127.0.0.1:1080", "defaultClient": "+tls+vless", "dial_addr": "199.xx.xxx.xxx:443"}
2022-12-24 21:57:41.123 INFO   New Accepted Conn       {"connid": 613439, "from": "127.0.0.1:52820", "handler": "+socks5://127.0.0.1:1080#my_socks5"}
2022-12-24 21:57:42.493 WARN   Read first payload but timeout, will relay without first payload.       {"connid": 613439, "target": "172.217.160.110:443", "error": "read tcp 127.0.0.1:1080->127.0.0.1:52820: i/o timeout"}
2022-12-24 21:57:42.493 DEBUG  Default Route   {"connid": 613439, "source": "172.217.160.110:443", "client": "+tls+vless", "addr": "199.xx.xxx.xxx:443"}
2022-12-24 21:57:42.496 INFO   Request {"connid": 613439, "From": "127.0.0.1:52820", "Target": "tcp://172.217.160.110:443", "through": "+tls+vless://199.xx.xxx.xxx:443#my_vlesss1"}
2022-12-24 21:57:42.886 DEBUG  TryCopy {"id": 613439, "from": "*vless.UserTCPConn", "->": "*net.TCPConn"}
2022-12-24 21:57:42.886 DEBUG  TryCopy {"id": 613439, "from": "*net.TCPConn", "->": "*vless.UserTCPConn"}
2022-12-24 21:57:42.889 DEBUG  copying with readv      {"id": 613439}
2022-12-24 21:57:42.886 DEBUG  copying with classic method     {"id": 613439}
2022-12-24 21:57:43.874 DEBUG  Relay End       {"id": 613439, "direction": "R->L", "target": "199.xx.xxx.xxx:443", "bytes": 6780}
2022-12-24 21:57:43.880 DEBUG  Relay End       {"id": 613439, "direction": "L->R", "target": "199.xx.xxx.xxx:443", "bytes": 597, "error": "raw-read tcp 127.0.0.1:1080->127.0.0.1:52820: use of closed network connection"}
2022-12-24 21:57:52.573 INFO   Program got close signal.
2022-12-24 21:57:52.573 INFO   Stopping...

服务端

===============================
verysimple v1.2.5-beta.2, go1.19.4 linux amd64, with advLayer packages: [quic grpcSimple ws]
===============================
A very simple app
===============================
2022-12-24 13:57:34.748 INFO    Program started
2022-12-24 13:57:34.748 INFO    zap log init complete.  {"logfile": "/var/log/verysimple/vs_log"}
2022-12-24 13:57:34.749 INFO    verysimple v1.2.5-beta.2, go1.19.4 linux amd64, with advLayer packages: [quic grpcSimple ws]

2022-12-24 13:57:34.749 INFO    Working at      {"dir": "/root/xray"}
2022-12-24 13:57:34.749 DEBUG   All Given Flags {"flags": {"c":"my string representation"}}
Log Level:0 debug
2022-12-24 13:57:34.750 INFO    Options {"Log Level": "debug", "UseReadv": true}
2022-12-24 13:57:34.751 INFO    Starting...
2022-12-24 13:57:34.752 INFO    Listening       {"tag": "vless-tls-in", "protocol": "+tls+vless", "listen_addr": "0.0.0.0:443", "defaultClient": "dual+direct", "dial_addr": ""}
2022-12-24 13:57:34.752 INFO    Listening       {"tag": "vless-tcp-in", "protocol": "unix+vless", "listen_addr": "/dev/shm/tcp.sock", "defaultClient": "dual+direct", "dial_addr": ""}
2022-12-24 13:57:40.555 INFO    New Accepted Conn       {"connid": 470159, "from": "112.xx.xxx.xxx:31193", "handler": "+tls+vless://0.0.0.0:443#vless-tls-in"}
2022-12-24 13:57:40.758 WARN    Failed handshakeInserver        {"connid": 470159, "handler": "0.0.0.0:443", "client RemoteAddr": "112.xx.xxx.xxx:31193", "error": " [ Vless Invalid user  , Detail: invalid data, Data: 0e54cef0-5298-4a28-85f6-4efb67ac0a92 ] , with Buffer,len 26"}
2022-12-24 13:57:40.758 DEBUG   Fallback to     {"addr": "/dev/shm/tcp.sock", "params": ["h2", "my.domain.com"]}
2022-12-24 13:57:40.759 DEBUG   Default Route   {"connid": 470159, "source": "/dev/shm/tcp.sock", "client": "dual+direct", "addr": ""}
2022-12-24 13:57:40.759 INFO    Request {"connid": 470159, "Fallback from": "112.xx.xxx.xxx:31193", "Target": "unix://%2Fdev%2Fshm%2Ftcp.sock", "through": "dual+direct://"}
2022-12-24 13:57:40.760 DEBUG   handshake client with first payload     {"connid": 470159, "len": 26}
2022-12-24 13:57:40.760 DEBUG   TryCopy {"id": 470159, "from": "*net.UnixConn", "->": "*tlsLayer.Conn"}
2022-12-24 13:57:40.761 DEBUG   copying with readv      {"id": 470159}
2022-12-24 13:57:40.760 INFO    New Accepted Conn       {"connid": 528996, "from": "/dev/shm/tcp.sock", "handler": "unix+vless:///dev/shm/tcp.sock#vless-tcp-in"}
2022-12-24 13:57:40.760 DEBUG   TryCopy {"id": 470159, "from": "*tlsLayer.Conn", "->": "*net.UnixConn"}
2022-12-24 13:57:40.762 DEBUG   copying with classic method     {"id": 470159}
2022-12-24 13:57:40.862 WARN    Read first payload but timeout, will relay without first payload.       {"connid": 528996, "target": "172.217.160.110:443", "error": "read unix /dev/shm/tcp.sock->@: i/o timeout"}
2022-12-24 13:57:40.862 DEBUG   Default Route   {"connid": 528996, "source": "172.217.160.110:443", "client": "dual+direct", "addr": ""}
2022-12-24 13:57:40.862 INFO    Request {"connid": 528996, "From": "/dev/shm/tcp.sock", "Target": "tcp://172.217.160.110:443", "through": "dual+direct://"}
2022-12-24 13:57:40.993 DEBUG   TryCopy {"id": 528996, "from": "*net.TCPConn", "->": "*vless.UserTCPConn"}
2022-12-24 13:57:40.993 DEBUG   copying with readv      {"id": 528996}
2022-12-24 13:57:40.993 DEBUG   TryCopy {"id": 528996, "from": "*vless.UserTCPConn", "->": "*net.TCPConn"}
2022-12-24 13:57:40.994 DEBUG   copying with readv      {"id": 528996, "with": "MultiReader"}
2022-12-24 13:57:41.547 DEBUG   Relay End       {"id": 528996, "direction": "R->L", "target": "172.217.160.110:443", "bytes": 6780, "error": "EOF"}
2022-12-24 13:57:41.547 DEBUG   Relay End       {"id": 528996, "direction": "L->R", "target": "172.217.160.110:443", "bytes": 4096, "error": "raw-read unix /dev/shm/tcp.sock->@: use of closed network connection"}
2022-12-24 13:57:41.548 DEBUG   Relay End       {"id": 470159, "direction": "R->L", "target": "/dev/shm/tcp.sock", "bytes": 6782, "error": "EOF"}
2022-12-24 13:57:41.548 DEBUG   Relay End       {"id": 470159, "direction": "L->R", "target": "/dev/shm/tcp.sock", "bytes": 517, "error": "read tcp 199.xx.xxx.xxx:443->112.xx.xxx.xxx:31193: use of closed network connection"}
^C2022-12-24 13:57:47.120       INFO    Program got close signal.
2022-12-24 13:57:47.120 INFO    Stopping...
2022-12-24 13:57:47.120 DEBUG   netLayer.loopAccept, listener got closed        {"error": "accept tcp [::]:443: use of closed network connection"}
2022-12-24 13:57:47.120 DEBUG   netLayer.loopAccept, listener got closed        {"error": "accept unix /dev/shm/tcp.sock: use of closed network connection"}

Other 【其他】
出现在配置文件和日志中的IP 199.xx.xxx.xxx为服务器IP
【注意，配置文件和客户端服务端配置 太长的话，前后加上三个 `, 如 ```】

[e1732a364fed]

收到。我测了一遍，实锤了，真没想到会有这种怪问题啊！

好像和unix无关，普通的tcp回落也不成！不知道是哪里改错了

从日志上看不出什么异常，但是就是无法正常访问网页

[e1732a364fed]

经排查，问题出在vless的usertcpconn的 ReadBuffers 函数，注释掉就能用了。正在分析原因

[e1732a364fed]

测出来了。这是一个非常诡异的readv的问题，因为以前测的时候没用回落，所以就没出现问题。

我一会儿详细解释一下。

马上修复。

[e1732a364fed]

首先，为啥trojan没这个问题呢？因为在trojan恰好没有实现ReadBuffers。可能是当时遗漏，也可能是因为我更倾向于把vless当作代码试验田，做一些研发。

其次，readv的代码写了一个bug，在buffer还没有使用完时就放入pool了。

但是为什么正常情况没有问题，而回落时才发现错误呢，因为要想触发问题，恰好需要 vless回落到vless这种情况，如果是vless回落到 外部web服务，都不会出错

这又是为什么呢，因为只有在vless回落到vless时，才会重复使用readv，而且是同一时间使用readv，只有这时，才会遇到在pool中又提取到刚放入的 buffer的情况

[e1732a364fed]

最新代码应该解决了。

[e1732a364fed]

另外，你可以先用 -readv=f 命令行参数来绕过该问题