分析DNS日志

在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    
USAGE 行标记    
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    
NSTATS 行标记    
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    
NSTATS  行标记     
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 、 3 、 4 行都可以得到     
而总查询请求有：  2+13192+321+11204+1173+4+32+4956=20884 次     
注：从第 2 行都可以得到 , 也就是每小时 107 次查询请求，每秒不到 2 次，可见负载还是比较小的。