flyinweb's blog

         对于排除DNS故障来说，日志文件是极其重要的工具，DNS日志可以记录服务器CPU占用时间，查询统计信息以及配置中存在的问题。经常分析日志可以了解服务器的负荷，性能安全性，从而及时采取措施纠正错误。BIND在默认情况下，日志是写到/var/log/messages文件中，由于这个文件是系统中的日志信息由syslog生成，所以不全是BIND的日志，要详细分类BIND的日志，需要修改配置文件named.conf,使用logging语句来定制自己 所需要的日志记录，logging语句的语法为：

logging {  
        channel <string>; {  
            file <logfile>;;  
            syslog <optional_facility>;;  
            null;  
            stderr;  
            severity <logseverity>;;  
            print-time <boolean>;;  
            print-severity <boolean>;;  
            print-category <boolean>;;  
       };  
       category <string>; { <string>;; ... };  
}; 

在日志中主要有两个概念：通道（channel）和类别（category）。通道指定了应该向哪里发送日志数据：是发送给syslog，还是写在一个文件里，或是发送给named的标准错误输出，还是发送到位存储桶（bit bucket）。类别则规定了哪些数据需要记录。下面我们主要介绍一下文件通道和类别。

在定义通道的语句中，severity是指定记录消息的级别。在bind中主要有以下几个级别（按照严重性递减的顺序）：

critical
error
warning
notice
info
debug [ level ]
dynamic

定义了某个级别后，系统会记录包括该级别以及比该级别更严重的级别的所有消息。比如定义级别为error，则会记录critical和error两个级别 的信息。一般情况下，我们记录到info级别就可以了。print-time是设定在日志中是否需要写入时间，print-severity是设定在日志 中是否需要写入消息级别，print-category是设定在日志中是否需要写入日志类别。

category语句是指定哪一种类别的数据使用哪个或者哪几个已经定义了的通道。在bind9中类别有：

default
default类别匹配所有未明确指定通道的类别，但是不匹配不属于任何类别的消息。这些不属于任何类别的消息属于下面列出的这些类别。
general
包括所有未明确分类的BIND消息。
client
处理客户端请求。
config
配置文件分析和处理。
database
同BIND内部数据库相关的消息，用来存储区数据和缓存记录。
dnssec
处理DNSSEC签名的响应。
lame-servers
发现错误授权。
network
网络操作
notify
异步区变动通知。
queries
查询日志
resolver
名字解析，包括对来自解析器的递归查询的处理。
security
认可/非认可的请求。
update
动态更新事件。
xfer-in
从远程名字服务器到本地名字服务器的区传送。
xfer-out
从本地名字服务器到远程名字服务器的区传送。

例如要记录queries消息，就可以如下配置（把以下语句添加到named.conf中就可以了）：

logging {  
          channel query_log {  
               file "query.log" versions 3 size 20m;  
               severity info;  
               print-time yes;  
               print-category   yes;  
          };  
          category queries {  
               query_log;  
          };  
}; 

这样服务器会在工作目录（directory语句所指定的目录，通常为：/var/named）下创建query.log这个文件，并把运行过程产生的queries消息写如到query.log文件中，如下：

Nov    28   16:04:55.516   queries: client 192.168.0.113#32770: query: dns.andy.com IN A

另外解释一下“file "query.log" versions 3 size 20m;”语句中“version”和“size”的意义：

version是指定允许同时存在多少个版本的该文件，比如指定3个版本（version 3），bind9会保存query.log、query.log0、query.log1和query.log2。

Size是指定文件大小的上限，如果只设定了size而没有设定version的话，当文件达到指定的文件大小上限时，服务器停止写入该文件。如果设定了 version的话，服务器会进行循环，比如把query.log变成query.log1，query.log1变成query.log2等，然后建立一个新的query.log进行写入。

 

      DNS日志应该根据实际需要多设置几个通道，将日子信息分类记录，在多看多分析的原则下发现各类问题，以便及时解决。例如：

/var/named/dns-default.log文件发现多条警告信息“Nov 02 15:15:34.647 client:warning 10.2.2.36#1036:no more recursive clients:quota reached” 。通过分析得知BIND客户端数量默认是1000，瞬间请求超过这个值就会出现这个警告，所以修改named.conf。添加语句“recursive-clients 10000”，即解决问题。 

        在Linux环境下，提供了广泛流行的BIND服务器，它是构建DNS服务器最常用的服务器软件。介绍BIND的安装的文章现在很多，现在我们就一起来谈一下维护的话题。我们如何才能够了解DNS服务器的运行情况下呢，它忙不忙、负载大不大?这一切，对于系统管理员而言，是比较重要的。

