linsui commented 4 years ago

1) 你正在使用哪个版本的 V2Ray？（如果服务器和客户端使用了不同版本，请注明） 4.22.0 2) 你的使用场景是什么？比如使用 Chrome 通过 Socks/VMess 代理观看 YouTube 视频。 dns 解析 3) 你看到的不正常的现象是什么？（请描述具体现象，比如访问超时，TLS 证书错误等） 4.22.0 无解析结果时 4 秒才会返回响应。 4) 你期待看到的正确表现是怎样的？无结果则立即返回。 5) 请附上你的配置（提交 Issue 前请隐藏服务器端IP地址）。客户端配置:

{
    "log": {
        "loglevel": "debug"
    },
    "inbounds": [
        {
            "listen": "0.0.0.0",
            "port": 4053,
            "protocol": "dokodemo-door",
            "settings": {
                "address": "127.0.0.1",
                "port": 4053,
                "network": "tcp,udp"
            },
            "tag": "dns-inbound"
        }
    ],
    "outbounds": [
        {
            "protocol": "freedom",
            "tag": "direct"
        },
        {
            "sendThrough": "127.0.0.1",
            "protocol": "dns",
            "settings": {
                "address": "1.1.1.1",
                "port": 53
            },
            "tag": "dns-outbound"
        }
    ],
    "routing": {
        "domainStrategy": "AsIs",
        "rules": [
            {
                "type": "field",
                "inboundTag": "dns-inbound",
                "outboundTag": "dns-outbound"
            }
        ]
    },
    "dns": {
        "servers": [
            {
                "address": "127.0.0.1",
                "port": 5053
            }
        ]
    }
}

6) 请附上出错时软件输出的错误日志。在 Linux 中，日志通常在 /var/log/v2ray/error.log 文件中。

客户端错误日志:

4.22.0 v2ray

V2Ray 4.22.0 (V2Fly, a community-driven edition of V2Ray.) Custom
A unified platform for anti-censorship.
2019/12/29 23:32:54 [Debug] v2ray.com/core/app/log: Logger started
2019/12/29 23:32:54 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 127.0.0.1:5053
2019/12/29 23:32:54 [Debug] v2ray.com/core/app/proxyman/inbound: creating stream worker on 0.0.0.0:4053
2019/12/29 23:32:54 [Info] v2ray.com/core/transport/internet/tcp: listening TCP on 0.0.0.0:4053
2019/12/29 23:32:54 [Info] v2ray.com/core/transport/internet/udp: listening UDP on 0.0.0.0:4053
2019/12/29 23:32:54 [Warning] v2ray.com/core: V2Ray 4.22.0 started
2019/12/29 23:32:58 [Debug] [2668863799] v2ray.com/core/proxy/dokodemo: processing connection from: 127.0.0.1:62252
2019/12/29 23:32:58 [Info] [2668863799] v2ray.com/core/app/dispatcher: taking detour [dns-outbound] for [udp:127.0.0.1:4053]
2019/12/29 23:32:58 [Info] [2668863799] v2ray.com/core/proxy/dns: handling DNS traffic to udp:1.1.1.1:53
2019/12/29 23:32:58 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 querying DNS for: startpage.com.
2019/12/29 23:32:58 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:127.0.0.1:5053
2019/12/29 23:32:58 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:127.0.0.1:5053
2019/12/29 23:32:58 [Info] v2ray.com/core/app/dispatcher: default route for udp:127.0.0.1:5053
2019/12/29 23:32:58 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:127.0.0.1:5053
2019/12/29 23:32:58 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 got answere: startpage.com. TypeAAAA -> [] 0s
2019/12/29 23:32:58 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 updating IP records for domain:startpage.com.
2019/12/29 23:33:02 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain startpage.com at server UDP:127.0.0.1:5053 > context deadline exceeded
2019/12/29 23:33:05 [Debug] v2ray.com/core/app/log: Logger closing

dig

; <<>> DiG 9.14.8 <<>> startpage.com @127.0.0.1 -p 4053 AAAA
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 43842
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;startpage.com.                 IN      AAAA

;; Query time: 4001 msec
;; SERVER: 127.0.0.1#4053(127.0.0.1)
;; WHEN: Sun Dec 29 23:33:02 中国标准时间 2019
;; MSG SIZE  rcvd: 31

4.21.3 v2ray

V2Ray 4.21.3 (V2Fly, a community-driven edition of V2Ray.) Custom
A unified platform for anti-censorship.
2019/12/29 23:31:36 [Debug] v2ray.com/core/app/log: Logger started
2019/12/29 23:31:36 [Warning] v2ray.com/core: V2Ray 4.21.3 started
2019/12/29 23:31:45 [Debug] [3539162844] v2ray.com/core/proxy/dokodemo: processing connection from: 127.0.0.1:62248
2019/12/29 23:31:45 [Info] [3539162844] v2ray.com/core/app/dispatcher: taking detour [dns-outbound] for [udp:127.0.0.1:4053]
2019/12/29 23:31:45 [Info] [3539162844] v2ray.com/core/proxy/dns: handling DNS traffic to udp:1.1.1.1:53
2019/12/29 23:31:45 [Debug] v2ray.com/core/app/dns: querying DNS for: startpage.com.
2019/12/29 23:31:45 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:127.0.0.1:5053
2019/12/29 23:31:45 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:127.0.0.1:5053
2019/12/29 23:31:45 [Info] v2ray.com/core/app/dispatcher: default route for udp:127.0.0.1:5053
2019/12/29 23:31:45 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:127.0.0.1:5053
2019/12/29 23:31:45 [Debug] v2ray.com/core/app/dns: updating IP records for domain:startpage.com.
2019/12/29 23:31:45 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain startpage.com at server udp:127.0.0.1:5053 > empty response

