help debug a BIND problem (debug output)

Mathias Koerber mathias at staff.singnet.com.sg
Fri Feb 18 10:43:36 UTC 2000


Hi all,

I have a wierd problem doing certain DNS lookups, and would like to 
solicit help with reading the BIND debug output.

I'm using BIND-8.2.2p5

The Problem:  None of my nameservers can perform DNS lookups
for www.chijstcs.moe.edu.sg, yet dig(1) queries for the same (from the
same nameserver to the auth NS of the domain) work fine:

	dnscache1:/u1/named.log# dig www.chijstcs.moe.edu.sg a

	; <<>> DiG 8.2 <<>> www.chijstcs.moe.edu.sg a 
	;; res options: init recurs defnam dnsrch
	;; res_nsend to server default -- 0.0.0.0: Connection timed out
	dnscache1:/u1/named.log# dig www.chijstcs.moe.edu.sg a @pridns.moe.edu.sg

	; <<>> DiG 8.2 <<>> www.chijstcs.moe.edu.sg a @pridns.moe.edu.sg 
	; (1 server found)
	;; res options: init recurs defnam dnsrch
	;; got answer:
	;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 6
	;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 2, ADDITIONAL: 1
	;; QUERY SECTION:
	;;      www.chijstcs.moe.edu.sg, type = A, class = IN

	;; ANSWER SECTION:
	www.chijstcs.moe.edu.sg.  8H IN A  202.181.236.138

	;; AUTHORITY SECTION:
	moe.edu.sg.             8H IN NS        pridns.moe.edu.sg.
	moe.edu.sg.             8H IN NS        secdns.moe.edu.sg.

	;; ADDITIONAL SECTION:
	secdns.moe.edu.sg.      8H IN A         166.121.9.200

	;; Total query time: 5 msec
	;; FROM: dnscache1 to SERVER: pridns.moe.edu.sg  166.121.9.114
	;; WHEN: Fri Feb 18 18:28:44 2000
	;; MSG SIZE  sent: 41  rcvd: 125

	dnscache1:/u1/named.log# dig www.chijstcs.moe.edu.sg a @secdns.moe.edu.sg

	; <<>> DiG 8.2 <<>> www.chijstcs.moe.edu.sg a @secdns.moe.edu.sg 
	; (1 server found)
	;; res options: init recurs defnam dnsrch
	;; got answer:
	;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 6
	;; flags: qr aa rd ra; QUERY: 1, ANSWER: 1, AUTHORITY: 2, ADDITIONAL: 1
	;; QUERY SECTION:
	;;      www.chijstcs.moe.edu.sg, type = A, class = IN

	;; ANSWER SECTION:
	www.chijstcs.moe.edu.sg.  8H IN A  202.181.236.138

	;; AUTHORITY SECTION:
	moe.edu.sg.             8H IN NS        pridns.moe.edu.sg.
	moe.edu.sg.             8H IN NS        secdns.moe.edu.sg.

	;; ADDITIONAL SECTION:
	secdns.moe.edu.sg.      8H IN A         166.121.9.200

	;; Total query time: 6 msec
	;; FROM: dnscache1 to SERVER: secdns.moe.edu.sg  166.121.9.200
	;; WHEN: Fri Feb 18 18:28:56 2000
	;; MSG SIZE  sent: 41  rcvd: 125

Doing a 
	# ndc trace 11;dig www.chijstcs.moe.edu.sg a; ndc notrace

