X-Git-Url: http://www.privoxy.org/gitweb/?p=privoxy.git;a=blobdiff_plain;f=tools%2Fprivoxy-log-parser.pl;h=dce3b3150d9e445738b107416b436fe8f0eec12b;hp=11ad7a88626f8fc38dfc28faba7de3a8604e6ece;hb=b5ce79b11f3159a17e6c519b1eb95b50d3fac350;hpb=21f4151998a8cde9deaa0def4986937ba87776d4 diff --git a/tools/privoxy-log-parser.pl b/tools/privoxy-log-parser.pl index 11ad7a88..dce3b315 100755 --- a/tools/privoxy-log-parser.pl +++ b/tools/privoxy-log-parser.pl @@ -1061,7 +1061,7 @@ sub handle_loglevel_re_filter($) { 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'}@; @@ -1210,6 +1210,12 @@ sub handle_loglevel_re_filter($) { 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); @@ -1610,7 +1616,10 @@ sub handle_loglevel_connect($) { # 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/) { @@ -1624,6 +1633,7 @@ sub handle_loglevel_connect($) { # 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]+(?=\.)'); @@ -1631,6 +1641,7 @@ sub handle_loglevel_connect($) { 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 /) { @@ -1735,6 +1746,49 @@ sub handle_loglevel_connect($) { $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 @@ -1988,14 +2042,19 @@ sub gather_loglevel_clf_stats($) { 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; } @@ -2006,12 +2065,11 @@ sub gather_loglevel_clf_stats($) { $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($$) { @@ -2167,60 +2225,66 @@ sub print_stats() { our %cli_options; my $new_connections = $stats{requests} - $stats{crunches} - $stats{'reused-connections'}; 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 "Client requests total: " . $requests_total . "\n"; if ($stats{crunches}) { - my $outgoing_requests = $stats{requests} - $stats{crunches}; + my $outgoing_requests = $requests_total - $stats{crunches}; print "Crunches: " . $stats{crunches} . " (" . - get_percentage($stats{requests}, $stats{crunches}) . ")\n"; + get_percentage($requests_total, $stats{crunches}) . ")\n"; print "Blocks: " . $stats{'blocked'} . " (" . - get_percentage($stats{requests}, $stats{'blocked'}) . ")\n"; + get_percentage($requests_total, $stats{'blocked'}) . ")\n"; print "Fast redirections: " . $stats{'fast-redirections'} . " (" . - get_percentage($stats{requests}, $stats{'fast-redirections'}) . ")\n"; + get_percentage($requests_total, $stats{'fast-redirections'}) . ")\n"; print "Connection timeouts: " . $stats{'connection-timeout'} . " (" . - get_percentage($stats{requests}, $stats{'connection-timeout'}) . ")\n"; + get_percentage($requests_total, $stats{'connection-timeout'}) . ")\n"; print "Connection failures: " . $stats{'connection-failure'} . " (" . - get_percentage($stats{requests}, $stats{'connection-failure'}) . ")\n"; + get_percentage($requests_total, $stats{'connection-failure'}) . ")\n"; print "Outgoing requests: " . $outgoing_requests . " (" . - get_percentage($stats{requests}, $outgoing_requests) . ")\n"; + 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"; @@ -2240,7 +2304,7 @@ sub print_stats() { 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"; @@ -2250,9 +2314,13 @@ sub print_stats() { } 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";