dig

; <<>> DiG 9.14.8 <<>> startpage.com @127.0.0.1 -p 4053 AAAA
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 25466
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;startpage.com.                 IN      AAAA

;; Query time: 0 msec
;; SERVER: 127.0.0.1#4053(127.0.0.1)
;; WHEN: Sun Dec 29 23:31:45 中国标准时间 2019
;; MSG SIZE  rcvd: 31

dns 服务器原始结果

; <<>> DiG 9.14.8 <<>> startpage.com @127.0.0.1 -p 5053 AAAA
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 49728
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 1, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1220
;; QUESTION SECTION:
;startpage.com.                 IN      AAAA

;; AUTHORITY SECTION:
startpage.com.          2579    IN      SOA     dns1.p01.nsone.net. hostmaster.nsone.net. 1576228903 3600 600 1209600 3600

;; Query time: 0 msec
;; SERVER: 127.0.0.1#5053(127.0.0.1)
;; WHEN: Sun Dec 29 22:58:46 中国标准时间 2019
;; MSG SIZE  rcvd: 107

kslr commented 4 years ago

try close ipv6

linsui commented 4 years ago

这个问题和 IPv6 应该没有关系。上面的示例我用 AAAA ，但使用一个不存在的域名（如 nosuchdomain.v2ray.com) 进行 A 查询可以得到相同的结果。4.21.3 可以立即返回空但 4.22.0 在 4 秒后才会响应。

kslr commented 4 years ago

因为ipv4和ipv6都在查询

linsui commented 4 years ago

关闭 IPv6 是指关闭适配器的 IPv6 协议吗？我禁用 IPv6 协议后上述问题依然存在。

kslr commented 4 years ago

发新的日志看看

linsui commented 4 years ago

V2Ray 4.22.0 (V2Fly, a community-driven edition of V2Ray.) Custom
A unified platform for anti-censorship.
2019/12/31 12:38:16 [Debug] v2ray.com/core/app/log: Logger started
2019/12/31 12:38:16 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 127.0.0.1:5053
2019/12/31 12:38:16 [Debug] v2ray.com/core/app/proxyman/inbound: creating stream worker on 0.0.0.0:4053
2019/12/31 12:38:16 [Info] v2ray.com/core/transport/internet/tcp: listening TCP on 0.0.0.0:4053
2019/12/31 12:38:16 [Info] v2ray.com/core/transport/internet/udp: listening UDP on 0.0.0.0:4053
2019/12/31 12:38:16 [Warning] v2ray.com/core: V2Ray 4.22.0 started
2019/12/31 12:38:24 [Debug] [314239593] v2ray.com/core/proxy/dokodemo: processing connection from: 127.0.0.1:63817
2019/12/31 12:38:24 [Info] [314239593] v2ray.com/core/app/dispatcher: taking detour [dns-outbound] for [udp:127.0.0.1:4053]
2019/12/31 12:38:24 [Info] [314239593] v2ray.com/core/proxy/dns: handling DNS traffic to udp:1.1.1.1:53
2019/12/31 12:38:24 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 querying DNS for: no.v2ray.com.
2019/12/31 12:38:24 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:127.0.0.1:5053
2019/12/31 12:38:24 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:127.0.0.1:5053
2019/12/31 12:38:24 [Info] v2ray.com/core/app/dispatcher: default route for udp:127.0.0.1:5053
2019/12/31 12:38:24 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:127.0.0.1:5053
2019/12/31 12:38:24 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 got answere: no.v2ray.com. TypeA -> [] 1.0015ms
2019/12/31 12:38:24 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 updating IP records for domain:no.v2ray.com.
2019/12/31 12:38:28 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain no.v2ray.com at server UDP:127.0.0.1:5053 > context deadline exceeded
2019/12/31 12:38:31 [Debug] v2ray.com/core/app/log: Logger closing

; <<>> DiG 9.14.8 <<>> no.v2ray.com @127.0.0.1 -p 4053 A
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 34490
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;no.v2ray.com.                  IN      A

;; Query time: 4000 msec
;; SERVER: 127.0.0.1#4053(127.0.0.1)
;; WHEN: Tue Dec 31 12:38:28 中国标准时间 2019
;; MSG SIZE  rcvd: 30

kslr commented 4 years ago

这是代码中定义的，如果4秒内没有查询到。 https://github.com/v2ray/v2ray-core/blob/0be2dbc37bd6ccda028d6151d004fcc4afa06cd8/app/dns/server.go#L235

这个设置是很合理的，因此该问题不会被修复。

linsui commented 4 years ago

