Recursion problems

Baird, Josh jbaird at follett.com
Wed Aug 4 14:09:43 UTC 2010 

Hi,

I am having problems with recursion for domains that reside on two
particular nameservers.  My BIND9 servers return a SERVFAIL and do not
attempt to recurse to the authoritative nameservers for
ugabookstore.com.  

I have verified that my caching servers are not contacting
ugabookstore.com's authoritative servers via tcpdump.  I have also
enabled debug logging (level 99) on my caching server.  Other servers
are obviously able to recurse to ugabookstore.com's authoritative
servers, so I feel like it may be an issue on my end.  Could someone
offer any advice?

Recursion for all other domains is working correctly.

Debug logs from my caching server:

04-Aug-2010 08:58:13.656 client: debug 3: client 172.26.101.56#46071:
UDP request
04-Aug-2010 08:58:13.656 client: debug 5: client 172.26.101.56#46071:
using view '_default'
04-Aug-2010 08:58:13.656 security: debug 3: client 172.26.101.56#46071:
request is not signed
04-Aug-2010 08:58:13.656 security: debug 3: client 172.26.101.56#46071:
recursion available
04-Aug-2010 08:58:13.656 client: debug 3: client 172.26.101.56#46071:
query
04-Aug-2010 08:58:13.656 queries: info: client 172.26.101.56#46071:
query: ugabookstore.com IN A +
04-Aug-2010 08:58:13.656 client: debug 10: client 172.26.101.56#46071:
ns_client_attach: ref = 1
04-Aug-2010 08:58:13.656 security: debug 3: client 172.26.101.56#46071:
query (cache) 'ugabookstore.com/A/IN' approved
04-Aug-2010 08:58:13.656 client: debug 3: client 172.26.101.56#46071:
replace
04-Aug-2010 08:58:13.656 general: debug 3: clientmgr @0x960deb8:
createclients
04-Aug-2010 08:58:13.656 general: debug 3: clientmgr @0x960deb8: recycle
04-Aug-2010 08:58:13.657 resolver: debug 1: createfetch:
ugabookstore.com A
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): create
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): join
04-Aug-2010 08:58:13.657 resolver: debug 3: fetch 0x98ee108 (fctx
0x9678d50(ugabookstore.com/A)): created
04-Aug-2010 08:58:13.657 client: debug 3: client @0x9e2a378: udprecv
04-Aug-2010 08:58:13.657 general: debug 50: socket 0x960e2f8:
socket_recv: event 0x9bdfe88 -> task 0x9913de0
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): start
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): try
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cancelqueries
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): getaddresses
04-Aug-2010 08:58:13.657 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): query
04-Aug-2010 08:58:13.658 resolver: debug 3: resquery 0x99353f0 (fctx
0x9678d50(ugabookstore.com/A)): send
04-Aug-2010 08:58:13.658 general: debug 90: socket 0x991db08
0.0.0.0#49050: bound
04-Aug-2010 08:58:13.658 dispatch: debug 90: dispatch 0x976cdc0 response
0x9b9db60 192.5.6.30#53: attached to task 0x9771b28
04-Aug-2010 08:58:13.658 general: debug 50: socket 0x991db08:
socket_recv: event 0x9e721c8 -> task 0x976eb80
04-Aug-2010 08:58:13.658 resolver: debug 3: resquery 0x99353f0 (fctx
0x9678d50(ugabookstore.com/A)): sent
04-Aug-2010 08:58:13.658 resolver: debug 3: resquery 0x99353f0 (fctx
0x9678d50(ugabookstore.com/A)): udpconnected
04-Aug-2010 08:58:13.658 resolver: debug 3: resquery 0x99353f0 (fctx
0x9678d50(ugabookstore.com/A)): senddone
04-Aug-2010 08:58:13.658 general: debug 60: sockmgr 0x95ba350: watcher
got message -3 for socket 513
04-Aug-2010 08:58:13.658 general: debug 60: sockmgr 0x95ba350: watcher
got message -3 for socket 514
04-Aug-2010 08:58:13.658 general: debug 60: sockmgr 0x95ba350: watcher
got message -2 for socket -1
04-Aug-2010 08:58:13.710 general: debug 50: socket 0x991db08:
dispatch_recv:  event 0x9e721c8 -> task 0x976eb80
04-Aug-2010 08:58:13.710 general: debug 60: socket 0x991db08:
internal_recv: task 0x976eb80 got event 0x991db68
04-Aug-2010 08:58:13.710 general: debug 60: socket 0x991db08
192.5.6.30#53: packet received correctly
04-Aug-2010 08:58:13.710 general: debug 90: socket 0x991db08: processing
cmsg 0x983d880
04-Aug-2010 08:58:13.710 dispatch: debug 90: dispatch 0x976cdc0: got
packet: requests 1, buffers 1, recvs 0
04-Aug-2010 08:58:13.710 dispatch: debug 92: dispatch 0x976cdc0: got
valid DNS message header, /QR 1, id 21927
04-Aug-2010 08:58:13.710 dispatch: debug 90: dispatch 0x976cdc0 response
0x9b9db60 192.5.6.30#53: [a] Sent event 0x96a2560 buffer 0x987c8c0 len
4096 to task 0x9771b28
04-Aug-2010 08:58:13.710 general: debug 50: socket 0x991db08:
socket_recv: event 0x9bfdd78 -> task 0x976eb80
04-Aug-2010 08:58:13.710 resolver: debug 3: resquery 0x99353f0 (fctx
0x9678d50(ugabookstore.com/A)): response
04-Aug-2010 08:58:13.710 resolver: debug 10: received packet:
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id:  21927
;; flags: qr ; QUESTION: 1, ANSWER: 0, AUTHORITY: 2, ADDITIONAL: 3
;; OPT PSEUDOSECTION:
; EDNS: version: 0, flags: do; udp: 512
;; QUESTION SECTION:
;ugabookstore.com.              IN      A

