bind v8 trace formatter
panderson at westpac.com.au
panderson at westpac.com.au
Wed May 10 22:33:59 UTC 2000
I've written a trace formatter in perl for bind v8.
It's a bit of a hack but it works OK.
It requires certain logging settings in named.conf and trace
level 3 (mostly to get update requests).
Logging config ...
logging {
channel option_debug {
file "named.run";
severity dynamic;
// print-severity yes;
print-time yes;
};
channel update_debug {
file "update.debug.log";
severity dynamic;
print-time yes;
};
channel update_debug_trc {
file "named.run";
severity dynamic;
print-time yes;
};
channel my_security_channel {
file "security.log";
severity info;
print-time yes;
};
category default { option_debug; default_syslog; };
category notify { update_debug; update_debug_trc; };
category update { update_debug; update_debug_trc; };
category security { my_security_channel; };
-----------------------------------------
#!/bin/perl
#
# changes DNS named.run file into a txt file with FQDNs
# needs debug level 2 or above
# must have logging print-time in named.conf enabled!
# due to no time strings in the trace anymore
# we don't use STDIN anymore - must supply trace filename on command
line
$reqy=0;
$reqn=0;
$reql=0;
$dgrams=0;
$start="";
$end="";
$source="";
$bigrate=0;
$reqthissec=1;
$curtime="";
$printed=1;
$cname=0;
$debug=0;
$update=0;
$numargs=@ARGV;
if ( $numargs < 1 ) {
print "dnsv8trc2rpt.pl: Supply trace filename on command
line!\n";
print "eg dnsv8trc2rpt.pl /local/etc/namedb/named.run\n\n";
exit(1);
}
else {
if ( $ARGV[0] eq "-d" ) {
$debug=1;
$tracefile=$ARGV[1];
}
else {
$tracefile=$ARGV[0];
}
if ( -f $tracefile ) {
# check date/time of file
@fstat=stat($tracefile);
$mtime=$fstat[9];
($ss,$mm,$hh,$mday,$mon,$yy,$wday,$yday,$isdst)=localtime($mtime);
# open file
open (TRACEFILE,"<$tracefile") or die "Cannot open
$tracefile - aborting.\n";
} else {
print "dnsv8trc2rpt.pl: $tracefile doesn't exist!\n\n";
exit(1);
}
}
@dummy = split('=',$x[7]);
$id=$dummy[1];
next;
}
if ( /last was cname/ ) { $cname=1; };
if ( /req: nlookup/ || /resp: nlookup/ ) {
$x[3]=~ s/\(/ /;
$x[3]=~ s/\)/ /;
if ( /req: nlookup/ ) { $id=$x[5]; }
@dummy = split(' ',$x[3]);
if ( $lookups && $printed==0 ) { # must be a
CNAME?
$retcode=0;
$cname=1;
printrec($id);
$cname=0;
}
$requestname = $dummy[1];
$key="${source}.$id";
if ( $stored_qrys{$key} ) { # this could be the
response from a forw
if ( $stored_qrys{$key}[2] eq
$requestname ) {
$forwloc=$source;
$time=$stored_qrys{$key}[0];
$source=$stored_qrys{$key}[1];
}
}
$printed=0;
$lookups++;
next;
next;
}
if ( /\: forw -/ || substr($x[2],0,6) eq "resend") {
# if ( "$x[2]" eq "forw:" ) {
$x[5]=~ s/\[/ /;
$x[5]=~ s/\]/ /;
@dummy = split('=',$x[8]);
$id=$dummy[1];
@dummy = split(' ',$x[5]);
$key="${source}.$id";
if ( $stored_qrys{$key} ) { delete($stored_qrys{$key});
}
$forwloc = $dummy[0];
$key="${forwloc}.$id";
$stored_qrys{$key}=[$time,$source,$requestname];
$printed=1;
$source='';
$forwloc='';
next;
}
# 08-May-2000 11:42:58.633 process_update: record section=UPDATE,
dname=xyz.test.westpac.com.au, class=ANY, type=ANY, ttl=600
# 08-May-2000 12:16:00.028 process_update: record section=PREREQUISITE,
dname=21.60.30.172.in-addr.arpa, class=NONE, type=CNAME,
if ( $_=~ /req_update:/ && /ZONE/) {
$update=1;
$printed=0;
next;
}
if ( $_=~ /update transaction aborted, rolling back/) {
$requestname="update transaction aborted, rolling back";
next;
}
if ( $_=~ /FORMERR/) {
$requestname.="FORMERR Query header counts wrong";
next;
}
if ( $x[2]=~ /process_update/ && ( /UPDATE/ || /PREREQUISITE/ ))
{
if ( /UPDATE/ ) { $update=3; }
if ( /PREREQUISITE/ ) { $update=2; }
$x[5]=~ s/dname=//;
$x[5]=~ s/,//;
$x[7]=~ s/type=//;
$type=$x[7];
$x[8]=~ s/ttl=//;
$ttl=$x[8];
if ( $type=~ /ANY/ && $ttl == 0) { $type="DEL"; }
$requestname=$x[5];
$printed=0;
next;
}
if ( "$x[2]" eq "ncache:" && "$x[3]" eq "dname" ) {
$inv_name=$x[4];
$inv_name=~ s/\,//;
$names{"$inv_name"} = 1;
next;
}
if ( "$x[2]" eq "rrsetupdate:") {
if ( $x[3] eq $requestname ) {
if ( $x[4] ne '' ) { $retcode=$x[4]; }
}
next;
}
if ( $_=~ /resp: got as much answer as there is/ ) { $retcode=0
};
if ( $_=~ /resp: nslookup reports danger/ ) { $retcode=6 };
if ( $_=~ /resp: leaving auth NO/ ) { $retcode=3 };
if ( $_=~ /findns: No root nameservers for class 256?/ )
{$retcode=4 };
if ( /req: leaving/ ) {
chop($x[6]);
$retcode=$x[6];
printrec($id);
$printed=1;
next;
}
if ( /ns_req: answer/ || "$x[2]" eq "send_msg" ) { # print
details
if ( $x[3] eq "answer" ) { $retcode=substr($x[9],3); }
if ( /send_msg/ ) {
@dummy=split('=',$x[7]);
$id=$dummy[1];
}
}
}
# work out time stuff ...
# 13-Apr-2000 11:33:05.910 Debug level 1
$ssecs=(substr($start,0,2)*3600) + (substr($start,3,2)*60) +
(substr($start,6,2));
$esecs=(substr($end,0,2)*3600) + (substr($end,3,2)*60) +
(substr($end,6,2));
$dur=$esecs-$ssecs;
if ( $dur==0 ) { $dur=1; }
if ( $debug ) { print "dur secs: $dur \n"; }
# $reqt=$reqy+$reql+$reqn;
# $reqt=$reqy+$reqn;
$reqpersec=$dgrams / $dur;
$reqpersec=sprintf("%3.2f",$reqpersec);
$reqpersec=~ s/ //g;
$hours=int($dur / 3600);
$dur=$dur-($hours*3600);
if ( $debug ) { print "dur secs: $dur \n"; }
$mins=int($dur / 60);
if ( $debug ) { print "dur secs: $dur \n"; }
$secs=$dur-($mins*60);
if ( $debug ) { print "secs: $secs \n"; }
$ttime=pad($hours,2).":".pad($mins,2).":".pad($secs,2);
print
"\n---------------------------------------------------------------------
\n";
print "Start time: $start ($ssecs) \n";
print "End time: $end ($esecs) \n";
printf("Total valid requests : %s\n",$reqy);
printf("Total invalid requests: %s\n",$reqn);
printf("Total locally resolved: %s\n",$reql);
printf("Total datagrams : %s\n",$dgrams);
print "Time duration $ttime - at $reqpersec datagrams\/sec. \n";
print "Highest request rate : $bigrate \n";
exit;
###################################################
sub pad {
($var,$len)=@_;
$retval=$var;
while ( length($retval) < $len ) {
$retval="0".$retval;
}
return $retval;
}
sub printrec {
my(@aID) = @_;
$id=$aID[0];
if ( $requestname ne "1.0.0.127.in-addr.arpa" ) {
if ( $names{"$requestname"} ) { $retcode=2; }
if ( $update == 2 ) { $requestname=$requestname . "
PREREQ $type $ttl" ; }
if ( $update == 3 ) { $requestname=$requestname . "
UPDATE $type $ttl" ; }
if ( $retcode eq '' ) { $retcode=" "; }
if ( $cname ) {
$out=sprintf("%8s %-16s $retcode %-60s CNAME
%-17s",$time,$source,$requestname,$forwloc);
}
else {
$out=sprintf("%8s %-16s $retcode %-60s
%-17s",$time,$source,$requestname,$forwloc);
}
print "$out\n";
if ( $forwloc eq '' ) { $reql++; }
if ( $retcode == 0 ) { $reqy++; }
else { $reqn++; }
$retcode='';
}
$forwloc='';
$source='';
$requestname='';
$key="${forwloc}.$id";
if ( $stored_qrys{$key} ) { delete($stored_qrys{$key}); }
$printed==1;
}
Sent via Deja.com http://www.deja.com/
Before you buy.
More information about the bind-users
mailing list