#
# http://www.fabiankeil.de/sourcecode/privoxy-log-parser/
#
-# $Id: privoxy-log-parser.pl,v 1.73 2010/01/05 23:36:43 fabiankeil Exp $
+# $Id: privoxy-log-parser.pl,v 1.161 2013/08/29 11:12:13 fabiankeil Exp $
#
# TODO:
# - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting
# - 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 <fk@fabiankeil.de>
+# Copyright (c) 2007-2013 Fabian Keil <fk@fabiankeil.de>
#
# Permission to use, copy, modify, and distribute this software for any
# purpose with or without fee is hereby granted, provided that the above
use Getopt::Long;
use constant {
- PRIVOXY_LOG_PARSER_VERSION => '0.6',
+ PRIVOXY_LOG_PARSER_VERSION => '0.8',
# 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_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_STRICT_CHECKS => 0,
+ CLI_OPTION_UNBREAK_LINES_ONLY => 0,
+ CLI_OPTION_URL_STATISTICS_THRESHOLD => 0,
+ CLI_OPTION_HOST_STATISTICS_THRESHOLD => 0,
+ CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION => 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,
my $html_output_mode;
my $no_msecs_mode; # XXX: should probably be removed
+my $shorten_thread_ids;
my $line_end;
sub prepare_our_stuff () {
'Gif-Deanimate' => 'blue',
Force => 'red',
Writing => 'light_green',
+ Received => 'yellow',
+ Actions => 'yellow',
# ----------------------
URL => 'yellow',
path => 'brown',
'action-bits-update' => 'light_red',
'configuration-line' => 'red',
'content-type' => 'yellow',
+ 'HOST' => HEADER_DEFAULT_COLOUR,
);
%h_colours = %h;
# XXX: The Rolling Stones reference has to go.
###############################################################
- my $colour = shift @_;
+ my $colour = shift;
return "" if cli_option_is_set('no-syntax-highlighting');
# Takes a string and returns a span element
###############################################################
- my $type = shift @_;
+ my $type = shift;
my $code;
if ($type =~ /Standard/) {
# markup should always be semantically correct.
###############################################################
- my $type = shift @_;
+ my $type = shift;
my $code;
if ($type =~ /Standard/) {
my $unknown = shift;
my $message;
- return if cli_option_is_set('accept-unknown-messages');
+ return unless cli_option_is_set('strict-checks');
return if ($unknown =~ /\[too long, truncated\]$/);
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);
}
}
$rl = h('invalid-request') . $rl . h('Standard');
- } elsif ($rl =~ m/^([-\w]+) (.*) (HTTP\/\d\.\d)/) {
+ } elsif ($rl =~ m/^([-\w]+) (.*) (HTTP\/\d+\.\d+)/) {
# XXX: might not match in case of HTTP method fuzzing.
# XXX: save these: ($method, $path, $http_version) = ($1, $2, $3);
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;
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/
+ or $c =~ m/^Multiple Content-Type headers detected. Removing and ignoring: Content-Type:/
)
{
# XXX: Some of these may need highlighting
# 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
+ # Multiple Content-Type headers detected. Removing and ignoring: Content-Type: text/html
} elsif ($c =~ m/^scanning headers for:/) {
$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);
# 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;
# 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);
} 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
$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:/) {
$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/) {
$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/) {
$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
+ } elsif ($c =~ m/^(?:Reusing|Closing) server socket / or
$c =~ m/^No additional client request/) {
# Reusing server socket 4. Opened for 10.0.0.1.
# No additional client request received in time. \
# Closing server socket 4, initially opened for 10.0.0.1.
# No additional client request received in time on socket 29.
+ # Privoxy 3.0.20 and later
+ # 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.
$c =~ s@(?<= socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
- $c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.$)');
+ $c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.)');
+ $c = highlight_matched_host($c, '(?<=connected to )[^\s]+(?=\.)');
+ for my $number_pattern ('requests', 'Keep-alive', 'Tainted', ' alive', 'Timeout', 'detected') {
+ $c = highlight_matched_pattern($c, 'Number', '(?<='. $number_pattern . ': )\d+');
+ }
} elsif ($c =~ m/^Connected to /) {
} 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|has been pipelined) /) {
# 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.
+ # Client request 8 has been pipelined on socket 7 and the socket is still alive.
+ $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]+');
$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/^Optimistically sending /) {
+
+ # Optimistically sending 318 bytes of client headers intended for www.privoxy.org
+ $c =~ s@(?<=sending )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c = highlight_matched_host($c, '(?<=for )[^\s]+');
+
+ } 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/^Drained \d+ bytes before closing/) {
+
+ # Drained 180 bytes before closing socket 6
+ $c =~ s@(?<=Drained )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Tainting client socket/ or
+ $c =~ m/^Failed to shutdown socket/) {
+
+ # Tainting client socket 7 due to unread data.
+ # Failed to shutdown socket 11: Connection reset by peer
+
+ $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+ } elsif ($c =~ m/^Shifting \d+ pipelined bytes/) {
+
+ # Shifting 360 pipelined bytes by 360 bytes
+ $c =~ s@(?<=Shifting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+ $c =~ s@(?<=by )(\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
$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/^There better be a request body./ 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.
# 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\.
+ # Privoxy 3.0.20 and later
+ # There better be a request body.
+ # Done reading from the client.
} else {
} 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
# Reloading configuration file '/usr/local/etc/privoxy/config'
$c =~ s@(?<=loading configuration file \')([^\']*)@$h{'file'}$1$h{'Standard'}@;
+ } elsif ($c =~ m/^Loading (actions|filter|trust) file: /) {
+
+ # Loading actions file: /usr/local/etc/privoxy/default.action
+ # Loading filter file: /usr/local/etc/privoxy/default.filter
+ # Loading trust file: /usr/local/etc/privoxy/trust
+
+ $c =~ s@(?<= file: )(.*)$@$h{'file'}$1$h{'Standard'}@;
+
} elsif ($c =~ m/^exiting by signal/) {
# exiting by signal 15 .. bye
# 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/) {
$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.
# 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 {
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;
$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'}++;
+ }
}
sub gather_loglevel_connect_stats ($$) {
- my $c = shift;
- my $thread = shift;
+ my ($c, $thread) = @_;
our %thread_data;
our %stats;
$thread_data{$thread}{'new_connection'} = 0;
$stats{'reused-connections'}++;
+
+ } elsif ($c =~ m/^Closing client socket \d+. .* Requests received: (\d+)\.$/) {
+
+ # Closing client socket 12. Keep-alive: 1. Socket alive: 1. Data available: 0. \
+ # Configuration file change detected: 0. Requests received: 14.
+
+ $stats{'client-requests-on-connection'}{$1}++;
+ $stats{'closed-client-connections'}++;
}
}
-sub gather_loglevel_header_stats ($) {
+sub gather_loglevel_header_stats ($$) {
- my $c = shift;
- my $thread = shift;
+ my ($c, $thread) = @_;
our %stats;
if ($c =~ m/^A HTTP\/1\.1 response without/ or
# 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}++;
}
}
'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,
+ 'closed-client-connections' => 0,
);
+ $stats{'client-requests-on-connection'}{1} = 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};
+ my $client_requests_checksum = 0;
if ($stats{requests} eq 0) {
print "No requests yet.\n";
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'} . " (" .
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: "
$stats{'empty-responses-on-reused-connections'} . " (" .
get_percentage($stats{requests}, $stats{'empty-responses-on-reused-connections'}) .
")\n";
+ print "Client connections: " . $stats{'closed-client-connections'} . "\n";
+
+ my $lines_printed = 0;
+ print "Client requests per connection distribution:\n";
+ foreach my $client_requests (sort {
+ $stats{'client-requests-on-connection'}{$b} <=> $stats{'client-requests-on-connection'}{$a}}
+ keys %{$stats{'client-requests-on-connection'}
+ })
+ {
+ my $count = $stats{'client-requests-on-connection'}{$client_requests};
+ $client_requests_checksum += $count * $client_requests;
+ if ($cli_options{'show-complete-request-distribution'} or ($lines_printed < 10)) {
+ printf "%8d: %d\n", $count, $client_requests;
+ $lines_printed++;
+ }
+ }
+ unless ($cli_options{'show-complete-request-distribution'}) {
+ 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);
+
+ 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;
+ }
+ }
}
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;
. $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);
'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;
sub stats_loop () {
- my ($day, $time_stamp, $thread, $log_level, $content, $c, $msecs);
+ my ($day, $time_stamp, $msecs, $thread, $log_level, $content);
+ my $strict_checks = cli_option_is_set('strict-checks');
my %log_level_handlers = (
- 'Re-Filter' => \&handle_loglevel_ignore,
- 'Header' => \&gather_loglevel_header_stats,
- 'Connect' => \&gather_loglevel_connect_stats,
- 'Redirect' => \&handle_loglevel_ignore,
- 'Request' => \&gather_loglevel_request_stats,
- 'Crunch' => \&gather_loglevel_crunch_stats,
- 'Gif-Deanimate' => \&handle_loglevel_ignore,
- 'Info' => \&handle_loglevel_ignore,
- 'CGI' => \&handle_loglevel_ignore,
- 'Force' => \&handle_loglevel_ignore,
- 'Error' => \&gather_loglevel_error_stats,
- 'Fatal error' => \&handle_loglevel_ignore,
- 'Writing' => \&handle_loglevel_ignore,
- 'Unknown log level' => \&handle_loglevel_ignore
+ 'Connect:' => \&gather_loglevel_connect_stats,
+ 'Crunch:' => \&gather_loglevel_crunch_stats,
+ 'Error:' => \&gather_loglevel_error_stats,
+ 'Header:' => \&gather_loglevel_header_stats,
+ 'Request:' => \&gather_loglevel_request_stats,
+ );
+ my %ignored_log_levels = (
+ 'Actions:' => \&handle_loglevel_ignore,
+ 'CGI:' => \&handle_loglevel_ignore,
+ 'Fatal error:' => \&handle_loglevel_ignore,
+ 'Force:' => \&handle_loglevel_ignore,
+ 'Gif-Deanimate:' => \&handle_loglevel_ignore,
+ 'Info:' => \&handle_loglevel_ignore,
+ 'Re-Filter:' => \&handle_loglevel_ignore,
+ 'Received:' => \&handle_loglevel_ignore,
+ 'Redirect:' => \&handle_loglevel_ignore,
+ 'Unknown log level:' => \&handle_loglevel_ignore,
+ 'Writing:' => \&handle_loglevel_ignore,
);
while (<>) {
- if (m/^(\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) {
- $day = $1;
- $time_stamp = $2;
- $msecs = $3 ? $3 : 0;
- $log_level = $5;
- $content = $c = $6;
- $thread = $4;
+ (undef, $time_stamp, $thread, $log_level, $content) = split(/ /, $_, 5);
- if (defined($log_level_handlers{$log_level})) {
+ # Skip LOG_LEVEL_CLF
+ next if (not defined($log_level) or $time_stamp eq "-");
- $content = $log_level_handlers{$log_level}($content, $thread);
+ if (defined($log_level_handlers{$log_level})) {
- } else {
+ $content = $log_level_handlers{$log_level}($content, $thread);
- die "No handler found for log level \"$log_level\"\n";
+ } elsif ($strict_checks and not defined($ignored_log_levels{$log_level})) {
- }
+ die "No handler found for: $_";
}
}
}
+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@<BR>$@@;
+ 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 <fk@fabiankeil.de>' . "\n";
$version_message .= 'http://www.fabiankeil.de/sourcecode/privoxy-log-parser/' . "\n";
print $version_message;
'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,
+ 'strict-checks' => CLI_OPTION_STRICT_CHECKS,
+ 'url-statistics-threshold' => CLI_OPTION_URL_STATISTICS_THRESHOLD,
+ 'unbreak-lines-only' => CLI_OPTION_UNBREAK_LINES_ONLY,
+ 'host-statistics-threshold'=> CLI_OPTION_HOST_STATISTICS_THRESHOLD,
+ 'show-complete-request-distribution' => CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION,
);
GetOptions (
'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'},
+ 'strict-checks' => \$cli_options{'strict-checks'},
+ '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'},
+ 'show-complete-request-distribution' => \$cli_options{'show-complete-request-distribution'},
'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();
}
print << " EOF"
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]
+ [--show-complete-request-distribution]
[--statistics]
+ [--unbreak-lines-only]
+ [--url-statistics-threshold $cli_options{'url-statistics-threshold'}]
[--title $cli_options{'title'}]
[--version]
see "perldoc $0" for more information
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();
=head1 SYNOPSIS
-B<privoxy-log-parser> [B<--accept-unknown-messages>] [B<--html-output>]
-[B<--no-msecs>] [B<--no-syntax-higlighting>] [B<--show-ineffective-filters>]
-[B<--version>]
+B<privoxy-log-parser> [B<--html-output>]
+[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
=head1 OPTIONS
-[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.
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<--show-complete-request-distribution>] Show the complete client request
+distribution in the B<--statistics> output. Without this option only the
+ten most common numbers are shown.
+
[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<--strict-checks>] When generating statistics, look more careful at the
+input data and abort if it is unexpected, even if it doesn't affect the
+results. Significantly slows the parsing down and is not expected to catch
+any problems that matter.
+When highlighting, print warnings in case of unknown messages which can't be
+properly highlighted.
+
+[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<privoxy-log-parser> 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