Diagnosing DS query timeouts

[notr1ch]

I run dnscrypt-proxy 2.0.44 behind a DNSSEC-validating PowerDNS recursor 4.5.1. I've noticed some intermittent SERVFAIL responses coming from pdns-recursor and after enabling trace=fail in pdns-recursor, it seems that dnscrypt-proxy (127.0.0.3 in the log below) is intermittently timing out for DS queries:

[4879] : no TA found for 'platform.twitter.com' among 2
[4879] : no TA found for 'twitter.com' among 2
[4879] : no TA found for 'com' among 2
[4879] : got TA for '.'
[4879] platform.twitter.com: Wants DNSSEC processing, auth data in query for A
[4879] platform.twitter.com: No cache hit for 'platform.twitter.com|A', trying to find an appropriate NS record
[4879] platform.twitter.com: Cache consultations done, have 1 NS to contact
[4879] platform.twitter.com: Domain has hardcoded nameserver
[4879] platform.twitter.com.: Nameservers: +127.0.0.3:53(3.34ms)
[4879] platform.twitter.com: Resolved '.' NS (empty) to: 127.0.0.3
[4879] platform.twitter.com: Trying IP 127.0.0.3:53, asking 'platform.twitter.com|A'
[4879] platform.twitter.com: Got 7 answers from (empty) (127.0.0.3), rcode=0 (No Error), aa=0, in 0ms
[4879] platform.twitter.com: accept answer 'platform.twitter.com|CNAME|cs472.wac.edgecastcdn.net.' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: accept answer 'cs472.wac.edgecastcdn.net|CNAME|cs1-apr-8315.wac.edgecastcdn.net.' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: accept answer 'cs1-apr-8315.wac.edgecastcdn.net|CNAME|wac.apr-8315.edgecastdns.net.' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: accept answer 'wac.apr-8315.edgecastdns.net|CNAME|cs1-lb-eu.8315.ecdns.net.' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: accept answer 'cs1-lb-eu.8315.ecdns.net|CNAME|cs41.wac.edgecastcdn.net.' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: accept answer 'cs41.wac.edgecastcdn.net|A|93.184.220.66' from '.' nameservers? ttl=59, place=1 YES! - This answer was received from a server we forward to.
[4879] platform.twitter.com: OPT answer '.' from '.' nameservers
[4879] : no signatures for platform.twitter.com, we likely missed a cut between . and platform.twitter.com, looking for it
[4879] : - Looking for a DS at com
[4879] : no TA found for 'com' among 2
[4879] : no TA found for 'com' among 2
[4879] : got TA for '.'
[4879]  com: Wants DNSSEC processing, auth data in query for DS
[4879]  com: Found cache hit for DS: 30909 8 2 e2d3c916f6deeac73294e8268fb5885044a833fc5459588f4a9184cfc41a5766[ttl=56940]
[4879]  com: updating validation state with cache content for com to Secure
[4879] : - Found cut at com
[4879] : New state for com is Secure
[4879] : - Looking for a DS at twitter.com
[4879] : no TA found for 'twitter.com' among 2
[4879] : no TA found for 'twitter.com' among 2
[4879] : no TA found for 'com' among 2
[4879] : got TA for '.'
[4879]  twitter.com: Wants DNSSEC processing, auth data in query for DS
[4879]  twitter.com: No cache hit for 'twitter.com|DS', trying to find an appropriate NS record
[4879]  twitter.com: Cache consultations done, have 1 NS to contact
[4879]  twitter.com: Domain has hardcoded nameserver
[4879]  twitter.com.: Nameservers: +127.0.0.3:53(1.82ms)
[4879]  twitter.com: Resolved '.' NS (empty) to: 127.0.0.3
[4879]  twitter.com: Trying IP 127.0.0.3:53, asking 'twitter.com|DS'
[4879]  twitter.com: timeout resolving after 5312.24msec
[4879]  twitter.com: Failed to resolve via any of the 1 offered NS at level '.'
[4879]  twitter.com: failed (res=-1)

I have a 5 second timeout configured in pdns-recursor as seen above, but a 2.5 second timeout in dnscrypt-proxy:

listen_addresses = ['127.0.0.3:53']
server_names = ['google']
user_name = '_dnscrypt-proxy'
max_clients = 250
timeout = 2500
keepalive = 60
block_unqualified = false
block_undelegated = false
log_level = 1
use_syslog = true
fallback_resolvers = ['1.1.1.1:53', '8.8.8.8:53', '9.9.9.9:53']
netprobe_timeout = 0

I was expecting that dnscrypt-proxy would send back a SERVFAIL or some other kind of response if it hits the timeout, but this does not appear to be happening. If I manually query the dnscrypt-proxy server for the DS record after experiencing this issue, it has so far responded correctly, so it's difficult to reproduce (possibly network / upstream DoH related). I did catch a similar issue where a query for type 65 (HTTPS) also resulted in a timeout and confirmed via tcpdump that dnscrypt-proxy never responded. Even with log_level = 1 there is no error or warning logged when this occurs.

So a couple of questions:

Is this the expected behavior for a timeout?

Is there a way to get more information as to why the query isn't being answered?

[karolyi]

Not sure if it's the same issue but I'm kinda getting a similar behavior.

My domains are now DNSSEC secured and validate properly. Upon doing a simple dig for my hostnames, sometimes the responses aren't DNSSEC validated: as in, missing the ad flag in the response.

This is all intermittent until their TTL expires and on the next request the hostname validates (sometimes). Knowing DNSSEC, this can only happen upon timeouts for the DS records, that should result in an error imo, especially in the case of DNSSEC secured domains.

Also, when I get the non-validated responses, the resolving takes a long time, I think they time out.

I observed this happening with mostly one TLD, that is .io. I tested their TLD nameservers for serving DS and NS records, they all seem to respond timely. I can only attribute this to network issues, the exact location of which I can't figure out.

I'm just spitballing here but I wouldn't be surprised if this could be used as an attack vector for DNS cache poisoning, in the case of DNSSEC secured domains timing out on DS requests. dnssec-proxy or the wrapper, or the nameservers aren't necessarily responsible for it, unless dnssec-proxy times out. As in, blocking a simple DS response anywhere in the recursive process might lead to domain records being able to be falsified, if not noted as an error in the recursive resolving process. A powerful enough adversary is able to pull off such a thing.

The question is, are DNSSEC validated DS record timeouts not noted as an error?

[karolyi]

Okay, I think my case is on unbound. On another server where I have it setup, it does the same thing, and I don't even use dnscrypt there.