这行代码是在去年提交的，但此问题仅在 4.22.0 才出现。另外并非所有域名都会出现这种现象（如 noexist.baidu.com ），同样是 SOA 响应，但 v2ray 会立即返回空结果。

V2Ray 4.22.0 (V2Fly, a community-driven edition of V2Ray.) Custom
A unified platform for anti-censorship.
2019/12/31 13:56:54 [Debug] v2ray.com/core/app/log: Logger started
2019/12/31 13:56:54 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 127.0.0.1:5053
2019/12/31 13:56:54 [Debug] v2ray.com/core/app/proxyman/inbound: creating stream worker on 0.0.0.0:4053
2019/12/31 13:56:54 [Info] v2ray.com/core/transport/internet/tcp: listening TCP on 0.0.0.0:4053
2019/12/31 13:56:54 [Info] v2ray.com/core/transport/internet/udp: listening UDP on 0.0.0.0:4053
2019/12/31 13:56:54 [Warning] v2ray.com/core: V2Ray 4.22.0 started
2019/12/31 13:56:56 [Debug] [3985451507] v2ray.com/core/proxy/dokodemo: processing connection from: 127.0.0.1:54621
2019/12/31 13:56:56 [Info] [3985451507] v2ray.com/core/app/dispatcher: taking detour [dns-outbound] for [udp:127.0.0.1:4053]
2019/12/31 13:56:56 [Info] [3985451507] v2ray.com/core/proxy/dns: handling DNS traffic to udp:1.1.1.1:53
2019/12/31 13:56:56 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 querying DNS for: noexist.baidu.com.
2019/12/31 13:56:56 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:127.0.0.1:5053
2019/12/31 13:56:56 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:127.0.0.1:5053
2019/12/31 13:56:56 [Info] v2ray.com/core/app/dispatcher: default route for udp:127.0.0.1:5053
2019/12/31 13:56:56 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:127.0.0.1:5053
2019/12/31 13:56:56 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 got answere: noexist.baidu.com. TypeA -> [] 1.0054ms
2019/12/31 13:56:56 [Debug] v2ray.com/core/app/dns: UDP:127.0.0.1:5053 updating IP records for domain:noexist.baidu.com.
2019/12/31 13:56:56 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain noexist.baidu.com at server UDP:127.0.0.1:5053 > rcode: 3
2019/12/31 13:56:59 [Debug] v2ray.com/core/app/log: Logger closing

kslr commented 4 years ago

你应该用其他域名测试 v2ray.com 已经被dns污染了

linsui commented 4 years ago

我使用 dnscrypt-proxy 作为上游服务器测试。这个问题似乎只在部分域名出现。我发现的一个存在此问题的国内域名是 noexist.jianshu.com 。而 noexist.twitter.com 可以立即返回空响应。可以观察到立即返回时的日志是

v2ray.com/core/app/dns: failed to lookup ip for domain noexist.twitter.com at server UDP:127.0.0.1:5053 > rcode: 3

而等待4秒时日志是

v2ray.com/core/app/dns: failed to lookup ip for domain noexist.jianshu.com at server UDP:127.0.0.1:5053 > context deadline exceeded

我不清楚 v2ray 如何处理 SOA 响应？

k79e commented 4 years ago

[Info] v2ray.com/core/app/dns: failed to lookup ip for domain xxxxx at server UDP:xxxxx:53 > rcode: 3 我这里没问题.

curl会显示io报错 4-5s后出日志浏览器访问的话随便挑个不存在的域名基本立刻就会返回查询失败的log.

好吧国内那个直连的果然卡了. 我是指定dns模式. 不知道是不是更系统dns有关呢.

我随便全局测试了jianshu.com的不存在的域名发现也挺快返回结果的 2秒之后报了个别的错误 failed to transport all TCP response > io: read/write on closed pipe

我又测试了个随意的直连的不存在的域名发现10秒+都在转圈圈. 可能跟系统用的dns有关 . 我本机直连dns用的是一个缓存.

好像果然有点问题我发现卡住的时候程序一直在 dialing TCP to tcp:xxxx 而且还重复连接. 他ip都没有 怎么连的... 奇怪的很看起来跟本机缓存关系不大啊. 本机返回内容也是空的记录.

任何一个国内不存在的域名. 不需要国内不国内. 只要客户端是直连就行. 然后就会卡那里卡很久.

linsui commented 4 years ago

可以测试一下 4.21.3 吗？如果 4.21.3 没有问题那么应该是同一个问题。

大部分国内域名我都没有遇到问题。我的测试里只做了 DNS 查询，没有访问。不太清楚是不是和 SOA 有关。

rainingNya commented 4 years ago

4.21.3没有问题

k79e commented 4 years ago

2019/12/31 17:59:55 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:53 got answere: xxxx.cn. TypeA -> [] 78.0045ms 2019/12/31 17:59:55 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n xxxx.cn at server UDP:127.0.0.1:53 > rcode: 3

dig ;; Query time: 4079 msec 新版本的话任意门dns会卡. 发现日志很快收到了空记录但是v2ray没有转发给程序.

甚至记录被缓存 2ms内v2自己得到结果 dig却收不到.

