X-Git-Url: http://www.privoxy.org/gitweb/?p=privoxy.git;a=blobdiff_plain;f=tools%2Fprivoxy-log-parser.pl;h=481455f56e0209f1d18d114961d09b85b51689e9;hp=6da4a133177016ea54d2821cdf386048e69229ce;hb=e0a1365d9a42490e6063603b2bde1c2f50915298;hpb=f49cb64f716c2364845c45ebf45f091a35dc144f diff --git a/tools/privoxy-log-parser.pl b/tools/privoxy-log-parser.pl index 6da4a133..481455f5 100755 --- a/tools/privoxy-log-parser.pl +++ b/tools/privoxy-log-parser.pl @@ -8,7 +8,7 @@ # # http://www.fabiankeil.de/sourcecode/privoxy-log-parser/ # -# $Id: privoxy-log-parser.pl,v 1.75 2010/01/11 11:47:59 fabiankeil Exp $ +# $Id: privoxy-log-parser.pl,v 1.140 2012/10/21 13:00:36 fabiankeil Exp $ # # TODO: # - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting @@ -23,8 +23,9 @@ # - Handle incomplete input without Perl warning about undefined variables. # - Use generic highlighting function that takes a regex and the # hash key as input. +# - Add --compress and --decompress options. # -# Copyright (c) 2007-2009 Fabian Keil +# Copyright (c) 2007-2010 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 @@ -44,7 +45,7 @@ use warnings; use Getopt::Long; use constant { - PRIVOXY_LOG_PARSER_VERSION => '0.6', + PRIVOXY_LOG_PARSER_VERSION => '0.7', # Feel free to mess with these ... DEFAULT_BACKGROUND => 'black', # Choose registered colour (like 'black') DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black') @@ -56,16 +57,19 @@ use constant { CLI_OPTION_NO_EMBEDDED_CSS => 0, CLI_OPTION_NO_MSECS => 0, CLI_OPTION_NO_SYNTAX_HIGHLIGHTING => 0, + CLI_OPTION_SHORTEN_THREAD_IDS => 0, CLI_OPTION_SHOW_INEFFECTIVE_FILTERS => 0, CLI_OPTION_ACCEPT_UNKNOWN_MESSAGES => 0, CLI_OPTION_STATISTICS => 0, + CLI_OPTION_UNBREAK_LINES_ONLY => 0, + CLI_OPTION_URL_STATISTICS_THRESHOLD => 0, + CLI_OPTION_HOST_STATISTICS_THRESHOLD => 0, SUPPRESS_SUCCEEDED_FILTER_ADDITIONS => 1, SHOW_SCAN_INTRO => 0, SHOW_FILTER_READIN_IN => 0, SUPPRESS_EMPTY_LINES => 1, SUPPRESS_SUCCESSFUL_CONNECTIONS => 1, - SUPPRESS_ACCEPTED_CONNECTIONS => 1, SUPPRESS_GIF_NOT_CHANGED => 1, SUPPRESS_NEED_TO_DE_CHUNK_FIRST => 1, @@ -105,6 +109,7 @@ my $header_highlight_regex = ''; my $html_output_mode; my $no_msecs_mode; # XXX: should probably be removed +my $shorten_thread_ids; my $line_end; sub prepare_our_stuff () { @@ -132,6 +137,8 @@ sub prepare_our_stuff () { 'Gif-Deanimate' => 'blue', Force => 'red', Writing => 'light_green', + Received => 'yellow', + Actions => 'yellow', # ---------------------- URL => 'yellow', path => 'brown', @@ -172,6 +179,7 @@ sub prepare_our_stuff () { 'action-bits-update' => 'light_red', 'configuration-line' => 'red', 'content-type' => 'yellow', + 'HOST' => HEADER_DEFAULT_COLOUR, ); %h_colours = %h; @@ -219,7 +227,7 @@ sub paint_it ($) { # XXX: The Rolling Stones reference has to go. ############################################################### - my $colour = shift @_; + my $colour = shift; return "" if cli_option_is_set('no-syntax-highlighting'); @@ -294,7 +302,7 @@ sub get_semantic_html_markup ($) { # Takes a string and returns a span element ############################################################### - my $type = shift @_; + my $type = shift; my $code; if ($type =~ /Standard/) { @@ -467,7 +475,7 @@ sub get_colour_html_markup ($) { # markup should always be semantically correct. ############################################################### - my $type = shift @_; + my $type = shift; my $code; if ($type =~ /Standard/) { @@ -564,9 +572,9 @@ sub log_parse_error ($) { my $message = shift; if (LOG_UNPARSED_LINES_TO_EXTRA_FILE) { - open(ERRORLOG, ">>" . ERROR_LOG_FILE) || die "Writing " . ERROR_LOG_FILE . " failed"; - print ERRORLOG $message; - close(ERRORLOG); + open(my $errorlog_fd, ">>", ERROR_LOG_FILE) || die "Writing " . ERROR_LOG_FILE . " failed"; + print $errorlog_fd $message; + close($errorlog_fd); } } @@ -801,19 +809,14 @@ sub handle_loglevel_header ($) { update_header_highlight_regex($header); } - } elsif ($c =~ m/^scan: ((\w+) (.+) (HTTP\/\d\.\d))/) { - - # Client request line - # Save for statistics (XXX: Not implemented yet) - $req{$t}{'method'} = $2; - $req{$t}{'destination'} = $3; - $req{$t}{'http-version'} = $4; + } elsif ($c =~ m/^(scan: )(\w+ .+ HTTP\/\d\.\d)/) { - $c = highlight_request_line($1); + # scan: GET http://p.p/ HTTP/1.1 + $c = $1 . highlight_request_line($2); } elsif ($c =~ m/^(scan: )((?:HTTP\/\d\.\d|ICY) (\d+) (.*))/) { - # Server response line + # scan: HTTP/1.1 200 OK $req{$t}{'response_line'} = $2; $req{$t}{'status_code'} = $3; $req{$t}{'status_message'} = $4; @@ -908,6 +911,10 @@ sub handle_loglevel_header ($) { or $c =~ m/^Appended client IP address to/ or $c =~ m/^Removing 'Connection: close' to imply keep-alive./ or $c =~ m/^keep-alive support is disabled/ + or $c =~ m/^Continue hack in da house/ + or $c =~ m/^Merged multiple header lines to:/ + or $c =~ m/^Added header: / + or $c =~ m/^Enlisting (?:sorted|left-over) header/ ) { # XXX: Some of these may need highlighting @@ -953,6 +960,11 @@ sub handle_loglevel_header ($) { # Appended client IP address to X-Forwarded-For: 10.0.0.2, 10.0.0.1 # Removing 'Connection: close' to imply keep-alive. # keep-alive support is disabled. Crunching: Keep-Alive: 300. + # Continue hack in da house. + # Merged multiple header lines to: 'X-FORWARDED-PROTO: http X-HOST: 127.0.0.1' + # Added header: Content-Encoding: deflate + # Enlisting sorted header User-Agent: Mozilla/5.0 (X11; SunOS i86pc; rv:10.0.3) Gecko/20100101 Firefox/10.0.3 + # Enlisting left-over header Connection: close } elsif ($c =~ m/^scanning headers for:/) { @@ -1005,6 +1017,12 @@ sub handle_loglevel_header ($) { $c =~ s@(?<= from )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<= to )(\d+)@$h{'Number'}$1$h{'Standard'}@; + } elsif ($c =~ m/^Killed all-caps Host header line: HOST:/) { + + # Killed all-caps Host header line: HOST: bestproxydb.com + $c = highlight_matched_host($c, '(?<=HOST: )[^\s]+'); + $c = highlight_matched_pattern($c, 'HOST', 'HOST'); + } else { found_unknown_content($c); @@ -1180,6 +1198,13 @@ sub handle_loglevel_re_filter ($) { # Adding dynamic re_filter job s@^(?:\w*)\s+.*\s+HTTP/\d\.\d\s*@IP-ADDRESS: $origin@D\ # to filter client-ip-address succeeded. + } elsif ($c =~ m/^Compressed content from /) { + + # Compressed content from 29258 to 8630 bytes. Compression level: 3 + $content =~ s@(?<=from )(\d+)@$h{'Number'}$1$h{'Standard'}@; + $content =~ s@(?<=to )(\d+)@$h{'Number'}$1$h{'Standard'}@; + $content =~ s@(?<=level: )(\d+)@$h{'Number'}$1$h{'Standard'}@; + } elsif ($c =~ m/^Reading in filter/) { return '' unless SHOW_FILTER_READIN_IN; @@ -1245,6 +1270,11 @@ sub handle_loglevel_redirect ($) { # XXX: assume the same? $c = highlight_matched_url($c, '(?<=assuming that \")[^"]*'); + } elsif ($c =~ m/^Percent-encoding redirect/) { + + # Percent-encoding redirect URL: http://www.example.org/\x02 + $c = highlight_matched_url($c, '(?<=redirect URL: ).*'); + } else { found_unknown_content($c); @@ -1287,7 +1317,7 @@ sub handle_loglevel_gif_deanimate ($) { } elsif ($content =~ m/^(?:No GIF header found|failed while parsing)/) { # No GIF header found (XXX: Did I ever commit this?) - # failed while parsing 195 134747048 (XXX: never commited) + # failed while parsing 195 134747048 (XXX: never committed) # Ignore these for now @@ -1392,14 +1422,31 @@ sub handle_loglevel_connect ($) { $c = highlight_matched_host($c, '(?<=to )[^\s]+'); - } elsif ($c =~ m/^accepted connection from .*/ or + } elsif ($c =~ m/^[Aa]ccepted connection from .*/ or $c =~ m/^OK/) { - # accepted connection from 10.0.0.1 + # Privoxy 3.0.20: + # Accepted connection from 10.0.0.1 on socket 5 + # Privoxy between 3.0.20 and 3.0.6: + # accepted connection from 10.0.0.1( on socket 5)? # Privoxy 3.0.6 and earlier just say: # OK - return '' if SUPPRESS_ACCEPTED_CONNECTIONS; - $c = highlight_matched_host($c, '(?<=connection from ).*'); + $c = highlight_matched_host($c, '(?<=connection from )[^ ]*'); + $c = highlight_matched_pattern($c, 'Number', '(?<=socket )\d+'); + + } elsif ($c =~ m/^Closing client socket/) { + + # Closing client socket 5. Keep-alive: 0, Socket alive: 1. Data available: 0. + # Privoxy 3.0.20 and later + # Closing client socket 8. Keep-alive: 1. Socket alive: 0. Data available: 0. \ + # Configuration file change detected: 0. Requests received: 11. + + $c = highlight_matched_pattern($c, 'Number', '(?<=socket )\d+'); + $c = highlight_matched_pattern($c, 'Number', '(?<=Keep-alive: )\d+'); + $c = highlight_matched_pattern($c, 'Number', '(?<=Socket alive: )\d+'); + $c = highlight_matched_pattern($c, 'Number', '(?<=available: )\d+'); + $c = highlight_matched_pattern($c, 'Number', '(?<=detected: )\d+'); + $c = highlight_matched_pattern($c, 'Number', '(?<=received: )\d+'); } elsif ($c =~ m/^write header to: .* failed:/) { @@ -1504,10 +1551,17 @@ sub handle_loglevel_connect ($) { $c =~ s@(?<=Timeout is: )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=Assumed latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@; - } elsif ($c =~ m/^Stopped waiting for the request line./) { + } elsif ($c =~ m/^Stopped waiting for the request line/ 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. + # Privoxy 3.0.19 and later: + # No request line on socket 5 received in time. Timeout: 1. + # The client side of the connection on socket 5 got closed \ + # without sending a complete request line. $c =~ s@(?<=Timeout: )(\d+)@$h{'Number'}$1$h{'Standard'}@; + $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@; } elsif ($c =~ m/^Waiting for \d/) { @@ -1532,15 +1586,18 @@ sub handle_loglevel_connect ($) { $c =~ s@(?<=received: )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@; - } elsif ($c =~ m/^Continuing buffering headers/) { + } elsif ($c =~ m/^Continuing buffering (?:server )?headers/) { # Continuing buffering headers. byte_count: 19. header_offset: 517. len: 536. $c =~ s@(?<=byte_count: )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=header_offset: )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=len: )(\d+)@$h{'Number'}$1$h{'Standard'}@; - # 3.0.15 and later: - # Continuing buffering headers. Bytes most recently read: %d. + # 3.0.15 up to 3.0.19: + # Continuing buffering headers. Bytes most recently read: 498. $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@; + # 3.0.20 and later: + # Continuing buffering server headers from socket 5. Bytes most recently read: 498. + $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@; } elsif ($c =~ m/^Received \d+ bytes while/) { @@ -1548,10 +1605,11 @@ sub handle_loglevel_connect ($) { $c =~ s@(?<=Received )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=expecting )(\d+)@$h{'Number'}$1$h{'Standard'}@; - } elsif ($c =~ m/^Connection from/) { + } elsif ($c =~ m/^(Rejecting c|C)onnection from/) { # Connection from 81.163.28.218 dropped due to ACL - $c =~ s@(?<=^Connection from )((?:\d+\.?){4})@$h{'Number'}$1$h{'Standard'}@; + # Rejecting connection from 178.63.152.227. Maximum number of connections reached. + $c =~ s@(?<=onnection from )((?:\d+\.?){3}\d+)@$h{'Number'}$1$h{'Standard'}@; } elsif ($c =~ m/^(?:Reusing|Closing) server socket \d./ or $c =~ m/^No additional client request/) { @@ -1582,13 +1640,19 @@ sub handle_loglevel_connect ($) { } elsif ($c =~ m/^Waiting for the next client request/ or $c =~ m/^The connection on server socket/ or - $c =~ m/^Client request arrived in time or the client closed the connection/) { + $c =~ m/^Client request (?:\d+ )?arrived in time /) { # Waiting for the next client request on socket 3. Keeping the server \ # socket 12 to a.fsdn.com open. # The connection on server socket 6 to upload.wikimedia.org isn't reusable. Closing. + # Privoxy 3.0.20 and later: + # Client request 4 arrived in time on socket 7. + # Used by Privoxy 3.0.18 and 3.0.19: + # Client request arrived in time on socket 21. + # Used by earlier version: # Client request arrived in time or the client closed the connection on socket 12. + $c =~ s@(?<=request )(\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, '(?<=to )[^\s]+'); @@ -1617,12 +1681,25 @@ sub handle_loglevel_connect ($) { $c =~ s@(?<=set to )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=reading )(\d+)@$h{'Number'}$1$h{'Standard'}@; + } elsif ($c =~ m/^Reducing expected bytes to /) { + + # Reducing expected bytes to 0. Marking the server socket tainted after throwing 4 bytes away. + $c =~ s@(?<=bytes to )(\d+)@$h{'Number'}$1$h{'Standard'}@; + $c =~ s@(?<=after throwing )(\d+)@$h{'Number'}$1$h{'Standard'}@; + } elsif ($c =~ m/^Waiting for up to /) { # Waiting for up to 4999 bytes from the client. $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@; - } elsif ($c =~ m/^Looks like we rea/ or + } elsif ($c =~ m/^Stopping to watch the client socket/) { + + # Stopping to watch the client socket. There's already another request waiting. + # Privoxy 3.0.20 and later: + # Stopping to watch the client socket 5. There's already another request waiting. + $c =~ s@(?<=client 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 $c =~ m/^Complete client request received/ or @@ -1631,12 +1708,13 @@ sub handle_loglevel_connect ($) { $c =~ m/^The server still wants to talk, but the client hung up on us./ or $c =~ m/^The server didn't specify how long the connection will stay open/ or $c =~ m/^There might be a request body. The connection will not be kept alive/ or - $c =~ m/^Stopping to watch the client socket. There's already another request waiting./ or $c =~ m/^Done reading from the client\.$/) { # Looks like we reached the end of the last chunk. We better stop reading. # Looks like we read the end of the last chunk together with the server \ # headers. We better stop reading. + # Looks like we got the last chunk together with the server headers. \ + # We better stop reading. # Unsetting keep-alive flag. # No connections to wait for left. # Client request arrived in time or the client closed the connection. @@ -1647,7 +1725,6 @@ sub handle_loglevel_connect ($) { # The server still wants to talk, but the client hung up on us. # The server didn't specify how long the connection will stay open. Assume it's only a second. # There might be a request body. The connection will not be kept alive. - # Stopping to watch the client socket. There's already another request waiting. # Done reading from the client\. } else { @@ -1671,12 +1748,15 @@ sub handle_loglevel_info ($) { } elsif ($c =~ m/^Decompress(ing deflated|ion didn)/ or $c =~ m/^Compressed content detected/ or + $c =~ m/^SDCH-compressed content detected/ or $c =~ m/^Tagger/ ) { # Decompressing deflated iob: 117 # Decompression didn't result in any content. # Compressed content detected, content filtering disabled. Consider recompiling Privoxy\ # with zlib support or enable the prevent-compression action. + # SDCH-compressed content detected, content filtering disabled.\ + # Consider suppressing SDCH offers made by the client. # Tagger 'complete-url' created empty tag. Ignored. # Ignored for now @@ -1687,6 +1767,12 @@ sub handle_loglevel_info ($) { # Reloading configuration file '/usr/local/etc/privoxy/config' $c =~ s@(?<=loading configuration file \')([^\']*)@$h{'file'}$1$h{'Standard'}@; + } elsif ($c =~ m/^Loading (actions|filter) file: /) { + + # Loading actions file: /usr/local/etc/privoxy/default.action + # Loading filter file: /usr/local/etc/privoxy/default.filter + $c =~ s@(?<= file: )(.*)$@$h{'file'}$1$h{'Standard'}@; + } elsif ($c =~ m/^exiting by signal/) { # exiting by signal 15 .. bye @@ -1717,12 +1803,15 @@ sub handle_loglevel_info ($) { # Request from 10.0.0.1 denied. limit-connect{,} doesn't allow CONNECT requests to port 443. # Request from 10.0.0.1 marked for blocking. limit-connect{,} doesn't allow CONNECT requests to port 443. + # 3.0.18 and later: + # Request from 10.0.0.1 marked for blocking. limit-connect{0} doesn't allow CONNECT requests to www.example.org:443 # Malformed server response detected. Downgrading to HTTP/1.0 impossible. $c =~ s@(?<=Request from )([^\s]*)@$h{'ip-address'}$1$h{'Standard'}@; $c =~ s@(denied|blocking)@$h{'warning'}$1$h{'Standard'}@; $c =~ s@(CONNECT)@$h{'method'}$1$h{'Standard'}@; $c =~ s@(?<=to port )(\d+)@$h{'port'}$1$h{'Standard'}@; + $c =~ s@(?<=to )([^\s]+)@$h{'request_'}$1$h{'Standard'}@; } elsif ($c =~ m/^Status code/) { @@ -1740,11 +1829,17 @@ sub handle_loglevel_info ($) { $c =~ s@(?<=Needed: )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=Limit: )(\d+)@$h{'Number'}$1$h{'Standard'}@; + } elsif ($c =~ m/^File modification detected: /) { + + # File modification detected: /usr/local/etc/privoxy/user-agent.action + $c =~ s@(?<= detected: )(.*)$@$h{'file'}$1$h{'Standard'}@; + } elsif ($c =~ m/^No logfile configured/ or $c =~ m/^Malformerd HTTP headers detected and MS IIS5 hack enabled/ or $c =~ m/^Invalid \"chunked\" transfer/ or $c =~ m/^Support for/ or - $c =~ m/^Flushing header and buffers/ + $c =~ m/^Flushing header and buffers/ or + $c =~ m/^Can not resolve/ ) { # No logfile configured. Please enable it before reporting any problems. @@ -1755,6 +1850,7 @@ sub handle_loglevel_info ($) { # Support for 'Connection: keep-alive' is experimental, incomplete and\ # known not to work properly in some situations. # Flushing header and buffers. Stepping back from filtering. + # Can not resolve doesnotexist: hostname nor servname provided, or not known } else { @@ -1815,14 +1911,24 @@ sub handle_loglevel_error ($) { my $c = shift; - if ($c =~ m/^Empty server or forwarder response received on socket \d+./) { + if ($c =~ m/^(?:Empty|No) server or forwarder response received on socket \d+\./) { # Empty server or forwarder response received on socket 4. # Empty server or forwarder response received on socket 3. \ # Closing client socket 15 without sending data. + # Used by Privoxy 3.0.18 and later: + # No server or forwarder response received on socket 8. \ + # Closing client socket 10 without sending data. + $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@; $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@; + + } elsif ($c =~ m/^Didn't receive data in time:/) { + + # Didn't receive data in time: a.fsdn.com:443 + $c =~ s@(?<=in time: )(.*)@$h{'destination'}$1$h{'Standard'}@; } + # XXX: There are probably more messages that deserve highlighting. return $c; @@ -1848,6 +1954,15 @@ sub gather_loglevel_crunch_stats ($$) { $stats{requests}++; $stats{crunches}++; + + if ($c =~ m/^Redirected:/) { + # Redirected: http://www.example.org/http://p.p/ + $stats{'fast-redirections'}++; + + } elsif ($c =~ m/^Blocked:/) { + # Blocked: blogger.googleusercontent.com:443 + $stats{'blocked'}++; + } } @@ -1915,6 +2030,18 @@ sub gather_loglevel_header_stats ($$) { # A HTTP/1.1 response without Connection header implies keep-alive. # Keeping the server header 'Connection: keep-alive' around. $stats{'server-keep-alive'}++; + + } elsif ($c =~ m/^scan: ((\w+) (.+) (HTTP\/\d\.\d))/) { + + # scan: HTTP/1.1 200 OK + $stats{'method'}{$2}++; + $stats{'resource'}{$3}++; + $stats{'http-version'}{$4}++; + + } elsif ($c =~ m/^scan: Host: ([^\s]+)/) { + + # scan: Host: p.p + $stats{'hosts'}{$1}++; } } @@ -1927,19 +2054,32 @@ sub init_stats () { 'empty-responses' => 0, 'empty-responses-on-new-connections' => 0, 'empty-responses-on-reused-connections' => 0, + 'fast-redirections' => 0, + 'blocked' => 0, + 'reused-connections' => 0, + 'server-keep-alive' => 0, ); } sub get_percentage ($$) { my $big = shift; my $small = shift; + + # If small is 0 the percentage is always 0%. + # Make sure it works even if big is 0 as well. + return "0.00%" if ($small eq 0); + + # Prevent division by zero. + # XXX: Is this still supposed to be reachable? return "NaN" if ($big eq 0); + return sprintf("%.2f%%", $small / $big * 100); } sub print_stats () { our %stats; + our %cli_options; my $new_connections = $stats{requests} - $stats{crunches} - $stats{'reused-connections'}; my $outgoing_requests = $stats{requests} - $stats{crunches}; @@ -1951,6 +2091,10 @@ sub print_stats () { 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 "Outgoing requests: " . $outgoing_requests . " (" . get_percentage($stats{requests}, $outgoing_requests) . ")\n"; print "Server keep-alive offers: " . $stats{'server-keep-alive'} . " (" . @@ -1958,7 +2102,9 @@ sub print_stats () { print "New outgoing connections: " . $new_connections . " (" . get_percentage($stats{requests}, $new_connections) . ")\n"; print "Reused connections: " . $stats{'reused-connections'} . " (" . - get_percentage($stats{requests}, $stats{'reused-connections'}) . ")\n"; + get_percentage($stats{requests}, $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"; print "Empty responses on new connections: " @@ -1969,6 +2115,45 @@ sub print_stats () { $stats{'empty-responses-on-reused-connections'} . " (" . get_percentage($stats{requests}, $stats{'empty-responses-on-reused-connections'}) . ")\n"; + + if ($stats{method} eq 0) { + print "No response lines parsed yet yet.\n"; + return; + } + print "Method distribution:\n"; + foreach my $method (sort {$stats{'method'}{$b} <=> $stats{'method'}{$a}} keys %{$stats{'method'}}) { + printf "%8d : %-8s\n", $stats{'method'}{$method}, $method; + } + print "Client HTTP versions:\n"; + foreach my $http_version (sort {$stats{'http-version'}{$b} <=> $stats{'http-version'}{$a}} keys %{$stats{'http-version'}}) { + printf "%d : %s\n", $stats{'http-version'}{$http_version}, $http_version; + } + + if ($cli_options{'url-statistics-threshold'} == 0) { + print "URL statistics are disabled. Increase --url-statistics-threshold to enable them.\n"; + } else { + print "Requested URLs:\n"; + foreach my $resource (sort {$stats{'resource'}{$b} <=> $stats{'resource'}{$a}} keys %{$stats{'resource'}}) { + if ($stats{'resource'}{$resource} < $cli_options{'url-statistics-threshold'}) { + print "Skipped statistics for URLs below the treshold.\n"; + last; + } + printf "%d : %s\n", $stats{'resource'}{$resource}, $resource; + } + } + + if ($cli_options{'host-statistics-threshold'} == 0) { + print "Host statistics are disabled. Increase --host-statistics-threshold to enable them.\n"; + } else { + print "Requested Hosts:\n"; + foreach my $host (sort {$stats{'hosts'}{$b} <=> $stats{'hosts'}{$a}} keys %{$stats{'hosts'}}) { + if ($stats{'hosts'}{$host} < $cli_options{'host-statistics-threshold'}) { + print "Skipped statistics for Hosts below the treshold.\n"; + last; + } + printf "%d : %s\n", $stats{'hosts'}{$host}, $host; + } + } } @@ -2001,7 +2186,7 @@ sub print_clf_message () { sub print_non_clf_message ($) { my $content = shift; - my $msec_string = "." . $req{$t}{'msecs'} unless $no_msecs_mode; + my $msec_string = $no_msecs_mode ? '' : '.' . $req{$t}{'msecs'}; my $line_start = $html_output_mode ? '' : $h{"Standard"}; return if DEBUG_SUPPRESS_LOG_MESSAGES; @@ -2023,6 +2208,20 @@ sub print_non_clf_message ($) { . $line_end; } +sub shorten_thread_id ($) { + + my $thread_id = shift; + + our %short_thread_ids; + our $max_threadid; + + unless (defined $short_thread_ids{$thread_id}) { + $short_thread_ids{$thread_id} = sprintf "%.3d", $max_threadid++; + } + + return $short_thread_ids{$thread_id} +} + sub parse_loop () { my ($day, $time_stamp, $thread, $log_level, $content, $c, $msecs); @@ -2048,13 +2247,15 @@ sub parse_loop () { 'Error' => \&handle_loglevel_error, 'Fatal error' => \&handle_loglevel_ignore, 'Writing' => \&handle_loglevel_ignore, + 'Received' => \&handle_loglevel_ignore, + 'Actions' => \&handle_loglevel_ignore, 'Unknown log level' => \&handle_loglevel_ignore, ); while (<>) { - if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) { - $thread = $t = $4; + if (m/^(\d{4}-\d{2}-\d{2}|\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) { + $thread = $t = ($shorten_thread_ids) ? shorten_thread_id($4) : $4; $req{$t}{'day'} = $day = $1; $req{$t}{'time-stamp'} = $time_stamp = $2; $req{$t}{'msecs'} = $msecs = $3 ? $3 : 0; # Only the cool kids have micro second resolution; @@ -2138,11 +2339,13 @@ sub stats_loop () { 'Error' => \&gather_loglevel_error_stats, 'Fatal error' => \&handle_loglevel_ignore, 'Writing' => \&handle_loglevel_ignore, + 'Received' => \&handle_loglevel_ignore, + 'Actions' => \&handle_loglevel_ignore, 'Unknown log level' => \&handle_loglevel_ignore ); while (<>) { - if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) { + if (m/^(\d{4}-\d{2}-\d{2}|\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) { $day = $1; $time_stamp = $2; $msecs = $3 ? $3 : 0; @@ -2166,11 +2369,35 @@ sub stats_loop () { } +sub unbreak_lines_only_loop() { + my $log_messages_reached = 0; + while (<>) { + chomp; + + # Log level other than LOG_LEVEL_CLF? + if (m/^(\d{4}-\d{2}-\d{2}|\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/ or + # LOG_LEVEL_CLF? + m/^((?:\d+\.\d+\.\d+\.\d+)) - - \[(.*)\] "(.*)" (\d+) (\d+)/) { + $log_messages_reached = 1; + print "\n"; + + } else { + # Wrapped message + $_ = "\n". $_ if /^(?:\d+\.\d+\.\d+\.\d+)/; + $_ = " " . $_; + } + s@
$@@; + print; + print "\n" unless $log_messages_reached; + } + print "\n"; +} + sub VersionMessage { my $version_message; $version_message .= 'Privoxy-Log-Parser ' . PRIVOXY_LOG_PARSER_VERSION . "\n"; - $version_message .= 'Copyright (C) 2007-2009 Fabian Keil ' . "\n"; + $version_message .= 'Copyright (C) 2007-2010 Fabian Keil ' . "\n"; $version_message .= 'http://www.fabiankeil.de/sourcecode/privoxy-log-parser/' . "\n"; print $version_message; @@ -2184,9 +2411,13 @@ sub get_cli_options () { 'no-syntax-highlighting' => CLI_OPTION_NO_SYNTAX_HIGHLIGHTING, 'no-embedded-css' => CLI_OPTION_NO_EMBEDDED_CSS, 'no-msecs' => CLI_OPTION_NO_MSECS, + 'shorten-thread-ids' => CLI_OPTION_SHORTEN_THREAD_IDS, 'show-ineffective-filters' => CLI_OPTION_SHOW_INEFFECTIVE_FILTERS, 'accept-unknown-messages' => CLI_OPTION_ACCEPT_UNKNOWN_MESSAGES, 'statistics' => CLI_OPTION_STATISTICS, + 'url-statistics-threshold' => CLI_OPTION_URL_STATISTICS_THRESHOLD, + 'unbreak-lines-only' => CLI_OPTION_UNBREAK_LINES_ONLY, + 'host-statistics-threshold'=> CLI_OPTION_HOST_STATISTICS_THRESHOLD, ); GetOptions ( @@ -2195,15 +2426,20 @@ sub get_cli_options () { 'no-syntax-highlighting' => \$cli_options{'no-syntax-highlighting'}, 'no-embedded-css' => \$cli_options{'no-embedded-css'}, 'no-msecs' => \$cli_options{'no-msecs'}, + 'shorten-thread-ids' => \$cli_options{'shorten-thread-ids'}, 'show-ineffective-filters' => \$cli_options{'show-ineffective-filters'}, 'accept-unknown-messages' => \$cli_options{'accept-unknown-messages'}, 'statistics' => \$cli_options{'statistics'}, + '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'}, 'version' => sub { VersionMessage && exit(0) }, 'help' => \&help, ) or exit(1); $html_output_mode = cli_option_is_set('html-output'); $no_msecs_mode = cli_option_is_set('no-msecs'); + $shorten_thread_ids = cli_option_is_set('shorten-thread-ids'); $line_end = get_line_end(); } @@ -2217,12 +2453,16 @@ sub help () { Options and their default values if they have any: [--accept-unknown-messages] + [--host-statistics-threshold $cli_options{'host-statistics-threshold'}] [--html-output] [--no-embedded-css] [--no-msecs] [--no-syntax-highlighting] + [--shorten-thread-ids] [--show-ineffective-filters] [--statistics] + [--unbreak-lines-only] + [--url-statistics-threshold $cli_options{'url-statistics-threshold'}] [--title $cli_options{'title'}] [--version] see "perldoc $0" for more information @@ -2242,7 +2482,10 @@ sub main () { print_intro(); - if (cli_option_is_set('statistics')) { + # 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(); } else { parse_loop(); @@ -2260,8 +2503,9 @@ B - A parser and syntax-highlighter for Privoxy log messages =head1 SYNOPSIS B [B<--accept-unknown-messages>] [B<--html-output>] -[B<--no-msecs>] [B<--no-syntax-higlighting>] [B<--show-ineffective-filters>] -[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>] =head1 DESCRIPTION @@ -2288,6 +2532,10 @@ will hide the "filter foo caused 0 hits" message. [B<--accept-unknown-messages>] Don't print warnings in case of unknown messages, just don't highlight them. +[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 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. @@ -2300,14 +2548,28 @@ 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. +[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<--show-ineffective-filters>] Don't suppress log lines for filters that didn't modify the content. [B<--statistics>] Gather various statistics instead of syntax highlighting log messages. This is an experimental feature, if the results look wrong -they very well might be. Also note that the results a pretty much guaranteed +they very well might be. Also note that the results are pretty much guaranteed to be incorrect if Privoxy and Privoxy-Log-Parser aren't in sync. +[B<--unbreak-lines-only>] Tries to fix lines that got messed up by a broken or +interestingly configured mail client and thus are no longer recognized properly. +Only fixes some breakage, but may be good enough or at least better than nothing. +Doesn't do anything else, so you probably want to pipe the output into +B again. + +[B<--url-statistics-threshold>] Only show the request count for a resource +if it's above or equal to the given threshold. If the threshold is 0, URL +statistics are disabled. + [B<--version>] Print version and exit. =head1 EXAMPLES