Logs and Debugging | The Concise Guide to DNS and BIND

BIND 8 has quite an advanced logging apparatus, and at first sight, it can also be incomprehensible. The logs are important and should be paid attention to, so you catch errors sooner rather than later.

All logging options must occur within one "logging" directive. If there are several logging directives the last one found takes precedence. To get the logging you want during the loading of zones, a good place to have the logging directive is at the very start of the named.conf file. The basic elements of logging are "channel"s and "category"s, I will return to these shortly.

BINDs Start, Reload, and Reconfig Logging

The main, day-to-day use of the BIND logs is to find out if the changes you make to the configuration and zones are syntactically correct. For this reason you should always look at the BIND log when a zone or configuration file is updated and loaded. If you don't notice that a zone is rejected by BIND because of syntax errors your server will become lame, not able to answer queries about a zone it was supposed to be authoritative for. After the expiry interval set in the SOA record the slave servers will expire the zone and they too will become lame. At this point names in the rejected zone will become impossible to resolve, and all service, mail, Web or otherwise will fail. Similarly, a syntax error early in the named.conf file might stop all further processing of it, causing the zones appearing later in the file to not be loaded with the same disrupting results. A simple log inspection would have revealed all. Running "tail -f" on the log file when restarting or reloading bind is good practice.

The prudent DNS admin will either read, or set up a log analysis tool to read the DNS logs for her periodically to discover problems, no matter if a change was made to her own configuration or not. Network configuration, or other problems at remote sites might cause zone transfer of slave zones to your server. This might not be obvious to the master admin, but should be plain to the slave admin because BIND will complain.

There are ways to automate quality control of your DNS. Some of them are described in Chapter 7, "The DNS Tool Chest."

Logging Channels

