BIND 8.2.1 creating lots of CPU usage for syslogd and named

[Jim Reid]

>>>>> "Marcel" == Marcel Janssen <maja at oce.nl> writes:

    Marcel> I'm running BIND 8.2.1 on Solaris 2.6

    Marcel> When I start named SYSLOGD and NAMED are using lots of CPU.

    Marcel> When I turn on querylogging I get this about 200 times a second
    Marcel> 08-Aug-1999 13:57:42.559 XX+/134.188.149.78/78.149.188.134.in-addr.arpa/PTR
    Marcel> 08-Aug-1999 13:57:42.561 XX+/134.188.149.78/ts1-st16.oce.nl/A

    Marcel> In which 134.188.149.78 is the ip adres and ts1-st16.oce.nl
    Marcel> is the hostname running NAMED. Thus it performs about 200
    Marcel> queries a second for its own ip/hostname.

    Marcel> Can anybody help me?

This behaviour is to be expect if you use syslog for query logging and
you're getting upwards of 200 queries a second. Each query causes
named to send a log entry via syslog() to syslogd, causing a context
switch. syslogd looks at the message, figures out what to do with it
and writes it to some file. It gives up the CPU. Then named gets a
chance to run again (=> yet another process context switch) and 5ms
later it gets another query. So no wonder there's lots of system
activity, process switching and a busy syslogd process.

When there are lots of queries, it's better to set up a file channel
in named.conf for query logging. That way, there's no syslog or
context switching overheads and named can block-buffer the I/O to that
file. Something like this in the logging{} statement will give you the
general idea:

        channel query_logging {
                file "/home/named/querylogs/qlog"
                /* keep up to 7 qlog files of 60 Mbytes */
                versions 7 size 60M;
		/* log the time of each query */
                print-time yes;
        };

	...
	category queries {
		/* send all query logs to out query_logging channel */
		query_logging;
	}

The next problem is to find out what's sending out these queries. top
will show you the busiest processes on your system. Then a system call
analyser like ktrace or truss can prove which of them is battering the
name server.

The + in the querylog entry is a new thing in BIND8.2. It indicates
the request had the recursion desired bit set. This usually indicates
a request from a resolver because name servers are generally able to
recurse for themselves. So it looks as though you've got a runaway
application stuck in an infinite loop doing a forward and reverse
lookup for the local machine.