Reading BIND Debugging Output
Contents:
Debugging LevelsTurning On Debugging
Reading Debugging Output
The Resolver Search Algorithm and Negative Caching (BIND 8)
The Resolver Search Algorithm and Negative Caching (BIND 9)
Tools
"O Tiger-lily!" said Alice, addressing herself to one that was waving gracefully about in the wind, "I wish you could talk!"
"We can talk," said the Tiger-lily, "when there's anybody worth talking to."
One of the tools in your troubleshooting toolchest is the name server's debugging output. As long as your name server has been compiled with DEBUG defined, you can get query-by-query reports of its internal operation. The messages you get are often quite cryptic; they were meant for someone who has the source code to follow. We'll explain some of the debugging output in this chapter. Our goal is to cover just enough for you to follow what the name server is doing; we aren't trying to supply an exhaustive compilation of debugging messages.
As you read through the explanations here, think back to material covered in earlier chapters. Seeing this information again, in another context, should help you understand more fully how a name server works.
Debugging Levels
The amount of information the name server provides depends on the debugging level. The lower the debugging level, the less information you get. Higher debugging levels give you more information, but they also fill up your disk faster. After you've read a lot of debugging output, you'll develop a feel for how much information you'll need to solve any particular problem. Of course, if you can easily recreate the problem, you can start at level 1 and increase the debugging level until you have enough information. For the most basic problem -- why a name can't be looked up -- level 1 will often suffice, so you should start there.What Information Is at Each Level?
Here's a list of the information that each debugging level produces for BIND 8 and BIND 9 name servers. The debugging information is cumulative; for example, level 2 includes all of level 1's debugging information. The data is divided into the following basic areas: starting up, updating the database, processing queries, and maintaining zones. We won't cover updating the name server's internal database -- problems almost always occur elsewhere. However, what the name server adds or deletes from its internal database can be a problem, as you'll see in "Troubleshooting DNS and BIND".BIND 8 and 9 have a whopping 99 debug levels, but most of the debugging messages are logged at just a few of those levels. We'll look at those now.
BIND 8 debugging levels
- Level 1
- The information at this level is necessarily brief. Name servers can process lots of queries, which can create lots of debugging output. Since the output is condensed, you can collect data over long periods. Use this debugging level for basic startup information and for watching query transactions. You'll see some errors logged at this level, including syntax errors and DNS packet formatting errors. This level also shows referrals.
- Level 2
- Level 2 provides lots of useful stuff: it lists the IP addresses of remote name servers used during a lookup, along with their roundtrip time values; it calls out bad responses; and it tags a response as to which type of query it is answering, a SYSTEM (sysquery) or a USER query. When you are tracking down a problem with a slave server loading a zone, this level shows you the zone values -- serial number, refresh time, retry time, expire time, and time left -- as the slave checks if it is up to date with its master.
- Level 3
- Level 3 debugging becomes much more verbose, because it generates lots of messages about updating the name server database. Make sure you have enough disk space if you are going to collect debugging output at level 3 or above. At level 3, you also see duplicate queries called out, system queries generated (sysquery), the names of the remote name servers used during a lookup, and the number of addresses found for each server.
- Level 4
- Use level 4 debugging when you want to see the query and response packets received by the name server. This level also shows the credibility level for cached data.
- Level 5
- There are a variety of messages at level 5, but none of them is particularly useful for general debugging. This level includes some error messages, for example when a malloc( ) fails or when the name server gives up on a query.
- Level 6
- Level 6 shows you the response sent to the original query.
- Level 7
- Level 7 shows you a few configuration and parsing messages.
- Level 8
- There is no significant debugging information at this level.
- Level 9
- There is no significant debugging information at this level.
- Level 10
- Use level 10 debugging when you want to see the query and response packets sent by the name server. The format of these packets is the same format used in level 4. You won't use this level very often since you can see the name server response packet with nslookup or dig.
- Level 11
- There are only a couple of debugging messages at and above this level, and they are in seldom-traversed code.
BIND 9 debugging levels
- Level 1
- Level 1 shows you basic name server operation: zone loading, maintenance (including SOA queries, zone transfers and zone expiration, and cache cleaning), NOTIFY messages, queries received, and high-level tasks dispatched (such as looking up addresses for a name server).
- Level 2
- Level 2 logs multicast requests.
- Level 3
- Level 3 shows you low-level task creation and operation. Unfortunately, most of these tasks don't have particularly descriptive names (requestmgr_detach ?) and the arguments they report are awfully cryptic. Level 3 also shows you journal activity, such as when the name server writes a record of a zone change to the zone's journal or when the name server applies a journal to a zone at startup. Operation of the DNSSEC validator and checking of TSIG signatures also come in at debug level 3.
- Level 4
- Level 4 logs when a master name server falls back to using AXFR because the transferred zone's journal isn't available.
- Level 5
- Level 5 logs which view was used while satisfying a particular request.
- Level 6
- A handful of outbound zone transfer messages are logged at level 6, including checks of the query that initiated the transfer.
- Level 7
- There are only a couple of new debugging messages at this level (logging of journal adds and deletes, and a count of how many bytes were returned by a zone transfer).
- Level 8
- Many dynamic update messages are logged at level 8: prerequisite checks, writing journal entries, and rollbacks. Several low-level zone transfer messages also appear here, including a log of resource records sent in a zone transfer.
- Level 10
- Level 10 reports a couple of messages about zone timer activity.
- Level 20
- Level 20 reports an update to a zone's refresh timer.
- Level 90
- Low-level operation of the BIND 9 task dispatcher is logged at level 90.
Keep in mind that this is debugging information -- it was used by the authors of BIND to debug the code, so it is not as readable as you might like. You can use it to figure out why the name server isn't doing what you think it should be or just to learn how the name server operates -- but don't expect nicely designed, carefully formatted output.