contrib/unbound/contrib/parseunbound.pl

   1 #!/usr/local/bin/perl -w
   2 #
   3 # Script to parse the output from the unbound namedaemon.
   4 # Unbound supports a threading model, and outputs a multiline log-blob for
   5 # every thread.
   6 #
   7 # This script should parse all threads of the once, and store it
   8 # in a local cached file for speedy results when queried lots.
   9 #
  10 use strict;
  11 use POSIX qw(SEEK_END);
  12 use Storable;
  13 use FileHandle;
  14 use Carp qw(croak carp);
  15 use constant UNBOUND_CACHE => "/var/tmp/unbound-cache.stor";
  16
  17 my $run_from_cron = @ARGV && $ARGV[0] eq "--cron" && shift;
  18 my $DEBUG = -t STDERR;
  19
  20 # NB. VERY IMPORTANTES: set this when running this script.
  21 my $numthreads = 4;
  22
  23 ### if cache exists, read it in. and is newer than 3 minutes
  24 if ( -r UNBOUND_CACHE ) {
  25     my $result = retrieve(UNBOUND_CACHE);
  26     if (-M _ < 3/24/60 && !$run_from_cron ) {
  27         print STDERR "Cached results:\n" if $DEBUG;
  28         print join("\n", @$result), "\n";
  29         exit;
  30     }
  31 }
  32 my $logfile = shift or die "Usage: parseunbound.pl --cron unboundlogfile";
  33 my $in = new FileHandle $logfile or die "Cannot open $logfile: $!\n";
  34
  35 # there is a special key 'thread' that indicates the thread. its not used, but returned anyway.
  36 my @records = ('thread', 'queries', 'cachehits', 'recursions', 'recursionavg',
  37         'outstandingmax', 'outstandingavg', 'outstandingexc',
  38         'median25', 'median50', 'median75',
  39         'us_0', 'us_1', 'us_2', 'us_4', 'us_8', 'us_16', 'us_32',
  40         'us_64', 'us_128', 'us_256', 'us_512', 'us_1024', 'us_2048',
  41         'us_4096', 'us_8192', 'us_16384', 'us_32768', 'us_65536',
  42         'us_131072', 'us_262144', 'us_524288', 's_1', 's_2', 's_4',
  43         's_8', 's_16', 's_32', 's_64', 's_128', 's_256', 's_512');
  44 # Stats hash containing one or more keys. for every thread, 1 key.
  45 my %allstats = (); # key="$threadid", stats={key => value}
  46 my %startstats = (); # when we got a queries entry for this thread
  47 my %donestats = (); # same, but only when we got a histogram entry for it
  48 # stats hash contains name/value pairs of the actual numbers for that thread.
  49 my $offset = 0;
  50 my $inthread=0;
  51 my $inpid;
  52
  53 # We should continue looping untill we meet these conditions:
  54 # a) more total queries than the previous run (which defaults to 0) AND
  55 # b) parsed all $numthreads threads in the log.
  56 my $numqueries = $previousresult ? $previousresult->[1] : 0;
  57
  58 # Main loop
  59 while ( scalar keys %startstats < $numthreads || scalar keys %donestats < $numthreads) {
  60     $offset += 10000;
  61     if ( $offset > -s $logfile or $offset > 10_000_000 ) {
  62         die "Cannot find stats in $logfile\n";
  63     }
  64     $in->seek(-$offset, SEEK_END) or croak "cannot seek $logfile: $!\n";
  65
  66     for my $line ( <$in> ) {
  67         chomp($line);
  68
  69         #[1208777234] unbound[6705:0]
  70         if ($line =~ m/^\[\d+\] unbound\[\d+:(\d+)\]/) {
  71             $inthread = $1;
  72             if ($inthread + 1 > $numthreads) {
  73                 die "Hey. lazy. change \$numthreads in this script to ($inthread)\n";
  74             }
  75         }
  76         # this line doesn't contain a pid:thread. skip.
  77         else {
  78             next;
  79         }
  80
  81         if ( $line =~ m/info: server stats for thread \d+: (\d+) queries, (\d+) answers from cache, (\d+) recursions/ ) {
  82             $startstats{$inthread} = 1;
  83             $allstats{$inthread}->{thread} = $inthread;
  84             $allstats{$inthread}->{queries} = $1;
  85             $allstats{$inthread}->{cachehits} = $2;
  86             $allstats{$inthread}->{recursions} = $3;
  87         }
  88         elsif ( $line =~ m/info: server stats for thread (\d+): requestlist max (\d+) avg ([0-9\.]+) exceeded (\d+)/ ) {
  89             $allstats{$inthread}->{outstandingmax} = $2;
  90             $allstats{$inthread}->{outstandingavg} = int($3); # This is a float; rrdtool only handles ints.
  91             $allstats{$inthread}->{outstandingexc} = $4;
  92         }
  93         elsif ( $line =~ m/info: average recursion processing time ([0-9\.]+) sec/ ) {
  94             $allstats{$inthread}->{recursionavg} = int($1 * 1000); # change sec to millisec.
  95         }
  96         elsif ( $line =~ m/info: histogram of recursion processing times/ ) {
  97             next;
  98         }
  99         elsif ( $line =~ m/info: \[25%\]=([0-9\.]+) median\[50%\]=([0-9\.]+) \[75%\]=([0-9\.]+)/ ) {
 100             $allstats{$inthread}->{median25} = int($1 * 1000000); # change seconds to usec
 101             $allstats{$inthread}->{median50} = int($2 * 1000000);
 102             $allstats{$inthread}->{median75} = int($3 * 1000000);
 103         }
 104         elsif ( $line =~ m/info: lower\(secs\) upper\(secs\) recursions/ ) {
 105             # since after this line we're unsure if we get these numbers
 106             # at all, we should consider this marker as the end of the
 107             # block. Chances that we're parsing a file halfway written
 108             # at this stage are small. Bold statement.
 109             $donestats{$inthread} = 1;
 110             next;
 111         }
 112         elsif ( $line =~ m/info:\s+(\d+)\.(\d+)\s+(\d+)\.(\d+)\s+(\d+)/ ) {
 113             my ($froms, $fromus, $toms, $tous, $counter) = ($1, $2, $3, $4, $5);
 114             my $prefix = '';
 115             if ($froms > 0) {
 116                 $allstats{$inthread}->{'s_' . int($froms)} = $counter;
 117             } else {
 118                 $allstats{$inthread}->{'us_' . int($fromus)} = $counter;
 119             }
 120         }
 121     }
 122 }
 123
 124 my @result;
 125 # loop on the records we want to store
 126 for my $key ( @records ) {
 127     my $sum = 0;
 128     # these are the different threads parsed
 129     foreach my $thread ( 0 .. $numthreads - 1 ) {
 130         $sum += ($allstats{$thread}->{$key} || 0);
 131     }
 132     print STDERR "$key = " . $sum . "\n" if $DEBUG;
 133     push @result, $sum;
 134 }
 135 print join("\n", @result), "\n";
 136 store \@result, UNBOUND_CACHE;
 137
 138 if ($DEBUG) {
 139     print STDERR "Threads: " . (scalar keys %allstats) . "\n";
 140 }