[Bug] reference query routine err nftable: failed to add ipv4 elems

performcanhe commented 1 year ago

在提交之前，请确认

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

mosdns 版本

v5.0.0-0-g81fff0b

操作系统

debian 11

Bug 描述和复现步骤

配置了 netflix 域名解析的 IP 使用插件写入 nftable set. 在观看 netflix 时, 日志中偶尔有写入 nftable set 错误如下.

Feb 05 20:01:17 storm mosdns[3226245]: 2023-02-05T20:01:17.416+0800 WARN sq_remote.r0 reference query routine err {"query": {"uqid": 2203, "client": "::ffff:192.168.2.23", "qname": "occ-0-37-33.1.nflxso.net.", " qtype": 1, "qclass": 1, "rcode": 0, "elapsed": "428.801625ms"}, "error": "nftable: failed to add ipv4 elems [23.246.15.183/24 23.246.15.213/24]: failed to get set, Receive: expected header error, but got unknown(2569)"} F

相关的 nftable set 里面已经写入了大量了 netflix IP , netflix 观看也没有出现问题.

使用的配置文件

log:
  level: debug

plugins:
  - tag: cache
    type: cache
    args:
      size: 1024
      lazy_cache_ttl: 86400

  - tag: domain_direct
    type: domain_set
    args:
      files:
        - "./direct-list.txt"

  - tag: domain_netflix
    type: domain_set
    args:
      files:
        - "./netflix"

  - tag: domain_video
    type: domain_set
    args:
      files:
        - "./youtube"

  - tag: domain_custom_1
    type: domain_set
    args:
      files:
        - "./custom-1"

  - tag: hosts_cf
    type: "hosts"
    args:
      files:
        - "./hosts"

  - tag: forward_local
    type: forward
    args:
      upstreams:
        - addr: udp://114.114.114.114

  - tag: forward_fake
    type: forward
    args:
      upstreams:
        - addr: udp://192.168.2.11:1053
  - tag: forward_remote
    type: forward
    args:
      upstreams:
        - addr: "https://8.8.8.8/dns-query"
          enable_pipeline: true
          socks5: 127.0.0.1:11880
        - addr: "https://1.1.1.1/dns-query"
          enable_pipeline: true
          socks5: 127.0.0.1:11880
        - addr: "https://cloudflare-dns.com/dns-query"
          enable_pipeline: true
          socks5: 127.0.0.1:11880

  - tag: sq_direct
    type: sequence
    args:
      - exec: $cache
      - matches: has_resp
        exec: accept         #找到缓存就结束
      - exec: prefer_ipv4
      - exec: $forward_local
      - exec: nftset inet,mangle,dr_p4,ipv4_addr,24 inet,mangle,dr_p6,ipv6_addr,48
      - exec: accept

  - tag: sq_fake
    type: sequence
    args:
      - exec: $forward_fake
      - exec: accept

  - tag: sq_local
    type: sequence
    args:
      - exec: prefer_ipv4
      - exec: $forward_local
      - matches: has_resp
        exec: accept         #找到就结束
      - exec: return         #找不到就返回

  - tag: sq_remote
    type: sequence
    args:
      - exec: prefer_ipv4
      - exec: $forward_remote
      - matches: qname $domain_custom_1
        exec: nftset inet,mangle,ct1_p4,ipv4_addr,0 inet,mangle,ct1_p6,ipv6_addr,0
      - matches: qname $domain_video
        exec: nftset inet,mangle,video_p4,ipv4_addr,24 inet,mangle,video_p6,ipv6_addr,48
      - matches: qname $domain_netflix
        exec: nftset inet,mangle,netflix_p4,ipv4_addr,24 inet,mangle,netflix_p6,ipv6_addr,48
      - exec: accept

  - tag: fake_sequence
    type: sequence
    args:
      - exec: $hosts_cf
      - matches: has_resp
        exec: accept         #找到cf hosts就结束
      - matches: qname $domain_direct
        exec: goto sq_direct  #直连域名流程
      - exec: goto sq_fake

  - tag: remote_sequence
    type: sequence
    args:
      - exec: $hosts_cf
      - matches: has_resp
        exec: accept         #找到cf hosts就结束
      - exec: $cache
      - matches: has_resp
        exec: accept         #找到缓存就结束
      - exec: goto sq_remote     #转发remote

  - tag: normal_sequence
    type: sequence
    args:
      - exec: $hosts_cf
      - matches: has_resp
        exec: accept         #找到cf hosts就结束
      - exec: $cache
      - matches: has_resp
        exec: accept         #找到缓存就结束
      - matches: qname $domain_direct
        exec: goto sq_direct  #直连域名流程
      - exec: goto sq_remote     #转发remote

  - tag: udp_server_normal
    type: udp_server
    args:
      entry: normal_sequence      # 收到的请求会执行上面的逻辑
      listen: :53
  - tag: tcp_server_normal
    type: tcp_server
    args:
      entry: normal_sequence
      listen: :53

mosdns 的 log 记录

