use Getopt::Long;
use constant {
- PRIVOXY_LOG_PARSER_VERSION => '0.9.2',
+ PRIVOXY_LOG_PARSER_VERSION => '0.9.3',
# Feel free to mess with these ...
DEFAULT_BACKGROUND => 'black', # Choose registered colour (like 'black')
DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
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');
$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}$/) {
$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;
}
# [...]&filter... [too long, truncated]
$content = highlight_matched_pattern($content, 'request_', '^.*(?=\.\.\. \[too long, truncated\]$)');
+ } elsif ($content =~ m/Certificate error:/) {
+
+ # Certificate error: ASN date error, current date after: https://expired.badssl.com/
+ $content = highlight_matched_pattern($content, 'request_', 'https://.*');
+
} else {
# Blocked: http://ads.example.org/
} 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@(?<=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/) {
$c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
$c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ } elsif ($c =~ m/^The last \d+ bytes of the request body have been read/) {
+
+ # The last 12078 bytes of the request body have been read
+ $c =~ s@(?<=The last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Flushed \d+ bytes of request body/) {
+
+ # 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/^Looks like we / or
$c =~ m/^Unsetting keep-alive flag/ or
$c =~ m/^No connections to wait/ or
# Didn't receive data in time: a.fsdn.com:443
$c =~ s@(?<=in time: )(.*)@$h{'destination'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Sending data on socket \d+ over TLS/) {
+
+ # 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'}@;
+
}
# XXX: There are probably more messages that deserve highlighting.
unless (defined $method) {
# +0200] "Invalid request" 400 0
return if ($content =~ m/^[+-]\d{4}\] "Invalid request"/);
- print("Failed to parse: $content\n");
+ # +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");
+ } else {
+ print("Failed to parse: $content\n");
+ }
return;
}
$stats{'method'}{$method}++;
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";
")\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";
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;
}
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,
[B<--keep-date>] Don't remove the date when printing highlighted log messages.
Useful when parsing multiple log files at once.
-[B<--no-msecs>] Don't expect milisecond resolution
+[B<--no-msecs>] Don't expect millisecond resolution
[B<--no-syntax-highlighting>] Disable syntax-highlighting. Useful when
the filtered output is piped into less in which case the ANSI control
=head1 SEE ALSO
-privoxy(1)
+privoxy(8)
=head1 AUTHOR