search

v2fly / v2ray-core

A platform for building proxies to bypass network restrictions.
https://v2fly.org
MIT License
28.34k stars 4.53k forks source link

outbound为trojan协议时内置dns服务异常 #1795

Closed moetayuko closed 1 year ago

moetayuko commented 2 years ago

What version of V2Ray are you using?

V2Ray 4.45.0 (V2Fly, a community-driven edition of V2Ray.) Custom (go1.18.1 linux/amd64)
A unified platform for anti-censorship.

What's your scenario of using V2Ray?

proxychains curl google.com

What problems have you encountered?

outbound为trojan协议时内置dns服务会返回context deadline exceeded错误（详见下面log），在配置了多个备选dns服务的情况下会一直retry到最后一个失败后再返回内容。vmess协议无此问题。

值得注意的时，context deadline exceeded错误发生在A记录返回成功之后，但与vmess的日志对比发现trojan的日志里完全没有AAAA记录的输出，所以猜测该报错是否实为AAAA解析失败？

What's your expectation?

outbound为trojan协议时能正常完成dns查询。

Please attach your configuration here

Server configuration:

使用机场，无法提供。

Client configuration:

基于https://github.com/v2fly/v2ray-core/blob/master/release/config/config.json 修改log level并分别增加如下两个outbound用于对比测试：

// config.json, dns解析异常的情况
{
    "protocol": "trojan",
    "settings":{
      "servers": [
        {
          "address": "xxxxxxxx",
          "port": xxxxx,
          "password": "xxxx"
        }
      ]
    },
    "streamSettings": {
      "network": "tcp",
      "security": "tls"
    },
    "tag": "proxy"
  }
// config_vmess.json, dns解析正常，仅用于与异常状态对比
{
    "protocol": "vmess",
    "settings": {
      "vnext": [
        {
          "address": "xxxxx",
          "port": 443,
          "users": [
            {
              "id": "xxxxx",
              "security": "none"
            }
          ]
        }
      ]
    },
    "streamSettings": {
      "network": "ws",
      "security": "tls",
      "wsSettings": {
        "path": "/foobar"
      }
    },
    "tag": "proxy"
  }

Please attach error logs here

Server error log:

使用机场，无法提供。

Client trojan log:

