Redudant parallel queries for nonexistent AAAA records generated when quering for names from one zone repeatatedly
Steps to reproduce on an isolated network:
- Setup a authoritative on 1.0.0.100 with simulated static (100 ms) latency to resolver with this zone
. 86400 IN SOA j.root-servers.net. nstld.verisign-grs.com. 2019072500 1800 900 604800 86400
*. 3600 IN A 1.1.1.1
. 86400 IN NS j.root-servers.net.
j.root-servers.net. 86400 IN A 1.0.0.100
- Start resolver on 1.0.0.1 with these root hints capturing the traffic to PCAP
. 3600000 NS J.ROOT-SERVERS.NET.
J.ROOT-SERVERS.NET. 3600000 A 1.0.0.100
- Query the resolver with questions to the root zone triggering cache misses (with
for i in $(seq 0 $(( 2 * N ))); do echo "$i A"; done | dnsperf -q $N -a 2.0.0.1 -s 1.0.0.1
). Capture the traffic to a PCAP file.
Note that -q
option in dnsperf
sets the maximum number of outstanding queries.
Now observe the PCAP. First N answers from resolver look OK, the next N however are more than 4 times slower than the rest.
This is a example for N=20:
Verbose log for all of these looks like this:
[00000.00][plan] plan '20.' type 'A' uid [00020.00]
[00020.00][iter] '20.' type 'A' new uid was assigned .01, parent uid .00
[00020.01][cach] => no NSEC* cached for zone: .
[00020.01][cach] => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
[00020.01][resl] => going insecure because there's no covering TA
[00020.01][zcut] found cut: . (rank 020 return codes: DS -2, DNSKEY -2)
[00020.01][plan] plan 'j.root-servers.net.' type 'AAAA' uid [00020.02]
[00020.02][iter] 'j.root-servers.net.' type 'AAAA' new uid was assigned .03, parent uid .01
[00020.03][cach] => no NSEC* cached for zone: .
[00020.03][cach] => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
[00020.03][iter] <= rcode: NOERROR
[00020.03][iter] <= retrying with non-minimized name
[00020.03][cach] => not overwriting NS net.
[00020.03][resl] <= server: '1.0.0.100' rtt: 64 ms
[00020.03][iter] 'j.root-servers.net.' type 'AAAA' new uid was assigned .04, parent uid .01
[00020.04][iter] <= rcode: NOERROR
[00020.04][cach] => not overwriting AAAA j.root-servers.net.
[00020.04][resl] <= server: '1.0.0.100' rtt: 101 ms
[00020.01][iter] '20.' type 'A' new uid was assigned .05, parent uid .00
[00020.05][plan] plan 'j.root-servers.net.' type 'A' uid [00020.06]
[00020.06][iter] 'j.root-servers.net.' type 'A' new uid was assigned .07, parent uid .05
[00020.07][cach] => skipping unfit NS packet: rank 020, new TTL 86400
[00020.07][cach] => no NSEC* cached for zone: .
[00020.07][cach] => skipping zone: ., NSEC, hash 0;new TTL -123456789, ret -2
[00020.07][iter] <= rcode: NOERROR
[00020.07][iter] <= retrying with non-minimized name
[00020.07][cach] => not overwriting NS net.
[00020.07][resl] <= server: '1.0.0.100' rtt: 100 ms
[00020.07][iter] 'j.root-servers.net.' type 'A' new uid was assigned .08, parent uid .05
[00020.08][iter] <= rcode: NOERROR
[00020.08][cach] => not overwriting A j.root-servers.net.
[00020.08][resl] <= server: '1.0.0.100' rtt: 100 ms
[00020.05][iter] '20.' type 'A' new uid was assigned .09, parent uid .00
[00020.09][resl] => id: '42223' querying: '1.0.0.100#00053' score: 100 zone cut: '.' qname: '20.' qtype: 'A' proto: 'udp'
[00020.09][iter] <= rcode: NOERROR
[00020.09][cach] => stashed 20. A, rank 020, 20 B total, incl. 0 RRSIGs
[00020.09][resl] <= server: '1.0.0.100' rtt: 103 ms
[00020.09][resl] AD: request NOT classified as SECURE
[00020.09][resl] finished: 4, queries: 3, mempool: 16400 B
Two AAAA
and one A
resolver queries are generated unnecessarily for each of these client queries.