DNS server generates an enormous amount of traffic
Irvine Short
irvines at iafrica.com
Tue Jul 27 20:56:55 UTC 1999
Hi again
I narrowed the traffic down to named by two things:
1. If I killed named the traffic went down
2. a ps or top indicated that named was munching most of the CPU, sometimes
up to 100%.
CPU is usually around 5%, if that.
The primary name server is a HP Netserver EISA / PCI 100MHz with 72MB RAM,
the secondary a P75 PCI system with 32MB RAM Neither have memory problems -
they're both configures with 128MB swap and never use more than about 5MB of
it according to top.
The secondary is connected to the Internet via two analog leased lines
running multilink PPP, which is what most of the 5% is taken up with.
The primary is on the 64k line via a router.
I'm using FreeBSD 2.2.8, the primary RELEASE and the secondary STABLE
I've been doing some reading, and tried a kill -USR1
I've included it below.
Are all those messages like:
ns_resp: ns F.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 207.159.77.18 rcnt 1 (busy)
ns_resp: ns I.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.36.148.17 rcnt 1 (busy)
OK?
I'm very new to name server debugging, they've always just worked for me.
I did notice that if I pinged say www.ibm.net there was a lookup the first
time, but the second time it answered it's own questions.
Here follows some log file:
Debug turned ON, Level 1
datagram from [127.0.0.1].1106, fd 22, len 35; now Tue Jul 27 22:42:26 1999
req: nlookup(www.microsoft.com) id 33986 type=1 class=1
req: found 'www.microsoft.com' as 'com' (cname=0)
forw: forw -> [128.9.0.107].53 ds=23 nsid=17681 id=33986 350ms retry 4sec
datagram from [128.9.0.107].53, fd 23, len 199; now Tue Jul 27 22:42:26 1999
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 17681
;; flags: qr; Ques: 1, Ans: 0, Auth: 4, Addit: 4
;; QUESTIONS:
;; www.microsoft.com, type = A, class = IN
;; AUTHORITY RECORDS:
MICROSOFT.com. 172800 IN NS ATBD.MICROSOFT.com.
MICROSOFT.com. 172800 IN NS DNS1.MICROSOFT.com.
MICROSOFT.com. 172800 IN NS DNS4.CP.MSFT.NET.
MICROSOFT.com. 172800 IN NS DNS5.CP.MSFT.NET.
;; ADDITIONAL RECORDS:
ATBD.MICROSOFT.com. 172800 IN A 131.107.1.7
DNS1.MICROSOFT.com. 172800 IN A 131.107.1.240
DNS4.CP.MSFT.NET. 172800 IN A 207.46.138.11
DNS5.CP.MSFT.NET. 172800 IN A 207.46.138.12
rrsetupdate: MICROSOFT.com
rrsetcmp: name not in database
rrsetupdate: MICROSOFT.com 0
rrsetupdate: MICROSOFT.com 0
rrsetupdate: MICROSOFT.com 0
rrsetupdate: MICROSOFT.com 0
rrsetupdate: ATBD.MICROSOFT.com
rrsetcmp: name not in database
rrsetupdate: ATBD.MICROSOFT.com 0
rrsetupdate: DNS1.MICROSOFT.com
rrsetcmp: name not in database
rrsetupdate: DNS1.MICROSOFT.com 0
resp: nlookup(www.microsoft.com) qtype=1
resp: found 'www.microsoft.com' as 'microsoft.com' (cname=0)
ns_resp: ns B.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.9.0.107 rcnt 1 (busy)
ns_resp: ns C.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.33.4.12 rcnt 1 (busy)
ns_resp: ns E.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.203.230.10 rcnt 1 (busy)
ns_resp: ns H.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.63.2.53 rcnt 1 (busy)
ns_resp: ns F.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 207.159.77.18 rcnt 1 (busy)
ns_resp: ns I.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.36.148.17 rcnt 1 (busy)
ns_resp: ns F.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.5.5.241 rcnt 1 (busy)
ns_resp: ns J.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 198.41.0.21 rcnt 1 (busy)
ns_resp: ns A.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 198.41.0.4 rcnt 1 (busy)
ns_resp: ns D.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.8.10.90 rcnt 1 (busy)
ns_resp: ns K.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 195.8.99.11 rcnt 1 (busy)
ns_resp: ns G.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.112.36.4 rcnt 1 (busy)
sysquery: send -> [192.33.4.12].53 dfd=23 nsid=17682 id=0 retry=933108150
sysquery: send -> [192.33.4.12].53 dfd=23 nsid=17683 id=0 retry=933108150
resp: forw -> [131.107.1.240].53 ds=23 nsid=17684 id=33986 6ms
datagram from [131.107.1.240].53, fd 23, len 145; now Tue Jul 27 22:42:27
1999
rrsetupdate: www.microsoft.com
rrsetcmp: name not in database
rrsetupdate: www.microsoft.com 0
rrsetupdate: microsoft.com
rrsetcmp: no records in database
rrsetupdate: microsoft.com 0
rrsetupdate: microsoft.com 0
rrsetupdate: microsoft.com 0
rrsetupdate: microsoft.com 0
rrsetupdate: microsoft.com 0
rrsetupdate: microsoft.com 0
send_msg -> [127.0.0.1].1106 (UDP 22) id=33986
qfree: ns DNS1.MICROSOFT.com rcnt 1 (busy)
qfree: nsdata 131.107.1.240 rcnt 1 (busy)
qfree: ns ATBD.MICROSOFT.com rcnt 1 (busy)
qfree: nsdata 131.107.1.7 rcnt 1 (busy)
datagram from [192.33.4.12].53, fd 23, len 126; now Tue Jul 27 22:42:27 1999
rrsetupdate: DNS4.CP.MSFT.NET
rrsetcmp: no records in database
rrsetupdate: DNS4.CP.MSFT.NET 0
rrsetupdate: MSFT.net
rrsetcmp: no records in database
rrsetupdate: MSFT.net 0
rrsetupdate: MSFT.net 0
rrsetupdate: DNS4.CP.MSFT.NET
rrsetcmp: rrsets matched
rrsetupdate: DNS5.CP.MSFT.net
rrsetcmp: no records in database
rrsetupdate: DNS5.CP.MSFT.net 0
qfree: ns C.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 192.33.4.12 rcnt 2 (busy)
qfree: ns E.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 192.203.230.10 rcnt 2 (busy)
qfree: ns H.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 128.63.2.53 rcnt 2 (busy)
qfree: ns F.GTLD-SERVERS.net rcnt 2 (busy)
qfree: nsdata 207.159.77.18 rcnt 2 (busy)
qfree: ns I.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 192.36.148.17 rcnt 2 (busy)
qfree: ns B.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 128.9.0.107 rcnt 2 (busy)
qfree: ns F.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 192.5.5.241 rcnt 2 (busy)
qfree: ns J.GTLD-SERVERS.net rcnt 2 (busy)
qfree: nsdata 198.41.0.21 rcnt 2 (busy)
qfree: ns A.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 198.41.0.4 rcnt 2 (busy)
qfree: ns D.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 128.8.10.90 rcnt 2 (busy)
qfree: ns K.GTLD-SERVERS.net rcnt 2 (busy)
qfree: nsdata 195.8.99.11 rcnt 2 (busy)
qfree: ns G.ROOT-SERVERS.net rcnt 2 (busy)
qfree: nsdata 192.112.36.4 rcnt 2 (busy)
datagram from [192.33.4.12].53, fd 23, len 126; now Tue Jul 27 22:42:27 1999
rrsetupdate: DNS5.CP.MSFT.NET
rrsetcmp: rrsets matched
rrsetupdate: MSFT.net
rrsetcmp: rrsets matched
rrsetupdate: DNS4.CP.MSFT.net
rrsetcmp: rrsets matched
rrsetupdate: DNS5.CP.MSFT.NET
rrsetcmp: rrsets matched
qfree: ns C.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 192.33.4.12 rcnt 1 (busy)
qfree: ns E.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 192.203.230.10 rcnt 1 (busy)
qfree: ns H.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 128.63.2.53 rcnt 1 (busy)
qfree: ns F.GTLD-SERVERS.net rcnt 1 (busy)
qfree: nsdata 207.159.77.18 rcnt 1 (busy)
qfree: ns I.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 192.36.148.17 rcnt 1 (busy)
qfree: ns B.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 128.9.0.107 rcnt 1 (busy)
qfree: ns F.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 192.5.5.241 rcnt 1 (busy)
qfree: ns J.GTLD-SERVERS.net rcnt 1 (busy)
qfree: nsdata 198.41.0.21 rcnt 1 (busy)
qfree: ns A.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 198.41.0.4 rcnt 1 (busy)
qfree: ns D.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 128.8.10.90 rcnt 1 (busy)
qfree: ns K.GTLD-SERVERS.net rcnt 1 (busy)
qfree: nsdata 195.8.99.11 rcnt 1 (busy)
qfree: ns G.ROOT-SERVERS.net rcnt 1 (busy)
qfree: nsdata 192.112.36.4 rcnt 1 (busy)
datagram from [127.0.0.1].1107, fd 22, len 43; now Tue Jul 27 22:43:45 1999
req: nlookup(59.85.31.196.in-addr.arpa) id 7207 type=12 class=1
req: found '59.85.31.196.in-addr.arpa' as '196.in-addr.arpa' (cname=0)
forw: forw -> [192.203.230.10].53 ds=23 nsid=17685 id=7207 369ms retry 4sec
datagram from [192.203.230.10].53, fd 23, len 179; now Tue Jul 27 22:43:46
1999
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 17685
;; flags: qr; Ques: 1, Ans: 0, Auth: 3, Addit: 3
;; QUESTIONS:
;; 59.85.31.196.in-addr.arpa, type = PTR, class = IN
;; AUTHORITY RECORDS:
31.196.IN-ADDR.ARPA. 518400 IN NS NS1.IAFRICA.COM.
31.196.IN-ADDR.ARPA. 518400 IN NS NS2.IAFRICA.COM.
31.196.IN-ADDR.ARPA. 518400 IN NS RIP.PSG.COM.
;; ADDITIONAL RECORDS:
NS1.IAFRICA.COM. 172800 IN A 196.7.0.139
NS2.IAFRICA.COM. 172800 IN A 196.7.142.133
RIP.PSG.COM. 172800 IN A 147.28.0.39
rrsetupdate: 31.196.IN-ADDR.ARPA
rrsetcmp: name not in database
rrsetupdate: 31.196.IN-ADDR.ARPA 0
rrsetupdate: 31.196.IN-ADDR.ARPA 0
rrsetupdate: 31.196.IN-ADDR.ARPA 0
resp: nlookup(59.85.31.196.in-addr.arpa) qtype=12
resp: found '59.85.31.196.in-addr.arpa' as '31.196.in-addr.arpa' (cname=0)
ns_resp: ns E.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.203.230.10 rcnt 1 (busy)
ns_resp: ns H.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.63.2.53 rcnt 1 (busy)
ns_resp: ns I.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.36.148.17 rcnt 1 (busy)
ns_resp: ns B.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.9.0.107 rcnt 1 (busy)
ns_resp: ns F.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.5.5.241 rcnt 1 (busy)
ns_resp: ns A.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 198.41.0.4 rcnt 1 (busy)
ns_resp: ns D.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.8.10.90 rcnt 1 (busy)
ns_resp: ns C.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.33.4.12 rcnt 1 (busy)
ns_resp: ns G.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.112.36.4 rcnt 1 (busy)
resp: forw -> [196.7.142.133].53 ds=23 nsid=17686 id=7207 89ms
datagram from [196.7.142.133].53, fd 23, len 171; now Tue Jul 27 22:43:46
1999
rrsetupdate: 59.85.31.196.in-addr.arpa
rrsetcmp: name not in database
rrsetupdate: 59.85.31.196.in-addr.arpa 0
rrsetupdate: 85.31.196.in-addr.arpa
rrsetcmp: no records in database
rrsetupdate: 85.31.196.in-addr.arpa 0
rrsetupdate: 85.31.196.in-addr.arpa 0
send_msg -> [127.0.0.1].1107 (UDP 22) id=7207
qfree: ns NS2.IAFRICA.COM rcnt 1 (busy)
qfree: nsdata 196.7.142.133 rcnt 1 (busy)
qfree: ns NS1.IAFRICA.COM rcnt 1 (busy)
qfree: nsdata 196.7.0.139 rcnt 1 (busy)
qfree: ns RIP.PSG.COM rcnt 1 (busy)
qfree: nsdata 147.28.0.39 rcnt 1 (busy)
datagram from [127.0.0.1].1108, fd 22, len 42; now Tue Jul 27 22:43:49 1999
req: nlookup(196-31-85-59.iafrica.com) id 1797 type=1 class=1
req: found '196-31-85-59.iafrica.com' as 'iafrica.com' (cname=0)
forw: forw -> [196.7.0.139].53 ds=23 nsid=17687 id=1797 158ms retry 4sec
datagram from [196.7.0.139].53, fd 23, len 175; now Tue Jul 27 22:43:49 1999
rrsetupdate: 196-31-85-59.iafrica.com
rrsetcmp: name not in database
rrsetupdate: 196-31-85-59.iafrica.com 0
rrsetupdate: iafrica.com
rrsetcmp: rrsets matched
rrsetupdate: ns1.iafrica.com
rrsetcmp: rrsets matched
rrsetupdate: ns2.iafrica.com
rrsetcmp: rrsets matched
send_msg -> [127.0.0.1].1108 (UDP 22) id=1797
qfree: ns NS1.IAFRICA.com rcnt 1 (busy)
qfree: nsdata 196.7.0.139 rcnt 1 (busy)
qfree: ns NS2.IAFRICA.com rcnt 1 (busy)
qfree: nsdata 196.7.142.133 rcnt 1 (busy)
qfree: ns RIP.PSG.com rcnt 1 (busy)
qfree: nsdata 147.28.0.39 rcnt 1 (busy)
datagram from [127.0.0.1].1109, fd 22, len 42; now Tue Jul 27 22:44:10 1999
req: nlookup(196-31-85-59.iafrica.com) id 1798 type=1 class=1
req: found '196-31-85-59.iafrica.com' as '196-31-85-59.iafrica.com'
(cname=0)
ns_req: answer -> [127.0.0.1].1109 fd=22 id=1798 size=175 Local
datagram from [196.7.0.152].2578, fd 23, len 32; now Tue Jul 27 22:45:50
1999
req: nlookup(intoafrica.com) id 63733 type=6 class=1
req: found 'intoafrica.com' as 'intoafrica.com' (cname=0)
sysquery: send -> [207.159.77.18].53 dfd=23 nsid=17690 id=0 retry=933108354
ns_req: answer -> [196.7.0.152].2578 fd=23 id=63733 size=194 Remote
resend(addr=1 n=0) -> [192.36.148.17].53 ds=23 nsid=17690 id=0 404ms
datagram from [192.36.148.17].53, fd 23, len 122; now Tue Jul 27 22:45:55
1999
;; ->>HEADER<<- opcode: QUERY, status: NOERROR, id: 17690
;; flags: qr; Ques: 1, Ans: 0, Auth: 2, Addit: 1
;; QUESTIONS:
;; ns2.intekom.com, type = A, class = IN
;; AUTHORITY RECORDS:
INTEKOM.com. 172800 IN NS WALLACE.CAPE.INTEKOM.com.
INTEKOM.com. 172800 IN NS CHEETAH.INTEKOM.CO.ZA.
;; ADDITIONAL RECORDS:
WALLACE.CAPE.INTEKOM.com. 172800 IN A 196.25.193.2
rrsetupdate: INTEKOM.com
rrsetcmp: no records in database
rrsetupdate: INTEKOM.com 0
rrsetupdate: INTEKOM.com 0
rrsetupdate: WALLACE.CAPE.INTEKOM.com
rrsetcmp: rrsets matched
resp: nlookup(ns2.intekom.com) qtype=1
resp: found 'ns2.intekom.com' as 'ns2.intekom.com' (cname=0)
ns_resp: ns F.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 207.159.77.18 rcnt 1 (busy)
ns_resp: ns I.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.36.148.17 rcnt 1 (busy)
ns_resp: ns B.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.9.0.107 rcnt 1 (busy)
ns_resp: ns F.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.5.5.241 rcnt 1 (busy)
ns_resp: ns J.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 198.41.0.21 rcnt 1 (busy)
ns_resp: ns A.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 198.41.0.4 rcnt 1 (busy)
ns_resp: ns H.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.63.2.53 rcnt 1 (busy)
ns_resp: ns E.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.203.230.10 rcnt 1 (busy)
ns_resp: ns D.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 128.8.10.90 rcnt 1 (busy)
ns_resp: ns C.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.33.4.12 rcnt 1 (busy)
ns_resp: ns K.GTLD-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 195.8.99.11 rcnt 1 (busy)
ns_resp: ns G.ROOT-SERVERS.NET rcnt 1 (busy)
ns_resp: nsdata 192.112.36.4 rcnt 1 (busy)
resp: forw -> [196.25.193.2].53 ds=23 nsid=17691 id=0 1006ms
datagram from [196.25.193.2].53, fd 23, len 141; now Tue Jul 27 22:45:55
1999
rrsetupdate: ns2.intekom.com
rrsetcmp: no records in database
rrsetupdate: ns2.intekom.com 0
rrsetupdate: intekom.com
rrsetcmp: record not in database
flushrrset(intekom.com, NS, IN, 1)
rm_datum: WALLACE.CAPE.INTEKOM.com rcnt = 1
rm_datum: CHEETAH.INTEKOM.CO.ZA rcnt = 1
flushrrset: 0
flushrrset: -4
rrsetupdate: intekom.com 0
rrsetupdate: intekom.com 0
rrsetupdate: cheetah.intekom.com
rrsetcmp: rrsets matched
rrsetupdate: wallace.cape.intekom.com
rrsetcmp: rrsets matched
qfree: ns WALLACE.CAPE.INTEKOM.com rcnt 0 (freed)
qfree: nsdata 196.25.193.2 rcnt 1 (busy)
qfree: ns CHEETAH.INTEKOM.CO.ZA rcnt 0 (freed)
qfree: nsdata 196.25.69.2 rcnt 1 (busy)
Debug turned OFF
Irvine Short <irvines at iafrica.com> wrote in message
news:7nks1t$4nl$1 at nnrp01.ops.uunet.co.za...
> Hi
>
> I've got a machine that is primary DNS for two domains.
>
> It's generating so much traffic as to cause 2 - 3 second pings on a 64k
> (like a USA 56k) leased line.
>
> How can I start debugging this?
>
> I'm starting now, but please if anyone has any ideas I need help
urgently -
> I've get too many things to do tonight as it is!
>
> --
> Regards,
>
> Irvine Short
>
> IS Consulting
> 196 Longmarket Street,
> Cape Town
> tel/fax 021 423 0233
> cell 082 494 3828
> email irvines at iafrica.com
>
>
>
>
More information about the bind-users
mailing list