Kresd: Not resolving a particular domain name (SERVFAIL reported)

This puzzles me. I have kresd running on my Omnia of course, and it works fine. Have been happy for years with it. Totally cool.

Resolves everything for. Except today, this one domain name: wbo.ophir.dev.

Regard:

$ nslookup wbo.ophir.dev
Server:		127.0.0.53
Address:	127.0.0.53#53

** server can't find wbo.ophir.dev: SERVFAIL

$ nslookup wbo.ophir.dev 1.1.1.1
Server:		1.1.1.1
Address:	1.1.1.1#53

Non-authoritative answer:
Name:	wbo.ophir.dev
Address: 104.21.78.67
Name:	wbo.ophir.dev
Address: 172.67.217.114
Name:	wbo.ophir.dev
Address: 2606:4700:3036::ac43:d972
Name:	wbo.ophir.dev
Address: 2606:4700:3036::6815:4e43

$ nmcli con show "Wired connection 1" | grep domain_name_servers
DHCP4.OPTION[3]:                        domain_name_servers = 192.168.0.1
DHCP4.OPTION[10]:                       requested_domain_name_servers = 1

And on the Omnia:

# ubus call network.interface.wan status | grep -m 1 -A 3 "dns-server"
	"dns-server": [
		"203.12.160.35",
		"203.12.160.36"
	],

which reveals my ISP’s DNS servers, so back on a LAN PC:

$ nslookup wbo.ophir.dev 203.12.160.35
Server:		203.12.160.35
Address:	203.12.160.35#53

Non-authoritative answer:
Name:	wbo.ophir.dev
Address: 172.67.217.114
Name:	wbo.ophir.dev
Address: 104.21.78.67
Name:	wbo.ophir.dev
Address: 2606:4700:3036::ac43:d972
Name:	wbo.ophir.dev
Address: 2606:4700:3036::6815:4e43

so the name resolves on open name servers, and ion my ISP’s webserver (upstream, which kresd normally forwards to, bar .lan names).

So the config:

# cat /etc/config/resolver

config resolver 'common'
	list interface '0.0.0.0'
	list interface '::0'
	option port '53'
	option keyfile '/etc/root.keys'
	option verbose '0'
	option msg_buffer_size '4096'
	option msg_cache_size '20M'
	option net_ipv6 '1'
	option net_ipv4 '1'
	option forward_upstream '1'
	option prefered_resolver 'kresd'
	option ignore_root_key '0'
	option prefetch 'yes'
	option static_domains '1'
	option dynamic_domains '1'

config resolver 'kresd'
	option rundir '/tmp/kresd'
	option log_stderr '1'
	option log_stdout '1'
	option forks '1'
	option keep_cache '0'
	list hostname_config '/etc/hosts'

config resolver 'unbound'
	option outgoing_range '60'
	option outgoing_num_tcp '1'
	option incoming_num_tcp '1'
	option msg_cache_slabs '1'
	option num_queries_per_thread '30'
	option rrset_cache_size '100K'
	option rrset_cache_slabs '1'
	option infra_cache_slabs '1'
	option infra_cache_numhosts '200'
	list access_control '0.0.0.0/0 allow'
	list access_control '::0/0 allow'
	option pidfile '/var/run/unbound.pid'
	option root_hints '/etc/unbound/named.cache'
	option target_fetch_policy '2 1 0 0 0'
	option harden_short_bufsize 'yes'
	option harden_large_queries 'yes'
	option qname_minimisation 'yes'
	option harden_below_nxdomain 'yes'
	option key_cache_size '100k'
	option key_cache_slabs '1'
	option neg_cache_size '10k'
	option prefetch_key 'yes'

config resolver 'unbound_remote_control'
	option control_enable 'yes'
	option control_use_cert 'no'
	list control_interface '127.0.0.1'

And an extract from the messages log for an nslookup:

2021-01-23 10:57:02 info kresd[31781]: [00000.00][plan] plan 'wbo.ophir.dev.' type 'A' uid [65907.00]
2021-01-23 10:57:02 info kresd[31781]: [65907.00][iter]   'wbo.ophir.dev.' type 'A' new uid was assigned .01, parent uid .00
2021-01-23 10:57:02 info kresd[31781]: [65907.01][cach]   => trying zone: ., NSEC, hash 0
2021-01-23 10:57:02 info kresd[31781]: [65907.01][cach]   => NSEC sname: range search miss (!covers)
2021-01-23 10:57:02 info kresd[31781]: [65907.01][cach]   => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
2021-01-23 10:57:02 info kresd[31781]: [65907.01][plan]   plan '.' type 'DNSKEY' uid [65907.02]
2021-01-23 10:57:02 info kresd[31781]: [65907.02][iter]     '.' type 'DNSKEY' new uid was assigned .03, parent uid .01
2021-01-23 10:57:02 info kresd[31781]: [65907.03][cach]     => satisfied by exact RRset: rank 060, new TTL 136011
2021-01-23 10:57:02 info kresd[31781]: [65907.03][iter]     <= answer received: 
2021-01-23 10:57:02 info kresd[31781]: ;; ->>HEADER<<- opcode: QUERY; status: NOERROR; id: 38242
2021-01-23 10:57:02 info kresd[31781]: ;; Flags: qr aa  QUERY: 1; ANSWER: 0; AUTHORITY: 0; ADDITIONAL: 0
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: ;; QUESTION SECTION
2021-01-23 10:57:02 info kresd[31781]: .                DNSKEY
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: ;; ANSWER SECTION
2021-01-23 10:57:02 info kresd[31781]: .                        136011  DNSKEY  256 3 8 AwEAAbKGKkqc1VAvQr48iPf9Nd39f337MitggxF0AB9kLKRNSuq9joOEPC/R6PD/4lTzUms8U9oP+aiF0rVC2rGOKSdOLxPHRLA3ameMFT2/3bmVCFsRsn03IVTdN5VUAfczjqjmA0t9NM7bbN5oVzuQL3P1FyQb1q6HX4M1qg+htMNEd9PdlPLMFcrUg5fcYtTr2llVkO1Xo3lAdrjmmxfGeIyQnskpwPyW88J527DEytmgPo5KzLBYLMoL2Q41PK0ul0rs7yN+g5IG4LnJOcjew1yrmHXrp/OzrpsO4FkicufYt/ygfQKkT5HYbr/yFgeZAfaF80nYyc7wgDYxOeHdiRk=
2021-01-23 10:57:02 info kresd[31781]: .                        136011  DNSKEY  257 3 8 AwEAAaz/tAm8yTn4Mfeh5eyI96WSVexTBAvkMgJzkKTOiW1vkIbzxeF3+/4RgWOq7HrxRixHlFlExOLAJr5emLvN7SWXgnLh4+B5xQlNVz8Og8kvArMtNROxVQuCaSnIDdD5LKyWbRd2n9WGe2R8PzgCmr3EgVLrjyBxWezF0jLHwVN8efS3rCj/EWgvIWgb9tarpVUDK/b58Da+sqqls3eNbuv7pr+eoZG+SrDK6nWeL3c6H5Apxz7LjVc1uTIdsIXxuOLYA4/ilBmSVIzuDWfdRUfhHdY6+cn8HFRm+2hM8AnXGXws9555KrUB5qihylGa8subX2Nn6UwNR1AkUTV74bU=
2021-01-23 10:57:02 info kresd[31781]: .                        172800  RRSIG   DNSKEY 8 0 172800 20210211000000 20210121000000 20326 . hdO/MozPh54eM3Ow9qSXrpqt0L3hj2RfqHeuDimtgMLSR3V16Xqm9k2ctaT4qyCZb51OtiuE+1Uuimx3Dj83myjz5mOGo0z1f1VEwV6QTuPkZeVecZAFCzsuVTlpUT1OdZQhnwvzIIPYBLlG3TOTQuPtUY9v1LcyoxYWEYy+SDdaQo1CGu4Ochy1aleL40pHWaqk0Swl0lLcgykgVWS3ZpCDL+R50cXg7z4i5GnpMzxy48Yf4ED+Ja/W+x9ZOSmWnRmCjCGrTbY943AgJjCYEBbHEdJYo9PTYJrMp+x75U1LVSVpzpfI7OXd5yvH7AA8b83yyks+Sv+G6w8y05oZNw==
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: [65907.03][iter]     <= rcode: NOERROR
2021-01-23 10:57:02 info kresd[31781]: [65907.03][vldr]     <= parent: updating DNSKEY
2021-01-23 10:57:02 info kresd[31781]: [65907.03][vldr]     <= answer valid, OK
2021-01-23 10:57:02 info kresd[31781]: [65907.01][iter]   'wbo.ophir.dev.' type 'A' new uid was assigned .04, parent uid .00
2021-01-23 10:57:02 info kresd[31781]: [65907.04][plan]   plan 'dev.' type 'DS' uid [65907.05]
2021-01-23 10:57:02 info kresd[31781]: [65907.05][iter]     'dev.' type 'DS' new uid was assigned .06, parent uid .04
2021-01-23 10:57:02 info kresd[31781]: [65907.06][cach]     => skipping exact packet: rank 025 (min. 030), new TTL -109
2021-01-23 10:57:02 info kresd[31781]: [65907.06][cach]     => trying zone: ., NSEC, hash 0
2021-01-23 10:57:02 info kresd[31781]: [65907.06][cach]     => NSEC sname: range search miss (!covers)
2021-01-23 10:57:02 info kresd[31781]: [65907.06][cach]     => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
2021-01-23 10:57:02 info kresd[31781]: [     ][nsre] score 21 for 203.12.160.35#00053;   cached RTT: 11
2021-01-23 10:57:02 info kresd[31781]: [     ][nsre] score 21 for 203.12.160.36#00053;   cached RTT: 50
2021-01-23 10:57:02 info kresd[31781]: [65907.06][resl]     => id: '56623' querying: '203.12.160.35#00053' score: 21 zone cut: '.' qname: 'Dev.' qtype: 'DS' proto: 'udp'
2021-01-23 10:57:02 info kresd[31781]: resolve('wbo.ophir.dev')
2021-01-23 10:57:02 info kresd[31781]: true
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: > [65907.06][iter]     <= answer received: 
2021-01-23 10:57:02 info kresd[31781]: ;; ->>HEADER<<- opcode: QUERY; status: NOERROR; id: 56623
2021-01-23 10:57:02 info kresd[31781]: ;; Flags: qr aa rd ra cd  QUERY: 1; ANSWER: 0; AUTHORITY: 0; ADDITIONAL: 1
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: ;; EDNS PSEUDOSECTION:
2021-01-23 10:57:02 info kresd[31781]: ;; Version: 0; flags: do; UDP size: 4096 B; ext-rcode: Unused
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: ;; QUESTION SECTION
2021-01-23 10:57:02 info kresd[31781]: dev.             DS
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: ;; ADDITIONAL SECTION
2021-01-23 10:57:02 info kresd[31781]: 
2021-01-23 10:57:02 info kresd[31781]: [65907.06][iter]     <= rcode: NOERROR
2021-01-23 10:57:02 info kresd[31781]: [65907.06][resl]     <= server: '203.12.160.35' rtt: 2 ms
2021-01-23 10:57:02 info kresd[31781]: [65907.06][resl]     => resuming yielded answer
2021-01-23 10:57:02 info kresd[31781]: [65907.06][vldr]     <= bad NODATA proof
2021-01-23 10:57:02 info kresd[31781]: [65907.06][cach]     => stashed packet: rank 025, TTL 5, DS dev. (44 B)
2021-01-23 10:57:02 info kresd[31781]: [65907.00][resl] request failed, answering with empty SERVFAIL
2021-01-23 10:57:02 info kresd[31781]: [65907.06][resl]     finished: 8, queries: 1, mempool: 147504 B

