[Bug] 如果2个上游中的一个dns发生故障，本地有机率解析不出结果

PHCSJC commented 2 weeks ago

在提交之前，请确认

[X] 我已经尝试搜索过 Issue ，但没有找到相关问题。
[X] 我正在使用最新的 mosdns 版本(或者最新的 commit)，问题依旧存在。
[X] 我仔细看过 wiki 后仍然无法自行解决该问题。
[X] 我非常确定这是 mosdns 核心的问题。(如果是通过第三方衍生软件使用 mosdns 核心，不确定问题源头时，请先向衍生软件开发者提交问题。)

mosdns 版本

v5.3.3

操作系统

debian

Bug 描述和复现步骤

一直在用的v5.1.3版本没有问题，最近升级到v5.3.3发现了此问题，重现步骤：用我的配置文件启动（重点就是223.8.8.8是无法解析的域名），然后用下面的命令手动解析，2秒一次，10次中基本会出现1-2解析不出结果

dig 163.com @127.0.0.1 -p 55

; <<>> DiG 9.16.44-Debian <<>> 163.com @127.0.0.1 -p 55
;; global options: +cmd
;; Got answer:
;; ->>HEADER<<- opcode: QUERY, status: SERVFAIL, id: 27814
;; flags: qr rd ra; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1

;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags:; udp: 1200
;; QUESTION SECTION:
;163.com.           IN  A

;; Query time: 0 msec
;; SERVER: 127.0.0.1#55(127.0.0.1)
;; WHEN: Tue Sep 24 12:07:59 CST 2024
;; MSG SIZE  rcvd: 36

使用的配置文件

log:
  level: info

plugins:
  - tag: forward_local
    type: forward
    args:
      concurrent: 2
      upstreams:
        - addr: udp://223.5.5.5
        - addr: udp://223.8.8.8

  - tag: main
    type: sequence
    args:
      - exec: $forward_local

  - tag: udp_server
    type: udp_server
    args:
      entry: main
      listen: :55

  - tag: tcp_server
    type: tcp_server
    args:
      entry: main
      listen: :55

mosdns 的 log 记录

./mosdns start -c config.yaml
2024-09-24T12:07:39.368+0800    INFO    main config loaded  {"file": "config.yaml"}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "cache", "type": "cache"}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "hosts", "type": "hosts"}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "redirect", "type": "redirect"}
2024-09-24T12:07:39.368+0800    INFO    redirect    redirect rules loaded   {"length": 1}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "forward_local", "type": "forward"}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "forward_remote", "type": "forward"}
2024-09-24T12:07:39.368+0800    INFO    loading plugin  {"tag": "local_ip", "type": "ip_set"}
2024-09-24T12:07:39.375+0800    INFO    loading plugin  {"tag": "local_sequence", "type": "sequence"}
2024-09-24T12:07:39.375+0800    INFO    loading plugin  {"tag": "remote_sequence", "type": "sequence"}
2024-09-24T12:07:39.375+0800    INFO    loading plugin  {"tag": "gfwlist-sequence", "type": "sequence"}
2024-09-24T12:07:39.375+0800    INFO    loading plugin  {"tag": "fallback", "type": "fallback"}
2024-09-24T12:07:39.375+0800    INFO    loading plugin  {"tag": "main_sequence", "type": "sequence"}
2024-09-24T12:07:39.429+0800    INFO    loading plugin  {"tag": "udp_server", "type": "udp_server"}
2024-09-24T12:07:39.429+0800    INFO    udp_server  udp server started  {"addr": "[::]:55"}
2024-09-24T12:07:39.429+0800    INFO    loading plugin  {"tag": "tcp_server", "type": "tcp_server"}
2024-09-24T12:07:39.429+0800    INFO    tcp_server  tcp server started  {"addr": "[::]:55", "tls": false}
2024-09-24T12:07:39.429+0800    INFO    all plugins are loaded
2024-09-24T12:07:48.971+0800    WARN    forward_local   upstream error  {"uqid": 1, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:50.319+0800    WARN    forward_local   upstream error  {"uqid": 2, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:51.401+0800    WARN    forward_local   upstream error  {"uqid": 3, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:53.562+0800    WARN    forward_local   upstream error  {"uqid": 5, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:54.595+0800    WARN    forward_local   upstream error  {"uqid": 6, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:56.713+0800    WARN    forward_local   upstream error  {"uqid": 8, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:57.650+0800    WARN    forward_local   upstream error  {"uqid": 9, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-24T12:07:58.915+0800    WARN    forward_local   upstream error  {"uqid": 10, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8","error": "context deadline exceeded"}
2024-09-24T12:07:59.924+0800    WARN    forward_local   upstream error  {"uqid": 11, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8","error": "context deadline exceeded"}
2024-09-24T12:07:59.925+0800    WARN    forward_local   upstream error  {"uqid": 11, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8","error": "context deadline exceeded"}
2024-09-24T12:07:59.925+0800    WARN    udp_server  entry err   {"query": {"uqid": 11, "client": "::ffff:127.0.0.1", "qname": "163.com.", "qtype": 1, "qclass": 1, "elapsed": "5.000508153s"}, "error": "context deadline exceeded"}
2024-09-24T12:08:04.923+0800    WARN    forward_local   upstream error  {"uqid": 12, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "udp://223.8.8.8","error": "context deadline exceeded"}

yyysuo commented 2 weeks ago

用tcp试试。

PHCSJC commented 2 weeks ago

用tcp试试。

改成tcp了，一样的问题

2024-09-25T14:13:14.166+0800    WARN    forward_local   upstream error  {"uqid": 2, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-25T14:13:14.166+0800    WARN    udp_server  entry err   {"query": {"uqid": 2, "client": "::ffff:127.0.0.1", "qname": "163.com.", "qtype": 1, "qclass": 1, "elapsed": "5.000318326s"}, "error": "context deadline exceeded"}
2024-09-25T14:13:14.166+0800    WARN    forward_local   upstream error  {"uqid": 2, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-25T14:13:19.163+0800    WARN    forward_local   upstream error  {"uqid": 3, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}

yyysuo commented 2 weeks ago

用tcp试试。

改成tcp了，一样的问题

2024-09-25T14:13:14.166+0800  WARN    forward_local   upstream error  {"uqid": 2, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-25T14:13:14.166+0800  WARN    udp_server  entry err   {"query": {"uqid": 2, "client": "::ffff:127.0.0.1", "qname": "163.com.", "qtype": 1, "qclass": 1, "elapsed": "5.000318326s"}, "error": "context deadline exceeded"}
2024-09-25T14:13:14.166+0800  WARN    forward_local   upstream error  {"uqid": 2, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}
2024-09-25T14:13:19.163+0800  WARN    forward_local   upstream error  {"uqid": 3, "qname": "163.com.", "qclass": 1, "qtype": 1, "upstream": "tcp://223.8.8.8", "error": "context deadline exceeded"}

电报群有大佬回复了，concurrent 2其实是随机在上游中选取1个上游发请求，执行2次，有机率2次随机选的都是不可用dns，已经有人pr了。

https://github.com/IrineSistiana/mosdns/pull/842

IrineSistiana / mosdns

[Bug] 如果2个上游中的一个dns发生故障，本地有机率解析不出结果 #846

在提交之前，请确认

mosdns 版本

操作系统

Bug 描述和复现步骤

使用的配置文件

mosdns 的 log 记录