Logging in BIND 8 and 9 (DNS and BIND, 4th Edition)

7.5. Logging in BIND 8 and 9

BIND 4 had an extensive logging system, writing information to a debug file and sending information to syslog. But BIND 4 gave you limited control over this logging process -- you could turn debugging up to a certain level, but that was it. BIND 8 and 9 have the same logging system as BIND 4, but both of the new BINDs give you control you didn't have with BIND 4.

This control has its costs though -- there's a lot to learn before you can effectively configure this subsystem. If you don't have some time you can spend to experiment with logging, use the defaults and come back to this topic later. Most of you won't need to change the default logging behavior.

There are two main concepts in logging: channels and categories. A channel specifies where logged data goes: to syslog, to a file, to named 's standard error output, or to the bit bucket. A category specifies what data is logged. In the BIND source code, most messages that the name server logs are categorized according to the function of the code they relate to. For example, a message produced by the part of BIND that handles dynamic updates is probably in the update category. We'll give you a list of the categories shortly.

Each category of data can be sent to a single channel or to multiple channels. In Figure 7-1, queries are logged to a file while statistics data is both logged to a file and to syslog.

Figure 7-1. Logging categories to channels

Channels allow you to filter by message severity. Here's the list of severities, from most severe to least:

critical
error
warning
notice
info
debug [level]
dynamic

The top five severities (critical, error, warning, notice, and info) are the familiar severity levels used by syslog. The other two (debug and dynamic) are unique to BIND 8 and 9.

debug is name server debugging for which you can specify a debug level. If you omit the debug level, then the level is assumed to be 1. If you specify a debug level, you will see messages of that level when name server debugging is turned on (e.g., if you specify "debug 3", then you will see level 3 debugging messages even when you send only one trace command to the name server). If you specify dynamic severity, then the name server will log messages that match its debug level (e.g., if you send one trace command to the name server, it will log messages from level 1. If you send three trace commands to the name server, it will log messages from levels 1 through 3.) The default severity is info, which means that you won't see debug messages unless you specify the severity.

TIP: You can configure a channel to log both debug messages and syslog messages to a file. However, the converse is not true: you cannot configure a channel to log both debug messages and syslog messages with syslog -- debug messages can't be sent to syslog.

Let's configure a couple of channels to show you how this works. The first channel will go to syslog and log with facility daemon, sending those messages of severity info and above. The second channel will go to a file, logging debug messages at any level as well as syslog messages. Here is the logging statement for the BIND 8 or 9 configuration file:

logging {
  channel my_syslog {
     syslog daemon;
     // Debug messages will not be sent to syslog, so
     // there is no point to setting the severity to
     // debug or dynamic; use the lowest syslog level: info.
     severity info;
  };
  channel my_file {
     file "log.msgs";
     // Set the severity to dynamic to see all the debug messages.
     severity dynamic;
  };
};

Now that we've configured a couple of channels, we have to tell the name server exactly what to send to those channels. Let's implement what was pictured in Figure 7-1, with statistics going to syslog and to the file, and queries going to the file. The category specification is part of the logging statement, so we'll build on the previous logging statement:

logging {
  channel my_syslog {
     syslog daemon;
     severity info;
  };
  channel my_file {
     file "log.msgs";
     severity dynamic;
  };

  category statistics { my_syslog; my_file; };
  category queries { my_file; };
};