想了解DNS服务器的运行状况，可以通过查看DNS服务器在运行时所产生的日志文件来实现。

BIND 8提供了一些控制日志系统的手段，不过呢，缺省状态所生成的日志已经够用了，通过这些日志信息，足以了解DNS服务器现在的运行状况了。

在缺省情况下，BIND是通过syslog来生成日志的，存放在/var/log/message文件中。注：与之相关的还有以下四个文件：

/var/log/message.1

/var/log/message.2

/var/log/message.3

/var/log/message.4

其实是将日志分为了5个文件来存储，防止文件过大，当message文件够大后，就变成了message.1，原来的message.1就成了message.2……，message.4的内容就消失了。

由于这个文件中的日志信息是syslog生成的，所以不并是全都是关于BIND的日志信息。我们执行以下命令，将所有BIND的日志信息挑选出来：

more /var/log/message|grep named >/tmp/named.log

注：BIND服务器的进程名是named。

这样，/var/log/message中与BIND相关的日志信息都会写入/tmp/named.log文件中了。最主要的日志有两种：LOG_NOTICE，LOG_INFO级的日志。

1.每次启动BIND服务器named时，会生成一个如下所示的LOG_NOTICE级日志信息：

Nov 28 10:37:45 www named[10134]: starting. named 8.2.2-P3

其中:

Nov 28 10:37:45 表示服务器启动时间

www 显示DNS服务器所在机器名

named[10134]： 显示DNS服务器进程名与进程ID

starting. 表示正在启动DNS服务器

named 8.2.2-p3 显示BIND软件版本

2.当给DNS服务器发送一个HUP信号，使DNS服务器重启时，会生成一个如下所示的LOG_NOTICE级日志信息：

Nov 28 10:37:45 www named[10134]: reloading nameserver

其中:

Nov 28 10:37:45 表示服务器重启动时间

www 显示DNS服务器所在机器名

named[10134]： 显示DNS服务器进程名与进程ID

reloading. 表示正在重新启动DNS服务器

nameserver 显示正在重启的服务器名

在DNS服务器运行时，每隔一小时会生成一组如下所示的LOG_INFO级日志信息，反馈DNS服务器的运行状态：

Dec 26 10:23:52 www named[1033]: Cleaned cache of 26 RRset

Dec 26 10:23:52 www named[1033]: USAGE 977797432 976760631 CPU=6.55u/6.24s CHILD CPU=0u/0s

Dec 26 10:23:52 www named[1033]: NSTATS 977797432 976760631 0=2 A=13192

CNAME=321 PTR=11204 MX=1173 TXT=4 AAAA=32 ANY=4956

Dec 26 10:23:52 www named[1033]: XSTATS 977797432 976760631 RR=7629 RNXD=1368

RFwdR=4836 RDupR=51 RFail=159 RFErr=0 RErr=12 RAXFR=0 RLame=175 ROpts=0

SSysQ=2082 SAns=26234 SFwdQ=4520 SDupQ=1263 SErr=0 RQ=30889 RIQ=4 RFwdQ=0

RDupQ=259 RTCP=2 SFwdR=4836 SFail=6 SFErr=0 SNaAns=21753 SNXD=10276

下面我们就逐句解读一下：

1. Dec 26 10:23:52 www named[1033]: Cleaned cache of 26 RRset

这是每一组日志信息的第一行，表示正在清空Cache。

其中：

Dec 26 10:23:52 表示日志生成时间

www 显示DNS服务器所在机器名

named[1033]： 显示DNS服务器进程名与进程ID

Cleaned cache of 26 RRset 表示正在清除cache

2. Dec 26 10:23:52 www named[1033]: USAGE 977797432 976760631 CPU=6.55u

/6.24s CHILD CPU=0u/0s

这一行是USAGE行，用于统计DNS服务器占用的CPU时间。

其中：

Dec 26 10:23:52 表示日志生成时间

www 显示DNS服务器所在机器名

named[1033]： 显示DNS服务器进程名与进程ID

977797432 976760631 977797432-976760631的值就是DNS服务器运行的总秒数

CPU=6.55u/6.24s 代表DNS服务器使用了用户态6.55秒，系统态6.24秒(u代表user，

s代表system)，

CHILD CPU 代表DNS服务器子进程的CPU占用情况。

3. Dec 26 10:23:52 www named[1033]: NSTATS 977797432 976760631 0=2 A=13192

CNAME=321 PTR=11204 MX=1173 TXT=4 AAAA=32 ANY=4956

