DNS cache is not working or is not working properly

ilfat12 commented 2 months ago

Operating system

Linux

System version

Linux 6.6

Installation type

Original sing-box Command Line

If you are using a graphical client, please provide the version of the client.

No response

Version

sing-box-1.10.0~beta.5-1.x86_64

Description

It looks like the dns cache is not working. I don't understand does it work or not? Why such a delay, it should be close to 0 ms

dig query time:

user@laptop ~ $ dig @127.0.0.1 mi.com | grep 'Query time'
;; Query time: 23 msec
user@laptop ~ $ dig @127.0.0.1 mi.com | grep 'Query time'
;; Query time: 26 msec
user@laptop ~ $ dig @127.0.0.1 mi.com | grep 'Query time'
;; Query time: 26 msec

Reproduction

Run sing-box with this config:

{
  "log": {
    "level": "trace"
  },
  "dns": {
    "servers": [
      {
        "address": "1.1.1.1"
      }
    ],
    "disable_cache": false
  },
  "inbounds": [
    {
      "type": "direct",
      "tag": "dns",
      "listen": "127.0.0.1",
      "listen_port": 53,
      "sniff": true
    }
  ],
  "outbounds": [
    {
      "type": "direct",
      "tag": "direct"
    },
    {
      "type": "dns",
      "tag": "dns"
    }
  ],
  "route": {
    "rules": [
      {
        "protocol": "dns",
        "outbound": "dns"
      }
    ],
    "auto_detect_interface": true
  }
}

Logs

INFO[0000] router: updated default interface enp2s0, index 2
INFO[0000] inbound/direct[dns]: tcp server started at 127.0.0.1:53
INFO[0000] inbound/direct[dns]: udp server started at 127.0.0.1:53
INFO[0000] sing-box started (0.00s)
INFO[0005] [1363955049 0ms] inbound/direct[dns]: inbound packet connection from 127.0.0.1:60380
DEBUG[0005] [1363955049 0ms] router: sniffed packet protocol: dns
DEBUG[0005] [1363955049 0ms] router: match[0] protocol=dns => dns
DEBUG[0005] [1363955049 0ms] dns: exchange mi.com. IN A
INFO[0005] [1363955049 0ms] outbound/direct[direct]: outbound packet connection to 1.1.1.1:53
DEBUG[0005] [1363955049 26ms] dns: exchanged mi.com NOERROR 163
INFO[0005] [1363955049 26ms] dns: exchanged mi.com CNAME mi.com. 163 IN CNAME sgp.ali.cdn.b2cop.lb.mi.com.
INFO[0005] [1363955049 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 163 IN A 161.117.97.92
INFO[0005] [1363955049 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 163 IN A 161.117.94.231
INFO[0005] [1363955049 26ms] dns: exchanged mi.com OPT OPT PSEUDOSECTION: EDNS: version 0 flags: MBZ: 0x00a3, udp: 1232
DEBUG[0015] [2865421721 10.3s] inbound/direct[dns]: connection closed: context canceled
INFO[0019] [2049832338 0ms] inbound/direct[dns]: inbound packet connection from 127.0.0.1:47505
DEBUG[0019] [2049832338 0ms] router: sniffed packet protocol: dns
DEBUG[0019] [2049832338 0ms] router: match[0] protocol=dns => dns
DEBUG[0019] [2049832338 0ms] dns: exchange mi.com. IN A
DEBUG[0019] [2049832338 26ms] dns: exchanged mi.com NOERROR 150
INFO[0019] [2049832338 26ms] dns: exchanged mi.com CNAME mi.com. 150 IN CNAME sgp.ali.cdn.b2cop.lb.mi.com.
INFO[0019] [2049832338 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 150 IN A 161.117.94.231
INFO[0019] [2049832338 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 150 IN A 161.117.97.92
INFO[0019] [2049832338 26ms] dns: exchanged mi.com OPT OPT PSEUDOSECTION: EDNS: version 0 flags: MBZ: 0x0096, udp: 1232
DEBUG[0029] [23162627 10.3s] inbound/direct[dns]: connection closed: context canceled
INFO[0046] [2619534138 0ms] inbound/direct[dns]: inbound packet connection from 127.0.0.1:55155
DEBUG[0046] [2619534138 0ms] router: sniffed packet protocol: dns
DEBUG[0046] [2619534138 0ms] router: match[0] protocol=dns => dns
DEBUG[0046] [2619534138 0ms] dns: exchange mi.com. IN A
DEBUG[0046] [2619534138 26ms] dns: exchanged mi.com NOERROR 124
INFO[0046] [2619534138 26ms] dns: exchanged mi.com CNAME mi.com. 124 IN CNAME sgp.ali.cdn.b2cop.lb.mi.com.
INFO[0046] [2619534138 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 124 IN A 161.117.97.92
INFO[0046] [2619534138 26ms] dns: exchanged mi.com A sgp.ali.cdn.b2cop.lb.mi.com. 124 IN A 161.117.94.231
INFO[0046] [2619534138 26ms] dns: exchanged mi.com OPT OPT PSEUDOSECTION: EDNS: version 0 flags: MBZ: 0x007c, udp: 1232
DEBUG[0056] [3469756800 10.3s] inbound/direct[dns]: connection closed: context canceled

Supporter

[ ] I am a sponsor

Integrity requirements

[X] I confirm that I have read the documentation, understand the meaning of all the configuration items I wrote, and did not pile up seemingly useful options or default values.
[X] I confirm that I have provided the server and client configuration files and process that can be reproduced locally, instead of a complicated client configuration file that has been stripped of sensitive data.
[X] I confirm that I have provided the simplest configuration that can be used to reproduce the error I reported, instead of depending on remote servers, TUN, graphical interface clients, or other closed-source software.
[X] I confirm that I have provided the complete configuration files and logs, rather than just providing parts I think are useful out of confidence in my own intelligence.

ilfat12 commented 2 months ago

Judging by the logs, the cache is used, but it is strange that there is such a delay. For example, dnsmasq, systemd-resolve, xray-core return a response for cached domains in 0-1 ms.

dyhkwong commented 2 months ago

For Exchange, only "simple DNS requests" (one Question, no NS, no extra RRs) will be cached. dig uses EDNS0 by default. Try dig +noedns.

ilfat12 commented 2 months ago

For Exchange, only "simple DNS requests" (one Question, no NS, no extra RRs) will be cached. dig uses EDNS0 by default. Try dig +noedns.

Yes, indeed, with +nodns, the response from the cache is returned in 0 ms. I think most application programs perform simple DNS queries, even nslookup, judging by the output of the time command, does not use EDNS. So, everything is fine. Thanks a lot for the clarification and for Sing-Box :)

SagerNet / sing-box