❯ v2ray -c config.json
V2Ray 4.45.0 (V2Fly, a community-driven edition of V2Ray.) Custom (go1.18.1 linux/amd64)
A unified platform for anti-censorship.
2022/05/21 15:49:41 [Info] main/jsonem: Reading config: config.json
2022/05/21 15:49:41 [Debug] app/log: Logger started
2022/05/21 15:49:41 [Info] app/dns: DNS: created UDP client initialized for 1.1.1.1:53
2022/05/21 15:49:41 [Info] app/dns: DNS: created UDP client initialized for 114.114.114.114:53
2022/05/21 15:49:41 [Info] app/dns: DNS: created UDP client initialized for 8.8.8.8:53
2022/05/21 15:49:41 [Info] app/dns: DNS: created localhost client
2022/05/21 15:49:41 [Debug] app/proxyman/inbound: creating stream worker on 127.0.0.1:1080
2022/05/21 15:49:41 [Info] transport/internet/tcp: listening TCP on 127.0.0.1:1080
2022/05/21 15:49:41 [Warning] V2Ray 4.45.0 started
2022/05/21 15:49:53 [Info] [1747427106] proxy/socks: TCP Connect request to tcp:[2404:6800:4005:801::200e]:80
2022/05/21 15:49:53 [Info] [1747427106] app/dispatcher: sniffed domain: google.com
2022/05/21 15:49:53 [Debug] app/dns: domain google.com will use DNS in order: [UDP:1.1.1.1:53 UDP:114.114.114.114:53 UDP:8.8.8.8:53 localhost]
2022/05/21 15:49:53 [Debug] app/dns: UDP:1.1.1.1:53 querying DNS for: google.com.
2022/05/21 15:49:53 [Debug] transport/internet/udp: dispatch request to: udp:1.1.1.1:53
2022/05/21 15:49:53 [Info] transport/internet/udp: establishing new connection for udp:1.1.1.1:53
2022/05/21 15:49:53 [Debug] transport/internet/udp: dispatch request to: udp:1.1.1.1:53
2022/05/21 15:49:53 [Info] app/dispatcher: default route for udp:1.1.1.1:53
2022/05/21 15:49:53 [Info] transport/internet/tcp: dialing TCP to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:49:53 [Info] proxy/trojan: tunneling request to udp:1.1.1.1:53 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:49:54 [Info] app/dns: UDP:1.1.1.1:53 got answer: google.com. TypeA -> [172.217.25.14] 203.649313ms
2022/05/21 15:49:54 [Debug] app/dns: UDP:1.1.1.1:53 updating IP records for domain:google.com.
2022/05/21 15:49:57 [Info] app/dns: failed to lookup ip for domain google.com at server UDP:1.1.1.1:53 > context deadline exceeded
2022/05/21 15:49:57 [Debug] app/dns: UDP:114.114.114.114:53 querying DNS for: google.com.
2022/05/21 15:49:57 [Debug] transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2022/05/21 15:49:57 [Info] transport/internet/udp: establishing new connection for udp:114.114.114.114:53
2022/05/21 15:49:57 [Debug] transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2022/05/21 15:49:57 [Info] app/dispatcher: default route for udp:114.114.114.114:53
2022/05/21 15:49:57 [Info] transport/internet/tcp: dialing TCP to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:49:57 [Info] proxy/trojan: tunneling request to udp:114.114.114.114:53 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:50:01 [Info] app/dns: failed to lookup ip for domain google.com at server UDP:114.114.114.114:53 > context deadline exceeded
2022/05/21 15:50:01 [Debug] app/dns: UDP:8.8.8.8:53 querying DNS for: google.com.
2022/05/21 15:50:01 [Debug] transport/internet/udp: dispatch request to: udp:8.8.8.8:53
2022/05/21 15:50:01 [Info] transport/internet/udp: establishing new connection for udp:8.8.8.8:53
2022/05/21 15:50:01 [Debug] transport/internet/udp: dispatch request to: udp:8.8.8.8:53
2022/05/21 15:50:01 [Info] app/proxyman/outbound: failed to process outbound traffic > proxy/trojan: connection ends > context canceled
2022/05/21 15:50:01 [Info] app/dispatcher: default route for udp:8.8.8.8:53
2022/05/21 15:50:01 [Info] transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe
2022/05/21 15:50:01 [Info] transport/internet/tcp: dialing TCP to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:50:01 [Info] app/proxyman/outbound: failed to process outbound traffic > proxy/trojan: connection ends > context canceled
2022/05/21 15:50:01 [Info] transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe
2022/05/21 15:50:01 [Info] proxy/trojan: tunneling request to udp:8.8.8.8:53 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:50:02 [Info] app/dns: UDP:8.8.8.8:53 got answer: google.com. TypeA -> [142.250.66.110] 154.079553ms
2022/05/21 15:50:02 [Debug] app/dns: UDP:8.8.8.8:53 updating IP records for domain:google.com.
2022/05/21 15:50:05 [Info] app/dns: failed to lookup ip for domain google.com at server UDP:8.8.8.8:53 > context deadline exceeded
2022/05/21 15:50:05 [Info] app/dns: Localhost got answer: google.com -> [2404:6800:4005:801::200e 142.250.204.78]
2022/05/21 15:50:05 [Info] [1747427106] app/dispatcher: default route for tcp:google.com:80
2022/05/21 15:50:05 tcp:127.0.0.1:35036 accepted tcp:[2404:6800:4005:801::200e]:80
2022/05/21 15:50:05 [Info] [1747427106] transport/internet/tcp: dialing TCP to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:50:05 [Info] [1747427106] proxy/trojan: tunneling request to tcp:google.com:80 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:50:06 [Info] [1747427106] app/proxyman/inbound: connection ends > proxy/socks: connection ends > context canceled
2022/05/21 15:50:06 [Info] [1747427106] app/proxyman/outbound: failed to process outbound traffic > proxy/trojan: connection ends > context canceled
2022/05/21 15:50:09 [Info] app/proxyman/outbound: failed to process outbound traffic > proxy/trojan: connection ends > context canceled
2022/05/21 15:50:09 [Info] transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe

Please attach access log here

Client vmess log:

// Please attach your server access log here.
❯ v2ray -c config_vmess.json
V2Ray 4.45.0 (V2Fly, a community-driven edition of V2Ray.) Custom (go1.18.1 linux/amd64)
A unified platform for anti-censorship.
2022/05/21 15:57:06 [Info] main/jsonem: Reading config: config_vmess.json
2022/05/21 15:57:06 [Debug] app/log: Logger started
2022/05/21 15:57:06 [Info] app/dns: DNS: created UDP client initialized for 1.1.1.1:53
2022/05/21 15:57:06 [Info] app/dns: DNS: created UDP client initialized for 114.114.114.114:53
2022/05/21 15:57:06 [Info] app/dns: DNS: created UDP client initialized for 8.8.8.8:53
2022/05/21 15:57:06 [Info] app/dns: DNS: created localhost client
2022/05/21 15:57:06 [Debug] app/proxyman/inbound: creating stream worker on 127.0.0.1:1080
2022/05/21 15:57:06 [Info] transport/internet/tcp: listening TCP on 127.0.0.1:1080
2022/05/21 15:57:06 [Warning] V2Ray 4.45.0 started
2022/05/21 15:57:13 [Info] [4260222460] proxy/socks: TCP Connect request to tcp:[2404:6800:4005:801::200e]:80
2022/05/21 15:57:13 [Info] [4260222460] app/dispatcher: sniffed domain: google.com
2022/05/21 15:57:13 [Debug] app/dns: domain google.com will use DNS in order: [UDP:1.1.1.1:53 UDP:114.114.114.114:53 UDP:8.8.8.8:53 localhost]
2022/05/21 15:57:13 [Debug] app/dns: UDP:1.1.1.1:53 querying DNS for: google.com.
2022/05/21 15:57:13 [Debug] transport/internet/udp: dispatch request to: udp:1.1.1.1:53
2022/05/21 15:57:13 [Info] transport/internet/udp: establishing new connection for udp:1.1.1.1:53
2022/05/21 15:57:13 [Debug] transport/internet/udp: dispatch request to: udp:1.1.1.1:53
2022/05/21 15:57:13 [Info] app/dispatcher: default route for udp:1.1.1.1:53
2022/05/21 15:57:13 [Info] transport/internet/websocket: creating connection to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:57:14 [Info] proxy/vmess/outbound: tunneling request to udp:1.1.1.1:53 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:57:14 [Info] app/dns: UDP:1.1.1.1:53 got answer: google.com. TypeA -> [172.217.161.46] 1.142444333s
2022/05/21 15:57:14 [Debug] app/dns: UDP:1.1.1.1:53 updating IP records for domain:google.com.
2022/05/21 15:57:14 tcp:127.0.0.1:35040 accepted tcp:[2404:6800:4005:801::200e]:80 [proxy]
2022/05/21 15:57:14 [Info] app/dns: UDP:1.1.1.1:53 got answer: google.com. TypeAAAA -> [[2404:6800:4004:80a::200e]] 1.142466659s
2022/05/21 15:57:14 [Debug] app/dns: UDP:1.1.1.1:53 updating IP records for domain:google.com.
2022/05/21 15:57:14 [Info] [4260222460] app/dispatcher: default route for tcp:google.com:80
2022/05/21 15:57:14 [Info] [4260222460] transport/internet/websocket: creating connection to tcp:xxxxxxxxxxxxxxx
2022/05/21 15:57:14 [Info] [4260222460] proxy/vmess/outbound: tunneling request to tcp:google.com:80 via tcp:xxxxxxxxxxxxxxx
2022/05/21 15:57:15 [Info] [4260222460] app/proxyman/inbound: connection ends > proxy/socks: connection ends > context canceled
2022/05/21 15:57:15 [Info] [4260222460] app/proxyman/outbound: failed to process outbound traffic > proxy/vmess/outbound: connection ends > context canceled

Other configurations (such as Nginx) and logs here

If V2Ray cannot start up, please attach output from --test command

If V2Ray service is abnormal, please attach journal log here

dream-hack commented 2 years ago

请问楼主，为啥我日志中没有dns记录？ 比如类似你上面的： ... [Debug] app/dns: domain google.com will use DNS in order: [UDP:1.1.1.1:53 UDP:114.114.114.114:53 UDP:8.8.8.8:53 localhost] [Debug] app/dns: UDP:1.1.1.1:53 querying DNS for: google.com. ...

我的日志级别也是debug，不管v2rayN还是命令行中运行都看不到dns的记录，请问该如何设置？

simplerick-simplefun commented 2 years ago

看起来是个bug。 逻辑上，应该是trojan模块获得的信息传递给dns模块，dns模块识别认为出错。 这两个模块都要检查，才能搞清楚问题在哪里。我倾向于认为trojan模块可能没问题，而是dns模块处理返还的数据没处理好。 要解决的话可能要搞出来一个test版本的v2ray给题主运行，把trojan和dns处理的数据都log下来。因为这个问题不是普遍的。

github-actions[bot] commented 1 year ago

This issue is stale because it has been open 120 days with no activity. Remove stale label or comment or this will be closed in 5 days

moetayuko commented 1 year ago

5.1.0仍可复现

github-actions[bot] commented 1 year ago

This issue is stale because it has been open 120 days with no activity. Remove stale label or comment or this will be closed in 5 days

moetayuko commented 1 year ago

bump