I get this debug log (only parts shown). The full log is available
on demand (don't want to clutter the list), including what I think they mean:

	18-Feb-2000 17:59:05.490 debug 1: Debug level 11
	18-Feb-2000 17:59:05.490 debug 1: Version = named 8.2.2-P5 Mon Dec 27 10:23:22 SGT 1999
		mathias at dnstest1TP:/usr/src/bind-822p5/src/bin/named
	18-Feb-2000 17:59:05.490 debug 1: conffile = /etc/named.conf
	18-Feb-2000 17:59:05.490 debug 5: ctl_readable: /var/run/ndc: read: Unexpected EOF
	18-Feb-2000 17:59:05.490 debug 5: ctl_new_state: /var/run/ndc: reading -> idling (ctl_stop_read)
	18-Feb-2000 17:59:05.490 debug 5: ctl_new_state: /var/run/ndc: idling -> closing (ctl_close)
	18-Feb-2000 17:59:05.490 debug 5: ctl_close: /var/run/ndc: closed (fd 6)

		# these 2 lines are the log of my request to my local nameserver
		# note id 4 (right?)
	18-Feb-2000 17:59:05.494 debug 1: datagram from [127.0.0.1].1025, fd 20, len 41
	18-Feb-2000 17:59:05.494 debug 1: req: nlookup(www.chijstcs.moe.edu.sg) id 4 type=1 class=1

		# here it looks into its cache for the relevant auth NS or nearest referral..
	18-Feb-2000 17:59:05.494 debug 1: req: found 'www.chijstcs.moe.edu.sg' as 'moe.edu.sg' (cname=0)
	18-Feb-2000 17:59:05.494 debug 5: findns: np 0x2abb83dc 'moe'
	18-Feb-2000 17:59:05.494 debug 3: findns: 2 NS's added for 'moe'
	18-Feb-2000 17:59:05.494 debug 3: ns_forw()
	18-Feb-2000 17:59:05.495 debug 5: qnew(0x2abd5650)
	18-Feb-2000 17:59:05.495 debug 3: nslookup(nsp=0x7fffec84, qp=0x2abd5650, "www.chijstcs.moe.edu.sg")
	18-Feb-2000 17:59:05.495 debug 3: nslookup: NS "pridns.moe.edu.sg" c=1 t=2 (flags 0x2)
	18-Feb-2000 17:59:05.495 debug 8: nslookup: 1 ns addrs
	18-Feb-2000 17:59:05.495 debug 3: nslookup: NS "secdns.moe.edu.sg" c=1 t=2 (flags 0x2)
	18-Feb-2000 17:59:05.495 debug 8: nslookup: 2 ns addrs
	18-Feb-2000 17:59:05.495 debug 3: nslookup: 2 ns addrs total
	18-Feb-2000 17:59:05.495 debug 10: qcomp(166.121.9.114, 166.121.9.200) 22 (0) - 15 (0) = 7
	18-Feb-2000 17:59:05.495 debug 10:      pos1=9998, pos2=9998
	18-Feb-2000 17:59:05.495 debug 3: retrytime: nstime0ms t4 nretry0 u4 : v4
	18-Feb-2000 17:59:05.495 debug 4: schedretry(0x2abd5650, 4 sec)
		# here it sends a query (nsid 30591) to one of them (166.121.9.200)
	18-Feb-2000 17:59:05.495 debug 1: forw: forw -> [166.121.9.200].53 ds=22 nsid=30591 id=4 15ms retry 4sec
	18-Feb-2000 17:59:05.495 debug 3: free_nsp: pridns.moe.edu.sg rcnt 3
	18-Feb-2000 17:59:05.495 debug 3: free_nsp: secdns.moe.edu.sg rcnt 3

		# This seems to be the reply. But I note it seems to come from a different
		# IP address ! I think this is the reply based on the nsid and IP below..
	18-Feb-2000 17:59:05.502 debug 1: datagram from [166.121.37.1].984, fd 22, len 125
	18-Feb-2000 17:59:05.502 debug 3: qfindid(30591) -> 0x2abd5650
	18-Feb-2000 17:59:05.502 debug 2: Response (USER NORMAL -) nsid=30591 id=4

To my understanding, BIND would ignore this reply and timeout.

The questions now are:
	1. Am I correct in my reading of the debug log?
	
	2. Why would the remote NS reply from a different IP address?
	2.a	Was this a sknown problem in a previ version of BIND or any other NS?
		(I have not managed to speak to the remote admin yet, I actually wanted
		some more data before I contact them).
	3. Does dig(1) not care about the sender's IP address, but BIND does?

Any help is appreciated...
Thanks

Mathias
-- 
Mathias Koerber	  | Tel: +65 / 471 9820    |   mathias at staff.singnet.com.sg
SingNet NOC	  | Fax: +65 / 475 3273    |            mathias at koerber.org
Q'town Tel. Exch. | PGP: Keyid: 768/25E082BD, finger mathias at singnet.com.sg
2 Stirling Rd     |      1A 8B FC D4 93 F1 9A FC BD 98 A3 1A 0E 73 01 65
S'pore 148943     | Disclaimer: I speak only for myself
* Eifersucht ist eine Leidenschaft, die mit Eifer sucht, was Leiden schafft *




More information about the bind-users mailing list