4.19客户端测试是第一个失败会走第二dns 然后才发结果. 因为我本地是有缓存的所以从dig的延时来看是根据第二查询才返回结果的. 新版本看起来不太会走第二dns 但是有时候也会走. 走的时候dig就高延时不走的时候就直接4秒默认超时都卡死.

新版本我测试的时候不定. 第一次访问域名的时候会卡. 第二次的时候看起来如果第一个结果返回特快他竟然就走第二dns了. 也就是查询结果是几十ms的时候他就会卡住. 不是的话直接就走第二dns. 然后也不卡了. 我的第二dns是国外域名才访问的. 可是我走的cn查询也跑第二去了!!!!

2019/12/31 18:00:50 [Warning] v2ray.com/core: V2Ray 4.22.0 started 2019/12/31 18:00:54 [Info] [373746896] v2ray.com/core/app/dispatcher: taking det our [dns-out] for [udp:8.8.8.8:53] 2019/12/31 18:00:54 [Info] [373746896] v2ray.com/core/proxy/dns: handling DNS tr affic to udp:8.8.8.8:53 2019/12/31 18:00:54 [Info] v2ray.com/core/transport/internet/udp: establishing n ew connection for udp:127.0.0.1:53 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dispatcher: taking detour [direct] for [udp:127.0.0.1:53] 2019/12/31 18:00:54 [Info] v2ray.com/core/proxy/freedom: opening connection to u dp:127.0.0.1:53 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:53 got answere: xxxx.cn. TypeA -> [] 151.0086ms 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n xxxx.cn at server UDP:127.0.0.1:53 > rcode: 3 2019/12/31 18:00:54 [Info] v2ray.com/core/transport/internet/udp: establishing n ew connection for udp:dns B:53 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dispatcher: default route for udp: dnsB:53 2019/12/31 18:00:54 [Info] v2ray.com/core/proxy/freedom: opening connection to u dp:dnsB:53 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dns: UDP:185.37.37.37:54 got answe re:xxxx.cn. TypeA -> [] 2xx.0147ms 2019/12/31 18:00:54 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n xxxx.cn at server UDP:dnsB:53 > rcode: 3 结果还是不定. 这个日志里面第一个dns结果是慢的他还走了第二dns. 走第二dns的时候 dig能收到结果. 如果只查询第一个的时候 dig收不到.

我发现卡的时候会这样 2019/12/31 18:xx:41 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n xxxx.cn at server UDP:xxxxxx > context deadline exceeded 2019/12/31 18:xx:41 [Info] v2ray.com/core/app/proxyman/outbound: failed to proce ss outbound traffic > v2ray.com/core/proxy/freedom: connection ends > context ca nceled 2019/12/31 18:xx:41 [Info] v2ray.com/core/transport/internet/udp: failed to hand le UDP input > io: read/write on closed pipe 但是前面有一个rcode3 也是相同域名. 就是我说的正常dns查询. 这个是卡在第二个dns上了而且还失败了. 然后dig超时.

我的设置是server段里面有2个dns 第一个是填的国外第二个是给他写了domain 匹配国内域名. 是我配置不科学吗? 那我如果颠倒下顺序. 岂能是国外域名先查询cn服务器 然后再走一遍匹配的!?? 况且日志上都显示的无论卡不卡 v2行为都是先查询匹配dns 而且无论卡不卡他都接收到了记录了. 反正从他改查询的位置都接到了记录

我卡的时候看起来那个失败没有rcode3 看起来真是网络卡. 但是这个卡了的dns不是他应该走的位置. 总之真是乱七八糟呢. 他接到了cn域名指定的记录就该立刻返回才对. 所以目前问题是 dns查询竟然在并行发送!!!

k79e commented 4 years ago

我一个域名重复测试了无数遍不可能出错看一眼dig的查询时间就知道他查询了第二dns. 那个不存在的域名我这里决定查询成功率100% 而且1-2ms内就有结果. 理论v2如果没问题立刻就转发结果才是. (我的具体配置就是dns里面server有2个大括号第一个dns是国外的第二个dns是本地回环地址是个缓存服务器. 然后缓存服务器配置的是让他专门接cn域名的.)

我见到1楼你配置里面是context deadline exceeded. 不是rcode3. 可能你那个卡了?!! 你仔细看时间你卡的时候是网络也卡了. 你老版本不卡的时候是瞬间有结果的时候.

azzvx commented 4 years ago

我这里发现问题了，如果一个域名AAAA记录为空，那么会查询4次AAAA记录导致解析巨慢。如果一个域名A记录，AAAA记录都有，那么会瞬间返回。你们可以试试www.baidu.com(A)，www.qq.com(A+AAAA)，www.126.com(A)，www.163.com(A+AAAA)这几个域名，其中A+AAAA的会秒回，只有A的会巨慢。也可以找其它域名试试，反正就这个规律没跑了。

k79e commented 4 years ago

目前我这里没结果(复现不了你说的多次重复查询) 全空的域名也就是发个并行.(空域名才那样其他都正常) 2020/01/01 13:xx:05 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:53 got answere: baidu.com. TypeA -> [xxxxxxxxxxxxxxxx] 8.0004ms 最典型的就是那个t.cn把还有百度和其他的我一律跑了个遍都没发现啥问题.

azzvx commented 4 years ago

