use Getopt::Long;
use constant {
- PRIVOXY_LOG_PARSER_VERSION => '0.9.1',
+ PRIVOXY_LOG_PARSER_VERSION => '0.9.2',
# Feel free to mess with these ...
DEFAULT_BACKGROUND => 'black', # Choose registered colour (like 'black')
DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
CLI_OPTION_DEFAULT_TO_HTML_OUTPUT => 0,
CLI_OPTION_TITLE => 'Privoxy-Log-Parser in da house',
+ CLI_OPTION_KEEP_DATE => 0,
CLI_OPTION_NO_EMBEDDED_CSS => 0,
CLI_OPTION_NO_MSECS => 0,
CLI_OPTION_NO_SYNTAX_HIGHLIGHTING => 0,
my $header_highlight_regex = '';
my $html_output_mode;
+my $keep_date_mode;
my $no_msecs_mode; # XXX: should probably be removed
my $shorten_thread_ids;
my $line_end;
return '';
}
- $c =~ s@(?<=\(size )(\d+)\)(?= with)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=\(size )(\d+)@$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'}@;
return '' unless SHOW_FILTER_READIN_IN;
+ } elsif ($c =~ m/^Decompression didn't result/) {
+
+ # Decompression didn't result in any content.
+
+ # Nothing to highlight.
+
} else {
found_unknown_content($content);
# Connection from 81.163.28.218 dropped due to ACL
# Rejecting connection from 178.63.152.227. Maximum number of connections reached.
- $c =~ s@(?<=onnection from )((?:\d+\.?){3}\d+)@$h{'Number'}$1$h{'Standard'}@;
+ # Connection from 192.168.2.1 on 127.0.1.1:8118 (socket 3) dropped due to ACL
+ $c = highlight_matched_host($c, '(?<=onnection from )[\d.:]+');
+ $c = highlight_matched_host($c, '(?<=on )[\d.:]+');
+ $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
} elsif ($c =~ m/^(?:Reusing|Closing) server socket / or
$c =~ m/^No additional client request/) {
# Reusing server socket 7 connected to www.privoxy.org. Total requests: 2.
# Closing server socket 6 connected to d.asset.soup.io. Keep-alive: 0.\
# Tainted: 1. Socket alive: 1. Timeout: 60. Configuration file change detected: 0.
+ # Reusing server socket 35 connected to nl.wikipedia.org. Requests already sent: 5.
$c =~ s@(?<= socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
$c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.)');
for my $number_pattern ('requests', 'Keep-alive', 'Tainted', ' alive', 'Timeout', 'detected') {
$c = highlight_matched_pattern($c, 'Number', '(?<='. $number_pattern . ': )\d+');
}
+ $c =~ s@(?<=already sent: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
} elsif ($c =~ m/^Connected to /) {
$c =~ s@(?<=Shifting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
$c =~ s@(?<=by )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ } elsif ($c =~ m/^Flushed (\d+) bytes of request body while expecting (\d+)/) {
+
+ # Flushed 30 bytes of request body while expecting 30
+ $c =~ s@(?<=Flushed )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=expecting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Performing the TLS\/SSL handshake with client. Hash of host:/) {
+
+ # Performing the TLS/SSL handshake with client. Hash of host: bab5296b25e256c7b06b92b17b56bcae
+ $c = highlight_matched_host($c, '(?<=Hash of host: ).+');
+
+ } elsif ($c =~ m/^Forwarding \d+ bytes of encrypted POST data/) {
+
+ # Forwarding 1954 bytes of encrypted POST data
+ $c =~ s@(?<=Forwarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Forwarded the last \d+ bytes/) {
+
+ # Forwarded the last 1954 bytes
+ $c =~ s@(?<=the last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Waiting for the next client connection. Currently active threads:/) {
+
+ # Waiting for the next client connection. Currently active threads: 30
+ $c =~ s@(?<=threads: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Data arrived in time on client socket/) {
+
+ # Data arrived in time on client socket 6. Requests so far: 3
+ $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=Requests so far: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Dropping the client connection on socket/) {
+
+ # Dropping the client connection on socket 71. The server connection has not been established yet.
+ $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^The client socket \d+ has become unusable while the server/) {
+
+ # The client socket 16 has become unusable while the server socket 24 is still open.
+ $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=server 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
our %cli_options;
# +0200] "GET https://www.youtube.com/watch?v=JmcA9LIIXWw HTTP/1.1" 200 68004
- $content =~ m/^[+-]\d{4}\] "(\w+) (.+) (HTTP\/\d\.\d)" (\d+) (\d+)/;
+ # +0200] "VERSION-CONTROL http://p.p/ HTTP/1.1" 200 2787
+ $content =~ m/^[+-]\d{4}\] "([^ ]+) (.+) (HTTP\/\d\.\d)" (\d+) (\d+)/;
$method = $1;
$resource = $2;
$http_version = $3;
$status_code = $4;
$size = $5;
+ $stats{requests_clf}++;
+
unless (defined $method) {
+ # +0200] "Invalid request" 400 0
+ return if ($content =~ m/^[+-]\d{4}\] "Invalid request"/);
print("Failed to parse: $content\n");
return;
}
$stats{'http-version'}{$http_version}++;
if ($cli_options{'host-statistics-threshold'} != 0) {
- $resource =~ m@(?:http[s]://)([^/]+)/?@;
+ $resource =~ m@(?:https?://)?([^/]+)/?@;
$stats{'hosts'}{$1}++;
}
$stats{'content-size-total'} += $size;
$stats{'status-code'}{$status_code}++;
- $stats{requests_clf}++;
}
sub gather_loglevel_request_stats($$) {
our %stats;
our %cli_options;
my $new_connections = $stats{requests} - $stats{crunches} - $stats{'reused-connections'};
- my $outgoing_requests = $stats{requests} - $stats{crunches};
my $client_requests_checksum = 0;
+ my $requests_total;
if ($stats{requests_clf} && $stats{requests}
&& $stats{requests_clf} != $stats{requests}) {
print "Inconsistent request counts: " . $stats{requests} . "/" . $stats{requests_clf} . "\n";
}
- if ($stats{requests_clf} && $stats{requests} eq 0) {
- $stats{requests} = $stats{requests_clf};
- }
- if ($stats{requests} eq 0) {
+ # To get the total number of requests we can use either the number
+ # of Common-Log-Format lines or the number of "Request:" messages.
+ # We prefer the number of CLF lines if available because using
+ # it works when analysing old log files from Privoxy versions before 3.0.29.
+ # In Privoxy 3.0.28 and earlier "Request:" messages excluded
+ # crunched messages.
+ $requests_total = $stats{requests_clf} ? $stats{requests_clf} : $stats{requests};
+
+ if ($requests_total 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 "Blocks: " . $stats{'blocked'} . " (" .
- get_percentage($stats{requests}, $stats{'blocked'}) . ")\n";
- print "Fast redirections: " . $stats{'fast-redirections'} . " (" .
- get_percentage($stats{requests}, $stats{'fast-redirections'}) . ")\n";
- print "Connection timeouts: " . $stats{'connection-timeout'} . " (" .
- get_percentage($stats{requests}, $stats{'connection-timeout'}) . ")\n";
- print "Connection failures: " . $stats{'connection-failure'} . " (" .
- get_percentage($stats{requests}, $stats{'connection-failure'}) . ")\n";
- print "Outgoing requests: " . $outgoing_requests . " (" .
- get_percentage($stats{requests}, $outgoing_requests) . ")\n";
+ print "Client requests total: " . $requests_total . "\n";
+ if ($stats{crunches}) {
+ my $outgoing_requests = $requests_total - $stats{crunches};
+ print "Crunches: " . $stats{crunches} . " (" .
+ get_percentage($requests_total, $stats{crunches}) . ")\n";
+ print "Blocks: " . $stats{'blocked'} . " (" .
+ get_percentage($requests_total, $stats{'blocked'}) . ")\n";
+ print "Fast redirections: " . $stats{'fast-redirections'} . " (" .
+ get_percentage($requests_total, $stats{'fast-redirections'}) . ")\n";
+ print "Connection timeouts: " . $stats{'connection-timeout'} . " (" .
+ get_percentage($requests_total, $stats{'connection-timeout'}) . ")\n";
+ print "Connection failures: " . $stats{'connection-failure'} . " (" .
+ get_percentage($requests_total, $stats{'connection-failure'}) . ")\n";
+ print "Outgoing requests: " . $outgoing_requests . " (" .
+ get_percentage($requests_total, $outgoing_requests) . ")\n";
+ } else {
+ print "No crunches detected. Is 'debug 1024' enabled?\n";
+ }
+
print "Server keep-alive offers: " . $stats{'server-keep-alive'} . " (" .
- get_percentage($stats{requests}, $stats{'server-keep-alive'}) . ")\n";
+ get_percentage($requests_total, $stats{'server-keep-alive'}) . ")\n";
print "New outgoing connections: " . $new_connections . " (" .
- get_percentage($stats{requests}, $new_connections) . ")\n";
+ get_percentage($requests_total, $new_connections) . ")\n";
print "Reused connections: " . $stats{'reused-connections'} . " (" .
- get_percentage($stats{requests}, $stats{'reused-connections'}) .
+ get_percentage($requests_total, $stats{'reused-connections'}) .
"; server offers accepted: " .
get_percentage($stats{'server-keep-alive'}, $stats{'reused-connections'}) . ")\n";
print "Empty responses: " . $stats{'empty-responses'} . " (" .
- get_percentage($stats{requests}, $stats{'empty-responses'}) . ")\n";
+ get_percentage($requests_total, $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'})
+ get_percentage($requests_total, $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'}) .
+ get_percentage($requests_total, $stats{'empty-responses-on-reused-connections'}) .
")\n";
print "Client connections: " . $stats{'closed-client-connections'} . "\n";
if ($stats{'content-size-total'}) {
- print "Bytes transfered excluding headers: " . $stats{'content-size-total'} . "\n";
+ print "Bytes of content transfered to the client: " . $stats{'content-size-total'} . "\n";
}
my $lines_printed = 0;
print "Client requests per connection distribution:\n";
printf "Enable --show-complete-request-distribution to get less common numbers as well.\n";
}
# Due to log rotation we may not have a complete picture for all the requests
- printf "Improperly accounted requests: ~%d\n", abs($stats{requests} - $client_requests_checksum);
+ printf "Improperly accounted requests: ~%d\n", abs($requests_total - $client_requests_checksum);
if (exists $stats{method}) {
print "Method distribution:\n";
} else {
print "Method distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
}
- print "Client HTTP versions:\n";
- foreach my $http_version (sort {$stats{'http-version'}{$b} <=> $stats{'http-version'}{$a}} keys %{$stats{'http-version'}}) {
- printf "%8d : %-8s\n", $stats{'http-version'}{$http_version}, $http_version;
+ if (exists $stats{'http-version'}) {
+ print "Client HTTP versions:\n";
+ foreach my $http_version (sort {$stats{'http-version'}{$b} <=> $stats{'http-version'}{$a}} keys %{$stats{'http-version'}}) {
+ printf "%8d : %-8s\n", $stats{'http-version'}{$http_version}, $http_version;
+ }
+ } else {
+ 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";
sub print_non_clf_message($) {
my $content = shift;
+ my $date_string = $keep_date_mode ? $req{$t}{'day'} . ' ' : '';
my $msec_string = $no_msecs_mode ? '' : '.' . $req{$t}{'msecs'};
my $line_start = $html_output_mode ? '' : $h{"Standard"};
return if DEBUG_SUPPRESS_LOG_MESSAGES;
print $line_start
+ . $date_string
. $time_colours[$time_colour_index % 2]
. $req{$t}{'time-stamp'}
. $msec_string
'Fatal error' => \&handle_loglevel_ignore,
'Writing' => \&handle_loglevel_ignore,
'Received' => \&handle_loglevel_ignore,
+ 'Tagging' => \&handle_loglevel_ignore,
'Actions' => \&handle_loglevel_ignore,
'Unknown log level' => \&handle_loglevel_ignore,
);
'Redirect:' => \&handle_loglevel_ignore,
'Unknown log level:' => \&handle_loglevel_ignore,
'Writing:' => \&handle_loglevel_ignore,
+ 'Tagging:' => \&handle_loglevel_ignore,
);
while (<>) {
our %cli_options = (
'html-output' => CLI_OPTION_DEFAULT_TO_HTML_OUTPUT,
'title' => CLI_OPTION_TITLE,
+ 'keep-date' => CLI_OPTION_KEEP_DATE,
'no-syntax-highlighting' => CLI_OPTION_NO_SYNTAX_HIGHLIGHTING,
'no-embedded-css' => CLI_OPTION_NO_EMBEDDED_CSS,
'no-msecs' => CLI_OPTION_NO_MSECS,
GetOptions (
'html-output' => \$cli_options{'html-output'},
'title' => \$cli_options{'title'},
+ 'keep-date' => \$cli_options{'keep-date'},
'no-syntax-highlighting' => \$cli_options{'no-syntax-highlighting'},
'no-embedded-css' => \$cli_options{'no-embedded-css'},
'no-msecs' => \$cli_options{'no-msecs'},
$html_output_mode = cli_option_is_set('html-output');
$no_msecs_mode = cli_option_is_set('no-msecs');
+ $keep_date_mode = cli_option_is_set('keep-date');
$shorten_thread_ids = cli_option_is_set('shorten-thread-ids');
$line_end = get_line_end();
}
This option is only intended to make embedding log excerpts in web pages easier.
It does not escape any input!
+[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-syntax-highlighting>] Disable syntax-highlighting. Useful when
projects / privoxy.git / blobdiff