Which is a lot to read for an inexperienced eye, but the key correlation with experience is the line:

2021-01-23 10:57:02 info kresd[31781]: [65907.00][resl] request failed, answering with empty SERVFAIL

Can someone with better interpretation skill shed light onto what is going on here, or suggest further diagnostics I can provide?

The TLDR: name resolution wokringflawlessly day in dayout. Thsi oen domain name “wbo.ophir.dev” not resolving by kresd but does resolve by the upstream DNS. kresd reports SERVFAIL but it isn’t clear what that means.

Very nice report. The log shows that DS dev. query is returned without empty but it should return answer. That blocks DNSSEC validation of anything under .dev.

You can report the failure to your ISP. One can run a similar query directly by dig DS dev @203.12.160.35 +dnssec

On your side I’d suggest not to forward to ISP’s DNS servers, which is easiest in (re)Foris “DNS” tab. My mode of choice is to uncheck forwarding (i.e. kresd asks authoritative servers directly). Another simple way is to keep forwarding to some other provider – there’s a list and reForis even allows selecting custom servers.

Thanks for responding. Can you kindly explain a little about what DS means? Forgive my naivite in that space. But also if we don’t forward to the ISPs DNS (which is fine by me) how does kresd resolve? You write: “kresd asks authoritative servers directly” and I’d love to know the mechanism here. So kresd receives a request from any of my LAN devices and how does it know what the authoritative nameserver is for any given domain? I’m very keen to learn more here.

How? It’s the same way that ISP’s DNS servers do it (and know it). There are designated root servers with hard-coded IPs, and they can tell you where to find top-level domain servers, etc. I’m not very good at explaining such things, better look elsewhere, e.g. these fun comics for basics: https://howdns.works

The security parts are more involved and not explained in simple intros like above. But the principle is similar – just as root tells us IPs of top-level domain servers, it also signs the signing keys for their data. That way the DNSSEC validator can verify the trust chain from the root key (basically hard-coded again) down to anywhere. And DS record is exactly that – hash of a signing key that’s one level below. And as anything in the secured chain, it needs RRSIG records which are signatures by the current level.