目前我这里没结果(复现不了你说的多次重复查询) 全空的域名也就是发个并行.(空域名才那样其他都正常) 2020/01/01 13:xx:05 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:53 got answere: baidu.com. TypeA -> [xxxxxxxxxxxxxxxx] 8.0004ms 最典型的就是那个t.cn把还有百度和其他的我一律跑了个遍都没发现啥问题.

我这里的日志是这样的，明显的1次www.baidu.com. TypeA -> [180.101.49.11 180.101.49.12]和4次www.baidu.com. TypeAAAA -> []。

2020/01/01 13:05:13 [Debug] [67397894] v2ray.com/core/proxy/dokodemo: processing connection from: 192.168.1.1:60931
2020/01/01 13:05:13 [Info] [67397894] v2ray.com/core/app/dispatcher: taking detour [dns-fwd] for [udp:114.114.114.114:53]
2020/01/01 13:05:13 [Info] [67397894] v2ray.com/core/proxy/dns: handling DNS traffic to udp:114.114.114.114:53
2020/01/01 13:05:13 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: www.baidu.com.
2020/01/01 13:05:13 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: www.baidu.com.
2020/01/01 13:05:13 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 13:05:13 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:114.114.114.114:53
2020/01/01 13:05:13 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 13:05:13 [Info] v2ray.com/core/app/dispatcher: default route for udp:114.114.114.114:53
2020/01/01 13:05:13 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:114.114.114.114:53
2020/01/01 13:05:13 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: www.baidu.com. TypeAAAA -> [] 21.9408ms
2020/01/01 13:05:13 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:www.baidu.com.
2020/01/01 13:05:13 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: www.baidu.com. TypeA -> [180.101.49.11 180.101.49.12] 21.9408ms
2020/01/01 13:05:13 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:www.baidu.com.
2020/01/01 13:05:16 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: www.baidu.com.
2020/01/01 13:05:16 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 13:05:16 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: www.baidu.com. TypeAAAA -> [] 22.9393ms
2020/01/01 13:05:16 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:www.baidu.com.
2020/01/01 13:05:17 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain www.baidu.com at server UDP:114.114.114.114:53 > context deadline exceeded
2020/01/01 13:05:17 [Debug] v2ray.com/core/app/dns: UDP:114.114.115.115:53 querying DNS for: www.baidu.com.
2020/01/01 13:05:17 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.115.115:53
2020/01/01 13:05:17 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:114.114.115.115:53
2020/01/01 13:05:17 [Info] v2ray.com/core/app/dispatcher: default route for udp:114.114.115.115:53
2020/01/01 13:05:17 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:114.114.115.115:53
2020/01/01 13:05:17 [Info] v2ray.com/core/app/dns: UDP:114.114.115.115:53 got answere: www.baidu.com. TypeAAAA -> [] 16.9546ms
2020/01/01 13:05:17 [Debug] v2ray.com/core/app/dns: UDP:114.114.115.115:53 updating IP records for domain:www.baidu.com.
2020/01/01 13:05:20 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain www.baidu.com at server UDP:114.114.114.114:53 > context deadline exceeded
2020/01/01 13:05:20 [Debug] v2ray.com/core/app/dns: UDP:114.114.115.115:53 querying DNS for: www.baidu.com.
2020/01/01 13:05:20 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.115.115:53
2020/01/01 13:05:20 [Info] v2ray.com/core/app/dns: UDP:114.114.115.115:53 got answere: www.baidu.com. TypeAAAA -> [] 15.9572ms
2020/01/01 13:05:20 [Debug] v2ray.com/core/app/dns: UDP:114.114.115.115:53 updating IP records for domain:www.baidu.com.
2020/01/01 13:05:21 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain www.baidu.com at server UDP:114.114.115.115:53 > context deadline exceeded
2020/01/01 13:05:21 [Info] v2ray.com/core/app/proxyman/outbound: failed to process outbound traffic > v2ray.com/core/proxy/freedom: connection ends > context canceled
2020/01/01 13:05:21 [Info] v2ray.com/core/transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe
2020/01/01 13:05:24 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain www.baidu.com at server UDP:114.114.115.115:53 > context deadline exceeded
2020/01/01 13:05:25 [Info] v2ray.com/core/app/proxyman/outbound: failed to process outbound traffic > v2ray.com/core/proxy/freedom: connection ends > context canceled
2020/01/01 13:05:25 [Info] v2ray.com/core/transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe

azzvx commented 4 years ago

另外查询AAAA记录是每个dns服务器查2次。也就是你有3个dns服务器那么会查6次，4个查8次。就是卡在查AAAA记录上了。

你nslookup或者dig aaaa都能复现的。

k79e commented 4 years ago

我用的64位v2 复现不了 aaaa也是查一次就是个空记录然后就结束了.

azzvx commented 4 years ago

我用的64位v2 复现不了 aaaa也是查一次就是个空记录然后就结束了.

k79e commented 4 years ago

天哪设置错了(aaaa only) 卡了8秒都没接到内容然后就跟查询空域名一样并行了一次就卡那里了

k79e commented 4 years ago

