X-Git-Url: http://www.privoxy.org/gitweb/?a=blobdiff_plain;f=tools%2Fprivoxy-log-parser.pl;h=04363f4a93f7553bc56c3d51c628cb240e857366;hb=b62a85ecdd8fd3f747336399ee188d136ca695aa;hp=899b16c7e309fda037f5004cd789145473601e4c;hpb=6b8470716bdfd93626b04493ec2f751b09091bd7;p=privoxy.git

diff --git a/tools/privoxy-log-parser.pl b/tools/privoxy-log-parser.pl
index 899b16c7..04363f4a 100755
--- a/tools/privoxy-log-parser.pl
+++ b/tools/privoxy-log-parser.pl
@@ -8,7 +8,7 @@
 #
 # http://www.fabiankeil.de/sourcecode/privoxy-log-parser/
 #
-# $Id: privoxy-log-parser.pl,v 1.48 2009/09/12 12:36:02 fabiankeil Exp $
+# $Id: privoxy-log-parser.pl,v 1.214 2009/12/30 14:08:09 fk Exp $
 #
 # TODO:
 #       - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting
@@ -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,
@@ -86,16 +86,37 @@ use constant {
     ESCAPE => "\033[",
 };
 
+# For performance reasons, these are global.
+
+my $t;
+my %req; # request data from previous lines
+my %h;
+my %thread_colours;
+my @all_colours;
+my @time_colours;
+my $thread_colour_index = 0;
+my $header_colour_index = 0;
+my $time_colour_index = 0;
+my %header_colours;
+my $no_special_header_highlighting;
+my %reason_colours;
+my %h_colours;
+my $header_highlight_regex = '';
+
+my $html_output_mode;
+my $no_msecs_mode; # XXX: should probably be removed
+my $line_end;
+
 sub prepare_our_stuff () {
 
     # Syntax Higlight hash
-    our @all_colours = (
+    @all_colours = (
         'red', 'green', 'brown', 'blue', 'purple', 'cyan',
         'light_gray', 'light_red', 'light_green', 'yellow',
         'light_blue', 'pink', 'light_cyan', 'white'
     );
 
-    our %h = (
+    %h = (
         # LOG_LEVEL
         Info            => 'blue',
         Header          => 'green',
@@ -153,10 +174,10 @@ sub prepare_our_stuff () {
         'content-type'       => 'yellow',
     );
 
-    our %h_colours = %h;
+    %h_colours = %h;
 
     # Header colours need their own hash so the keys can be accessed properly
-    our %header_colours = (
+    %header_colours = (
         # Prefilled with headers that should not appear with default header colours
         Cookie => 'light_red',
         'Set-Cookie' => 'light_red',
@@ -165,7 +186,7 @@ sub prepare_our_stuff () {
     );
 
     # Crunch reasons need their own hash as well
-    our %reason_colours = (
+    %reason_colours = (
         'Unsupported HTTP feature'               => 'light_red',
         Blocked                                  => 'light_red',
         Untrusted                                => 'light_red',
@@ -178,7 +199,7 @@ sub prepare_our_stuff () {
         'No reason recorded'                     => 'light_red',
     );
 
-    our @time_colours = ('white', 'light_gray');
+    @time_colours = ('white', 'light_gray');
 
     # Translate highlight strings into highlight code
     prepare_highlight_hash(\%header_colours);
@@ -187,6 +208,8 @@ sub prepare_our_stuff () {
     prepare_colour_array(\@all_colours);
     prepare_colour_array(\@time_colours);
     init_css_colours();
+
+    init_stats();
 }
 
 sub paint_it ($) {
@@ -336,8 +359,6 @@ sub get_css_colour ($) {
 
 sub get_css_line ($) {
 
-    our %h_colours;
-
     my $class = shift;
     my $css_line;
 
@@ -352,8 +373,6 @@ sub get_css_line ($) {
 
 sub get_css_line_for_colour ($) {
 
-    our %h_colours;
-
     my $colour = shift;
     my $css_line;
 
@@ -380,7 +399,6 @@ sub get_missing_css_lines () {
 
 sub get_css () {
 
-    our %h_colours;
     our %css_colours; #XXX: Wrong solution
 
     my $css = '';
@@ -439,12 +457,7 @@ sub print_outro () {
 }
 
 sub get_line_end () {
-
-    my $line_end = "\n";
-
-    $line_end = '<br>' . $line_end if cli_option_is_set('html-output');
-
-    return $line_end;
+    return cli_option_is_set('html-output') ? "<br>\n" : "\n";
 }
 
 sub get_colour_html_markup ($) {
@@ -510,7 +523,7 @@ sub get_background (){
 sub prepare_highlight_hash ($) {
     my $ref = shift;
 
-    if (!cli_option_is_set('html-output')) {
+    if (!$html_output_mode) {
 
         foreach my $key (keys %$ref) {
             $$ref{$key} = paint_it($$ref{$key}); 
@@ -528,7 +541,7 @@ sub prepare_highlight_hash ($) {
 sub prepare_colour_array ($) {
     my $ref = shift;
 
-    if (!cli_option_is_set('html-output')) {
+    if (!$html_output_mode) {
 
         foreach my $i (0 ... @$ref - 1) {
             $$ref[$i] = paint_it($$ref[$i]); 
@@ -548,9 +561,6 @@ sub found_unknown_content ($) {
     my $unknown = shift;
     my $message;
 
-    our %req;
-    our $t;
-
     return if cli_option_is_set('accept-unknown-messages');
 
     return if ($unknown =~ /\[too long, truncated\]$/);
@@ -578,7 +588,6 @@ sub log_parse_error ($) {
 
 sub debug_message (@) {
     my @message = @_;
-    our %h;
 
     print $h{'debug'} . "@message" . $h{'Standard'} . "\n";
 }
@@ -590,7 +599,6 @@ sub debug_message (@) {
 sub h ($) {
 
     # Get highlight marker
-    our %h;
     my $highlight = shift; # XXX: Stupid name;
     my $result = '';
     my $message;
@@ -613,16 +621,13 @@ sub h ($) {
 sub highlight_known_headers ($) {
 
     my $content = shift;
-    our %header_colours;
-    our %h;
-    my $headers = join ('|', keys %header_colours);
 
     debug_message("Searching $content for things to highlight.") if DEBUG_HEADER_HIGHLIGHTING;
 
-    if ($content =~ m/(?<=\s)($headers):/) {
+    if ($content =~ m/(?<=\s)($header_highlight_regex):/) {
         my $header = $1;
         $content =~ s@(?<=[\s|'])($header)(?=:)@$header_colours{$header}$1$h{'Standard'}@ig;
-        debug_message("Highlighted $content") if DEBUG_HEADER_HIGHLIGHTING;
+        debug_message("Highlighted '$header' in '$content'") if DEBUG_HEADER_HIGHLIGHTING;
     }
 
     return $content;
@@ -642,7 +647,6 @@ sub highlight_request_line ($) {
 
     my $rl = shift;
     my ($method, $url, $http_version);
-    our %h;
 
     #GET http://images.sourceforge.net/sfx/icon_warning.gif HTTP/1.1
     if ($rl =~ m/Invalid request/) {
@@ -724,11 +728,10 @@ sub highlight_matched_url ($$) {
 
 sub highlight_matched_host ($$) {
 
-    my $result = shift; # XXX: Stupid name;
-    my $regex = shift;
+    my ($result, $regex) = @_; # XXX: result ist stupid name;
 
     if ($result =~ m@(.*?)($regex)(.*)@) {
-        $result = $1 . h('host') . $2 . h('Standard') . $3;
+        $result = $1 . $h{host} . $2 . $h{Standard} . $3;
     }
 
     return $result;
@@ -736,7 +739,6 @@ sub highlight_matched_host ($$) {
 
 sub highlight_matched_pattern ($$$) {
 
-    our %h;
     my $result = shift; # XXX: Stupid name;
     my $key = shift;
     my $regex = shift;
@@ -766,7 +768,7 @@ sub highlight_url ($) {
 
     my $url = shift;
 
-    if (cli_option_is_set('html-output')) {
+    if ($html_output_mode) {
 
         $url = '<a href="' . $url . '">' . $url . '</a>';
 
@@ -779,6 +781,15 @@ sub highlight_url ($) {
     return $url;
 }
 
+sub update_header_highlight_regex ($) {
+
+    my $header = shift;
+    my $headers = join ('|', keys %header_colours);
+
+    $header_highlight_regex = qr/$headers/;
+    print "Registering '$header'\n" if DEBUG_HEADER_HIGHLIGHTING;
+}
+
 ################################################################################
 # loglevel-specific highlighter functions
 ################################################################################
@@ -787,31 +798,10 @@ sub handle_loglevel_header ($) {
 
     my $content = shift;
     my $c = $content;
-    our $t;
-    our %req;
-    our %h;
-    our %header_colours;
-    our @all_colours;
-    our $header_colour_index;
-    our $no_special_header_highlighting;
-
-    # Register new headers
-    # scan: Accept: image/png,image/*;q=0.8,*/*;q=0.5
-    if ($c =~ m/^scan: ((?>[^:]+)):/) {
-        my $header = $1;
-        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) {
-                $header_colours{$header} =  $header_colours{'Default'};
-            } else {
-                $header_colours{$header} = $all_colours[$header_colour_index % @all_colours];
-                $header_colour_index++;
-            }
-        }
-    }
+    if ($c =~ /^scan:/) {
 
-    if ($c =~ m/^scan: ((\w*) (.*) (HTTP\/\d\.\d))/) {
+        if ($c =~ m/^scan: ((\w+) (.+) (HTTP\/\d\.\d))/) {
 
             # Client request line
             # Save for statistics (XXX: Not implemented yet)
@@ -821,7 +811,7 @@ sub handle_loglevel_header ($) {
 
             $content = highlight_request_line($1);
 
-    } elsif ($c =~ m/^(scan: )((?:HTTP\/\d\.\d|ICY) (\d+) (.*))/) {
+        } elsif ($c =~ m/^(scan: )((?:HTTP\/\d\.\d|ICY) (\d+) (.*))/) {
 
             # Server response line
             $req{$t}{'response_line'} = $2;
@@ -829,6 +819,25 @@ sub handle_loglevel_header ($) {
             $req{$t}{'status_message'} = $4;
             $content = $1 . highlight_response_line($req{$t}{'response_line'});
 
+        } elsif ($c =~ m/^scan: ((?>[^:]+)):/) {
+
+            # Register new headers
+            # scan: Accept: image/png,image/*;q=0.8,*/*;q=0.5
+            my $header = $1;
+            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) {
+                    $header_colours{$header} =  $header_colours{'Default'};
+                } else {
+                    $header_colours{$header} = $all_colours[$header_colour_index % @all_colours];
+                    $header_colour_index++;
+                }
+                update_header_highlight_regex($header);
+            }
+
+        }
+
     } elsif ($c =~ m/^Crunching (?:server|client) header: .* \(contains: ([^\)]*)\)/) {
 
         # Crunching server header: Set-Cookie: trac_form_token=d5308c34e16d15e9e301a456; (contains: Cookie:)
@@ -916,6 +925,7 @@ sub handle_loglevel_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./
+          or $c =~ m/^keep-alive support is disabled/
             )
     {
         # XXX: Some of these may need highlighting
@@ -960,6 +970,7 @@ sub handle_loglevel_header ($) {
         # 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.
+        # keep-alive support is disabled. Crunching: Keep-Alive: 300.
 
     } elsif ($c =~ m/^scanning headers for:/) {
 
@@ -1030,14 +1041,39 @@ sub handle_loglevel_re_filter ($) {
     my $content = shift;
     my $c = $content;
     my $key;
-    our $t;
-    our %req;
-    our %h;
-    our %header_colours;
-    our @all_colours;
-    our $header_colour_index;
-
-    if ($c =~ /\.{3}$/
+
+    if ($c =~ m/^(?:re_)?filtering ([^\s]+) \(size (\d+)\) with (?:filter )?\'?([^\s]+?)\'? produced (\d+) hits \(new size (\d+)\)/) {
+
+        # XXX: only the second version gets highlighted properly.
+        # re_filtering www.lfk.de/favicon.ico (size 209) with filter untrackable-hulk produced 0 hits (new size 209).
+        # filtering aci.blogg.de/ (size 37988) with 'blogg.de' produced 3 hits (new size 38057)
+        $req{$t}{'content_source'} = $1;
+        $req{$t}{'content_size'}   = $2;
+        $req{$t}{'content_filter'} = $3;
+        $req{$t}{'content_hits'}   = $4;
+        $req{$t}{'new_content_size'} = $5;
+        $req{$t}{'content_size_change'} = $req{$t}{'new_content_size'} - $req{$t}{'content_size'};
+        #return '' if ($req{$t}{'content_hits'} == 0 && !cli_option_is_set('show-ineffective-filters'));
+        if ($req{$t}{'content_hits'} == 0 and
+            not (cli_option_is_set('show-ineffective-filters')
+                 or ($req{$t}{'content_filter'} =~ m/^privoxy-filter-test$/))) {
+                return '';
+        }
+
+        $c =~ s@(?<=\(size )(\d+)\)(?= with)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=\(new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=produced )(\d+)(?= hits)@$h{'Number'}$1$h{'Standard'}@;
+
+        $c =~ s@([^\s]+?)(\'? produced)@$h{'filter'}$1$h{'Standard'}$2@;
+        $c = highlight_matched_host($c, '(?<=filtering )[^\s]+');
+
+        $c =~ s@\.$@ @;
+        $c .= "(" . $h{'Number'};
+        $c .= "+" if ($req{$t}{'content_size_change'} >= 0);
+        $c .= $req{$t}{'content_size_change'} . $h{'Standard'} . ")";
+        $content = $c;
+
+  } elsif ($c =~ /\.{3}$/
         and $c =~ m/^(?:re_)?filtering \'?(.*?)\'? \(size (\d*)\) with (?:filter )?\'?([^\s]*?)\'? ?\.{3}$/) {
 
         # Used by Privoxy 3.0.5 and 3.0.6:
@@ -1115,37 +1151,6 @@ sub handle_loglevel_re_filter ($) {
 
         $content =~ s@(?<=$1 )([^\s]*)@$h{'filter'}$1$h{'Standard'}@;
 
-    } elsif ($c =~ m/^(?:re_)?filtering ([^\s]+) \(size (\d+)\) with (?:filter )?\'?([^\s]+?)\'? produced (\d+) hits \(new size (\d+)\)/) {
-
-        # XXX: only the second version gets highlighted properly.
-        # re_filtering www.lfk.de/favicon.ico (size 209) with filter untrackable-hulk produced 0 hits (new size 209).
-        # filtering aci.blogg.de/ (size 37988) with 'blogg.de' produced 3 hits (new size 38057)
-        $req{$t}{'content_source'} = $1;
-        $req{$t}{'content_size'}   = $2;
-        $req{$t}{'content_filter'} = $3;
-        $req{$t}{'content_hits'}   = $4;
-        $req{$t}{'new_content_size'} = $5;
-        $req{$t}{'content_size_change'} = $req{$t}{'new_content_size'} - $req{$t}{'content_size'};
-        #return '' if ($req{$t}{'content_hits'} == 0 && !cli_option_is_set('show-ineffective-filters'));
-        if ($req{$t}{'content_hits'} == 0 and
-            not (cli_option_is_set('show-ineffective-filters')
-                 or ($req{$t}{'content_filter'} =~ m/^privoxy-filter-test$/))) {
-                return ''; 
-        }
-
-        $c =~ s@(?<=\(size )(\d+)\)(?= with)@$h{'Number'}$1$h{'Standard'}@;
-        $c =~ s@(?<=\(new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
-        $c =~ s@(?<=produced )(\d+)(?= hits)@$h{'Number'}$1$h{'Standard'}@;
-
-        $c =~ s@([^\s]+?)(\'? produced)@$h{'filter'}$1$h{'Standard'}$2@;
-        $c = highlight_matched_host($c, '(?<=filtering )[^\s]+');
-
-        $c =~ s@\.$@ @;
-        $c .= "(" . $h{'Number'};
-        $c .= "+" if ($req{$t}{'content_size_change'} >= 0);
-        $c .= $req{$t}{'content_size_change'} . $h{'Standard'} . ")";
-        $content = $c;
-
     } elsif ($c =~ m/^De-chunking successful. Shrunk from (\d+) to (\d+)/) {
 
         $req{$t}{'chunked-size'} = $1;
@@ -1209,9 +1214,6 @@ sub handle_loglevel_re_filter ($) {
 sub handle_loglevel_redirect ($) {
 
     my $c = shift;
-    our $t;
-    our %req;
-    our %h;
 
     if ($c =~ m/^Decoding "([^""]*)"/) {
 
@@ -1229,13 +1231,11 @@ sub handle_loglevel_redirect ($) {
          $c = highlight_matched_path($c, '(?<=Checking ")[^"]*');
          $c =~ s@\"@@g;
 
-    } elsif ($c =~ m/^pcrs command "([^""]*)" changed "([^""]*)" to "([^""]*)" \((\d+) hits?\)/) {
+    } elsif ($c =~ m/^pcrs command "([^""]*)" changed /) {
 
-        # pcrs command "s@&from=rss@@" changed "http://it.slashdot.org/article.pl?sid=07/03/02/1657247&from=rss"\
+        # pcrs command "s@&from=rss@@" changed \
+        #  "http://it.slashdot.org/article.pl?sid=07/03/02/1657247&from=rss"\
         #  to "http://it.slashdot.org/article.pl?sid=07/03/02/1657247" (1 hit).
-
-        my ($pcrs_command, $url_before, $url_after, $hits) = ($1, $2, $3, $4); # XXX: save these?
-
         $c =~ s@(?<=pcrs command )"([^""]*)"@$h{'filter'}$1$h{'Standard'}@;
         $c = highlight_matched_url($c, '(?<=changed ")[^""]*');
         $c =~ s@(?<=changed )"([^""]*)"@$1@; # Remove quotes
@@ -1243,6 +1243,13 @@ sub handle_loglevel_redirect ($) {
         $c =~ s@(?<=to )"([^""]*)"@$1@; # Remove quotes
         $c =~ s@(\d+)(?= hits?)@$h{'hits'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^pcrs command "([^""]*)" didn\'t change/) {
+
+        # pcrs command "s@^http://([^.]+?)/?$@http://www.bing.com/search?q=$1@" didn't \
+        #  change "http://www.example.org/".
+        $c =~ s@(?<=pcrs command )"([^""]*)"@$h{'filter'}$1$h{'Standard'}@;
+        $c = highlight_matched_url($c, '(?<=change ")[^""]*');
+
     } elsif ($c =~ m/(^New URL is: )(.*)/) {
 
         # New URL is: http://it.slashdot.org/article.pl?sid=07/03/04/1511210
@@ -1268,9 +1275,6 @@ sub handle_loglevel_redirect ($) {
 sub handle_loglevel_gif_deanimate ($) {
 
     my $content = shift;
-    our $t;
-    our %req;
-    our %h;
 
     if ($content =~ m/Success! GIF shrunk from (\d+) bytes to (\d+)\./) {
 
@@ -1317,10 +1321,6 @@ sub handle_loglevel_gif_deanimate ($) {
 sub handle_loglevel_request ($) {
 
     my $content = shift;
-    our $t;
-    our %req;
-    our %h;
-    our %reason_colours;
 
     if ($content =~ m/crunch! /) {
 
@@ -1356,8 +1356,6 @@ sub handle_loglevel_request ($) {
 sub handle_loglevel_crunch ($) {
 
     my $content = shift;
-    our %h;
-    our %reason_colours;
 
     # Highlight crunch reason
     foreach my $reason (keys %reason_colours) {
@@ -1382,9 +1380,6 @@ sub handle_loglevel_crunch ($) {
 sub handle_loglevel_connect ($) {
 
     my $c = shift;
-    our $t;
-    our %req;
-    our %h;
 
     if ($c =~ m/^via [^\s]+ to: [^\s]+/) {
 
@@ -1478,9 +1473,15 @@ sub handle_loglevel_connect ($) {
     } elsif ($c =~ m/^Found reusable socket/) {
 
         # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
+        # 3.0.15 and later:
+        # Found reusable socket 8 for www.privoxy.org:80 in slot 2.\
+        #  Timestamp made 0 seconds ago. Timeout: 1. Latency: 0.
         $c =~ s@(?<=Found reusable socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=made )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Timeout: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Marking open socket/) {
 
@@ -1521,6 +1522,11 @@ sub handle_loglevel_connect ($) {
         $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.
@@ -1538,8 +1544,9 @@ sub handle_loglevel_connect ($) {
         # 3.0.15 and later:
         # Done reading from server. Expected content length: 24892. \
         #  Actual content length: 24892. Bytes most recently read: 4412.
-        $c =~ s@(?<=Expected content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
-        $c =~ s@(?<=Actual content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        # 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'}@;
 
@@ -1571,8 +1578,9 @@ sub handle_loglevel_connect ($) {
         # 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.
+        # No additional client request received in time on socket 29.
 
-        $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<= socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.$)');
 
     } elsif ($c =~ m/^Connected to /) {
@@ -1591,11 +1599,15 @@ sub handle_loglevel_connect ($) {
         $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/ ) {
+             $c =~ m/^The connection on server socket/ or
+             $c =~ m/^Client request arrived in time or the client closed the connection/) {
 
-        # Waiting for the next client request. Keeping the server socket 5 to 10.0.0.1 open.
+        # Waiting for the next client request on socket 3. Keeping the server \
+        #  socket 12 to a.fsdn.com open.
         # The connection on server socket 6 to upload.wikimedia.org isn't reusable. Closing.
+        # Client request arrived in time or the client closed the connection on socket 12.
 
+        $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c = highlight_matched_host($c, '(?<=to )[^\s]+');
 
@@ -1617,17 +1629,28 @@ sub handle_loglevel_connect ($) {
         $c =~ s@(?<=closed socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^Expected client content length set /) {
+
+        # Expected client content length set to 667325411 after reading 4999 bytes.
+        $c =~ s@(?<=set to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=reading )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Waiting for up to /) {
+
+        # Waiting for up to 4999 bytes from the client.
+        $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
     } elsif ($c =~ m/^Looks like we rea/ or
              $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./) {
+             $c =~ m/^Stopping to watch the client socket. There's already another request waiting./ or
+             $c =~ m/^Done reading from the client\.$/) {
 
         # 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 \
@@ -1643,6 +1666,7 @@ sub handle_loglevel_connect ($) {
         # 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.
+        # Done reading from the client\.
 
     } else {
 
@@ -1657,9 +1681,6 @@ sub handle_loglevel_connect ($) {
 sub handle_loglevel_info ($) {
 
     my $c = shift;
-    our $t;
-    our %req;
-    our %h;
  
     if ($c =~ m/^Rewrite detected:/) {
 
@@ -1765,9 +1786,6 @@ sub handle_loglevel_info ($) {
 sub handle_loglevel_cgi ($) {
 
     my $c = shift;
-    our $t;
-    our %req;
-    our %h;
 
     if ($c =~ m/^Granting access to/) {
       
@@ -1790,9 +1808,6 @@ sub handle_loglevel_cgi ($) {
 sub handle_loglevel_force ($) {
 
     my $c = shift;
-    our $t;
-    our %req;
-    our %h;
 
     if ($c =~ m/^Ignored force prefix in request:/) {
       
@@ -1817,12 +1832,14 @@ sub handle_loglevel_force ($) {
 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.
+        # Empty server or forwarder response received on socket 3. \
+        #  Closing client socket 15 without sending data.
         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
     }
     # XXX: There are probably more messages that deserve highlighting.
 
@@ -1834,6 +1851,147 @@ 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
 ################################################################################
@@ -1841,7 +1999,6 @@ sub handle_loglevel_ignore ($) {
 sub print_clf_message () {
 
     our ($ip, $timestamp, $request_line, $status_code, $size);
-    our %h;
     my $output = '';
 
     return if DEBUG_SUPPRESS_LOG_MESSAGES;
@@ -1856,69 +2013,46 @@ sub print_clf_message () {
     $output .= $h{'Status'} . $status_code . $h{'Standard'};
     $output .= " ";
     $output .= $h{'Number'} . $size . $h{'Standard'};
-    $output .= get_line_end();
+    $output .= $line_end;
 
     print $output;
 }
 
 sub print_non_clf_message ($) {
 
-    our %req;
-    our %thread_colours;
-    our %h;
-    our $t;
-    our $time_colour_index;
-    our @time_colours;
-    my $output;
     my $content = shift;
-    my ($day, $time_stamp, $msecs, $thread, $log_level)
-     = ($req{$t}{'day'}, $req{$t}{'time-stamp'}, $req{$t}{'msecs'}, $t, $req{$t}{'log-level'} );
+    my $msec_string = "." . $req{$t}{'msecs'} unless $no_msecs_mode;
+    my $line_start = $html_output_mode ? '' : $h{"Standard"};
 
     return if DEBUG_SUPPRESS_LOG_MESSAGES;
 
-    $output .= $h{"Standard"} unless cli_option_is_set('html-output');
-    #    $output .= "$day ";
-    $output .= $time_colours[$time_colour_index % 2]; 
-
-    $output .= $time_stamp;
-    $output .= ".$msecs" unless cli_option_is_set('no-msecs');
-    $output .= $h{"Standard"};
-    $output .= " ";
-    $output .= $thread_colours{$thread} if (defined($thread_colours{$thread}));
-    $output .= $thread;
-    $output .= $h{"Standard"} . " ";
-    $output .= $h{$log_level} if (defined($h{$log_level}));
-    $output .= $log_level;
-    $output .= $h{"Standard"} . ": ";
-    $output .= "$content";
-    $output .= get_line_end();
-
-    print $output;
+    print $line_start
+        . $time_colours[$time_colour_index % 2]
+        . $req{$t}{'time-stamp'}
+        . $msec_string
+        . $h{Standard} . " "
+        . $thread_colours{$t}
+        . $t
+        . $h{Standard}
+        . " "
+        . $h{$req{$t}{'log-level'}}
+        . $req{$t}{'log-level'}
+        . $h{Standard}
+        . ": "
+        . $content
+        . $line_end;
 }
 
 sub parse_loop () {
 
-    our $t;
-    our %req; # request data from previous lines
-    our %h;
-    our %thread_colours;
-    our @all_colours;
-    our @time_colours;
-    our $thread_colour_index = 0;
-    our $header_colour_index = 0;
-    our $time_colour_index = 0;
-
     my ($day, $time_stamp, $thread, $log_level, $content, $c, $msecs);
     my $last_msecs  = 0;
     my $last_thread = 0;
     my $last_timestamp = 0;
-    my $output;
     my $filters_that_did_nothing;
     my $key;
     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,
@@ -1939,27 +2073,16 @@ sub parse_loop () {
 
     while (<>) {
  
-        $output = '';
-
         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;
-            $msecs = $3 ? $3 : 0; # Only the cool kids have micro second resolution
-            $log_level = $5;
-            $content = $c = $6;
             $thread = $t = $4;
-
-            $req{$t}{'day'} = $day;
-            $req{$t}{'time-stamp'} = $time_stamp;
-            $req{$t}{'msecs'} = $msecs; # Only the cool kids have micro second resolution;
-            $req{$t}{'log-level'} = $log_level;
-            $req{$t}{'content'} = $content;
+            $req{$t}{'day'} = $day = $1;
+            $req{$t}{'time-stamp'} = $time_stamp = $2;
+            $req{$t}{'msecs'} = $msecs = $3 ? $3 : 0; # Only the cool kids have micro second resolution;
+            $req{$t}{'log-level'} = $log_level = $5;
+            $req{$t}{'content'} = $content = $c = $6;
             $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);
@@ -1984,15 +2107,15 @@ sub parse_loop () {
             }
 
             # Switch timestamp colour if timestamps differ
-            if ($msecs != $last_msecs || !($time_stamp =~ m/$last_timestamp/)) {
+            if (($msecs ne $last_msecs) || ($time_stamp ne $last_timestamp)) {
                debug_message("Tick tack!") if DEBUG_TICKS;
                $time_colour = $time_colours[$time_colour_index % 2]; 
-               $time_colour_index++
+               $time_colour_index++;
+               $last_msecs = $msecs;
+               $last_timestamp = $time_stamp;
             }
 
-            $last_msecs = $msecs;
             $last_thread = $thread;
-            $last_timestamp = $time_stamp;
 
             print_non_clf_message($content);
 
@@ -2017,12 +2140,51 @@ sub parse_loop () {
             }
         }
     }
+}
 
-    if (cli_option_is_set('statistic')) {
-        foreach (keys %log_level_count) {
-            print $_ . ": " . $log_level_count{$_} . " ";
+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 {
+
+                die "No handler found for log level \"$log_level\"\n";
+
+            }
         }
     }
+
+    print_stats();
+
 }
 
 sub VersionMessage {
@@ -2045,7 +2207,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 (
@@ -2056,12 +2218,39 @@ 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'},
-        'version'                  => sub { VersionMessage && exit(0) }
-   );
+        'statistics'               => \$cli_options{'statistics'},
+        'version'                  => sub { VersionMessage && exit(0) },
+        'help'                     => \&help,
+   ) or exit(1);
+
+   $html_output_mode = cli_option_is_set('html-output');
+   $no_msecs_mode = cli_option_is_set('no-msecs');
+   $line_end = get_line_end();
 }
 
+sub help () {
 
+    our %cli_options;
+
+    VersionMessage();
+
+    print << "    EOF"
+
+Options and their default values if they have any:
+    [--accept-unknown-messages]
+    [--html-output]
+    [--no-embedded-css]
+    [--no-msecs]
+    [--no-syntax-highlighting]
+    [--show-ineffective-filters]
+    [--statistics]
+    [--title $cli_options{'title'}]
+    [--version]
+see "perldoc $0" for more information
+    EOF
+    ;
+    exit(0);
+}
 
 ################################################################################
 # main
@@ -2074,7 +2263,11 @@ sub main () {
 
     print_intro();
 
-    parse_loop();
+    if (cli_option_is_set('statistics')) {
+        stats_loop();
+    } else {
+        parse_loop();
+    }
 
     print_outro();
 }
@@ -2131,6 +2324,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