Accept two additional keep-alive related messages.
[privoxy.git] / tools / privoxy-log-parser.pl
index 5994628..bfc4892 100755 (executable)
@@ -8,7 +8,7 @@
 #
 # http://www.fabiankeil.de/sourcecode/privoxy-log-parser/
 #
-# $Id: privoxy-log-parser.pl,v 1.111 2008/08/02 07:31:54 fk Exp $
+# $Id: privoxy-log-parser.pl,v 1.117 2008/10/18 16:22:45 fk Exp $
 #
 # TODO:
 #       - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting
@@ -688,10 +688,11 @@ sub highlight_response_line ($) {
     my ($http_version, $status_code, $status_message);
 
     #HTTP/1.1 200 OK
+    #ICY 200 OK
 
     # TODO: Mark different status codes differently
 
-    if ($rl =~ m/(HTTP\/\d\.\d) (\d+) (.*)/) {
+    if ($rl =~ m/((?:HTTP\/\d\.\d|ICY)) (\d+) (.*)/) {
         ($http_version, $status_code, $status_message) = ($1, $2, $3);
     } else {
         debug_message ("Can't parse response line: $rl") and die 'Fix this';
@@ -824,7 +825,7 @@ sub handle_loglevel_header ($) {
 
             $content = highlight_request_line($1);
 
-    } elsif ($c =~ m/^(scan: )(HTTP\/\d\.\d (\d+) (.*))/) {
+    } elsif ($c =~ m/^(scan: )((?:HTTP\/\d\.\d|ICY) (\d+) (.*))/) {
 
             # Server response line
             $req{$t}{'response_line'} = $2;
@@ -919,7 +920,9 @@ sub handle_loglevel_header ($) {
 
         # Modified: User-Agent: Mozilla/5.0 (X11; U; SunOS i86pc; pl-PL; rv:1.8.1.1) Gecko/20070214 Firefox/2.0.0.1
         # Accept-Language header crunched and replaced with: Accept-Language: pl-pl
-        # cookie 'Set-Cookie: eZSessionCookie=07bfec287c197440d299f81580593c3d; expires=Thursday, 12-Apr-07 15:16:18 GMT; path=/' send by http://wirres.net/article/articleview/4265/1/6/ appears to be using time format 1 (XXX: gone with the wind)
+        # cookie 'Set-Cookie: eZSessionCookie=07bfec287c197440d299f81580593c3d; \
+        #  expires=Thursday, 12-Apr-07 15:16:18 GMT; path=/' send by \
+        #  http://wirres.net/article/articleview/4265/1/6/ appears to be using time format 1 (XXX: gone with the wind)
         # Cookie rewritten to a temporary one: Set-Cookie: NSC_gffe-iuuq-mc-wtfswfs=8efb33a53660;path=/
         # Text mode is already enabled
         # Denied request with NULL byte(s) turned into line break(s)
@@ -945,7 +948,8 @@ sub handle_loglevel_header ($) {
         # Content-Disposition header crunched and replaced with: content-disposition: filename=baz
         # Reducing white space in 'X-LWS-Test: "This  is  quoted" this is not "this  is  " but " this again   is  not'
         # Ignoring single quote in 'X-LWS-Test: "This  is  quoted" this is not "this  is  " but "  this again   is  not'
-        # Converting tab to space in 'X-LWS-Test:   "This  is  quoted" this   is  not "this  is  "  but  "  this again   is  not'
+        # Converting tab to space in 'X-LWS-Test:   "This  is  quoted" this   is  not "this  is  "  but  "\
+        #  this again   is  not'
 
     } elsif ($c =~ m/^scanning headers for:/) {
 
@@ -965,7 +969,8 @@ sub handle_loglevel_header ($) {
  
     } elsif ($c =~ m/^(Transforming \")(.*?)(\" to \")(.*?)(\")/) {
 
-        # Transforming "Proxy-Authenticate: Basic realm="Correos Proxy Server"" to "Proxy-Authenticate: Basic realm="Correos Proxy Server""
+        # Transforming "Proxy-Authenticate: Basic realm="Correos Proxy Server"" to\
+        #  "Proxy-Authenticate: Basic realm="Correos Proxy Server""
 
        $content =~ s@(?<=^Transforming \")(.*)(?=\" to)@$h{'Header'}$1$h{'Standard'}@;
        $content =~ s@(?<=to \")(.*)(?=\")@$h{'Header'}$1$h{'Standard'}@;
@@ -977,7 +982,8 @@ sub handle_loglevel_header ($) {
 
     } elsif ($c =~ m/^Content-Type: .* not replaced/) {
 
-        # Content-Type: application/octet-stream not replaced. It doesn't look like text. Enable force-text-mode if you know what you're doing.
+        # Content-Type: application/octet-stream not replaced. It doesn't look like text.\
+        #  Enable force-text-mode if you know what you're doing.
         # XXX: Could highlight more here.
         $content =~ s@(?<=^Content-Type: )(.*)(?= not replaced)@$h{'content-type'}$1$h{'Standard'}@;
 
@@ -1159,7 +1165,8 @@ sub handle_loglevel_re_filter ($) {
         return ''  if (SUPPRESS_SUCCEEDED_FILTER_ADDITIONS && m/succeeded/);
 
         # Adding re_filter job ...
-        # Adding dynamic re_filter job s@^(?:\w*)\s+.*\s+HTTP/\d\.\d\s*@IP-ADDRESS: $origin@D to filter client-ip-address succeeded.
+        # 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/^Reading in filter/) {
 
@@ -1190,7 +1197,8 @@ sub handle_loglevel_redirect ($) {
 
     } elsif ($c =~ m/^Checking/) {
 
-         # Checking /_ylt=A0geu.Z76BRGR9kAH2RXNyoA/SIG=14gqhtscv/EXP=1175861755/**http://search.yahoo.com/search?p=view+odb+presentation+on+freebsd&ei=UTF-8&xargs=0&pstart=1&fr=moz2&b=11 for redirects.
+         # Checking /_ylt=A0geu.Z76BRGR9k/**http://search.yahoo.com/search?p=view+odb+presentation+on+freebsd\
+         #  &ei=UTF-8&xargs=0&pstart=1&fr=moz2&b=11 for redirects.
 
          # TODO: Change colour if really url-decoded
          $req{$t}{'decoded-original-destination'} = $1;
@@ -1199,7 +1207,8 @@ sub handle_loglevel_redirect ($) {
 
     } elsif ($c =~ m/^pcrs command "([^""]*)" changed "([^""]*)" to "([^""]*)" \((\d+) hits?\)/) {
 
-        # pcrs command "s@&from=rss@@" changed "http://it.slashdot.org/article.pl?sid=07/03/02/1657247&from=rss" to "http://it.slashdot.org/article.pl?sid=07/03/02/1657247" (1 hit).
+        # pcrs command "s@&from=rss@@" changed "http://it.slashdot.org/article.pl?sid=07/03/02/1657247&from=rss"\
+        #  to "http://it.slashdot.org/article.pl?sid=07/03/02/1657247" (1 hit).
 
         my ($pcrs_command, $url_before, $url_after, $hits) = ($1, $2, $3, $4); # XXX: save these?
 
@@ -1218,7 +1227,8 @@ sub handle_loglevel_redirect ($) {
         $c = $1 . h('rewritten-URL') . $2 . h('Standard');
 
     } elsif ($c =~ m/No pcrs command recognized, assuming that/) {
-        # No pcrs command recognized, assuming that "http://config.privoxy.org/user-manual/favicon.png" is already properly formatted.
+        # No pcrs command recognized, assuming that "http://config.privoxy.org/user-manual/favicon.png"\
+        #  is already properly formatted.
         # XXX: assume the same?
         $c = higlight_matched_url($c, '(?<=assuming that \")[^"]*');
 
@@ -1409,6 +1419,64 @@ sub handle_loglevel_connect ($) {
     
         $c =~ s@(?<=socks5_connect: )(.*)@$h{'error'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^Found reusable socket/) {
+
+        # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
+        $c =~ s@(?<=Found reusable socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = higlight_matched_host($c, '(?<=for )[^\s]+');
+        $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Marking open socket/) {
+
+        # Marking open socket 9 for www.privoxy.org:80 in slot 0 as unused.
+        $c =~ s@(?<=Marking open socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = higlight_matched_host($c, '(?<=for )[^\s]+');
+        $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^No reusable/) {
+
+        # No reusable socket for addons.mozilla.org:443 found. Opening a new one.
+        $c = higlight_matched_host($c, '(?<=for )[^\s]+');
+
+    } elsif ($c =~ m/^(Remembering|Forgetting) socket/) {
+
+        # Remembering socket 13 for www.privoxy.org:80 in slot 0.
+        # Forgetting socket 38 for www.privoxy.org:80 in slot 5.
+        $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = higlight_matched_host($c, '(?<=for )[^\s]+');
+        $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Socket/) {
+
+        # Socket 18 for www.privoxy.org:80 in slot 0 is no longer usable. Closing.
+        # Socket 16 already forgotten or never remembered.
+        $c =~ s@(?<=Socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c = higlight_matched_host($c, '(?<=for )[^\s]+');
+        $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^The connection to/) {
+
+        # The connection to www.privoxy.org:80 in slot 0 timed out. Closing.
+        $c = higlight_matched_host($c, '(?<=connection to )[^\s]+');
+        $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Initialized/) {
+
+        # Initialized 20 socket slots.
+        $c =~ s@(?<=Initialized )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Done reading from server/) {
+
+        # Done reading from server. Expected content length: 24892. \
+        #  Actual content length: 24892. Most recently received: 4412.
+        $c =~ s@(?<=Expected content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=Actual content length: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+        $c =~ s@(?<=received: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Looks like we reached/) {
+
+        # Looks like we reached the end of the last chunk. We better stop reading.
+
     } else {
 
         found_unknown_content($c);
@@ -1437,7 +1505,8 @@ sub handle_loglevel_info ($) {
             ) {
         # 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.
+        # Compressed content detected, content filtering disabled. Consider recompiling Privoxy\
+        #  with zlib support or enable the prevent-compression action.
         # Tagger 'complete-url' created empty tag. Ignored.
 
         # Ignored for now
@@ -1456,7 +1525,7 @@ sub handle_loglevel_info ($) {
     } elsif ($c =~ m/^Privoxy version/) {
         
         # Privoxy version 3.0.7
-        $c =~ s@(?<=Privoxy version )(\d.\d.\d)@$h{'version'}$1$h{'Standard'}@;
+        $c =~ s@(?<=^Privoxy version )(\d+\.\d+\.\d+)$@$h{'version'}$1$h{'Standard'}@;
 
     } elsif ($c =~ m/^Program name: /) {
 
@@ -1485,15 +1554,29 @@ sub handle_loglevel_info ($) {
         $c =~ s@(CONNECT)@$h{'method'}$1$h{'Standard'}@;
         $c =~ s@(?<=to port )(\d+)@$h{'port'}$1$h{'Standard'}@;
 
+    } elsif ($c =~ m/^Status code/) {
+
+        # Status code 304 implies no body.
+        $c =~ s@(?<=Status code )(\d+)@$h{'status-code'}$1$h{'Standard'}@;
+
+    } elsif ($c =~ m/^Method/) {
+
+        # Method HEAD implies no body.
+        $c =~ s@(?<=Method )([^\s]+)@$h{'method'}$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/
+             $c =~ m/^Invalid \"chunked\" transfer/ or
+             $c =~ m/^Support for/
              ) {
 
         # No logfile configured. Please enable it before reporting any problems.
-        # Malformerd HTTP headers detected and MS IIS5 hack enabled. Expect an invalid response or even no response at all.
+        # Malformerd HTTP headers detected and MS IIS5 hack enabled. Expect an invalid \
+        #  response or even no response at all.
         # No logfile configured. Logging disabled.
         # Invalid "chunked" transfer encoding detected and ignored.
+        # Support for 'Connection: keep-alive' is experimental, incomplete and\
+        #  known not to work properly in some situations.
 
     } else {
 
@@ -1723,7 +1806,9 @@ sub parse_loop () {
         } elsif (m/^(\d+\.\d+\.\d+\.\d+) - - \[(.*)\] "(.*)" (\d+) (\d+)/) {
 
             # LOG_LEVEL_CLF lines look like this
-            # 61.152.239.32 - - [04/Mar/2007:18:28:23 +0100] "GET http://ad.yieldmanager.com/imp?z=1&Z=120x600&s=109339&u=http%3A%2F%2Fwww.365loan.co.uk%2F&r=1 HTTP/1.1" 403 1730
+            # 61.152.239.32 - - [04/Mar/2007:18:28:23 +0100] "GET \
+            #  http://ad.yieldmanager.com/imp?z=1&Z=120x600&s=109339&u=http%3A%2F%2Fwww.365loan.co.uk%2F&r=1\
+            #  HTTP/1.1" 403 1730
             our ($ip, $timestamp, $request_line, $status_code, $size) = ($1, $2, $3, $4, $5);
 
             print_clf_message();