我发现aaaa only的时候竟然不是rcode:3 而是收到空记录之后等4秒才报错 2020/01/01 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n xxxcn at server UDP:127.0.0.1:53 > context deadline exceeded 然后又过4秒之后他自己发疯了用另一个dns再去查. 我算是服了. 又测了下发现第二dns的查询延时不定. 现在又成了失败之后立刻查了

很诡异. 目前观察到的情况是. 空域名的aaaa也算在rcode3里面. 如果是个已存在的域名 查aaaa如果不存在会卡4秒. 这时候就没rcode3了. xx:xx:05 [Info] v2ray.com/core/app/dns: UDP:127.0.0.1:53 got answere: t.cn. TypeAAAA -> [] 1ms //注意这里是立刻接到结果 xx:xx:09 [Info] v2ray.com/core/app/dns: failed to lookup ip for domai n t.cn at server UDP:127.0.0.1:53 > context deadline exceeded

k79e commented 4 years ago

dig要 +retry=0才行

azzvx commented 4 years ago

反正就是把空记录当成查询失败了呗。然后一些没有AAAA记录的域名查起来都巨慢。

k79e commented 4 years ago

默认重试不关的话程序自己会重新查询. 必须+retry=0 除非你日志里面没有新查询的情况然而并不是.

反正目前问题我发现的是如果不是rcode3. (这个状态码可能是空域名的意思) 比如aaaa only 是一个服务器就算立刻收到空记录 v2也不把他看作有效记录然后等4秒之后报错. 然后用另一个服务器查询还是一样就算收到空记录也不算有效然后等4秒之后再报错. 这样就卡了2x4=8s 如果用n个dns 那岂不是要卡n x 8s了!!

收到rcode3 也还是一样是总的查询时间加起来全查完了之后v2才转发结果. 第一个服务器用了1ms 第二个200ms 那总的时间就是201ms

e.g TypeA -> [] 105.006ms .... TypeA -> [] 486.0278ms

;; Query time: 592 msec ;; SERVER: 127.0.0.2#53(127.0.0.2)

反正1L说的超时连接超时 4秒我不认为是问题. 但是如果立刻收到了空记录还等4秒 乃至一串dns都查一遍这问题就大了

azzvx commented 4 years ago

问题就是立刻收到了空记录，还等4秒。因为v2把空记录当成查询失败了，会一直重试下去，直到每个dns服务器都试上2次。但是实际问题不大，你查一次dns，dig或者nslookup或者系统查询dns都有个timeout在，一般每次查询也就等个5s左右。

k79e commented 4 years ago

超时之内会允许多次重试而且你日志上面是发起了多次新查询我这边没有新查询只有第二个他自己跑的查询

我这边v2也没有重试只查询一次. 所以这不是一个问题.

k79e commented 4 years ago

果然跟楼上其他人说的一样出问题的时候都有一个权威服务器的记录里面是soa类型的回答. 这个时候查询结果里面 没有answers字段这个时候 flags里面最后4个位组是0000 也就是无错误. 所以这毫无疑问是个有效结果. (一般是0x8180) 8180我感觉不是判断依据还不如根据位组第一个bit证明他是个dns回显就够了

note 0x8180=1000 0001 1000 0000

目前发现是rcode:3 出现的时候 dns回显是0x8183 最后4个位组就是0011 是no such name 如前所说无论是不是空域名都会轮寻一遍而且还违背了dns路由策略!! https://github.com/v2ray/v2ray-core/issues/2144#issuecomment-570027691

Dns flags https://en.wikipedia.org/wiki/Domain_Name_System#DNS_message_format

我发现卡4秒的 soa only 也就是缺少answers字段的记录最后4个位组都是0000 所以判断他是否有效理论应该是使用dns结果的类型(第一个bit 和最后4个bit) 如果要判断是否出错的话那需要最后4个位组如果不是的话就第一个就够了反正参考下flags规范就行. 用hex匹配的话万万不能. 一定要用位组.

azzvx commented 4 years ago

根本问题已经很清楚了：v2把返回的AAAA空记录当成了查询失败，然后重试，直到查询超时。 你去查A+AAAA记录的域名，那么没问题，去查只有A记录的域名，那么查起来巨慢。不需要去试一些奇怪的域名，只要去试 www.baidu.com(A) 和 www.qq.com(A+AAAA) 就可以了。只要v2在收到AAAA空记录的时候马上返回，那么就一切OK了。 dig qq秒回， dig baidu等到死。 QQ截图20200101150544 QQ截图20200101150611

k79e commented 4 years ago

不是那样根据规定如果用路由 cn只允许查询分配给cn的dns才对. 不可以乱跑所以这背后还有其他问题.

你的问题非常不明确是多次发起新请求貌似这里就你一人是这样.

azzvx commented 4 years ago

不是那样根据规定如果用路由 cn只允许查询分配给cn的dns才对. 不可以乱跑所以这背后还有其他问题.

你的问题非常不明确是多次发起新请求貌似这里就你一人是这样.

我的问题很明确，一个域名没有AAAA记录那么v2会当成查询失败重试。如果有，那么v2会立即返回。 我用来测试的配置是简化的配置，没有任何其他因素的干扰。只测试v2内部dns服务器的问题。

