BIND 8.4.5 as cache server, long delay to resolve some domains...

Jacques-André Petit japetit at ccis.be
Wed Jan 26 08:51:05 UTC 2005


Hello,

I get some delays before response from BIND 8.4.5 running as cache DNS 
in "erratic" domains.

After debugging a while, it seems that the problem arises when the 
requested domain info depends of one root and the DNS record for that 
domain is depending of another root.
A sample :   domain would be my_domain.*net* with a NS record pointing 
to ns.another_domain.*com*

BIND behave as if it "forgot" the primary request (www.my_domain.net) to 
resolve ns.another_domain.com.
Once resolved (ns.another_domain.com), BIND stops and never resolves 
www.my_domain.net

Then, after about 5 seconds, there is a new request from the client 
(timeout) and BIND can resolve further as it then knows how to resolve 
ns.another_domain.com.

A realworld example would be www.isfc.org  (dig response pasted below)

We suppose that this situation is not RFC compliant (where NS pointers 
must belong to the same root as the domain they manage), and that this 
cannot "semantically" be considered as bug, but from the user point of 
view, it is translated as long delays and frustration.

Is there a way to fix that behavior?

Regards,
Jacques Petit

[root at localhost ~]# dig www.isfc.org

; <<>> DiG 8.4 <<>> www.isfc.org
;; res options: init recurs defnam dnsrch no-nibble2
;; got answer:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 12390
;; flags: qr rd ra; QUERY: 1, ANSWER: 2, AUTHORITY: 2, ADDITIONAL: 2
;; QUERY SECTION:
;;      www.isfc.org, type = A, class = IN

;; ANSWER SECTION:
www.isfc.org.           1H IN CNAME     isfc.org.
isfc.org.               1H IN A         12.168.33.186

;; AUTHORITY SECTION:
isfc.org.               23h59m54s IN NS  ns2.vhostdns2.com.
isfc.org.               23h59m54s IN NS  ns1.vhostdns2.com.

;; ADDITIONAL SECTION:
ns2.vhostdns2.com.      1d23h59m54s IN A  12.168.33.99
ns1.vhostdns2.com.      1d23h59m54s IN A  12.168.33.98

;; Total query time: 5213 msec
;; FROM: localhost.localdomain to SERVER: 127.0.0.1
;; WHEN: Wed Jan 26 09:22:24 2005
;; MSG SIZE  sent: 30  rcvd: 153


and the trace level 2 output

