ention --statistics option in perldoc.
[privoxy.git] / tools / privoxy-log-parser.pl
index 5009c55..5215267 100755 (executable)
@@ -8,7 +8,7 @@
 #
 # http://www.fabiankeil.de/sourcecode/privoxy-log-parser/
 #
-# $Id: privoxy-log-parser.pl,v 1.130 2008/12/22 18:57:59 fk Exp $
+# $Id: privoxy-log-parser.pl,v 1.53 2009/10/08 11:45:56 fabiankeil Exp $
 #
 # TODO:
 #       - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting
@@ -24,7 +24,7 @@
 #       - Use generic highlighting function that takes a regex and the
 #         hash key as input.
 #
-# Copyright (c) 2007-2008 Fabian Keil <fk@fabiankeil.de>
+# Copyright (c) 2007-2009 Fabian Keil <fk@fabiankeil.de>
 #
 # Permission to use, copy, modify, and distribute this software for any
 # purpose with or without fee is hereby granted, provided that the above
@@ -44,7 +44,7 @@ use warnings;
 use Getopt::Long;
 
 use constant {
-    PRIVOXY_LOG_PARSER_VERSION => '0.4',
+    PRIVOXY_LOG_PARSER_VERSION => '0.5',
     # Feel free to mess with these ...
     DEFAULT_BACKGROUND => 'black',  # Choose registered colour (like 'black')
     DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
@@ -59,7 +59,7 @@ use constant {
     CLI_OPTION_ERROR_LOG_FILE => '/var/log/privoxy-log.log',
     CLI_OPTION_SHOW_INEFFECTIVE_FILTERS => 0,
     CLI_OPTION_ACCEPT_UNKNOWN_MESSAGES => 0,
-    CLI_OPTION_STATISTIC => 0,
+    CLI_OPTION_STATISTICS => 0,
 
     SUPPRESS_SUCCEEDED_FILTER_ADDITIONS => 1,
     SHOW_SCAN_INTRO => 0,
@@ -187,6 +187,8 @@ sub prepare_our_stuff () {
     prepare_colour_array(\@all_colours);
     prepare_colour_array(\@time_colours);
     init_css_colours();
+
+    init_stats();
 }
 
 sub paint_it ($) {
@@ -370,7 +372,7 @@ sub get_missing_css_lines () {
 
     my $css_line;
 
-    $css_line .= '.' . 'default' . ' {'; # XXX: lc() shouldn't be necessary
+    $css_line .= '.' . 'default' . ' {';
     $css_line .= 'color:' . HEADER_DEFAULT_COLOUR . ';';
     $css_line .= 'background-color:' . get_css_colour(DEFAULT_BACKGROUND) . ';';
     $css_line .= '}' . "\n"; 
@@ -799,7 +801,7 @@ sub handle_loglevel_header ($) {
     # scan: Accept: image/png,image/*;q=0.8,*/*;q=0.5
     if ($c =~ m/^scan: ((?>[^:]+)):/) {
         my $header = $1;
-        if (!defined($header_colours{$header})) {
+        if (!defined($header_colours{$header}) and $header =~ /^[\d\w-]*$/) {
             debug_message "Registering previously unknown header $1" if DEBUG_HEADER_REGISTERING;
 
             if (REGISTER_HEADERS_WITH_THE_SAME_COLOUR) {
@@ -912,6 +914,10 @@ sub handle_loglevel_header ($) {
           or $c =~ m/^Converting tab to space in /
           or $c =~ m/A HTTP\/1\.1 response without/
           or $c =~ m/Disabled filter mode on behalf of the client/
+          or $c =~ m/Keeping the (?:server|client) header /
+          or $c =~ m/Content modified with no Content-Length header set/
+          or $c =~ m/^Appended client IP address to/
+          or $c =~ m/^Removing 'Connection: close' to imply keep-alive./
             )
     {
         # XXX: Some of these may need highlighting
@@ -950,6 +956,12 @@ sub handle_loglevel_header ($) {
         #  this again   is  not'
         # A HTTP/1.1 response without Connection header implies keep-alive.
         # Disabled filter mode on behalf of the client.
+        # Keeping the server header 'Connection: keep-alive' around.
+        # Keeping the client header 'Connection: close' around. The connection will not be kept alive.
+        # Keeping the client header 'Connection: keep-alive' around. The connection will be kept alive if possible.
+        # Content modified with no Content-Length header set. Creating a fake one for adjustment later on.
+        # Appended client IP address to X-Forwarded-For: 10.0.0.2, 10.0.0.1
+        # Removing 'Connection: close' to imply keep-alive.
 
     } elsif ($c =~ m/^scanning headers for:/) {
 
@@ -987,6 +999,21 @@ sub handle_loglevel_header ($) {
         # XXX: Could highlight more here.
         $content =~ s@(?<=^Content-Type: )(.*)(?= not replaced)@$h{'content-type'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^(Server|Client) keep-alive timeout is/) {
+
+       # Server keep-alive timeout is 5. Sticking with 10.
+       # Client keep-alive timeout is 20. Sticking with 10.
+
+       $content =~ s@(?<=timeout is )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+       $content =~ s@(?<=Sticking with )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Reducing keep-alive timeout/) {
+
+       # Reducing keep-alive timeout from 60 to 10.
+
+       $content =~ s@(?<= from )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+       $content =~ s@(?<= to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
     } else {
 
         found_unknown_content($content);
@@ -1334,14 +1361,10 @@ sub handle_loglevel_crunch ($) {
     our %h;
     our %reason_colours;
 
-    # Blocked: ads.example.org/
-
     # Highlight crunch reason
     foreach my $reason (keys %reason_colours) {
         $content =~ s@($reason)@$reason_colours{$reason}$1$h{'Standard'}@g;
     }
-    # Highlight request URL
-    $content = highlight_matched_pattern($content, 'request_', '(?<= )[^ \[]*$');
 
     if ($content =~ m/\[too long, truncated\]$/) {
 
@@ -1349,6 +1372,10 @@ sub handle_loglevel_crunch ($) {
         #  [...]&filter... [too long, truncated]
         $content = highlight_matched_pattern($content, 'request_', '^.*(?=\.\.\. \[too long, truncated\]$)');
 
+    } else {
+
+        # Blocked: http://ads.example.org/
+        $content = highlight_matched_pattern($content, 'request_', '(?<=: ).*');
     }
 
     return $content;
@@ -1376,9 +1403,10 @@ sub handle_loglevel_connect ($) {
 
         $c =~ s@(?<=failed: )(.*)@$h{'error'}$1$h{'Standard'}@;
 
-    } elsif ($c =~ m/^to ([^\s]*) successful$/) {
+    } elsif ($c =~ m/^to ([^\s]*)( successful)?$/) {
 
         # Connect: to www.nzherald.co.nz successful
+        # Connect: to archiv.radiotux.de
 
         return '' if SUPPRESS_SUCCESSFUL_CONNECTIONS;
         $c = highlight_matched_host($c, '(?<=to )[^\s]+');
@@ -1449,7 +1477,7 @@ sub handle_loglevel_connect ($) {
         $c = highlight_matched_host($c, '(?<=connection to )[^\s]+');
         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
-    } elsif ($c =~ m/^^Found reusable socket/) {
+    } elsif ($c =~ m/^Found reusable socket/) {
 
         # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
         $c =~ s@(?<=Found reusable socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
@@ -1472,6 +1500,7 @@ sub handle_loglevel_connect ($) {
 
         # Remembering socket 13 for www.privoxy.org:80 in slot 0.
         # Forgetting socket 38 for www.privoxy.org:80 in slot 5.
+
         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
@@ -1483,11 +1512,26 @@ sub handle_loglevel_connect ($) {
 
     } elsif ($c =~ m/^The connection to/) {
 
-        # The connection to www.privoxy.org:80 in slot 6 timed out. Closing socket 19.
+        # The connection to www.privoxy.org:80 in slot 6 timed out. Closing socket 19. Timeout is: 61.
+        # 3.0.15 and later:
+        # The connection to 1.bp.blogspot.com:80 in slot 0 timed out. Closing socket 5.\
+        #  Timeout is: 1. Assumed latency: 4.
         # The connection to 10.0.0.1:80 in slot 0 is no longer usable. Closing socket 4.
         $c = highlight_matched_host($c, '(?<=connection to )[^\s]+');
         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=Closing socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Timeout is: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Assumed latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Stopped waiting for the request line./) {
+
+        # Stopped waiting for the request line. Timeout: 121.
+        $c =~ s@(?<=Timeout: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Waiting for \d/) {
+
+        # Waiting for 1 connections to timeout.
+        $c =~ s@(?<=^Waiting for )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Initialized/) {
 
@@ -1498,9 +1542,14 @@ sub handle_loglevel_connect ($) {
 
         # Done reading from server. Expected content length: 24892. \
         #  Actual content length: 24892. Most recently received: 4412.
-        $c =~ s@(?<=Expected content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
-        $c =~ s@(?<=Actual content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        # 3.0.15 and later:
+        # Done reading from server. Expected content length: 24892. \
+        #  Actual content length: 24892. Bytes most recently read: 4412.
+        # Done reading from server. Content length: 6018 as expected. \
+        #  Bytes most recently read: 294.
+        $c =~ s@(?<=ontent length: )(\d+)@$h{'Number'}$1$h{'Standard'}@g;
         $c =~ s@(?<=received: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Continuing buffering headers/) {
 
@@ -1508,6 +1557,9 @@ sub handle_loglevel_connect ($) {
         $c =~ s@(?<=byte_count: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=header_offset: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=len: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        # 3.0.15 and later:
+        # Continuing buffering headers. Bytes most recently read: %d.
+        $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Received \d+ bytes while/) {
 
@@ -1515,13 +1567,90 @@ sub handle_loglevel_connect ($) {
         $c =~ s@(?<=Received )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=expecting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^Connection from/) {
+
+        # Connection from 81.163.28.218 dropped due to ACL
+        $c =~ s@(?<=^Connection from )((?:\d+\.?){4})@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^(?:Reusing|Closing) server socket \d./ or
+             $c =~ m/^No additional client request/) {
+
+        # Reusing server socket 4. Opened for 10.0.0.1.
+        # Closing server socket 2. Opened for 10.0.0.1.
+        # No additional client request received in time. \
+        #  Closing server socket 4, initially opened for 10.0.0.1.
+
+        $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.$)');
+
+    } elsif ($c =~ m/^Connected to /) {
+
+        # Connected to tor-jail[10.0.0.2]:9050.
+
+        $c = highlight_matched_host($c, '(?<=\[)[^\]]+');
+        $c = highlight_matched_host($c, '(?<=Connected to )[^\[\s]+');
+        $c =~ s@(?<=\]:)(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Could not connect to /) {
+
+        # Could not connect to [10.0.0.1]:80.
+
+        $c = highlight_matched_host($c, '(?<=\[)[^\]]+');
+        $c =~ s@(?<=\]:)(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Waiting for the next client request/ or
+             $c =~ m/^The connection on server socket/ ) {
+
+        # Waiting for the next client request. Keeping the server socket 5 to 10.0.0.1 open.
+        # The connection on server socket 6 to upload.wikimedia.org isn't reusable. Closing.
+
+        $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = highlight_matched_host($c, '(?<=to )[^\s]+');
+
+    } elsif ($c =~ m/^Marking the server socket/) {
+
+        # Marking the server socket 7 tainted.
+
+        $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Reduced expected bytes to /) {
+
+        # Reduced expected bytes to 0 to account for the 1542 ones we already got.
+        $c =~ s@(?<=bytes to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=for the )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^The client closed socket /) {
+
+        # The client closed socket 2 while the server socket 4 is still open.
+        $c =~ s@(?<=closed socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
     } elsif ($c =~ m/^Looks like we rea/ or
-             $c =~ m/^Unsetting keep-alive flag/) {
+             $c =~ m/^Unsetting keep-alive flag/ or
+             $c =~ m/^No connections to wait/ or
+             $c =~ m/^Client request arrived in time or the client closed the connection/ or
+             $c =~ m/^Complete client request received/ or
+             $c =~ m/^Possible pipeline attempt detected./ or
+             $c =~ m/^POST request detected. The connection will not be kept alive./ or
+             $c =~ m/^The server still wants to talk, but the client hung up on us./ or
+             $c =~ m/^The server didn't specify how long the connection will stay open/ or
+             $c =~ m/^There might be a request body. The connection will not be kept alive/ or
+             $c =~ m/^Stopping to watch the client socket. There's already another request waiting./) {
 
         # Looks like we reached the end of the last chunk. We better stop reading.
         # Looks like we read the end of the last chunk together with the server \
         #  headers. We better stop reading.
         # Unsetting keep-alive flag.
+        # No connections to wait for left.
+        # Client request arrived in time or the client closed the connection.
+        # Complete client request received
+        # Possible pipeline attempt detected. The connection will not be \
+        #  kept alive and we will only serve the first request.
+        # POST request detected. The connection will not be kept alive.
+        # The server still wants to talk, but the client hung up on us.
+        # The server didn't specify how long the connection will stay open. Assume it's only a second.
+        # There might be a request body. The connection will not be kept alive.
+        # Stopping to watch the client socket. There's already another request waiting.
 
     } else {
 
@@ -1610,10 +1739,17 @@ sub handle_loglevel_info ($) {
         # Method HEAD implies no body.
         $c =~ s@(?<=Method )([^\s]+)@$h{'method'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^Buffer limit reached while extending /) {
+
+        # Buffer limit reached while extending the buffer (iob). Needed: 4197470. Limit: 4194304
+        $c =~ s@(?<=Needed: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Limit: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
     } elsif ($c =~ m/^No logfile configured/ or
              $c =~ m/^Malformerd HTTP headers detected and MS IIS5 hack enabled/ or
              $c =~ m/^Invalid \"chunked\" transfer/ or
-             $c =~ m/^Support for/
+             $c =~ m/^Support for/ or
+             $c =~ m/^Flushing header and buffers/
              ) {
 
         # No logfile configured. Please enable it before reporting any problems.
@@ -1623,6 +1759,7 @@ sub handle_loglevel_info ($) {
         # Invalid "chunked" transfer encoding detected and ignored.
         # Support for 'Connection: keep-alive' is experimental, incomplete and\
         #  known not to work properly in some situations.
+        # Flushing header and buffers. Stepping back from filtering.
 
     } else {
 
@@ -1685,10 +1822,167 @@ sub handle_loglevel_force ($) {
     return $c;
 }
 
+sub handle_loglevel_error ($) {
+
+    my $c = shift;
+    our %h;
+
+    if ($c =~ m/^Empty server or forwarder response received on socket \d+./) {
+
+        # Empty server or forwarder response received on socket 4.
+        $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+    }
+    # XXX: There are probably more messages that deserve highlighting.
+
+    return $c;
+}
+
+
 sub handle_loglevel_ignore ($) {
     return shift;
 }
 
+sub gather_loglevel_request_stats ($$) {
+    my $c = shift;
+    my $thread = shift;
+    our %stats;
+
+    $stats{requests}++;
+}
+
+sub gather_loglevel_crunch_stats ($$) {
+    my $c = shift;
+    my $thread = shift;
+    our %stats;
+
+    $stats{requests}++;
+    $stats{crunches}++;
+}
+
+
+sub gather_loglevel_error_stats ($$) {
+
+    my $c = shift;
+    my $thread = shift;
+    our %stats;
+    our %thread_data;
+
+    if ($c =~ m/^Empty server or forwarder response received on socket \d+./) {
+
+        # Empty server or forwarder response received on socket 4.
+        $stats{'empty-responses'}++;
+        if ($thread_data{$thread}{'new_connection'}) {
+            $stats{'empty-responses-on-new-connections'}++;
+        } else {
+            $stats{'empty-responses-on-reused-connections'}++;
+        }
+    }
+}
+
+sub gather_loglevel_connect_stats ($$) {
+
+    my $c = shift;
+    my $thread = shift;
+    our %thread_data;
+    our %stats;
+
+    if ($c =~ m/^via ([^\s]+) to: [^\s]+/) {
+
+        # Connect: via 10.0.0.1:8123 to: www.example.org.noconnect
+        $thread_data{$thread}{'forwarder'} = $1; # XXX: is this missue?
+
+    } elsif ($c =~ m/^to ([^\s]*)$/) {
+
+        # Connect: to lists.sourceforge.net:443
+
+        $thread_data{$thread}{'forwarder'} = 'direct connection';
+
+    } elsif ($c =~ m/^Created new connection to/) {
+
+        # Created new connection to www.privoxy.org:80 on socket 11.
+
+        $thread_data{$thread}{'new_connection'} = 1;
+
+    } elsif ($c =~ m/^Reusing server socket \d./ or
+             $c =~ m/^Found reusable socket/) {
+
+        # Reusing server socket 4. Opened for 10.0.0.1.
+        # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
+
+        $thread_data{$thread}{'new_connection'} = 0;
+        $stats{'reused-connections'}++;
+    }
+}
+
+sub gather_loglevel_header_stats ($) {
+
+    my $c = shift;
+    my $thread = shift;
+    our %stats;
+
+    if ($c =~ m/^A HTTP\/1\.1 response without/ or
+        $c =~ m/^Keeping the server header 'Connection: keep-alive' around./)
+    {
+        # A HTTP/1.1 response without Connection header implies keep-alive.
+        # Keeping the server header 'Connection: keep-alive' around.
+        $stats{'server-keep-alive'}++;
+    }
+}
+
+sub init_stats () {
+    our %stats = (
+        requests => 0,
+        crunches => 0,
+        'server-keep-alive' => 0,
+        'reused-connections' => 0,
+        'empty-responses' => 0,
+        'empty-responses-on-new-connections' => 0,
+        'empty-responses-on-reused-connections' => 0,
+        );
+}
+
+sub get_percentage ($$) {
+    my $big = shift;
+    my $small = shift;
+    return "NaN" if ($big eq 0);
+    return sprintf("%.2f%%", $small / $big * 100);
+}
+
+sub print_stats () {
+
+    our %stats;
+    my $new_connections = $stats{requests} - $stats{crunches} - $stats{'reused-connections'};
+    my $outgoing_requests = $stats{requests} - $stats{crunches};
+
+    if ($stats{requests} eq 0) {
+        print "No requests yet.\n";
+        return;
+    }
+
+    print "Client requests total: " . $stats{requests} . "\n";
+    print "Crunches: " . $stats{crunches} . " (" .
+        get_percentage($stats{requests}, $stats{crunches}) . ")\n";
+    print "Outgoing requests: " . $outgoing_requests . " (" .
+        get_percentage($stats{requests}, $outgoing_requests) . ")\n";
+    print "Server keep-alive offers: " . $stats{'server-keep-alive'} . " (" .
+        get_percentage($stats{requests}, $stats{'server-keep-alive'}) . ")\n";
+    print "New outgoing connections: " . $new_connections . " (" .
+        get_percentage($stats{requests}, $new_connections) . ")\n";
+    print "Reused connections: " . $stats{'reused-connections'} . " (" .
+        get_percentage($stats{requests}, $stats{'reused-connections'}) . ")\n";
+    print "Empty responses: " . $stats{'empty-responses'} . " (" .
+        get_percentage($stats{requests}, $stats{'empty-responses'}) . ")\n";
+    print "Empty responses on new connections: "
+         . $stats{'empty-responses-on-new-connections'} . " (" .
+        get_percentage($stats{requests}, $stats{'empty-responses-on-new-connections'})
+        . ")\n";
+    print "Empty responses on reused connections: " .
+        $stats{'empty-responses-on-reused-connections'} . " (" .
+        get_percentage($stats{requests}, $stats{'empty-responses-on-reused-connections'}) .
+        ")\n";
+}
+
+
 ################################################################################
 # Functions that actually print stuff
 ################################################################################
@@ -1773,29 +2067,29 @@ sub parse_loop () {
     my $time_colour;
     our $no_special_header_highlighting;
     $time_colour = paint_it('white');
-    my %log_level_count;
 
     my %log_level_handlers = (
-        'Re-Filter'     => \&handle_loglevel_re_filter,
-        'Header'        => \&handle_loglevel_header,
-        'Connect'       => \&handle_loglevel_connect,
-        'Redirect'      => \&handle_loglevel_redirect,
-        'Request'       => \&handle_loglevel_request,
-        'Crunch'        => \&handle_loglevel_crunch,
-        'Gif-Deanimate' => \&handle_loglevel_gif_deanimate,
-        'Info'          => \&handle_loglevel_info,
-        'CGI'           => \&handle_loglevel_cgi,
-        'Force'         => \&handle_loglevel_force,
-        'Error'         => \&handle_loglevel_ignore,
-        'Fatal error'   => \&handle_loglevel_ignore,
-        'Writing'       => \&handle_loglevel_ignore,
+        'Re-Filter'         => \&handle_loglevel_re_filter,
+        'Header'            => \&handle_loglevel_header,
+        'Connect'           => \&handle_loglevel_connect,
+        'Redirect'          => \&handle_loglevel_redirect,
+        'Request'           => \&handle_loglevel_request,
+        'Crunch'            => \&handle_loglevel_crunch,
+        'Gif-Deanimate'     => \&handle_loglevel_gif_deanimate,
+        'Info'              => \&handle_loglevel_info,
+        'CGI'               => \&handle_loglevel_cgi,
+        'Force'             => \&handle_loglevel_force,
+        'Error'             => \&handle_loglevel_error,
+        'Fatal error'       => \&handle_loglevel_ignore,
+        'Writing'           => \&handle_loglevel_ignore,
+        'Unknown log level' => \&handle_loglevel_ignore,
     );
 
     while (<>) {
  
         $output = '';
 
-        if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*)$/) {
+        if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) {
             # XXX: Put in req hash?
             $day = $1;
             $time_stamp = $2;
@@ -1812,8 +2106,6 @@ sub parse_loop () {
             $req{$t}{'log-message'} = $_;
             $no_special_header_highlighting = 0;
 
-            $log_level_count{$log_level}++;
-
             if (defined($log_level_handlers{$log_level})) {
 
                 $content = $log_level_handlers{$log_level}($content);
@@ -1850,7 +2142,7 @@ sub parse_loop () {
 
             print_non_clf_message($content);
 
-        } elsif (m/^(\d+\.\d+\.\d+\.\d+) - - \[(.*)\] "(.*)" (\d+) (\d+)/) {
+        } elsif (m/^((?:\d+\.\d+\.\d+\.\d+|[:\d]+)) - - \[(.*)\] "(.*)" (\d+) (\d+)/) {
 
             # LOG_LEVEL_CLF lines look like this
             # 61.152.239.32 - - [04/Mar/2007:18:28:23 +0100] "GET \
@@ -1871,19 +2163,58 @@ sub parse_loop () {
             }
         }
     }
+}
+
+sub stats_loop () {
+
+    my ($day, $time_stamp, $thread, $log_level, $content, $c, $msecs);
+    my %log_level_handlers = (
+         'Re-Filter'         => \&handle_loglevel_ignore,
+         'Header'            => \&gather_loglevel_header_stats,
+         'Connect'           => \&gather_loglevel_connect_stats,
+         'Redirect'          => \&handle_loglevel_ignore,
+         'Request'           => \&gather_loglevel_request_stats,
+         'Crunch'            => \&gather_loglevel_crunch_stats,
+         'Gif-Deanimate'     => \&handle_loglevel_ignore,
+         'Info'              => \&handle_loglevel_ignore,
+         'CGI'               => \&handle_loglevel_ignore,
+         'Force'             => \&handle_loglevel_ignore,
+         'Error'             => \&gather_loglevel_error_stats,
+         'Fatal error'       => \&handle_loglevel_ignore,
+         'Writing'           => \&handle_loglevel_ignore,
+         'Unknown log level' => \&handle_loglevel_ignore
+    );
+
+    while (<>) {
+        if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) {
+            $day = $1;
+            $time_stamp = $2;
+            $msecs = $3 ? $3 : 0;
+            $log_level = $5;
+            $content = $c = $6;
+            $thread = $4;
+
+            if (defined($log_level_handlers{$log_level})) {
+
+                $content = $log_level_handlers{$log_level}($content, $thread);
+
+            } else {
 
-    if (cli_option_is_set('statistic')) {
-        foreach (keys %log_level_count) {
-            print $_ . ": " . $log_level_count{$_} . " ";
+                die "No handler found for log level \"$log_level\"\n";
+
+            }
         }
     }
+
+    print_stats();
+
 }
 
 sub VersionMessage {
     my $version_message;
 
     $version_message .= 'Privoxy-Log-Parser ' . PRIVOXY_LOG_PARSER_VERSION  . "\n";
-    $version_message .= 'Copyright (C) 2007-2008 Fabian Keil <fk@fabiankeil.de>' . "\n";
+    $version_message .= 'Copyright (C) 2007-2009 Fabian Keil <fk@fabiankeil.de>' . "\n";
     $version_message .= 'http://www.fabiankeil.de/sourcecode/privoxy-log-parser/' . "\n";
 
     print $version_message;
@@ -1899,7 +2230,7 @@ sub get_cli_options () {
         'no-msecs'                 => CLI_OPTION_NO_MSECS,
         'show-ineffective-filters' => CLI_OPTION_SHOW_INEFFECTIVE_FILTERS,
         'accept-unknown-messages'  => CLI_OPTION_ACCEPT_UNKNOWN_MESSAGES,
-        'statistic'                => CLI_OPTION_STATISTIC,
+        'statistics'               => CLI_OPTION_STATISTICS,
     ); 
 
     GetOptions (
@@ -1910,7 +2241,7 @@ sub get_cli_options () {
         'no-msecs'                 => \$cli_options{'no-msecs'},
         'show-ineffective-filters' => \$cli_options{'show-ineffective-filters'},
         'accept-unknown-messages'  => \$cli_options{'accept-unknown-messages'},
-        'statistic'                => \$cli_options{'statistic'},
+        'statistics'               => \$cli_options{'statistics'},
         'version'                  => sub { VersionMessage && exit(0) }
    );
 }
@@ -1928,7 +2259,11 @@ sub main () {
 
     print_intro();
 
-    parse_loop();
+    if (cli_option_is_set('statistics')) {
+        stats_loop();
+    } else {
+        parse_loop();
+    }
 
     print_outro();
 }
@@ -1973,7 +2308,7 @@ just don't highlight them.
 [B<--html-output>] Use HTML and CSS for the syntax highlighting. If this option is
 omitted, ANSI escape sequences are used unless B<--no-syntax-highlighting> is active.
 This option is only intended to make embedding log excerpts in web pages easier.
-It does not excape any input!
+It does not escape any input!
 
 [B<--no-msecs>] Don't expect milisecond resolution
 
@@ -1985,6 +2320,11 @@ codes.
 [B<--show-ineffective-filters>] Don't suppress log lines for filters
 that didn't modify the content.
 
+[B<--statistics>] Gather various statistics instead of syntax highlighting
+log messages. This is an experimental feature, if the results look wrong
+they very well might be. Also note that the results a pretty much guaranteed
+to be incorrect if Privoxy and Privoxy-Log-Parser aren't in sync.
+
 [B<--version>] Print version and exit.
 
 =head1 EXAMPLES