{
    "log": {
        "loglevel": "debug"
    },
    "inbounds": [
        {
            "tag": "dns-in",
            "protocol": "dokodemo-door",
            "port": 8053,
            "settings": {
                "address": "114.114.114.114",
                "port": 53,
                "network": "udp,tcp"
            }
        }
    ],
    "outbounds": [
        {
            "tag": "direct",
            "protocol": "freedom"
        },
        {
            "tag": "dns-fwd",
            "protocol": "dns"
        }
    ],
    "dns": {
        "servers": [
            "114.114.114.114"
        ],
        "tag": "dns-direct"
    },
    "routing": {
        "rules": [
            {
                "type": "field",
                "inboundTag": [
                    "dns-in"
                ],
                "outboundTag": "dns-fwd"
            }
        ]
    }
}

k79e commented 4 years ago

我给你讲了多少遍让你+retry=0你非不用如果测试出了问题咋办? 你不知道dig默认重试好几次么!! 多试一次又死不了.

没有aaaa不会失败空域名也没有aaaa 他为啥不失败? 因为目前能判断rcode:3 这个我看了其实就是域名不存在的意思. 是dns规范. 既然这样 v2自己都识别出来了(或者根本就没写识别机制只是加了个log) 然而还是有问题. 不存在的话也没必要轮寻. 如前所说有没有rcode3 识别不识别都会出问题.

azzvx commented 4 years ago

我给你讲了多少遍让你+retry=0你非不用如果测试出了问题咋办? 你不知道dig默认重试好几次么!! 多试一次又死不了.

没有aaaa不会失败空域名也没有aaaa 他为啥不失败? 因为目前能判断rcode:3 这个我看了其实就是域名不存在的意思. 是dns规范. 既然这样 v2自己都识别出来了(或者根本就没写识别机制只是加了个log) 然而还是有问题. 不存在的话也没必要轮寻. 如前所说有没有rcode3 识别不识别都会出问题.

搞不懂你为什么死扣dig不放，要测试用nslookup更接近系统的dns查询机制。还有就是既然要测试问题就不要把配置文件搞的太复杂。你用我的简化配置nslookup一下www.qq.com和www.baidu.com就能直接发现问题了。qq秒回，baidu很慢。然后我是来反馈问题的，具体解决问题该怎么改代码、如何实现就不是我关心的了，我只是把发现的问题具体的提出来。

azzvx commented 4 years ago

关于空域名，直接返回的是域名不存在，和域名存在但是AAAA记录为空是两码事。你dig看空域名的status是NXDOMAIN，AAAA为空的status是NOERROR，完全不同好吧。但是v2把AAAA为空的status当成了ERROR，这就是问题。

k79e commented 4 years ago

空域名也存在轮寻非空域名还是轮寻我这里就是这样的 2个情况都是一个行为不过第二个是等4秒. 他不等4秒还是要轮寻反正查询机制有问题.

azzvx commented 4 years ago

空域名也存在轮寻非空郁闷还是轮寻我这里就是这样的 2个情况都是一个行为不过第二个是等4秒. 他不等4秒还是要轮寻反正查询机制有问题.

我这边nslookup了空域名，直接返回NXDOMAIN，没有发现轮询的现象。

root@AzzvxOWRT:~# nslookup qqqq.baidu.com 192.168.1.24#8053
Server:         192.168.1.24
Address:        192.168.1.24#8053

** server can't find qqqq.baidu.com: NXDOMAIN
** server can't find qqqq.baidu.com: NXDOMAIN

v2 log:

2020/01/01 15:44:18 [Debug] [1319679940] v2ray.com/core/proxy/dokodemo: processing connection from: 192.168.1.1:56737
2020/01/01 15:44:18 [Info] [1319679940] v2ray.com/core/app/dispatcher: taking detour [dns-fwd] for [udp:114.114.114.114:53]
2020/01/01 15:44:18 [Info] [1319679940] v2ray.com/core/proxy/dns: handling DNS traffic to udp:114.114.114.114:53
2020/01/01 15:44:18 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: qqqq.baidu.com.
2020/01/01 15:44:18 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: qqqq.baidu.com.
2020/01/01 15:44:18 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 15:44:18 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:114.114.114.114:53
2020/01/01 15:44:18 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 15:44:18 [Info] v2ray.com/core/app/dispatcher: default route for udp:114.114.114.114:53
2020/01/01 15:44:18 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:114.114.114.114:53
2020/01/01 15:44:18 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: qqqq.baidu.com. TypeA -> [] 35.9037ms
2020/01/01 15:44:18 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:qqqq.baidu.com.
2020/01/01 15:44:18 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain qqqq.baidu.com at server UDP:114.114.114.114:53 > rcode: 3
2020/01/01 15:44:18 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: qqqq.baidu.com. TypeAAAA -> [] 91.7544ms
2020/01/01 15:44:18 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:qqqq.baidu.com.
2020/01/01 15:44:18 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain qqqq.baidu.com at server UDP:114.114.114.114:53 > rcode: 3
2020/01/01 15:44:26 [Info] v2ray.com/core/app/proxyman/outbound: failed to process outbound traffic > v2ray.com/core/proxy/freedom: connection ends > context canceled
2020/01/01 15:44:26 [Info] v2ray.com/core/transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe

k79e commented 4 years ago

