Radicale/contrib/logwatch/radicale

# This file is related to Radicale - CalDAV and CardDAV server
#  for logwatch (script)
# Copyright © 2024-2025 Peter Bieringer <pb@bieringer.de>
#
# Detail levels
# >= 5: Logins
# >= 10: ResponseTimes

$Detail = $ENV{'LOGWATCH_DETAIL_LEVEL'} || 0;

my %ResponseTimes;
my %ResponseSizes;
my %Responses;
my %Requests;
my %Logins;
my %Loglevel;
my %OtherEvents;

my $sum;
my $length;

sub ResponseTimesMinMaxSum($$) {
   my $req = $_[0];
   my $time = $_[1];

   $ResponseTimes{$req}->{'cnt'}++;

   if (! defined $ResponseTimes{$req}->{'min'}) {
      $ResponseTimes{$req}->{'min'} = $time;
   } elsif ($ResponseTimes{$req}->{'min'} > $time) {
      $ResponseTimes{$req}->{'min'} = $time;
   }

   if (! defined $ResponseTimes{$req}->{'max'}) {
      $ResponseTimes{$req}{'max'} = $time;
   } elsif ($ResponseTimes{$req}->{'max'} < $time) {
      $ResponseTimes{$req}{'max'} = $time;
   }

   $ResponseTimes{$req}->{'sum'} += $time;
}

sub ResponseSizesMinMaxSum($$$) {
   my $req = $_[0];
   my $type = $_[1];
   my $size = $_[2];

   $ResponseSizes{$type}->{$req}->{'cnt'}++;

   if (! defined $ResponseSizes{$type}->{$req}->{'min'}) {
      $ResponseSizes{$type}->{$req}->{'min'} = $size;
   } elsif ($ResponseSizes{$type}->{$req}->{'min'} > $size) {
      $ResponseSizes{$type}->{$req}->{'min'} = $size;
   }

   if (! defined $ResponseSizes{$type}->{$req}->{'max'}) {
      $ResponseSizes{$type}->{$req}{'max'} = $size;
   } elsif ($ResponseSizes{$type}->{$req}->{'max'} < $size) {
      $ResponseSizes{$type}->{$req}{'max'} = $size;
   }

   $ResponseSizes{$type}->{$req}->{'sum'} += $size;
}

sub Sum($) {
   my $phash = $_[0];
   my $sum = 0;
   foreach my $entry (keys %$phash) {
      $sum += $phash->{$entry};
   }
   return $sum;
}

sub MaxLength($) {
   my $phash = $_[0];
   my $length = 0;
   foreach my $entry (keys %$phash) {
      $length = length($entry) if (length($entry) > $length);
   }
   return $length;
}

sub ConvertTokens($) {
   my %tokens_h;
   # unique
   foreach my $token (split(" ", $_[0])) {
      $tokens_h{$token} = 1;
   }
   # map tokens
   my @result_a;
   if (defined $tokens_h{"sync-token"}) {
      push @result_a, "ST";
   }
   if (defined $tokens_h{"sync-collection"}) {
      push @result_a, "SC";
   }
   if (defined $tokens_h{"getctag"}) {
      push @result_a, "GCT";
   }
   if (defined $tokens_h{"getetag"}) {
      push @result_a, "GET";
   }
   # TODO: add potential others which causing long duration
   $result = "";
   if (scalar(@result_a) > 0) {
      $result = ":F=" . join(",", @result_a);
   }
   return $result;
}