With this logging statement in your configuration file, start your name server and send it a few queries. But nothing is written to log.msgs ! (Well, if you wait long enough, the name server's statistics will show up in log.msgs.) You expected queries to be logged. Alas, you have to turn on name server debugging to get queries logged:

# ndc trace

Now if you send your name server some queries they're logged to log.msgs. But look around the name server's working directory -- there's a new file called named.run. It has all the other debugging information written to it. You didn't want all this other debugging, though; you just wanted the statistics and queries. How do you get rid of named.run?

There's a special category we haven't told you about: default. If you don't specify any channels for a category, BIND sends those messages to whichever channel the default category is assigned to. Let's change the default category to discard all logging messages (there's a channel called null for this purpose):

logging {
  channel my_syslog {
     syslog daemon;
     severity info;
  };
  channel my_file {
     file "log.msgs";
     severity dynamic;
  };

  category default { null; };
  category statistics { my_syslog; my_file; };
  category queries { my_file; };
};

Now, start your server, turn on debugging to level 1, and send some queries. The queries end up in log.msgs, and named.run is created but stays empty. Great! We're getting the hang of this after all.

A few days pass. One of your coworkers notices that the name server is sending many fewer messages to syslog than it used to. In fact, the only syslog messages are statistics messages. The ones your coworker watched, the zone transfer messages, are gone. What happened?

Well, the default category is set up, by default, to send messages to both syslog and to the debug file (named.run). When you assigned the default category to the null channel, you turned off the other syslog messages, too. Here's what we should have used:

category default { my_syslog; };

This sends the syslog messages to syslog, but does not write debug or syslog messages to a file.

Remember, we said you'd have to experiment for a while with logging to get exactly what you want. We hope this example gives you a hint of what you might run into. Now, let's go over the details of logging.

7.5.1. The Logging Statement

Here's the syntax of the logging statement. It's rather intimidating. We'll go over some more examples as we explain what each substatement means:

logging {
  [ channel channel_name {
    ( 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 )
     | stderr
     | null );

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

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

Here are the default channels. The name server creates these channels even if you don't want them. You can't redefine these channels; you can only add more of them:

channel default_syslog {
    syslog daemon;        // send to syslog's daemon facility
    severity info;        // only send severity info and higher
};

channel default_debug {
    file "named.run";     // write to named.run in the
                          // working directory
    severity dynamic;     // log at the server's current debug level
};

channel default_stderr {  // writes to stderr
    stderr;               // only BIND 9 lets you define your own stderr
                          // channel, though BIND 8 has the built-in
                          // default_stderr channel.
    severity info;        // only send severity info and higher
};													

channel null {
    null;                 // toss anything sent to this channel
};

If you don't assign channels to the categories default, panic, packet, and eventlib, a BIND 8 name server assigns them these channels by default:

logging {
    category default { default_syslog; default_debug; };
    category panic { default_syslog; default_stderr; };
    category packet { default_debug; };
    category eventlib { default_debug; };
};

A BIND 9 name server uses this as the default logging statement:

logging {
	category default {
		default_syslog;
		default_debug;
	};
};

As we mentioned earlier, the default category logs to both syslog and to the debug file (which by default is named.run). This means that all syslog messages of severity info and above are sent to syslog, and when debugging is turned on, the syslog messages and debug messages are written to named.run. This more or less matches the BIND 4 behavior.

7.5.2. Channel Details

A channel may be defined to go to a file, to syslog, or to null.

7.5.2.1. File channels

If a channel goes to a file, you must specify the file's pathname. Optionally, you can specify how many versions of the file can exist at one time and how big the file may grow.

If you specify that there can be three versions, BIND 8 or 9 will keep file, file.0, file.1, and file.2 around. After the name server starts or after it is reloaded, it will move file.1 to file.2, file.0 to file.1, file to file.0, and start writing to a new copy of file. If you specify unlimited versions, BIND will keep 99 versions.

If you specify a maximum file size, the name server will stop writing to the file after it reaches the specified size. Unlike the versions substatement (mentioned in the last paragraph), the file will not be rolled over and a new file opened when the specified size is reached. The name server just stops writing to the file. If you do not specify a file size, the file will grow indefinitely.

Here is an example file channel using the versions and size substatements:

logging{
  channel my_file {
     file "log.msgs" versions 3 size 10k;
     severity dynamic;
  };
};

The size can include a scaling factor as in the example. K or k is kilobytes. M or m is megabytes. G or g is gigabytes.

It's important to specify the severity as either debug or dynamic if you want to see debug messages. The default severity is info, which will show you only syslog messages.

7.5.2.2. Syslog channels

If a channel goes to syslog, you can specify the facility to be any of the following: kern, user, mail, daemon, auth, syslog, lpr, news, uucp, cron, authpriv, ftp, local0, local1, local2, local3, local4, local5, local6, or local7. The default is daemon, and we recommend that you use that.

Here's an example syslog channel using the facility local0 instead of daemon:

logging {
    channel my_syslog {
        syslog local0;        // send to syslog's local0 facility
        severity info;        // only send severity info and higher
    };
};

Here's an example debug message that has all the extra goodies:

01-Feb-1998 13:19:18.889 config: debug 1: source = db.127.0.0

The category for this message is config, and the severity is debug level one.

Here's an example channel configuration that includes all three additions:

logging {
  channel my_file {
     file "log.msgs";
     severity debug;
     print-category yes;
     print-severity yes;
     print-time yes;
  };
};

There isn't much point in adding a timestamp for messages to a syslog channel because syslog adds the time and date itself.

7.5.3. Category Details

Both BIND 8 and BIND 9 have lots of categories -- lots! Unfortunately, they're different categories. We'll list them here so you can see them all. Rather than trying to figure out which you want to see, we recommend that you configure your name server to print out all of its log messages with their category and severity, and then pick out the ones you want to see. We'll show you how to do this after describing the categories.

7.5.3.1. BIND 8 categories

default

cname

config

db

eventlib

insist

lame-servers

load

maintenance

ncache

notify

os

packet

panic

parser

queries

response-checks

security

statistics

update

xfer-in

xfer-out

7.5.3.2. BIND 9 categories

default

general: The general category contains all of the BIND messages that aren't explicitly classified.

client: Processing client requests.

config: Configuration file parsing and processing.

database: Messages relating to BIND's internal database; used to store zone data and cache records.

dnssec: Processing DNSSEC-signed responses.

lame-servers: Detection of bad delegation (re-added in BIND 9.1.0; before that, lame server messages were logged to resolver).

network: Network operations.

notify: Asynchronous zone change notifications.

queries: Analogous to BIND 8's query logging (added in BIND 9.1.0).

resolver: Name resolution, including the processing of recursive queries from resolvers.

security: Approved/unapproved requests.

update: Dynamic update events.

xfer-in

xfer-out: Zone transfers from the local name server to remote name servers.

7.5.3.3. Viewing all category messages

A good way to start your foray into logging is to configure your name server to log all its messages to a file, including the category and severity, and then pick out which messages you are interested in.

Earlier, we listed the categories that are configured by default. For BIND 8, that's:

logging {
    category default { default_syslog; default_debug; };
    category panic { default_syslog; default_stderr; };
    category packet { default_debug; };
    category eventlib { default_debug; };
};

For BIND 9, it's:

logging {
    category default { default_syslog; default_debug; };
};

By default, the category and severity are not included with messages written to the default_debug channel. In order to see all the log messages, with their category and severity, you'll have to configure each of these categories yourself.

Here's a BIND 8 logging statement that does just that:

logging {
  channel my_file {
     file "log.msgs";
     severity dynamic;
     print-category yes;
     print-severity yes;
  };

  category default  { default_syslog; my_file; };
  category panic    { default_syslog; my_file; };
  category packet   { my_file; };
  category eventlib { my_file; };
  category queries  { my_file; };
};

(A BIND 9 logging statement wouldn't have panic, packet, or eventlib categories.)

Notice that we've defined each category to include the channel my_file. We also added one category that wasn't in the previous default logging statement: queries. Queries aren't printed unless you configure the queries category.

Start your server and turn on debugging to level one. You'll then see messages in log.msgs that look like the following:

queries: info: XX /192.253.253.4/foo.movie.edu/A
default: debug 1: req: nlookup(foo.movie.edu) id 4 type=1 class=1
default: debug 1: req: found 'foo.movie.edu' as 'foo.movie.edu' (cname=0)
default: debug 1: ns_req: answer -> [192.253.253.4].2338 fd=20 id=4 size=87

Once you've determined the messages that interest you, configure your server to log only those messages.