privoxy-log-parser: Highlight: 'Reducing the chunk offset from 1096654 to 32704 after...

[privoxy.git] / tools / privoxy-log-parser.pl

diff --git a/tools/privoxy-log-parser.pl b/tools/privoxy-log-parser.pl
index 335e2df..3265ac7 100755 (executable)
--- a/tools/privoxy-log-parser.pl
+++ b/tools/privoxy-log-parser.pl
@@ -23,7 +23,7 @@
 #         hash key as input.
 #       - Add --compress and --decompress options.
 #
 #         hash key as input.
 #       - Add --compress and --decompress options.
 #

-# Copyright (c) 2007-2021 Fabian Keil <fk@fabiankeil.de>
+# Copyright (c) 2007-2022 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
 #
 # Permission to use, copy, modify, and distribute this software for any
 # purpose with or without fee is hereby granted, provided that the above


@@ -43,15 +43,17 @@ use warnings;
 use Getopt::Long;
 
 use constant {
 use Getopt::Long;
 
 use constant {

-    PRIVOXY_LOG_PARSER_VERSION => '0.9.2',
+    PRIVOXY_LOG_PARSER_VERSION => '0.9.4',

     # Feel free to mess with these ...
     DEFAULT_BACKGROUND => 'black',  # Choose registered colour (like 'black')
     DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
     HEADER_DEFAULT_COLOUR => 'yellow',
     REGISTER_HEADERS_WITH_THE_SAME_COLOUR => 1,
 
     # Feel free to mess with these ...
     DEFAULT_BACKGROUND => 'black',  # Choose registered colour (like 'black')
     DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
     HEADER_DEFAULT_COLOUR => 'yellow',
     REGISTER_HEADERS_WITH_THE_SAME_COLOUR => 1,
 

+    CLI_OPTION_DETECT_INACTIVITY => 0,

     CLI_OPTION_DEFAULT_TO_HTML_OUTPUT => 0,
     CLI_OPTION_TITLE => 'Privoxy-Log-Parser in da house',
     CLI_OPTION_DEFAULT_TO_HTML_OUTPUT => 0,
     CLI_OPTION_TITLE => 'Privoxy-Log-Parser in da house',

+    CLI_OPTION_INACTIVITY_THRESHOLD => 100,

     CLI_OPTION_KEEP_DATE => 0,
     CLI_OPTION_NO_EMBEDDED_CSS => 0,
     CLI_OPTION_NO_MSECS => 0,
     CLI_OPTION_KEEP_DATE => 0,
     CLI_OPTION_NO_EMBEDDED_CSS => 0,
     CLI_OPTION_NO_MSECS => 0,


@@ -62,6 +64,7 @@ use constant {
     CLI_OPTION_STRICT_CHECKS => 0,
     CLI_OPTION_UNBREAK_LINES_ONLY => 0,
     CLI_OPTION_URL_STATISTICS_THRESHOLD => 0,
     CLI_OPTION_STRICT_CHECKS => 0,
     CLI_OPTION_UNBREAK_LINES_ONLY => 0,
     CLI_OPTION_URL_STATISTICS_THRESHOLD => 0,

+    CLI_OPTION_PASSED_REQUEST_STATISTICS_THRESHOLD => 0,

     CLI_OPTION_HOST_STATISTICS_THRESHOLD => 0,
     CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION => 0,
 
     CLI_OPTION_HOST_STATISTICS_THRESHOLD => 0,
     CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION => 0,
 


@@ -644,7 +647,7 @@ sub highlight_request_line($) {
     my ($method, $url, $http_version);
 
     #GET http://images.sourceforge.net/sfx/icon_warning.gif HTTP/1.1
     my ($method, $url, $http_version);
 
     #GET http://images.sourceforge.net/sfx/icon_warning.gif HTTP/1.1

-    if ($rl =~ m/Invalid request/) {
+    if ($rl =~ m/Invalid request/ or $rl =~ m/Failed reading chunked client body/) {

 
         $rl = h('invalid-request') . $rl . h('Standard');
 
 
         $rl = h('invalid-request') . $rl . h('Standard');
 


@@ -1078,6 +1081,17 @@ sub handle_loglevel_re_filter($) {
         $c .= $req{$t}{'content_size_change'} . $h{'Standard'} . ")";
         $content = $c;
 
         $c .= $req{$t}{'content_size_change'} . $h{'Standard'} . ")";
         $content = $c;
 

+    } elsif ($c =~ m/^filtering request body from client /) {
+
+        # filtering request body from client 127.0.0.1 (size 958) with 'null-filter' produced 0 hits (new size 958).
+
+        $c =~ s@(?<=from client )([^\s]+)@$h{'ip-address'}$1$h{'Standard'}@;
+        $c =~ s@(?<=\(size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@([^\s]+?)(\'? produced)@$h{'filter'}$1$h{'Standard'}$2@;
+        $c =~ s@(?<=\(new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=produced )(\d+)(?= hits)@$h{'Number'}$1$h{'Standard'}@;
+        $content = $c;
+

   } elsif ($c =~ /\.{3}$/
         and $c =~ m/^(?:re_)?filtering \'?(.*?)\'? \(size (\d*)\) with (?:filter )?\'?([^\s]*?)\'? ?\.{3}$/) {
 
   } elsif ($c =~ /\.{3}$/
         and $c =~ m/^(?:re_)?filtering \'?(.*?)\'? \(size (\d*)\) with (?:filter )?\'?([^\s]*?)\'? ?\.{3}$/) {
 


@@ -1245,7 +1259,38 @@ sub handle_loglevel_tagging($) {
         $c =~ s@(?<=^Tagger \')([^\']*)@$h{'tagger'}$1$h{'Standard'}@;
         $c =~ s@(?<=added tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
         $c =~ s@(?<=Action bits )(updated)@$h{'action-bits-update'}$1$h{'Standard'}@;
         $c =~ s@(?<=^Tagger \')([^\']*)@$h{'tagger'}$1$h{'Standard'}@;
         $c =~ s@(?<=added tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
         $c =~ s@(?<=Action bits )(updated)@$h{'action-bits-update'}$1$h{'Standard'}@;

+
+    } elsif ($c =~ /^Enlisting tag/) {
+
+        # Enlisting tag 'forward-directly' for client 127.0.0.1.
+
+        $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
+        $c = highlight_matched_host($c, '[^\s]+(?=\.$)');
+
+    } elsif ($c =~ /^Tag/) {
+
+        # Tag 'change-tor-socks-port' for client 127.0.0.1 expired 1 seconds ago. Deleting it.
+
+        $c =~ s@(?<=Tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
+        $c =~ s@(?<=expired )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = highlight_matched_host($c, '(?<=client )[^\s]+');
+
+    } elsif ($c =~ /^Evaluating/) {
+
+        # Evaluating tag 'change-tor-socks-port' for client 127.0.0.1. End of life 1613162302.
+
+        $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
+        $c = highlight_matched_host($c, '(?<=client )[^\s]+(?=\.)');
+        $c =~ s@(?<=life )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ /^Client tag/) {
+
+        # Client tag 'forward-directly' matches
+
+        $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
+

     }
     }

+

     return $c;
 }
 
     return $c;
 }
 


@@ -1580,9 +1625,10 @@ sub handle_loglevel_connect($) {
         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 

-    } elsif ($c =~ m/^Socket/) {
+    } elsif ($c =~ m/^Socket \d+ (already|closed)/) {

 
         # Socket 16 already forgotten or never remembered.
 
         # Socket 16 already forgotten or never remembered.

+        # Socket 9 closed while waiting for client headers

         $c =~ s@(?<=Socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^The connection to/) {
         $c =~ s@(?<=Socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^The connection to/) {


@@ -1599,7 +1645,7 @@ sub handle_loglevel_connect($) {
         $c =~ s@(?<=Assumed latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Stopped waiting for the request line/ or
         $c =~ s@(?<=Assumed latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Stopped waiting for the request line/ or

-             $c =~ m/^No request line on socket \d received in time/ or
+             $c =~ m/^No request line on socket \d+ received in time/ or

              $c =~ m/^The client side of the connection on socket \d/) {
 
         # Stopped waiting for the request line. Timeout: 121.
              $c =~ m/^The client side of the connection on socket \d/) {
 
         # Stopped waiting for the request line. Timeout: 121.


@@ -1821,7 +1867,11 @@ sub handle_loglevel_connect($) {
     } elsif ($c =~ m/^Dropping the client connection on socket/) {
 
         # Dropping the client connection on socket 71. The server connection has not been established yet.
     } elsif ($c =~ m/^Dropping the client connection on socket/) {
 
         # Dropping the client connection on socket 71. The server connection has not been established yet.

+        # Dropping the client connection on socket 23 with server socket 24 connected to \
+        #  www.reddit.com. The forwarder has changed.

         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
         $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, '(?<=connected to )[^ ]+(?=\.)');

 
     } elsif ($c =~ m/^The client socket \d+ has become unusable while the server/) {
 
 
     } elsif ($c =~ m/^The client socket \d+ has become unusable while the server/) {
 


@@ -1839,6 +1889,54 @@ sub handle_loglevel_connect($) {
         # Flushed 3153 bytes of request body
         $c =~ s@(?<=Flushed )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
         # Flushed 3153 bytes of request body
         $c =~ s@(?<=Flushed )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 

+    } elsif ($c =~ m/^Complete client request followed by/) {
+
+        # Complete client request followed by 59 bytes of pipelined data received.
+        $c =~ s@(?<=followed by )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^The peer notified us that the connection on socket/) {
+
+        # The peer notified us that the connection on socket 11 is going to be closed
+        $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Client socket \d is no longer usable/) {
+
+        # Client socket 7 is no longer usable. The server socket has been closed.
+        $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Socket timeout \d+ reached/) {
+
+        # Socket timeout 3 reached: http://127.0.0.1:20000/no-filter/chunked-content/36
+        $c =~ s@(?<=timeout )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = highlight_matched_url($c, "(?<=reached: ).*")
+
+    } elsif ($c =~ m/^Prepared to read up to /) {
+
+        # Prepared to read up to 157 bytes of encrypted request body from the client.
+        $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Forwarding \d+ bytes /) {
+
+        # Forwarding 157 bytes of encrypted request body.
+        $c =~ s@(?<=Forwarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Buffering encrypted client body/) {
+
+        # Buffering encrypted client body. Prepared to read up to 2236 bytes.
+        $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^The last \d+ bytes of the encrypted request body have been read/) {
+
+        # The last 6945 bytes of the encrypted request body have been read.
+        $c =~ s@(?<=The last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Reducing the chunk offset from/) {
+
+        # Reducing the chunk offset from 1096654 to 32704 after discarding 1063950 bytes to make room in the buffer.
+        $c =~ s@(?<=\d to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=offset from )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=after discarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+

     } elsif ($c =~ m/^Looks like we / or
              $c =~ m/^Unsetting keep-alive flag/ or
              $c =~ m/^No connections to wait/ or
     } elsif ($c =~ m/^Looks like we / or
              $c =~ m/^Unsetting keep-alive flag/ or
              $c =~ m/^No connections to wait/ or


@@ -2078,6 +2176,17 @@ sub handle_loglevel_error($) {
         # Sending data on socket 33 over TLS/SSL failed: no TLS/SSL errors detected
         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 
         # Sending data on socket 33 over TLS/SSL failed: no TLS/SSL errors detected
         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 

+    } elsif ($c =~ m/^Chunk size \d+ exceeds buffered data left/) {
+
+        # Chunk size 291 exceeds buffered data left. Already digested 69894 of 69957 buffered bytes.
+        $c =~ s@(?<=size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=digested )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=of )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^The socks connection timed out after/) {
+
+        # The socks connection timed out after 60 seconds.
+        $c =~ s@(?<=after )(\d+)@$h{'Number'}$1$h{'Standard'}@;

     }
 
     # XXX: There are probably more messages that deserve highlighting.
     }
 
     # XXX: There are probably more messages that deserve highlighting.


@@ -2111,6 +2220,8 @@ sub gather_loglevel_clf_stats($) {
     unless (defined $method) {
         # +0200] "Invalid request" 400 0
         return if ($content =~ m/^[+-]\d{4}\] "Invalid request"/);
     unless (defined $method) {
         # +0200] "Invalid request" 400 0
         return if ($content =~ m/^[+-]\d{4}\] "Invalid request"/);

+        # +0100] "Failed reading chunked client body" 400 0
+        return if ($content =~ m/^[+-]\d{4}\] "Failed reading chunked client body"/);

         # +0100] "GET https://securepubads.g.doubleclick.net/gampad/ads?gd[...]... [too long, truncated]
         if ($content =~ m/\[too long, truncated\]$/) {
             print("Skipped LOG_LEVEL_CLF message that got truncated by Privoxy. Statistics will be inprecise.\n");
         # +0100] "GET https://securepubads.g.doubleclick.net/gampad/ads?gd[...]... [too long, truncated]
         if ($content =~ m/\[too long, truncated\]$/) {
             print("Skipped LOG_LEVEL_CLF message that got truncated by Privoxy. Statistics will be inprecise.\n");


@@ -2134,17 +2245,25 @@ sub gather_loglevel_clf_stats($) {
 }
 
 sub gather_loglevel_request_stats($$) {
 }
 
 sub gather_loglevel_request_stats($$) {

-    my $c = shift;
+    my $request_url = shift;

     my $thread = shift;
     our %stats;
     my $thread = shift;
     our %stats;

+    our %cli_options;

 
     $stats{requests}++;
 
     $stats{requests}++;

+    if ($cli_options{'passed-request-statistics-threshold'} != 0) {
+        # If the request get blocked we'll decrement
+        # in gather_loglevel_crunch_stats()
+        chomp $request_url;
+        $stats{'passed-request-url'}{$request_url}++;
+    }

 }
 
 sub gather_loglevel_crunch_stats($$) {
     my $c = shift;
     my $thread = shift;
     our %stats;
 }
 
 sub gather_loglevel_crunch_stats($$) {
     my $c = shift;
     my $thread = shift;
     our %stats;

+    our %cli_options;

 
     $stats{crunches}++;
 
 
     $stats{crunches}++;
 


@@ -2164,6 +2283,15 @@ sub gather_loglevel_crunch_stats($$) {
         # Connection failure: http://127.0.0.1:8080/
         $stats{'connection-failure'}++;
     }
         # Connection failure: http://127.0.0.1:8080/
         $stats{'connection-failure'}++;
     }

+    if ($cli_options{'passed-request-statistics-threshold'} != 0) {
+        $c =~ m/^[^:]+: (.*)/;
+        if ($stats{'passed-request-url'}{$1}) {
+            $stats{'passed-request-url'}{$1}-- ;
+            if ($stats{'passed-request-url'}{$1} == 0) {
+                delete($stats{'passed-request-url'}{$1});
+            }
+        }
+    }

 }
 
 
 }
 
 


@@ -2329,7 +2457,7 @@ sub print_stats() {
         get_percentage($requests_total, $stats{'server-keep-alive'}) . ")\n";
     print "New outgoing connections: " . $new_connections . " (" .
         get_percentage($requests_total, $new_connections) . ")\n";
         get_percentage($requests_total, $stats{'server-keep-alive'}) . ")\n";
     print "New outgoing connections: " . $new_connections . " (" .
         get_percentage($requests_total, $new_connections) . ")\n";

-    print "Reused connections: " . $stats{'reused-connections'} . " (" .
+    print "Reused server connections: " . $stats{'reused-connections'} . " (" .

         get_percentage($requests_total, $stats{'reused-connections'}) .
         "; server offers accepted: " .
         get_percentage($stats{'server-keep-alive'}, $stats{'reused-connections'}) . ")\n";
         get_percentage($requests_total, $stats{'reused-connections'}) .
         "; server offers accepted: " .
         get_percentage($stats{'server-keep-alive'}, $stats{'reused-connections'}) . ")\n";


@@ -2345,7 +2473,7 @@ sub print_stats() {
         ")\n";
     print "Client connections: " .  $stats{'closed-client-connections'} . "\n";
     if ($stats{'content-size-total'}) {
         ")\n";
     print "Client connections: " .  $stats{'closed-client-connections'} . "\n";
     if ($stats{'content-size-total'}) {

-        print "Bytes of content transfered to the client: " .  $stats{'content-size-total'} . "\n";
+        print "Bytes of content transferred to the client: " .  $stats{'content-size-total'} . "\n";

     }
     my $lines_printed = 0;
     print "Client requests per connection distribution:\n";
     }
     my $lines_printed = 0;
     print "Client requests per connection distribution:\n";


@@ -2384,7 +2512,7 @@ sub print_stats() {
         print "HTTP version distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
     }
     if (exists $stats{'status-code'}) {
         print "HTTP version distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
     }
     if (exists $stats{'status-code'}) {

-        print "HTTP status codes:\n";
+        print "HTTP status codes according to 'debug 512' (status codes sent by the server may differ):\n";

         foreach my $status_code (sort {$stats{'status-code'}{$b} <=> $stats{'status-code'}{$a}} keys %{$stats{'status-code'}}) {
             printf "%8d : %-8d\n",  $stats{'status-code'}{$status_code}, $status_code;
         }
         foreach my $status_code (sort {$stats{'status-code'}{$b} <=> $stats{'status-code'}{$a}} keys %{$stats{'status-code'}}) {
             printf "%8d : %-8d\n",  $stats{'status-code'}{$status_code}, $status_code;
         }


@@ -2405,6 +2533,19 @@ sub print_stats() {
         }
     }
 
         }
     }
 

+    if ($cli_options{'passed-request-statistics-threshold'} == 0) {
+        print "Passed request statistics are disabled. Increase --passed-request-statistics-threshold to enable them.\n";
+    } else {
+        print "Requested requests that were passed:\n";
+        foreach my $passed_url (sort {$stats{'passed-request-url'}{$b} <=> $stats{'passed-request-url'}{$a}}
+                                keys %{$stats{'passed-request-url'}}) {
+            if ($stats{'passed-request-url'}{$passed_url} < $cli_options{'passed-request-statistics-threshold'}) {
+                print "Skipped statistics for passed URLs below the treshold.\n";
+                last;
+            }
+            printf "%d : %s\n", $stats{'passed-request-url'}{$passed_url}, $passed_url;
+        }
+    }

     if ($cli_options{'host-statistics-threshold'} == 0) {
         print "Host statistics are disabled. Increase --host-statistics-threshold to enable them.\n";
     } else {
     if ($cli_options{'host-statistics-threshold'} == 0) {
         print "Host statistics are disabled. Increase --host-statistics-threshold to enable them.\n";
     } else {


@@ -2590,7 +2731,7 @@ sub parse_loop() {
 
 sub stats_loop() {
 
 
 sub stats_loop() {
 

-    my ($day, $time_stamp, $msecs, $thread, $log_level, $content);
+    my ($day, $time_stamp, $thread, $log_level, $content);

     my $strict_checks = cli_option_is_set('strict-checks');
     my %log_level_handlers = (
          'Connect:'           => \&gather_loglevel_connect_stats,
     my $strict_checks = cli_option_is_set('strict-checks');
     my %log_level_handlers = (
          'Connect:'           => \&gather_loglevel_connect_stats,


@@ -2638,6 +2779,75 @@ sub stats_loop() {
 
 }
 
 
 }
 

+# Convert a timestamp like 18:07:28.733 into milliseconds
+sub time_stamp_to_msecs($) {
+    my $time_stamp = shift;
+
+    if ($time_stamp =~ /(\d\d):(\d\d):(\d\d)\.(\d{3})/) {
+        my ($hours, $minutes, $seconds, $msecs) = ($1, $2, $3, $4);
+
+        $msecs += $seconds * 1000;
+        $msecs += $minutes * 1000 * 60;
+        $msecs += $hours   * 1000 * 60 * 60;
+
+        return $msecs;
+    }
+    return undef;
+}
+
+sub inactivity_detection_loop() {
+
+    our %cli_options;
+    my ($date, $time_stamp, $thread, $log_level, $content);
+    my ($msecs, $previous_msecs, $inactivity);
+    my $inactivity_threshold = $cli_options{'inactivity-threshold'};
+    my $previous_date;
+    my $log_messages_out_of_order = 0;
+
+    while (<>) {
+        ($date, $time_stamp, $thread, $log_level, $content) = split(/ /, $_, 5);
+
+        next if (not defined($log_level));
+        next if ($time_stamp eq "-");
+        $msecs = time_stamp_to_msecs($time_stamp);
+        unless (defined $msecs) {
+            print "Failed to convert $time_stamp into milliseconds\n";
+            print "$_";
+            next;
+        }
+        unless (defined $previous_msecs) {
+            $previous_msecs = $msecs;
+            $previous_date = $date;
+            print "$_";
+            next;
+        }
+        $inactivity = $msecs - $previous_msecs;
+        if ($inactivity < 0) {
+            # This can happen if there's a high load in which case
+            # a Privoxy thread may be moved off schedule between
+            # getting the timestamp for the log message and actually
+            # writing it.
+            $log_messages_out_of_order++;
+        }
+        if ($inactivity > $inactivity_threshold) {
+            if ($previous_date eq $date) {
+                print "Detected inactivity: $inactivity msecs\n";
+            } else {
+                # While we could include the date in the timestamp
+                # we currently don't.
+                print "Detected date change. Timestamp difference ignored.\n";
+            }
+        }
+        print "$_";
+        $previous_msecs = $msecs;
+        $previous_date = $date;
+    }
+    if ($log_messages_out_of_order) {
+        print "At least $log_messages_out_of_order messages were written out of the chronological order.\n";
+        print "This can result in false positives. Consider sorting the log first.\n";
+    }
+}
+

 sub unbreak_lines_only_loop() {
     my $log_messages_reached = 0;
     while (<>) {
 sub unbreak_lines_only_loop() {
     my $log_messages_reached = 0;
     while (<>) {


@@ -2674,6 +2884,8 @@ sub VersionMessage {
 sub get_cli_options() {
 
     our %cli_options = (
 sub get_cli_options() {
 
     our %cli_options = (

+        'detect-inactivity'        => CLI_OPTION_DETECT_INACTIVITY,
+        'inactivity-threshold'     => CLI_OPTION_INACTIVITY_THRESHOLD,

         'html-output'              => CLI_OPTION_DEFAULT_TO_HTML_OUTPUT,
         'title'                    => CLI_OPTION_TITLE,
         'keep-date'                => CLI_OPTION_KEEP_DATE,
         'html-output'              => CLI_OPTION_DEFAULT_TO_HTML_OUTPUT,
         'title'                    => CLI_OPTION_TITLE,
         'keep-date'                => CLI_OPTION_KEEP_DATE,


@@ -2687,10 +2899,13 @@ sub get_cli_options() {
         'url-statistics-threshold' => CLI_OPTION_URL_STATISTICS_THRESHOLD,
         'unbreak-lines-only'       => CLI_OPTION_UNBREAK_LINES_ONLY,
         'host-statistics-threshold'=> CLI_OPTION_HOST_STATISTICS_THRESHOLD,
         'url-statistics-threshold' => CLI_OPTION_URL_STATISTICS_THRESHOLD,
         'unbreak-lines-only'       => CLI_OPTION_UNBREAK_LINES_ONLY,
         'host-statistics-threshold'=> CLI_OPTION_HOST_STATISTICS_THRESHOLD,

+        'passed-request-statistics-threshold' => CLI_OPTION_PASSED_REQUEST_STATISTICS_THRESHOLD,

         'show-complete-request-distribution' => CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION,
     );
 
     GetOptions (
         'show-complete-request-distribution' => CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION,
     );
 
     GetOptions (

+        'detect-inactivity'        => \$cli_options{'detect-inactivity'},
+        'inactivity-threshold=i'   => \$cli_options{'inactivity-threshold'},

         'html-output'              => \$cli_options{'html-output'},
         'title'                    => \$cli_options{'title'},
         'keep-date'                => \$cli_options{'keep-date'},
         'html-output'              => \$cli_options{'html-output'},
         'title'                    => \$cli_options{'title'},
         'keep-date'                => \$cli_options{'keep-date'},


@@ -2704,6 +2919,7 @@ sub get_cli_options() {
         'unbreak-lines-only'       => \$cli_options{'unbreak-lines-only'},
         'url-statistics-threshold=i'=> \$cli_options{'url-statistics-threshold'},
         'host-statistics-threshold=i'=> \$cli_options{'host-statistics-threshold'},
         'unbreak-lines-only'       => \$cli_options{'unbreak-lines-only'},
         'url-statistics-threshold=i'=> \$cli_options{'url-statistics-threshold'},
         'host-statistics-threshold=i'=> \$cli_options{'host-statistics-threshold'},

+        'passed-request-statistics-threshold=i' => \$cli_options{'passed-request-statistics-threshold'},

         'show-complete-request-distribution' => \$cli_options{'show-complete-request-distribution'},
         'version'                  => sub { VersionMessage && exit(0) },
         'help'                     => \&help,
         'show-complete-request-distribution' => \$cli_options{'show-complete-request-distribution'},
         'version'                  => sub { VersionMessage && exit(0) },
         'help'                     => \&help,


@@ -2725,6 +2941,8 @@ sub help() {
     print << "    EOF"
 
 Options and their default values if they have any:
     print << "    EOF"
 
 Options and their default values if they have any:

+    [--detect-innactivity]
+    [--inactivity-threshold $cli_options{'inactivity-threshold'}]

     [--host-statistics-threshold $cli_options{'host-statistics-threshold'}]
     [--html-output]
     [--no-embedded-css]
     [--host-statistics-threshold $cli_options{'host-statistics-threshold'}]
     [--html-output]
     [--no-embedded-css]


@@ -2736,6 +2954,7 @@ Options and their default values if they have any:
     [--statistics]
     [--unbreak-lines-only]
     [--url-statistics-threshold $cli_options{'url-statistics-threshold'}]
     [--statistics]
     [--unbreak-lines-only]
     [--url-statistics-threshold $cli_options{'url-statistics-threshold'}]

+    [--passed-request-statistics-threshold $cli_options{'passed-request-statistics-threshold'}]

     [--title $cli_options{'title'}]
     [--version]
 see "perldoc $0" for more information
     [--title $cli_options{'title'}]
     [--version]
 see "perldoc $0" for more information


@@ -2753,18 +2972,18 @@ sub main() {
     set_background(DEFAULT_BACKGROUND);
     prepare_our_stuff();
 
     set_background(DEFAULT_BACKGROUND);
     prepare_our_stuff();
 

-    print_intro();
-

     # XXX: should explicitly reject incompatible argument combinations
     if (cli_option_is_set('unbreak-lines-only')) {
         unbreak_lines_only_loop();
     } elsif (cli_option_is_set('statistics')) {
         stats_loop();
     # XXX: should explicitly reject incompatible argument combinations
     if (cli_option_is_set('unbreak-lines-only')) {
         unbreak_lines_only_loop();
     } elsif (cli_option_is_set('statistics')) {
         stats_loop();

+    } elsif (cli_option_is_set('detect-inactivity')) {
+        inactivity_detection_loop();

     } else {
     } else {

+        print_intro();

         parse_loop();
         parse_loop();

+        print_outro();

     }
     }

-
-    print_outro();

 }
 
 main();
 }
 
 main();


@@ -2775,7 +2994,8 @@ B<privoxy-log-parser> - A parser and syntax-highlighter for Privoxy log messages
 
 =head1 SYNOPSIS
 
 
 =head1 SYNOPSIS
 

-B<privoxy-log-parser> [B<--html-output>]
+B<privoxy-log-parser> [B<--detect-inactivity>] [B<--inactivity-threshold msecs>]
+[B<--html-output>]

 [B<--no-msecs>] [B<--no-syntax-higlighting>] [B<--statistics>]
 [B<--shorten-thread-ids>] [B<--show-ineffective-filters>]
 [B<--url-statistics-threshold>] [B<--version>]
 [B<--no-msecs>] [B<--no-syntax-higlighting>] [B<--statistics>]
 [B<--shorten-thread-ids>] [B<--show-ineffective-filters>]
 [B<--url-statistics-threshold>] [B<--version>]


@@ -2802,15 +3022,23 @@ will hide the "filter foo caused 0 hits" message.
 
 =head1 OPTIONS
 
 
 =head1 OPTIONS
 

+[B<--detect-inactivity>] Instead of syntax highlighting, detect periods
+of log inactivity of more than the amount of milliseconds specified with
+the B<--inactivity-threshold> option. Mainly useful for debugging.
+

 [B<--host-statistics-threshold>] Only show the request count for a host
 if it's above or equal to the given threshold. If the threshold is 0, host
 statistics are disabled.
 
 [B<--host-statistics-threshold>] Only show the request count for a host
 if it's above or equal to the given threshold. If the threshold is 0, host
 statistics are disabled.
 

-[B<--html-output>] Use HTML and CSS for the syntax highlighting. If this option is
+[B<--html-output>] Use HTML and CSS when 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 escape any input!
 
 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 escape any input!
 

+[B<--inactivity-threshold msecs>] Specifies the number of milliseconds between
+log messages to consider inactivity when running in [B<--detect-inactivity>]
+mode.
+

 [B<--keep-date>] Don't remove the date when printing highlighted log messages.
 Useful when parsing multiple log files at once.
 
 [B<--keep-date>] Don't remove the date when printing highlighted log messages.
 Useful when parsing multiple log files at once.
 


@@ -2821,6 +3049,10 @@ the filtered output is piped into less in which case the ANSI control
 codes don't work, or if the terminal itself doesn't support the control
 codes.
 
 codes don't work, or if the terminal itself doesn't support the control
 codes.
 

+[B<--passed-request-statistics-threshold>] Only show the request count for
+a passed requests if it's above or equal to the given threshold. If the
+threshold is 0, passed request statistics are disabled.
+

 [B<--shorten-thread-ids>] Shorten the thread ids to a three-digit decimal number.
 Note that the mapping from thread ids to shortened ids is created at run-time
 and thus varies with the input.
 [B<--shorten-thread-ids>] Shorten the thread ids to a three-digit decimal number.
 Note that the mapping from thread ids to shortened ids is created at run-time
 and thus varies with the input.


@@ -2903,7 +3135,7 @@ Many settings can't be controlled through command line options yet.
 
 =head1 SEE ALSO
 
 
 =head1 SEE ALSO
 

-privoxy(1)
+privoxy(8)

 
 =head1 AUTHOR
 
 
 =head1 AUTHOR