;; AUTHORITY SECTION:
ugabookstore.com.       172800  IN      NS      aphrodite.efollett.com.
ugabookstore.com.       172800  IN      NS      demeter.efollett.com.

;; ADDITIONAL SECTION:
aphrodite.efollett.com. 172800  IN      A       64.37.224.76
demeter.efollett.com.   172800  IN      A       64.37.224.78


04-Aug-2010 08:58:13.710 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): noanswer_response
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cache_message
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cancelquery
04-Aug-2010 08:58:13.711 dispatch: debug 90: dispatch 0x976cdc0 response
0x9b9db60 192.5.6.30#53: detaching from task 0x9771b28
04-Aug-2010 08:58:13.711 dispatch: debug 90: dispatch 0x976cdc0: detach:
refcount 2
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cancelqueries
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9bfde88
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9d57018
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9c8f9e8
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x99ae148
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9ac20a0
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9c0dbd0
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x990d540
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9922958
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9bc77e0
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9915800
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9bc4658
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9a30538
04-Aug-2010 08:58:13.711 database: debug 5: dns_adb_destroyfind on find
0x9c120e8
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): try
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cancelqueries
04-Aug-2010 08:58:13.711 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): getaddresses
04-Aug-2010 08:58:13.712 database: debug 20: adb name 0x991da50: caching
alias target
04-Aug-2010 08:58:13.712 database: debug 5: dns_adb_createfind: name
0x991da50 is an alias
04-Aug-2010 08:58:13.712 database: debug 5: dns_adb_destroyfind on find
0x9c120e8
04-Aug-2010 08:58:13.712 database: debug 20: adb name 0x99b7bc8: caching
alias target
04-Aug-2010 08:58:13.712 database: debug 5: dns_adb_createfind: name
0x99b7bc8 is an alias
04-Aug-2010 08:58:13.712 database: debug 5: dns_adb_destroyfind on find
0x9c120e8
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): no addresses
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): done
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): stopeverything
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): cancelqueries
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): sendevents
04-Aug-2010 08:58:13.712 dispatch: debug 90: dispatch 0x976cdc0: got
packet: requests 0, buffers 1, recvs 0
04-Aug-2010 08:58:13.712 resolver: debug 3: fetch 0x98ee108 (fctx
0x9678d50(ugabookstore.com/A)): destroyfetch
04-Aug-2010 08:58:13.712 resolver: debug 3: fctx
0x9678d50(ugabookstore.com/A'): shutdown
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
error
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
send
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
sendto
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
senddone
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
next
04-Aug-2010 08:58:13.712 client: debug 10: client 172.26.101.56#46071:
ns_client_detach: ref = 0
04-Aug-2010 08:58:13.712 client: debug 3: client 172.26.101.56#46071:
endrequest
04-Aug-2010 08:58:13.712 dispatch: debug 90: dispatch 0x960df08: detach:
refcount 2

Any advice would be greatly appreciated.

Thanks,

Josh

More information about the bind-users mailing list