Feb 05 20:00:36 storm mosdns[3226245]: 2023-02-05T20:00:36.200+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2193, "client": "::ffff:192.168.2.86", "qname": "commnat-cohort-gc.ess.apple.[1039/9507]
pe": 1, "qclass": 1, "elapsed": "693.248µs"}}
Feb 05 20:00:36 storm mosdns[3226245]: 2023-02-05T20:00:36.358+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2192, "client": "::ffff:192.168.2.86", "qname": "commnat-main-gc.ess.apple.com.", "qtype": 1,
 "qclass": 1, "rcode": 0, "elapsed": "167.082569ms"}}
Feb 05 20:00:36 storm mosdns[3226245]: 2023-02-05T20:00:36.375+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2193, "client": "::ffff:192.168.2.86", "qname": "commnat-cohort-gc.ess.apple.com.", "qtype":
1, "qclass": 1, "rcode": 0, "elapsed": "175.150688ms"}}
Feb 05 20:01:08 storm mosdns[3226245]: 2023-02-05T20:01:08.299+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2197, "client": "::ffff:192.168.2.46", "qname": "iosack.tuisong.baidu.com.", "qtype": 1,
 "qclass": 1, "elapsed": "560.588µs"}}
Feb 05 20:01:08 storm mosdns[3226245]: 2023-02-05T20:01:08.300+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2197, "client": "::ffff:192.168.2.46", "qname": "iosack.tuisong.baidu.com.", "qtype": 1, "qcl
ass": 1, "rcode": 0, "elapsed": "910.294µs"}}
Feb 05 20:01:08 storm mosdns[3226245]: 2023-02-05T20:01:08.299+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2198, "client": "::ffff:192.168.2.46", "qname": "iosack.tuisong.baidu.com.", "qtype": 65
, "qclass": 1, "elapsed": "508.802µs"}}
Feb 05 20:01:08 storm mosdns[3226245]: 2023-02-05T20:01:08.300+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2198, "client": "::ffff:192.168.2.46", "qname": "iosack.tuisong.baidu.com.", "qtype": 65, "qc
lass": 1, "rcode": 0, "elapsed": "1.138664ms"}}
Feb 05 20:01:17 storm mosdns[3226245]: 2023-02-05T20:01:17.416+0800        WARN        sq_remote.r0        reference query routine err        {"query": {"uqid": 2203, "client": "::ffff:192.168.2.23", "qname": "occ-0-37-33.1.nflxso.net.", "
qtype": 1, "qclass": 1, "rcode": 0, "elapsed": "428.801625ms"}, "error": "nftable: failed to add ipv4 elems [23.246.15.183/24 23.246.15.213/24]: failed to get set, Receive: expected header error, but got unknown(2569)"}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.038+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2215, "client": "::ffff:192.168.2.231", "qname": "dict-mobile.iciba.com.", "qtype": 1, "
qclass": 1, "elapsed": "607.038µs"}}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.039+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2215, "client": "::ffff:192.168.2.231", "qname": "dict-mobile.iciba.com.", "qtype": 1, "qclas
s": 1, "rcode": 0, "elapsed": "874.832µs"}}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.307+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2217, "client": "::ffff:192.168.2.231", "qname": "staticedu-wps.cache.iciba.com.", "qtyp
e": 65, "qclass": 1, "elapsed": "632.987µs"}}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.307+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2217, "client": "::ffff:192.168.2.231", "qname": "staticedu-wps.cache.iciba.com.", "qtype": 6
5, "qclass": 1, "rcode": 0, "elapsed": "908.681µs"}}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.308+0800        DEBUG        cache        start lazy cache update        {"query": {"uqid": 2218, "client": "::ffff:192.168.2.231", "qname": "staticedu-wps.cache.iciba.com.", "qtyp
e": 1, "qclass": 1, "elapsed": "542.264µs"}}
Feb 05 20:01:49 storm mosdns[3226245]: 2023-02-05T20:01:49.308+0800        DEBUG        cache        lazy cache updated        {"query": {"uqid": 2218, "client": "::ffff:192.168.2.231", "qname": "staticedu-wps.cache.iciba.com.", "qtype": 1
, "qclass": 1, "rcode": 0, "elapsed": "783.521µs"}}

performcanhe commented 1 year ago

nft list set inet mangle netflix_p4

table inet mangle { set netflix_p4 { typeof ip daddr flags interval auto-merge elements = { 3.132.196.0/24, 3.138.84.0/24, 3.141.219.0/24, 3.248.68.0/24, 3.248.72.0/24, 3.248.114.0/24, 3.248.144.0/24, 18.202.93.0/24, 18.202.100.0/24, 18.203.229.0/24, 18.214.21.0/24, 23.15.14.0/24, 23.39.1.0/24, 23.40.45.0/24, 23.42.156.0/24, 23.43.165.0/24, 23.46.150.0/24, 23.56.4.0/24, 23.57.112.0/24, 23.59.252.0/24,

urlesistiana commented 1 year ago

已经知道问题所在了。但不是很好修正。

虽然报错 nftable: failed to add ipv4 elems 写入失败，但其实已经成功写入了，只是获取写入结果的时候出错了。所以不影响使用。

urlesistiana commented 1 year ago

should be fixed by 7bac782fec036a55e245b6c401d746f33e0fc583

performcanhe commented 1 year ago

好的, 我更新测一下.

IrineSistiana / mosdns