那是因为你只用了1个dns 怎么个轮寻法. 我前面一开始就说明了是多个dns.

azzvx commented 4 years ago

那是因为你只用了1个dns 怎么个轮寻法. 我前面一开始就说明了是多个dns.

3个dns也是直接返回。没有轮询。nslookup, dig 都是直接返回。

; <<>> DiG 9.14.8 <<>> qqqq.baidu.com @192.168.1.24 -p 8053 aaaa
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: NXDOMAIN, id: 16972
;; flags: qr aa rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 0

;; QUESTION SECTION:
;qqqq.baidu.com.                        IN      AAAA

;; Query time: 18 msec
;; SERVER: 192.168.1.24#8053(192.168.1.24)
;; WHEN: Wed Jan 01 15:49:54 CST 2020
;; MSG SIZE  rcvd: 32

V2Ray 4.22.0 (V2Fly, a community-driven edition of V2Ray.) Custom
A unified platform for anti-censorship.
2020/01/01 15:47:47 [Debug] v2ray.com/core/app/log: Logger started
2020/01/01 15:47:47 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 114.114.114.114:53
2020/01/01 15:47:47 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 115.114.114.115:53
2020/01/01 15:47:47 [Info] v2ray.com/core/app/dns: DNS: created udp client inited for 223.5.5.5:53
2020/01/01 15:47:47 [Debug] v2ray.com/core/app/proxyman/inbound: creating stream worker on 0.0.0.0:8053
2020/01/01 15:47:47 [Info] v2ray.com/core/transport/internet/tcp: listening TCP on 0.0.0.0:8053
2020/01/01 15:47:47 [Info] v2ray.com/core/transport/internet/udp: listening UDP on 0.0.0.0:8053
2020/01/01 15:47:47 [Warning] v2ray.com/core: V2Ray 4.22.0 started
2020/01/01 15:47:51 [Debug] [230785998] v2ray.com/core/proxy/dokodemo: processing connection from: 192.168.1.1:39238
2020/01/01 15:47:51 [Info] [230785998] v2ray.com/core/app/dispatcher: taking detour [dns-fwd] for [udp:114.114.114.114:53]
2020/01/01 15:47:51 [Info] [230785998] v2ray.com/core/proxy/dns: handling DNS traffic to udp:114.114.114.114:53
2020/01/01 15:47:51 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: qqqq.baidu.com.
2020/01/01 15:47:51 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 15:47:51 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 querying DNS for: qqqq.baidu.com.
2020/01/01 15:47:51 [Info] v2ray.com/core/transport/internet/udp: establishing new connection for udp:114.114.114.114:53
2020/01/01 15:47:51 [Debug] v2ray.com/core/transport/internet/udp: dispatch request to: udp:114.114.114.114:53
2020/01/01 15:47:51 [Info] v2ray.com/core/app/dispatcher: default route for udp:114.114.114.114:53
2020/01/01 15:47:51 [Info] v2ray.com/core/proxy/freedom: opening connection to udp:114.114.114.114:53
2020/01/01 15:47:51 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: qqqq.baidu.com. TypeA -> [] 19.9473ms
2020/01/01 15:47:51 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:qqqq.baidu.com.
2020/01/01 15:47:51 [Info] v2ray.com/core/app/dns: UDP:114.114.114.114:53 got answere: qqqq.baidu.com. TypeAAAA -> [] 19.9473ms
2020/01/01 15:47:52 [Debug] v2ray.com/core/app/dns: UDP:114.114.114.114:53 updating IP records for domain:qqqq.baidu.com.
2020/01/01 15:47:52 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain qqqq.baidu.com at server UDP:114.114.114.114:53 > rcode: 3
2020/01/01 15:47:52 [Info] v2ray.com/core/app/dns: failed to lookup ip for domain qqqq.baidu.com at server UDP:114.114.114.114:53 > rcode: 3
2020/01/01 15:47:59 [Info] v2ray.com/core/app/proxyman/outbound: failed to process outbound traffic > v2ray.com/core/proxy/freedom: connection ends > context canceled
2020/01/01 15:47:59 [Info] v2ray.com/core/transport/internet/udp: failed to handle UDP input > io: read/write on closed pipe

k79e commented 4 years ago

你这个果然是对的跟你那样测我也不轮寻了可我一开始就说明了我开路由了. 所以开路由又是另一个情况

azzvx commented 4 years ago

你这个果然是对的跟你那样测我也不轮寻了可我一开始就说明了我开路由了. 所以开路由又是另一个情况

你可以去试下，纯Ipv6的域名解析也会出问题，比如ipv6.vm0.test-ipv6.com，这回是A记录重复查询了。

k79e commented 4 years ago

对的就是空记录有4s问题算失败了. 位组需要判断下. 我开路由的环境也复现这个问题了.

真是够夸张的明明接到记录了v2还睁眼瞎!!! 哈哈因为他不认识哇!!!

kslr commented 4 years ago

来试试这个版本的

v2ray.exe.zip

linsui commented 4 years ago

这个版本没有出现问题，谢谢！

kslr commented 4 years ago

try 4.22.1

v2ray / v2ray-core

v2ray 4.22.0 dns 无解析结果时返回时间过长 #2144

note 0x8180=1000 0001 1000 0000