X-Git-Url: http://www.privoxy.org/gitweb/?a=blobdiff_plain;f=tools%2Fprivoxy-log-parser.pl;h=04d5865658f57f959d631a9bc545d135f474edc1;hb=a1abf1b337b97a725db41349b37fac4ecc6a4827;hp=9ef389d817c1577502ff6c5e680dab0de6c1200c;hpb=e6d86c5315c2f0e6bbf9b6e9cf496f72dc0660af;p=privoxy.git diff --git a/tools/privoxy-log-parser.pl b/tools/privoxy-log-parser.pl index 9ef389d8..04d58656 100755 --- 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. # -# Copyright (c) 2007-2020 Fabian Keil +# Copyright (c) 2007-2021 Fabian Keil # # Permission to use, copy, modify, and distribute this software for any # purpose with or without fee is hereby granted, provided that the above @@ -43,7 +43,7 @@ use warnings; 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') @@ -644,7 +644,7 @@ sub highlight_request_line($) { 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'); @@ -1078,6 +1078,17 @@ sub handle_loglevel_re_filter($) { $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}$/) { @@ -1245,7 +1256,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'}@; + + } 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; } @@ -1422,6 +1464,11 @@ sub handle_loglevel_crunch($) { # [...]&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/ @@ -1816,7 +1863,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. + # 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/) { @@ -1824,6 +1875,26 @@ sub handle_loglevel_connect($) { $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/^Looks like we / or $c =~ m/^Unsetting keep-alive flag/ or $c =~ m/^No connections to wait/ or @@ -2057,6 +2128,19 @@ sub handle_loglevel_error($) { # 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. @@ -2090,7 +2174,14 @@ sub gather_loglevel_clf_stats($) { 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}++; @@ -2303,7 +2394,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"; - 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"; @@ -2319,7 +2410,7 @@ sub print_stats() { ")\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"; @@ -2358,7 +2449,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 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; } @@ -2564,7 +2655,7 @@ sub parse_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, @@ -2788,7 +2879,7 @@ 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-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 @@ -2877,7 +2968,7 @@ Many settings can't be controlled through command line options yet. =head1 SEE ALSO -privoxy(1) +privoxy(8) =head1 AUTHOR