A channel is a logging method, a way to funnel log messages somewhere, usually the syslog daemon or a file. A channel can have several other properties as well. The general syntax for a channel is quite complex:

 channel channel_name {   facility   [ severity ( critical | error | warning | notice |                info  | debug [ level ] | dynamic ); ]   [ print-category yes_or_no; ]   [ print-severity yes_or_no; ]   [ print-time yes_or_no; ]

Severity is like syslogs priority concept. And indeed, when BIND logs to syslog it logs at the analogous syslog priority. The severity field gives the cutoff level of messages sent to the channel. The severities above are given in order of increasing verbosity. If you specify "critical" only critical messages will be sent there. If you specify "notice" all levels from "critical" down to "notice" will be sent there. If you desire debugging output specify "dynamic" and use "ndc trace" and "ndc notrace" to change the debugging level dynamically. There is an example of this earlier in this chapter, when I discussed zone transfer by NOTIFY.

If you want to find out what category a message is setting "print-category" to, "yes" will be helpful. Ditto for "print-severity." yes_or_no should be "yes" or "no," but "true" or "false" and "0" or "1" is also recognized. By default all the print settings are off. Setting these will help you customize BINDs logging exactly to your needs, because you can see at what levels and in which categories the interesting messages occur. It can also help automated reading of the logs because words such as "critical" are a lot easier to identify automatically than the wording of a message, which can change. The default severity is "info."

The facility is a logging facility, and is specified with this syntax:

 ( file path_name    [ versions ( number | unlimited ) ]    [ size size_spec ]  | syslog ( kern | user | mail | daemon | auth | syslog | lpr |             news | uucp | cron | authpriv | ftp |             local0 | local1 | local2 | local3 |             local4 | local5 | local6 | local7 ) | null );

As you see there are three ways to log: to file, to syslog, and to null the great bit bucket in the sky.

Time to concentrate. BIND has logging facilities. These are places to put log entries. Syslog is one of these facilities within BIND, a simple file is another. Syslog has facilities as well, but they are not the same. In syslog a facility is a message originator, or category. A syslog facility bears a name such as "kern," "user," "mail," or "local0," to "local7" as shown earlier. BIND facilities does not have names beyond "file," "syslog," and "null." Please don't confuse the two kinds of facilities.

If BIND is to log to the syslog facility you also need to specify with which of syslog's facilities you want the messages to be associated. Thus, the appearance of syslog facility names in the listing shown earlier. The syslog priority is given by BINDs own severity. If you check, you'll see that the syslog priorities match the severities well. If you want to run a chroot'ed BIND, you must log to file because the syslogd is not available from a chroot environment. See Chapters 8, "Security Concerns," and 15, "Compiling and Maintaining BIND," for more information about BIND in chroot'ed environments.

The file facility is quite advanced for a file logging facility. It can rotate its own logs. The log is rotated whenever it becomes bigger than the size and is kept for the number of generations given by the "size" and "versions" clauses. If your OS services include log rotation, be careful to not let syslogs own log rotation be interfered with by the OS log rotation. When logging to file it's usually a good idea to add "print-time yes." Syslog adds timestamps automatically, but output to file does not. The size_spec should be a number or "unlimited." The number can be followed by one of K, M or G, possibly in lowercase. The letters mean exactly what you think they mean.

Logging Categories

By this BIND refers to the category of messages. The syntax goes like this:

 category category_name {          channel_name; [ channel_name; … ]  };

The channel names are the channels you have named with your channel clauses as described earlier, or one of the default channels, described later. The category name gives the category of messages that should go to that channel. It should be one of these:

config Configuration file processing
Parser Low-level parsing of the configuration file
queries Log every query received (but briefly)
lame-servers The warnings about lame servers
statistics Various statistics
panic The last "eeeep!" from the server before exiting after a fatal a error is discovered
update Notices about dynamic updates
ncache About negative caching
xfer-in Zone-transfers to the server
xfer-out Zone-transfers to other servers
db Database operations
eventlib The latest from the event loop. Only one file channel can be specified.
packet The packets BIND sends and receives are decoded into the channel associated with this category. Only one file channel can be specified.
notify Everything about NOTIFY events
ncname CNAME warnings
security Of approved and unapproved requests
os Problems with the OS
insist Failures of internal consistency checks
maintenance Internal maintenance events
load Zone loading events
nresponse-checks Problems found in answers BIND receive

BINDs Default Logging Configuration

This is shamelessly stolen from the named.conf man page (see Appendix A):

 logging {         channel default_syslog {                 syslog daemon;    # send to syslog's daemon facility                 severity info;    # only send priority info and higher         };         channel default_debug {              file "named.run";              # write to named.run in the working directory              # Note: stderr is used instead of "named.run" if the server              # is started with the -f option.              severity dynamic;              # log at the server's current debug level          };          channel default_stderr { # writes to stderr              file "<stderr>";              # this is illustrative only; there's currently no way of              # specifying an internal file descriptor in the              # configuration language.              severity info;       # only send priority info and higher          };          channel null {              null;                # toss anything sent to this channel          };          category default { default_syslog; default_debug; };          category panic { default_syslog; default_stderr; };          category packet { default_debug; };          category eventlib { default_debug; }; };

This puts channels and categories in context. "Packet" and "eventlib" messages are sent to default_debug. "Panic" messages to default_syslog and default_stderr, while the "default" category is sent to default_syslog and default_debug. The "default" category is made up of all the categories that are not assigned to one or more channels explicitly. So, any category not listed in your logging directive will end up in "default."

The shown channels are defined no matter what, and cannot be redefined. The shown categories on the other hand will only be defined if you don't define anything for those categories, and they are meant to be overridden, if needed.

Controlling Debug Logging

The debug channel, shown earlier, and the my_log channel, which was declared like this earlier in this chapter both use "dynamic" severity setting.

 channel my_log {                 file "/var/log/named.db";                 severity dynamic;                 print-category yes;                 print-severity yes;          };

This allows you to control the level of output sent to the channel dynamically with the "ndc trace" and "ndc notrace" commands. This is very handy because there is no need to restart the server to adjust the log level. The downside is of course that all active channels are affected by the global debug level, which "ndc trace" adjusts. It might be a bit much to look through when looking for a problem. Too much information is overwhelming, and too little is of no use. The following declaration has the same effect as the combined "dynamic" severity and "ndc trace 3" command used earlier in this chapter, because it simply sets the debug level for the channel to 3, statically:

 channel my_log {                 file "/var/log/named.db";                 severity debug 3;                 print-time yes;          };

Of course, it will spew debug messages as long as BIND runs, too. And a lot at that, even a quite unloaded DNS server risks filling its disk quite quickly this way. But, by replacing and/or customizing BINDs default logging configuration you can get pretty much any result you want.