[BUG] TProxy: unable to obtain original destination: %!s()

[WROIATE]

问题详情

在路由器上运行时（passwall），会出现客户端挂掉的情况，请问是什么原因呢？

服务端安装信息或者一键脚本信息

hysteria version v1.1.0 2022-07-07T01:29:44.076Z 160145f712d93d08f770374bb49edb85fe7d2420

VPS 信息

ablenet 大阪机房

服务端配置

{
    "listen": ":*",
    "protocol": "wechat-video",
    "cert": "*",
    "key": "*",
    "obfs": "*",
    "alpn": "*",
    "resolve_preference": "46",
    "auth": {
        "mode": "passwords",
        "config": [
            "*"
        ]
    }
}

服务端日志

服务端没有看到相关的日志

客户端安装信息

hysteria version v1.1.0 2022-07-07T01:29:44.076Z 160145f712d93d08f770374bb49edb85fe7d2420

客户端配置

{
  "insecure": false,
  "protocol": "wechat-video",
  "tproxy_tcp": {
    "timeout": 300,
    "listen": "0.0.0.0:1041"
  },
  "down_mbps": 1000,
  "socks5": {
    "timeout": 300,
    "disable_udp": false,
    "listen": "0.0.0.0:1080"
  },
  "obfs": "*",
  "server": "*",
  "tproxy_udp": {
    "timeout": 60,
    "listen": "0.0.0.0:1041"
  },
  "disable_mtu_discovery": false,
  "auth_str": "*",
  "retry_interval": 5,
  "up_mbps": 30,
  "retry": -1,
  "alpn": "*",
  "server_name": "*"
}

客户端运行环境（操作系统）

OpenWRT Passwall 4.54-3

客户端日志