datagram from [127.0.0.1].32775, fd 20, len 30
req: nlookup(www.isfc.org) id 12390 type=1 class=1
req: found 'www.isfc.org' as 'org' (cname=0)
forw: forw -> [204.74.112.1].53 ds=4 nsid=8752 id=12390 15ms retry 4sec
datagram from [204.74.112.1].53, fd 22, len 79
Response (USER NORMAL -) nsid=8752 id=12390
++ ns_resp(rcvd) ++ (79)
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 8752
;; flags: qr; QUERY: 1, ANSWER: 0, AUTHORITY: 2, ADDITIONAL: 0
;;      www.isfc.org, type = A, class = IN
isfc.org.               1D IN NS        ns2.vhostdns2.com.
isfc.org.               1D IN NS        ns1.vhostdns2.com.
-- ns_resp(rcvd) --
NS #0 addr [204.74.112.1].53 used, rtt 14
NS #1 [204.74.113.1].53 rtt now 17
rrsetupdate: isfc.org
resp: nlookup(www.isfc.org) qtype=1
resp: found 'www.isfc.org' as 'isfc.org' (cname=0)
sysquery: send -> [192.52.178.30].53 dfd=4 nsid=4277 id=0 retry=1106727742
sysquery: send -> [192.52.178.30].53 dfd=4 nsid=958 id=0 retry=1106727742
datagram from [192.52.178.30].53, fd 22, len 115
Response (SYSTEM NORMAL -) nsid=4277 id=0
++ ns_resp(rcvd) ++ (115)
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 4277
;; flags: qr; QUERY: 1, ANSWER: 1, AUTHORITY: 2, ADDITIONAL: 2
;;      ns2.vhostdns2.com, type = A, class = IN
ns2.vhostdns2.com.      2D IN A         12.168.33.99
vhostdns2.com.          2D IN NS        ns1.vhostdns2.com.
vhostdns2.com.          2D IN NS        ns2.vhostdns2.com.
ns1.vhostdns2.com.      2D IN A         12.168.33.98
ns2.vhostdns2.com.      2D IN A         12.168.33.99
-- ns_resp(rcvd) --
NS #0 addr [192.52.178.30].53 used, rtt 13
NS #1 [192.43.172.30].53 rtt now 18
NS #2 [192.5.6.30].53 rtt now 21
NS #3 [192.41.162.30].53 rtt now 24
NS #4 [192.31.80.30].53 rtt now 30
NS #5 [192.26.92.30].53 rtt now 37
NS #6 [192.12.94.30].53 rtt now 46
NS #7 [192.42.93.30].53 rtt now 46
NS #8 [192.54.112.30].53 rtt now 79
NS #9 [192.35.51.30].53 rtt now 124
NS #10 [192.48.79.30].53 rtt now 135
NS #11 [192.33.14.30].53 rtt now 225
NS #12 [192.55.83.30].53 rtt now 418
rrsetupdate: ns2.vhostdns2.com
rrsetupdate: vhostdns2.com
rrsetupdate: ns1.vhostdns2.com
rrsetupdate: ns2.vhostdns2.com
datagram from [192.52.178.30].53, fd 22, len 115
Response (SYSTEM NORMAL -) nsid=958 id=0
++ ns_resp(rcvd) ++ (115)
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 958
;; flags: qr; QUERY: 1, ANSWER: 1, AUTHORITY: 2, ADDITIONAL: 2
;;      ns1.vhostdns2.com, type = A, class = IN
ns1.vhostdns2.com.      2D IN A         12.168.33.98
vhostdns2.com.          2D IN NS        ns1.vhostdns2.com.
vhostdns2.com.          2D IN NS        ns2.vhostdns2.com.
ns1.vhostdns2.com.      2D IN A         12.168.33.98
ns2.vhostdns2.com.      2D IN A         12.168.33.99
-- ns_resp(rcvd) --
NS #0 addr [192.52.178.30].53 used, rtt 14
NS #1 [192.43.172.30].53 rtt now 17
NS #2 [192.5.6.30].53 rtt now 20
NS #3 [192.41.162.30].53 rtt now 23
NS #4 [192.31.80.30].53 rtt now 29
NS #5 [192.26.92.30].53 rtt now 36
NS #6 [192.12.94.30].53 rtt now 45
NS #7 [192.42.93.30].53 rtt now 45
NS #8 [192.54.112.30].53 rtt now 77
NS #9 [192.35.51.30].53 rtt now 121
NS #10 [192.48.79.30].53 rtt now 132
NS #11 [192.33.14.30].53 rtt now 220
NS #12 [192.55.83.30].53 rtt now 409
rrsetupdate: ns1.vhostdns2.com
flushrrset(ns1.vhostdns2.com, A, IN, 2)
rrsetupdate: vhostdns2.com
rrsetupdate: ns1.vhostdns2.com
rrsetupdate: ns2.vhostdns2.com
datagram from [127.0.0.1].32775, fd 20, len 30
req: nlookup(www.isfc.org) id 12390 type=1 class=1
req: found 'www.isfc.org' as 'isfc.org' (cname=0)
forw: forw -> [12.168.33.98].53 ds=4 nsid=2032 id=12390 21ms retry 4sec
datagram from [12.168.33.98].53, fd 22, len 41
Response (USER NORMAL -) nsid=2032 id=12390
++ ns_resp(rcvd) ++ (41)
;; ->>HEADER<<- opcode: QUERY, status: FORMERR, id: 2032
;; flags: qr; QUERY: 1, ANSWER: 0, AUTHORITY: 0, ADDITIONAL: 1
;;      www.isfc.org, type = A, class = IN
; EDNS: version: 0, udp=4096, flags=0000
-- ns_resp(rcvd) --
resp: error (ret 1, op 0), dropped
resend(addr=0 n=1) -> [12.168.33.98].53 ds=4 nsid=2032 id=12390 21ms
datagram from [12.168.33.98].53, fd 22, len 60
Response (USER NORMAL -) nsid=2032 id=12390
++ ns_resp(rcvd) ++ (60)
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 2032
;; flags: qr aa ra; QUERY: 1, ANSWER: 2, AUTHORITY: 0, ADDITIONAL: 0
;;      www.isfc.org, type = A, class = IN
www.isfc.org.           1H IN CNAME     isfc.org.
isfc.org.               1H IN A         12.168.33.186
-- ns_resp(rcvd) --
NS #0 addr [12.168.33.98].53 used, rtt 77
NS #1 [12.168.33.99].53 rtt now 23
rrsetupdate: www.isfc.org
rrsetupdate: isfc.org
resp: nlookup(www.isfc.org) qtype=1
resp: found 'www.isfc.org' as 'www.isfc.org' (cname=0)
resp: nlookup(isfc.org) qtype=1
resp: found 'isfc.org' as 'isfc.org' (cname=1)
send_msg -> [127.0.0.1].32775 (UDP 20) id=12390





More information about the bind-users mailing list