BIND 8.2.1 creating lots of CPU usage for syslogd and named

Michael Voight mvoight at cisco.com
Tue Aug 10 15:29:21 UTC 1999


Jim, 

Someone else mentioned earlier that it appeared syslog might be
recursively looking up the local hostname.  Syslog should not be
recursively doing name lookups. This might be because they told syslog
to log DNS queries. Since syslog is doing a dns query that needs to get
logged to syslog, the cycle never ends.

Michael

Jim Reid wrote:
> 
> >>>>> "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.


More information about the bind-users mailing list