2022-07-25T10:52:55Z[37m [DEBU] [src:127.0.0.1:42046] [dst:1.1.1.1:53] [action:Proxy] [0mSOCKS5 TCP request
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:44267] [dst:61.224.25.225:13052] [error:connection rejected: dial tcp 61.224.25.225:13052: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:59373] [dst:89.44.10.167:49161] [error:connection rejected: dial tcp 89.44.10.167:49161: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:50883] [dst:61.64.30.115:51413] [error:connection rejected: dial tcp 61.64.30.115:51413: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:46465] [dst:70.71.165.123:18354] [error:connection rejected: dial tcp 70.71.165.123:18354: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:60545] [dst:84.17.57.67:21861] [error:connection rejected: dial tcp 84.17.57.67:21861: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[36m [INFO] [src:192.168.1.102:45377] [dst:59.127.20.65:15000] [error:connection rejected: dial tcp 59.127.20.65:15000: i/o timeout] [0mTCP TProxy error
2022-07-25T10:52:56Z[31m [FATA] [error:unable to obtain original destination: %!s()] [0mClient shutdown

2022-07-25T11:11:50Z[36m [INFO] [src:192.168.1.102:42127] [dst:36.226.81.225:51413] [error:connection rejected: dial tcp 36.226.81.225:51413: connect: connection refused] [0mTCP TProxy error
2022-07-25T11:11:50Z[37m [DEBU] [src:192.168.1.102:60511] [dst:111.240.43.127:17048] [0mTCP TProxy EOF
2022-07-25T11:11:51Z[37m [DEBU] [src:192.168.1.102:41499] [dst:36.231.44.190:11126] [0mTCP TProxy request
2022-07-25T11:11:51Z[37m [DEBU] [src:192.168.1.102:54207] [dst:36.231.49.202:13065] [0mTCP TProxy request
2022-07-25T11:11:51Z[36m [INFO] [src:192.168.1.102:44489] [dst:112.105.52.11:16545] [error:connection rejected: dial tcp 112.105.52.11:16545: i/o timeout] [0mTCP TProxy error
2022-07-25T11:11:51Z[36m [INFO] [src:192.168.1.102:40205] [dst:45.76.50.229:53120] [error:connection rejected: dial tcp 45.76.50.229:53120: i/o timeout] [0mTCP TProxy error
2022-07-25T11:11:51Z[36m [INFO] [src:192.168.1.102:52023] [dst:89.187.163.193:6881] [error:connection rejected: dial tcp 89.187.163.193:6881: i/o timeout] [0mTCP TProxy error
2022-07-25T11:11:51Z[36m [INFO] [src:192.168.1.102:36519] [dst:71.150.133.198:34265] [error:connection rejected: dial tcp 71.150.133.198:34265: i/o timeout] [0mTCP TProxy error
2022-07-25T11:11:52Z[31m [FATA] [error:unable to obtain original destination: %!s()] [0mClient shutdown

[haruue]

是 tproxy 的报错。 https://github.com/LiamHaworth/go-tproxy/blob/ef7efd7f24ed7e9bf8f479c890c81ce7db27000e/tproxy_udp.go#L91-L93

看起来不满足 msg.Header.Level == syscall.SOL_IP && msg.Header.Type == syscall.IP_RECVORIGDSTADDR 这个条件的情况下就会返回这个错误。

Hysteria 相关的调用 https://github.com/HyNetwork/hysteria/blob/b9d0108af3ded6afd5cee6181009afd31a51dda8/pkg/tproxy/udp_linux.go#L50

看起来对于这个 err 应该忽略而不是 fatal 。。

[haruue]

另外 tproxy 只需监听 127.0.0.1:1041 而不是 0.0.0.0:1041， tproxy 是由 iptables 转发， 即使是走 PREROUTING 也就是局域网来的包， 也总是从本地发起连接的， 这个和 socks5 不一样。

~~这边试了下如果 tproxy_tcp 监听 0.0.0.0:1041 ， 那么如果局域网里的哪台机器尝试与路由器的 1041 端口创建 TCP 连接， 会产生循环并导致 Hysteria 崩溃 error:accept tcp [::]:1041: accept4: too many open files 。~~

但是我暂时没找到在 tproxy_udp 上触发 error:unable to obtain original destination 的条件。

[haruue]

@WROIATE 能给一下 OpenWRT 版本和内核版本么？ OpenWRT 首页的「系统信息」截图一下就可以。

[WROIATE]

@WROIATE 能给一下 OpenWRT 版本和内核版本么？ OpenWRT 首页的「系统信息」截图一下就可以。

固件版本	OpenWrt R22.5.5 / LuCI Master (git-22.146.34683-df8288f)
内核版本	5.15.41

[WROIATE]

另外 tproxy 只需监听 127.0.0.1:1041 而不是 0.0.0.0:1041， tproxy 是由 iptables 转发， 即使是走 PREROUTING 也就是局域网来的包， 也总是从本地发起连接的， 这个和 socks5 不一样。

这边试了下如果 tproxy_tcp 监听 0.0.0.0:1041 ， 那么如果局域网里的哪台机器尝试与路由器的 1041 端口创建 TCP 连接， 会产生循环并导致 Hysteria 崩溃 error:accept tcp [::]:1041: accept4: too many open files 。

但是我暂时没找到在 tproxy_udp 上触发 error:unable to obtain original destination 的条件。

这个配置实际上不是人为配置，而是passwall选择了后自动生成的

[WROIATE]

是 tproxy 的报错。 https://github.com/LiamHaworth/go-tproxy/blob/ef7efd7f24ed7e9bf8f479c890c81ce7db27000e/tproxy_udp.go#L91-L93

看起来不满足 msg.Header.Level == syscall.SOL_IP && msg.Header.Type == syscall.IP_RECVORIGDSTADDR 这个条件的情况下就会返回这个错误。

Hysteria 相关的调用

https://github.com/HyNetwork/hysteria/blob/b9d0108af3ded6afd5cee6181009afd31a51dda8/pkg/tproxy/udp_linux.go#L50

看起来对于这个 err 应该忽略而不是 fatal 。。

https://github.com/LiamHaworth/go-tproxy/blob/ef7efd7f24ed7e9bf8f479c890c81ce7db27000e/tproxy_udp.go#L92 这块看代码也很奇怪，根据上下文，就算不满足也不会有新的err出现，这个地方返回打印的err必定是无效信息

[haruue]

should be fixed in e67f2d6c7e4d978d4f8a90a3d4bc83c2cbd43cfb