这一行是NSTATS行，用于统计接收到的查询总数

其中：

Dec 26 10:23:52 表示日志生成时间

www 显示DNS服务器所在机器名

named[1033]： 显示DNS服务器进程名与进程ID

977797432 976760631 977797432-976760631的值就是DNS服务器运行的总秒数

0=2 代表未知类型的DNS查询2个

A=13192 代表A类地址查询13192个(最标准)

CNAME=321 代表CNAME类地址查询321个(一般是有些版本的sendmail使用CNAME程序

规范化邮件地址而发出的，还有就是dig或nslookup发出的)

PTR=11204 代表指针查询11204个(许多软件通过这种方法来查找IP地址)

MX=1173 代表邮件交换器的查询1173个(是由邮件发送程序发起的)

TXT=4 代表应用程序进行的文本查询共有4个

AAAA=32 代表AAAA类查询32个

ANY=4956 有些Sendmail使用的地址查询方式，共4956个

注：还有可能有：

NS=xx 代表名字服务器查询(例如：名字服务器试图查找根域的服务器)

SOA=xx 代表辅助DNS更新

HINFO=xx 主机信息查询

NSAP=xx 将域名映射成OSI网络服务访问点地址

AXFR=xx 辅助DNS的区传送

这些在本例中并未出现。

4. Dec 26 10:23:52 www named[1033]: XSTATS 977797432 976760631 RR=7629 RNXD=1368

RFwdR=4836 RDupR=51 RFail=159 RFErr=0 RErr=12 RAXFR=0 RLame=175 ROpts=0 SSysQ=2082

SAns=26234 SFwdQ=4520 SDupQ=1263 SErr=0 RQ=30889 RIQ=4 RFwdQ=0

RDupQ=259 RTCP=2

SFwdR=4836 SFail=6 SFErr=0 SNaAns=21753 SNXD=10276

这是XSTATS行，它用于统计其它一些数据。

其中：

Dec 26 10:23:52 表示日志生成时间

www 显示DNS服务器所在机器名

named[1033]： 显示DNS服务器进程名与进程ID

977797432 976760631 977797432-976760631的值就是DNS服务器运行的总秒数

RR=7629 代表收到其它主机的响应共有7629个(DNS向其它机器或进程发出的查询得到的响应数、与RQ无关)

RNXD=1368 代表收到“没有这样的域”回答共有1368个

RFwdR=108 收到对原始查询的响应为108个

RDupR=51 重复响应51个(当DNS在它悬而未决的查询列表中，找不到引起该响应的原始查询时，这个响应就是重复响应)

RFail=159 收到SERVFAIL(远程服务器错误)159个

RFErr=0 没有收到FORMERR(远程名字服务器认为本地名字服务器的查询有格式错误)

Rerr=12 收到除了SERVFAIL、FORMERR以外的错误12个

RAXFR=0 共有0次区传送

RLame=175 收到175个坏授权(意味着有的区被授权给其它名字服务器，而这个名字服务器不是这个区的权威)

ROpts=0 共收到带有IP选项的包的个数为0

SSysQ=2082 共发出系统查询2082个(系统查询是由本地名字服务器进行的查询。大多数都是针对根名字服务器的)

SAns=26234 共回答了查询26234个

SFwdQ=4520 不在这个名字服务器，而转发共4520个

SDupQ=1263 重复查询数1263个

SErr=0 发出的非SERVFAIL、FORMERR的错误总数

RQ=30889 收到的查询共有30889个

RIQ=4 收到反向查询4个(反向查询是为了将地址映射为名字，现在这个功能被 PTR实现了。较早的nslookup才使用这种查询)

RFwdQ=0 没有需要进一步处理的查询

RDupQ=259 重复查询共有259个

RTCP=2 通过TCP连接收到2个查询(一般使用UDP)

SFwdR=4836 来自其它名字服务器转发的响应4836个

SFail=6 发出被认为SERVFAIL响应共6个

SFErr=0 发出的被认为FORMERR的响应个数

SNaAns=21753 非权威回答共21753

SNXD=10276 发出没有这个域回答10276个

这些统计数据都是从DNS开启后到现在的总统计，而非本小时内的统计数字。如何衡量DNS服务器的负载呢?很简单，将总查询数除以DNS运行的总时间，不就知道了吗?在本例中：DNS服务器已运行了： 977797432-976760631=1036801秒=288小时

而总查询请求有： 2+13192+321+11204+1173+4+32+4956=20884次

注：从第2行都可以得到,也就是每小时107次查询请求，每秒不到2次，可见负载还是比较小的。