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次，可見負載還是比較小的。