while (defined($ThisLine = <STDIN>)) {
   # count loglevel
   if ( $ThisLine =~ /\[(DEBUG|INFO|WARNING|ERROR|CRITICAL)\] /o ) {
      $Loglevel{$1}++
   }       
  
   # parse log for events
   if ( $ThisLine =~ /Radicale server ready/o ) {
      $OtherEvents{"Radicale server started"}++;
   }
   elsif ( $ThisLine =~ /Stopping Radicale/o ) {
      $OtherEvents{"Radicale server stopped"}++;
   }
   elsif ( $ThisLine =~ / (\S+) response status/o ) {
      my $req = $1;
      if ( $ThisLine =~ / \S+ response status for .* with depth '(\d)' in ([0-9.]+) seconds: (\d+)/o ) {
         $req .= ":D=" . $1 . ":R=" . $3;
         ResponseTimesMinMaxSum($req, $2) if ($Detail >= 10);
      } elsif ( $ThisLine =~ / \S+ response status for .* in ([0-9.]+) seconds: (\d+)/o ) {
         $req .= ":R=" . $2;
         ResponseTimesMinMaxSum($req, $1) if ($Detail >= 10);
      } elsif ( $ThisLine =~ / \S+ response status for .* with depth '(\d)' in ([0-9.]+) seconds (\S+) (\d+) bytes: (\d+)/o ) {
         $req .= ":D=" . $1 . ":R=" . $5;
         ResponseTimesMinMaxSum($req, $2) if ($Detail >= 10);
         ResponseSizesMinMaxSum($req, $3, $4) if ($Detail >= 10);
      } elsif ( $ThisLine =~ / \S+ response status for .* in ([0-9.]+) seconds (\S+) (\d+) bytes: (\d+)/o ) {
         $req .= ":R=" . $4;
         ResponseTimesMinMaxSum($req, $1) if ($Detail >= 10);
         ResponseSizesMinMaxSum($req, $2, $3) if ($Detail >= 10);
      } elsif ( $ThisLine =~ / \S+ response status for .* with depth '(\d)' in ([0-9.]+) seconds (\S+) (\d+) bytes \((.*)\): (\d+)/o ) {
         $req .= ":D=" . $1 . ":R=" . $6;
         $reqWithFlags = $req . ConvertTokens($5);
         ResponseTimesMinMaxSum($reqWithFlags, $2) if ($Detail >= 10);
         ResponseSizesMinMaxSum($req, $3, $4) if ($Detail >= 10);
      } elsif ( $ThisLine =~ / \S+ response status for .* in ([0-9.]+) seconds (\S+) (\d+) bytes \((.*)\): (\d+)/o ) {
         $req .= ":R=" . $5;
         $reqWithFlags = $req . ConvertTokens($4);
         ResponseTimesMinMaxSum($reqWithFlags, $1) if ($Detail >= 10);
         ResponseSizesMinMaxSum($req, $2, $3) if ($Detail >= 10);
      }
      $Responses{$req}++;
   }
   elsif ( $ThisLine =~ / (\S+) request for/o ) {
      my $req = $1;
      if ( $ThisLine =~ / \S+ request for .* with depth '(\d)' received/o ) {
         $req .= ":D=" . $1;
      }
      $Requests{$req}++;
   }
   elsif ( $ThisLine =~ / (Successful login): '([^']+)'/o ) {
      $Logins{$2}++ if ($Detail >= 5);
      $OtherEvents{$1}++;
   }
   elsif ( $ThisLine =~ / (Failed login attempt) /o ) {
      $OtherEvents{$1}++;
   }
   elsif ( $ThisLine =~ / (Profiling data per request method \S+) /o ) {
      my $info = $1;
      if ( $ThisLine =~ /(no request seen so far)/o ) {
         $OtherEvents{$info . " - " . $1}++;
      } else {
         $OtherEvents{$info}++;
      };
   }
   elsif ( $ThisLine =~ / (Profiling data per request \S+) /o ) {
      my $info = $1;
      if ( $ThisLine =~ /(suppressed because duration below minimum|suppressed because of no data)/o ) {
         $OtherEvents{$info . " - " . $1}++;
      } else {
         $OtherEvents{$info}++;
      };
   }
   elsif ( $ThisLine =~ /\[(DEBUG|INFO)\] /o ) {
      # skip if DEBUG+INFO
   }
   else {
      # Report any unmatched entries...
      if ($ThisLine =~ /^({\'| )/o) {
         # skip profiling or raw header data
         next;
      };
      if ($ThisLine =~ /^$/o) {
         # skip empty line
         next;
      };
      $ThisLine =~ s/^\[\d+(\/Thread-\d+)?\] //; # remove process/Thread ID
      chomp($ThisLine);
      $OtherList{$ThisLine}++;
   }
}

if ($Started) {
   print "\nStatistics:\n";
   print "   Radicale started: $Started Time(s)\n";
}

if (keys %Loglevel) {
   $sum = Sum(\%Loglevel);
   print "\n**Loglevel counters**\n";
   printf "%-18s | %7s | %5s |\n", "Loglevel", "cnt", "ratio";
   print "-" x38 . "\n";
   foreach my $level (sort keys %Loglevel) {
      printf "%-18s | %7d |  %3d%% |\n", $level, $Loglevel{$level}, int(($Loglevel{$level} * 100) / $sum);
   }
   print "-" x38 . "\n";
   printf "%-18s | %7d |  %3d%% |\n", "", $sum, 100;
}

if (keys %Requests) {
   $sum = Sum(\%Requests);
   print "\n**Request counters (D=<depth>)**\n";
   printf "%-18s | %7s | %5s |\n", "Request", "cnt", "ratio";
   print "-" x38 . "\n";
   foreach my $req (sort keys %Requests) {
      printf "%-18s | %7d |  %3d%% |\n", $req, $Requests{$req}, int(($Requests{$req} * 100) / $sum);
   }
   print "-" x38 . "\n";
   printf "%-18s | %7d |  %3d%% |\n", "", $sum, 100;
}

if (keys %Responses) {
   $sum = Sum(\%Responses);
   $length = MaxLength(\%Responses);
   print "\n**Response result counters ((D=<depth> R=<result>)**\n";
   printf "%-" . $length . "s | %7s | %5s |\n", "Response", "cnt", "ratio";
   print "-" x($length + 20) . "\n";
   foreach my $req (sort keys %Responses) {
      printf "%-" . $length . "s | %7d |  %3d%% |\n", $req, $Responses{$req}, int(($Responses{$req} * 100) / $sum);
   }
   print "-" x($length + 20) . "\n";
   printf "%-" . $length . "s | %7d |  %3d%% |\n", "", $sum, 100;
}

if (keys %Logins) {
   $sum = Sum(\%Logins);
   $length = MaxLength(\%Logins);
   print "\n**Successful login counters**\n";
   printf "%-" . $length . "s | %7s | %5s |\n", "Login", "cnt", "ratio";
   print "-" x($length + 20) . "\n";
   foreach my $login (sort keys %Logins) {
      printf "%-" . $length . "s | %7d |  %3d%% |\n", $login, $Logins{$login}, int(($Logins{$login} * 100) / $sum);
   }
   print "-" x($length + 20) . "\n";
   printf "%-" . $length . "s | %7d |  %3d%% |\n", "", $sum, 100;
}

if (keys %ResponseTimes) {
   $length = MaxLength(\%ResponseTimes);
   print "\n**Response timings (counts, seconds) (D=<depth> R=<result> F=<flags>)**\n";
   print "*  Flags: ST:sync-token SC:sync-collection GCT:getctag GET:getetag\n";
   printf "%-" . $length . "s | %7s | %7s | %7s | %7s |\n", "Response", "cnt", "min", "max", "avg";
   print "-" x($length + 42) . "\n";
   foreach my $req (sort keys %ResponseTimes) {
      printf "%-" . $length . "s | %7d | %7.3f | %7.3f | %7.3f |\n", $req
         , $ResponseTimes{$req}->{'cnt'}
         , $ResponseTimes{$req}->{'min'}
         , $ResponseTimes{$req}->{'max'}
         , $ResponseTimes{$req}->{'sum'} / $ResponseTimes{$req}->{'cnt'};
   }
   print "-" x($length + 42) . "\n";
}

if (keys %ResponseSizes) {
   for my $type (sort keys %ResponseSizes) {
      $length = MaxLength($ResponseSizes{$type});
      print "\n**Response sizes (counts, bytes: $type) (D=<depth> R=<result>)**\n";
      printf "%-" . $length . "s | %7s | %9s | %9s | %9s |\n", "Response", "cnt", "min", "max", "avg";
      print "-" x($length + 48) . "\n";
      foreach my $req (sort keys %{$ResponseSizes{$type}}) {
         printf "%-" . $length . "s | %7d | %9d | %9d | %9d |\n", $req
            , $ResponseSizes{$type}->{$req}->{'cnt'}
            , $ResponseSizes{$type}->{$req}->{'min'}
            , $ResponseSizes{$type}->{$req}->{'max'}
            , $ResponseSizes{$type}->{$req}->{'sum'} / $ResponseSizes{$type}->{$req}->{'cnt'};
      }
      print "-" x($length + 48) . "\n";
   }
}

if (keys %OtherEvents) {
   print "\n**Other Events**\n";
   foreach $ThisOne (sort keys %OtherEvents) {
      print "$ThisOne: $OtherEvents{$ThisOne} Time(s)\n";
   }
}

if (keys %OtherList) {
   print "\n**Unmatched Entries**\n";
   foreach $ThisOne (sort keys %OtherList) {
      print "$ThisOne: $OtherList{$ThisOne} Time(s)\n";
   }
}

exit(0);

# vim: shiftwidth=3 tabstop=3 syntax=perl et smartindent