tools/privoxy-log-parser.pl

   1 #!/usr/bin/perl
   2
   3 ################################################################################
   4 # privoxy-log-parser
   5 #
   6 # A parser for Privoxy log messages. For incomplete documentation run
   7 # perldoc privoxy-log-parser(.pl), for fancy screenshots see:
   8 #
   9 # https://www.fabiankeil.de/sourcecode/privoxy-log-parser/
  10 #
  11 # TODO:
  12 #       - LOG_LEVEL_CGI, LOG_LEVEL_ERROR, LOG_LEVEL_WRITE content highlighting
  13 #       - create fancy statistics
  14 #       - grep through Privoxy sources to find unsupported log messages
  15 #       - hunt down substitutions that match content from variables which
  16 #         can contain stuff like ()?'[]
  17 #       - replace $h{'foo'} with h('foo') where possible
  18 #       - hunt down XXX comments instead of just creating them
  19 #       - add example log lines for every regex and mark them up for
  20 #         regression testing
  21 #       - Handle incomplete input without Perl warning about undefined variables.
  22 #       - Use generic highlighting function that takes a regex and the
  23 #         hash key as input.
  24 #       - Add --compress and --decompress options.
  25 #
  26 # Copyright (c) 2007-2022 Fabian Keil <fk@fabiankeil.de>
  27 #
  28 # Permission to use, copy, modify, and distribute this software for any
  29 # purpose with or without fee is hereby granted, provided that the above
  30 # copyright notice and this permission notice appear in all copies.
  31 #
  32 # THE SOFTWARE IS PROVIDED "AS IS" AND THE AUTHOR DISCLAIMS ALL WARRANTIES
  33 # WITH REGARD TO THIS SOFTWARE INCLUDING ALL IMPLIED WARRANTIES OF
  34 # MERCHANTABILITY AND FITNESS. IN NO EVENT SHALL THE AUTHOR BE LIABLE FOR
  35 # ANY SPECIAL, DIRECT, INDIRECT, OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
  36 # WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN AN
  37 # ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING OUT OF
  38 # OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
  39 ################################################################################
  40
  41 use strict;
  42 use warnings;
  43 use Getopt::Long;
  44
  45 use constant {
  46     PRIVOXY_LOG_PARSER_VERSION => '0.9.5',
  47     # Feel free to mess with these ...
  48     DEFAULT_BACKGROUND => 'black',  # Choose registered colour (like 'black')
  49     DEFAULT_TEXT_COLOUR => 'white', # Choose registered colour (like 'black')
  50     HEADER_DEFAULT_COLOUR => 'yellow',
  51     REGISTER_HEADERS_WITH_THE_SAME_COLOUR => 1,
  52
  53     CLI_OPTION_DETECT_INACTIVITY => 0,
  54     CLI_OPTION_DEFAULT_TO_HTML_OUTPUT => 0,
  55     CLI_OPTION_TITLE => 'Privoxy-Log-Parser in da house',
  56     CLI_OPTION_INACTIVITY_THRESHOLD => 100,
  57     CLI_OPTION_KEEP_DATE => 0,
  58     CLI_OPTION_NO_EMBEDDED_CSS => 0,
  59     CLI_OPTION_NO_MSECS => 0,
  60     CLI_OPTION_NO_SYNTAX_HIGHLIGHTING => 0,
  61     CLI_OPTION_SHORTEN_THREAD_IDS => 0,
  62     CLI_OPTION_SHOW_INEFFECTIVE_FILTERS => 0,
  63     CLI_OPTION_STATISTICS => 0,
  64     CLI_OPTION_STRICT_CHECKS => 0,
  65     CLI_OPTION_UNBREAK_LINES_ONLY => 0,
  66     CLI_OPTION_URL_STATISTICS_THRESHOLD => 0,
  67     CLI_OPTION_PASSED_REQUEST_STATISTICS_THRESHOLD => 0,
  68     CLI_OPTION_HOST_STATISTICS_THRESHOLD => 0,
  69     CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION => 0,
  70
  71     SUPPRESS_SUCCEEDED_FILTER_ADDITIONS => 1,
  72     SHOW_SCAN_INTRO => 0,
  73     SHOW_FILTER_READIN_IN => 0,
  74     SUPPRESS_EMPTY_LINES => 1,
  75     SUPPRESS_SUCCESSFUL_CONNECTIONS => 1,
  76     SUPPRESS_GIF_NOT_CHANGED => 1,
  77     SUPPRESS_NEED_TO_DE_CHUNK_FIRST => 1,
  78
  79     DEBUG_HEADER_REGISTERING => 0,
  80     DEBUG_HEADER_HIGHLIGHTING => 0,
  81     DEBUG_TICKS => 0,
  82     DEBUG_PAINT_IT => 0,
  83     DEBUG_SUPPRESS_LOG_MESSAGES => 0,
  84
  85     PUNISH_MISSING_LOG_KNOWLEDGE_WITH_DEATH => 0,
  86     PUNISH_MISSING_HIGHLIGHT_KNOWLEDGE_WITH_DEATH => 1,
  87
  88     LOG_UNPARSED_LINES_TO_EXTRA_FILE => 0,
  89     ERROR_LOG_FILE => '/var/log/privoxy-log-parser',
  90
  91     # You better leave these alone unless you know what you're doing.
  92     COLOUR_RESET      => "\033[0;0m",
  93     ESCAPE => "\033[",
  94 };
  95
  96 # For performance reasons, these are global.
  97
  98 my $t;
  99 my %req; # request data from previous lines
 100 my %h;
 101 my %thread_colours;
 102 my @all_colours;
 103 my @time_colours;
 104 my $thread_colour_index = 0;
 105 my $header_colour_index = 0;
 106 my $time_colour_index = 0;
 107 my %header_colours;
 108 my $no_special_header_highlighting;
 109 my %reason_colours;
 110 my %h_colours;
 111 my $header_highlight_regex = '';
 112
 113 my $html_output_mode;
 114 my $keep_date_mode;
 115 my $no_msecs_mode; # XXX: should probably be removed
 116 my $shorten_thread_ids;
 117 my $line_end;
 118
 119 sub prepare_our_stuff() {
 120
 121     # Syntax Higlight hash
 122     @all_colours = (
 123         'red', 'green', 'brown', 'blue', 'purple', 'cyan',
 124         'light_gray', 'light_red', 'light_green', 'yellow',
 125         'light_blue', 'pink', 'light_cyan', 'white'
 126     );
 127
 128     %h = (
 129         # LOG_LEVEL
 130         Info            => 'blue',
 131         Header          => 'green',
 132         Filter          => 'purple', # XXX: Used?
 133         'Re-Filter'     => 'purple',
 134         Connect         => 'brown',
 135         Request         => 'light_cyan',
 136         Tagging         => 'purple',
 137         CGI             => 'light_green',
 138         Redirect        => 'cyan',
 139         Error           => 'light_red',
 140         Crunch          => 'cyan',
 141         'Fatal error'   => 'light_red',
 142         'Gif-Deanimate' => 'blue',
 143         Force           => 'red',
 144         Writing         => 'light_green',
 145         Received        => 'yellow',
 146         Actions         => 'yellow',
 147         # ----------------------
 148         URL                  => 'yellow',
 149         path                 => 'brown',
 150         request_             => 'brown', # host+path but no protocol
 151         'ip-address'         => 'yellow',
 152         Number               => 'yellow',
 153         Standard             => 'reset',
 154         Truncation           => 'light_red',
 155         Status               => 'brown',
 156         Timestamp            => 'brown',
 157         Crunching            => 'light_red',
 158         crunched             => 'light_red',
 159         'Request-Line'       => 'pink',
 160         method               => 'purple',
 161         destination          => 'yellow',
 162         'http-version'       => 'pink',
 163         'crunch-pattern'     => 'pink',
 164         not                  => 'brown',
 165         file                 => 'brown',
 166         signal               => 'yellow',
 167         version              => 'green',
 168         'program-name'       => 'cyan',
 169         port                 => 'red',
 170         host                 => 'red',
 171         warning              => 'light_red',
 172         debug                => 'light_red',
 173         filter               => 'green',
 174         tag                  => 'green',
 175         tagger               => 'green',
 176         'status-message'     => 'light_cyan',
 177         'status-code'        => 'yellow',
 178         'invalid-request'    => 'light_red',
 179         'hits'               => 'yellow',
 180         error                => 'light_red',
 181         'rewritten-URL'      => 'light_red',
 182         'pcrs-delimiter'     => 'light_red',
 183         'ignored'            => 'light_red',
 184         'action-bits-update' => 'light_red',
 185         'http-downgrade'     => 'light_red',
 186         'configuration-line' => 'red',
 187         'content-type'       => 'yellow',
 188         'HOST'               => HEADER_DEFAULT_COLOUR,
 189     );
 190
 191     %h_colours = %h;
 192
 193     # Header colours need their own hash so the keys can be accessed properly
 194     %header_colours = (
 195         # Prefilled with headers that should not appear with default header colours
 196         Cookie => 'light_red',
 197         'Set-Cookie' => 'light_red',
 198         Warning => 'light_red',
 199         Default => HEADER_DEFAULT_COLOUR,
 200     );
 201
 202     # Crunch reasons need their own hash as well
 203     %reason_colours = (
 204         'Unsupported HTTP feature'               => 'light_red',
 205         Blocked                                  => 'light_red',
 206         Untrusted                                => 'light_red',
 207         Redirected                               => 'green',
 208         'CGI Call'                               => 'white',
 209         'DNS failure'                            => 'red',
 210         'Forwarding failed'                      => 'light_red',
 211         'Connection failure'                     => 'light_red',
 212         'Out of memory (may mask other reasons)' => 'light_red',
 213         'No reason recorded'                     => 'light_red',
 214     );
 215
 216     @time_colours = ('white', 'light_gray');
 217
 218     # Translate highlight strings into highlight code
 219     prepare_highlight_hash(\%header_colours);
 220     prepare_highlight_hash(\%reason_colours);
 221     prepare_highlight_hash(\%h);
 222     prepare_colour_array(\@all_colours);
 223     prepare_colour_array(\@time_colours);
 224     init_css_colours();
 225
 226     init_stats();
 227 }
 228
 229 sub paint_it($) {
 230 ###############################################################
 231 # Takes a colour string and returns an ANSI escape sequence
 232 # (unless --no-syntax-highlighting is used).
 233 # XXX: The Rolling Stones reference has to go.
 234 ###############################################################
 235
 236     my $colour = shift;
 237
 238     return "" if cli_option_is_set('no-syntax-highlighting');
 239
 240     my %light = (
 241         black       => 0,
 242         red         => 0,
 243         green       => 0,
 244         brown       => 0,
 245         blue        => 0,
 246         purple      => 0,
 247         cyan        => 0,
 248         light_gray  => 0,
 249         gray        => 0,
 250         dark_gray   => 1,
 251         light_red   => 1,
 252         light_green => 1,
 253         yellow      => 1,
 254         light_blue  => 1,
 255         pink        => 1,
 256         light_cyan  => 1,
 257         white       => 1,
 258     );
 259
 260     my %text = (
 261         black       => 30,
 262         red         => 31,
 263         green       => 32,
 264         brown       => 33,
 265         blue        => 34,
 266         purple      => 35,
 267         cyan        => 36,
 268         gray        => 37,
 269         light_gray  => 37,
 270         dark_gray   => 30,
 271         light_red   => 31,
 272         light_green => 32,
 273         yellow      => 33,
 274         light_blue  => 34,
 275         pink        => 35,
 276         light_cyan  => 36,
 277         white       => 37,
 278     );
 279
 280     my $bg_code = get_background();
 281     my $colour_code;
 282     our $default = default_colours();
 283
 284     if (defined($text{$colour})) {
 285         $colour_code  = ESCAPE;
 286         $colour_code .= $text{$colour};
 287         $colour_code .= ";";
 288         $colour_code .= $light{$colour} ? "1" : "2";
 289         $colour_code .= ";";
 290         $colour_code .= $bg_code;
 291         $colour_code .= "m";
 292         debug_message $colour . " is \'" . $colour_code . $colour . $default . "\'" if DEBUG_PAINT_IT;
 293
 294     } elsif ($colour =~ /reset/) {
 295
 296         $colour_code = default_colours();
 297
 298     } else {
 299
 300         die "What's $colour supposed to mean?\n";
 301     }
 302
 303     return $colour_code;
 304 }
 305
 306 sub get_semantic_html_markup($) {
 307 ###############################################################
 308 # Takes a string and returns a span element
 309 ###############################################################
 310
 311     my $type = shift;
 312     my $code;
 313
 314     if ($type =~ /Standard/) {
 315         $code = '</span>';
 316     } else {
 317         $type = lc($type);
 318         $code = '<span title="' . $type . '" class="' . $type . '">';
 319     }
 320
 321     return $code;
 322 }
 323
 324 sub cli_option_is_set($) {
 325
 326     our %cli_options;
 327     my $cli_option = shift;
 328
 329     die "Unknown CLI option: $cli_option" unless defined $cli_options{$cli_option};
 330
 331     return $cli_options{$cli_option};
 332 }
 333
 334 sub get_html_title() {
 335
 336     our %cli_options;
 337     return $cli_options{'title'};
 338
 339 }
 340
 341 sub init_css_colours() {
 342
 343     our %css_colours = (
 344         black       => "000",
 345         red         => "F00",
 346         green       => "0F0",
 347         brown       => "C90",
 348         blue        => "0F0",
 349         purple      => "F06", # XXX: wrong
 350         cyan        => "F09", # XXX: wrong
 351         light_gray  => "999",
 352         gray        => "333",
 353         dark_gray   => "222",
 354         light_red   => "F33",
 355         light_green => "33F",
 356         yellow      => "FF0",
 357         light_blue  => "30F",
 358         pink        => "F0F",
 359         light_cyan  => "66F",
 360         white       => "FFF",
 361     );
 362 }
 363
 364 sub get_css_colour($) {
 365
 366    our %css_colours;
 367    my $colour = shift;
 368
 369    die "What's $colour supposed to mean?\n" unless defined($css_colours{$colour});
 370
 371    return '#' . $css_colours{$colour};
 372 }
 373
 374 sub get_css_line($) {
 375
 376     my $class = shift;
 377     my $css_line;
 378
 379     $css_line .= '.' . lc($class) . ' {'; # XXX: lc() shouldn't be necessary
 380     die "What's $class supposed to mean?\n" unless defined($h_colours{$class});
 381     $css_line .= 'color:' . get_css_colour($h_colours{$class}) . ';';
 382     $css_line .= 'background-color:' . get_css_colour(DEFAULT_BACKGROUND) . ';';
 383     $css_line .= '}' . "\n";
 384
 385     return $css_line;
 386 }
 387
 388 sub get_css_line_for_colour($) {
 389
 390     my $colour = shift;
 391     my $css_line;
 392
 393     $css_line .= '.' . lc($colour) . ' {'; # XXX: lc() shouldn't be necessary
 394     $css_line .= 'color:' . get_css_colour($colour) . ';';
 395     $css_line .= 'background-color:' . get_css_colour(DEFAULT_BACKGROUND) . ';';
 396     $css_line .= '}' . "\n";
 397
 398     return $css_line;
 399 }
 400
 401 # XXX: Wrong solution
 402 sub get_missing_css_lines() {
 403
 404     my $css_line;
 405
 406     $css_line .= '.' . 'default' . ' {';
 407     $css_line .= 'color:' . HEADER_DEFAULT_COLOUR . ';';
 408     $css_line .= 'background-color:' . get_css_colour(DEFAULT_BACKGROUND) . ';';
 409     $css_line .= '}' . "\n";
 410
 411     return $css_line;
 412 }
 413
 414 sub get_css() {
 415
 416     our %css_colours; #XXX: Wrong solution
 417
 418     my $css = '';
 419
 420     $css .= '.privoxy-log {';
 421     $css .= 'color:' . get_css_colour(DEFAULT_TEXT_COLOUR) . ';';
 422     $css .= 'background-color:' . get_css_colour(DEFAULT_BACKGROUND) . ';';
 423     $css .= '}' . "\n";
 424
 425     foreach my $key (keys %h_colours) {
 426
 427         next if ($h_colours{$key} =~ m/reset/); #XXX: Wrong solution.
 428         $css .= get_css_line($key);
 429
 430     }
 431
 432     foreach my $colour (keys %css_colours) {
 433
 434         $css .= get_css_line_for_colour($colour);
 435
 436     }
 437
 438     $css .= get_missing_css_lines(); #XXX: Wrong solution
 439
 440     return $css;
 441 }
 442
 443 sub print_intro() {
 444
 445     my $intro = '';
 446
 447     if (cli_option_is_set('html-output')) {
 448
 449         my $title = get_html_title();
 450
 451         $intro .= '<html><head>';
 452         $intro .= '<title>' . $title . '</title>';
 453         $intro .= '<style>' . get_css() . '</style>' unless cli_option_is_set('no-embedded-css');
 454         $intro .= '</head><body>';
 455         $intro .= '<h1>' . $title . '</h1><p class="privoxy-log">';
 456
 457         print $intro;
 458     }
 459 }
 460
 461 sub print_outro() {
 462
 463     my $outro = '';
 464
 465     if (cli_option_is_set('html-output')) {
 466
 467         $outro = '</p></body></html>';
 468         print $outro;
 469
 470     }
 471 }
 472
 473 sub get_line_end() {
 474     return cli_option_is_set('html-output') ? "<br>\n" : "\n";
 475 }
 476
 477 sub get_colour_html_markup($) {
 478 ###############################################################
 479 # Takes a colour string a span element. XXX: WHAT?
 480 # XXX: This function shouldn't be necessary, the
 481 # markup should always be semantically correct.
 482 ###############################################################
 483
 484     my $type = shift;
 485     my $code;
 486
 487     if ($type =~ /Standard/) {
 488         $code = '</span>';
 489     } else {
 490         $code = '<span class="' . lc($type) . '">';
 491     }
 492
 493     return $code;
 494 }
 495
 496 sub default_colours() {
 497     # XXX: Properly
 498     our $bg_code;
 499     return reset_colours();
 500 }
 501
 502 sub show_colours() {
 503     # XXX: Implement
 504 }
 505
 506 sub reset_colours() {
 507     return ESCAPE . "0m";
 508 }
 509
 510 sub set_background($) {
 511
 512     my $colour = shift;
 513     our $bg_code;
 514     my %backgrounds = (
 515               black       => "40",
 516               red         => "41",
 517               green       => "42",
 518               brown       => "43",
 519               blue        => "44",
 520               magenta     => "45",
 521               cyan        => "46",
 522               white       => "47",
 523               default     => "49",
 524     );
 525
 526     if (defined($backgrounds{$colour})) {
 527         $bg_code = $backgrounds{$colour};
 528     } else {
 529         die "Invalid background colour: " . $colour;
 530     }
 531 }
 532
 533 sub get_background() {
 534     return our $bg_code;
 535 }
 536
 537 sub prepare_highlight_hash($) {
 538     my $ref = shift;
 539
 540     foreach my $key (keys %$ref) {
 541         $$ref{$key} = $html_output_mode ?
 542             get_semantic_html_markup($key) :
 543             paint_it($$ref{$key});
 544     }
 545 }
 546
 547 sub prepare_colour_array($) {
 548     my $ref = shift;
 549
 550     foreach my $i (0 ... @$ref - 1) {
 551         $$ref[$i] = $html_output_mode ?
 552             get_colour_html_markup($$ref[$i]) :
 553             paint_it($$ref[$i]);
 554     }
 555 }
 556
 557 sub found_unknown_content($) {
 558
 559     my $unknown = shift;
 560     my $message;
 561
 562     return unless cli_option_is_set('strict-checks');
 563
 564     return if ($unknown =~ /\[too long, truncated\]$/);
 565
 566     $message = "found_unknown_content: Don't know how to highlight: ";
 567     # Break line so the log file can later be parsed as Privoxy log file again
 568     $message .= '"' . $unknown . '"' . " in:\n";
 569     $message .= $req{$t}{'log-message'};
 570     debug_message($message);
 571     log_parse_error($req{$t}{'log-message'});
 572
 573     die "Unworthy content parser" if PUNISH_MISSING_LOG_KNOWLEDGE_WITH_DEATH;
 574 }
 575
 576 sub log_parse_error($) {
 577
 578     my $message = shift;
 579
 580     if (LOG_UNPARSED_LINES_TO_EXTRA_FILE) {
 581         open(my $errorlog_fd, ">>", ERROR_LOG_FILE) || die "Writing " . ERROR_LOG_FILE . " failed";
 582         print $errorlog_fd $message;
 583         close($errorlog_fd);
 584     }
 585 }
 586
 587 sub debug_message(@) {
 588     my @message = @_;
 589
 590     print $h{'debug'} . "@message" . $h{'Standard'} . "\n";
 591 }
 592
 593 ################################################################################
 594 # highlighter functions that aren't loglevel-specific
 595 ################################################################################
 596
 597 sub h($) {
 598
 599     # Get highlight marker
 600     my $highlight = shift; # XXX: Stupid name;
 601     my $result = '';
 602     my $message;
 603
 604     if (defined($highlight)) {
 605
 606         $result = $h{$highlight};
 607
 608     } else {
 609
 610         $message = "h: Don't recognize highlighter $highlight.";
 611         debug_message($message);
 612         log_parser_error($message);
 613         die "Unworthy highlighter function" if PUNISH_MISSING_HIGHLIGHT_KNOWLEDGE_WITH_DEATH;
 614     }
 615
 616     return $result;
 617 }
 618
 619 sub highlight_known_headers($) {
 620
 621     my $content = shift;
 622
 623     debug_message("Searching $content for things to highlight.") if DEBUG_HEADER_HIGHLIGHTING;
 624
 625     if ($content =~ m/(?<=\s)($header_highlight_regex):/) {
 626         my $header = $1;
 627         $content =~ s@(?<=[\s|'])($header)(?=:)@$header_colours{$header}$1$h{'Standard'}@ig;
 628         debug_message("Highlighted '$header' in '$content'") if DEBUG_HEADER_HIGHLIGHTING;
 629     }
 630
 631     return $content;
 632 }
 633
 634 sub highlight_matched_request_line($$) {
 635
 636     my $result = shift; # XXX: Stupid name;
 637     my $regex = shift;
 638     if ($result =~ m@(.*)($regex)(.*)@) {
 639         $result = $1 . highlight_request_line($2) . $3
 640     }
 641     return $result;
 642 }
 643
 644 sub highlight_request_line($) {
 645
 646     my $rl = shift;
 647     my ($method, $url, $http_version);
 648
 649     #GET http://images.sourceforge.net/sfx/icon_warning.gif HTTP/1.1
 650     if ($rl =~ m/Invalid request/ or $rl =~ m/Failed reading chunked client body/) {
 651
 652         $rl = h('invalid-request') . $rl . h('Standard');
 653
 654     } elsif ($rl =~ m/^([-\w]+) (.*) (HTTP\/\d+\.\d+)/) {
 655
 656         # XXX: might not match in case of HTTP method fuzzing.
 657         # XXX: save these: ($method, $path, $http_version) = ($1, $2, $3);
 658         $rl =~ s@^(\w+)@$h{'method'}$1$h{'Standard'}@;
 659         if ($rl =~ /http:\/\//) {
 660             $rl = highlight_matched_url($rl, '[^\s]*(?=\sHTTP)');
 661         } else {
 662             $rl = highlight_matched_pattern($rl, 'request_', '[^\s]*(?=\sHTTP)');
 663         }
 664
 665         $rl =~ s@(HTTP\/\d\.\d)$@$h{'http-version'}$1$h{'Standard'}@;
 666
 667     } elsif ($rl =~ m/\.\.\. \[too long, truncated\]$/) {
 668
 669         $rl =~ s@^(\w+)@$h{'method'}$1$h{'Standard'}@;
 670         $rl = highlight_matched_url($rl, '[^\s]*(?=\.\.\.)');
 671
 672     } elsif ($rl =~ m/^ $/) {
 673
 674         $rl = h('error') . "No request line specified!" . h('Standard');
 675
 676     } else {
 677
 678         debug_message ("Can't parse request line: $rl");
 679
 680     }
 681
 682     return $rl;
 683 }
 684
 685 sub highlight_response_line($) {
 686
 687     my $rl = shift;
 688     my ($http_version, $status_code, $status_message);
 689
 690     #HTTP/1.1 200 OK
 691     #ICY 200 OK
 692
 693     # TODO: Mark different status codes differently
 694
 695     if ($rl =~ m/((?:HTTP\/\d\.\d|ICY)) (\d+) (.*)/) {
 696         ($http_version, $status_code, $status_message) = ($1, $2, $3);
 697     } else {
 698         debug_message ("Can't parse response line: $rl") and die 'Fix this';
 699     }
 700
 701     # Rebuild highlighted
 702     $rl= "";
 703     $rl .= h('http-version') . $http_version . h('Standard');
 704     $rl .= " ";
 705     $rl .= h('status-code') . $status_code . h('Standard');
 706     $rl .= " ";
 707     $rl .= h('status-message') . $status_message . h('Standard');
 708
 709     return $rl;
 710 }
 711
 712 sub highlight_matched_url($$) {
 713
 714     my $result = shift; # XXX: Stupid name;
 715     my $regex = shift;
 716
 717     #print "Got $result, regex ($regex)\n";
 718
 719     if ($result =~ m@(.*?)($regex)(.*)@) {
 720         $result = $1 . highlight_url($2) . $3;
 721         #print "Now the result is $result\n";
 722     }
 723
 724     return $result;
 725 }
 726
 727 sub highlight_matched_host($$) {
 728
 729     my ($result, $regex) = @_; # XXX: result ist stupid name;
 730
 731     if ($result =~ m@(.*?)($regex)(.*)@) {
 732         $result = $1 . $h{host} . $2 . $h{Standard} . $3;
 733     }
 734
 735     return $result;
 736 }
 737
 738 sub highlight_matched_pattern($$$) {
 739
 740     my $result = shift; # XXX: Stupid name;
 741     my $key = shift;
 742     my $regex = shift;
 743
 744     die "Unknown key $key" unless defined $h{$key};
 745
 746     if ($result =~ m@(.*?)($regex)(.*)@) {
 747         $result = $1 . h($key) . $2 . h('Standard') . $3;
 748     }
 749
 750     return $result;
 751 }
 752
 753 sub highlight_matched_path($$) {
 754
 755     my $result = shift; # XXX: Stupid name;
 756     my $regex = shift;
 757
 758     if ($result =~ m@(.*?)($regex)(.*)@) {
 759         $result = $1 . h('path') . $2 . h('Standard') . $3;
 760     }
 761
 762     return $result;
 763 }
 764
 765 sub highlight_url($) {
 766
 767     my $url = shift;
 768
 769     if ($html_output_mode) {
 770
 771         $url = '<a href="' . $url . '">' . $url . '</a>';
 772
 773     } else {
 774
 775         $url = h('URL') . $url . h('Standard');
 776
 777     }
 778
 779     return $url;
 780 }
 781
 782 sub update_header_highlight_regex($) {
 783
 784     my $header = shift;
 785     my $headers = join ('|', keys %header_colours);
 786
 787     $header_highlight_regex = qr/$headers/;
 788     print "Registering '$header'\n" if DEBUG_HEADER_HIGHLIGHTING;
 789 }
 790
 791 ################################################################################
 792 # loglevel-specific highlighter functions
 793 ################################################################################
 794
 795 sub handle_loglevel_header($) {
 796
 797     my $c = shift;
 798
 799     if ($c =~ /^scan:/) {
 800
 801         if ($c =~ m/^scan: ([^: ]+):/) {
 802
 803             # Register new headers
 804             # scan: Accept: image/png,image/*;q=0.8,*/*;q=0.5
 805             my $header = $1;
 806             if (!defined($header_colours{$header}) and $header =~ /^[\d\w-]*$/) {
 807                 debug_message "Registering previously unknown header $1" if DEBUG_HEADER_REGISTERING;
 808
 809                 if (REGISTER_HEADERS_WITH_THE_SAME_COLOUR) {
 810                     $header_colours{$header} =  $header_colours{'Default'};
 811                 } else {
 812                     $header_colours{$header} = $all_colours[$header_colour_index % @all_colours];
 813                     $header_colour_index++;
 814                 }
 815                 update_header_highlight_regex($header);
 816             }
 817
 818         } elsif ($c =~ m/^(scan: )(\w+ .+ HTTP\/\d\.\d)/) {
 819
 820             # scan: GET http://p.p/ HTTP/1.1
 821             $c = $1 . highlight_request_line($2);
 822
 823         } elsif ($c =~ m/^(scan: )((?:HTTP\/\d\.\d|ICY) (\d+) (.*))/) {
 824
 825             # scan: HTTP/1.1 200 OK
 826             $req{$t}{'response_line'} = $2;
 827             $req{$t}{'status_code'} = $3;
 828             $req{$t}{'status_message'} = $4;
 829             $c = $1 . highlight_response_line($req{$t}{'response_line'});
 830         }
 831
 832     } elsif ($c =~ m/^Crunching (?:server|client) header: .* \(contains: ([^\)]*)\)/) {
 833
 834         # Crunching server header: Set-Cookie: trac_form_token=d5308c34e16d15e9e301a456; (contains: Cookie:)
 835         $c =~ s@(?<=contains: )($1)@$h{'crunch-pattern'}$1$h{'Standard'}@;
 836         $c =~ s@(Crunching)@$h{$1}$1$h{'Standard'}@;
 837
 838     } elsif ($c =~ m/^New host is: ([^\s]*)\./) {
 839
 840         # New host is: trac.vidalia-project.net. Crunching Referer: http://www.vidalia-project.net/!
 841         $c = highlight_matched_host($c, '(?<=New host is: )[^\s]+(?=\.)');
 842         $c = highlight_matched_url($c, '(?<=Crunching Referer: )[^\s!]+');
 843
 844     } elsif ($c =~ m/^Text mode enabled by force. (Take cover)!/) {
 845
 846         # Text mode enabled by force. Take cover!
 847         $c =~ s@($1)@$h{'warning'}$1$h{'Standard'}@;
 848
 849     } elsif ($c =~ m/^(New HTTP Request-Line: )(.*)/) {
 850
 851         # New HTTP Request-Line: GET http://www.privoxy.org/ HTTP/1.1
 852         $c = $1 . highlight_request_line($2);
 853
 854     } elsif ($c =~ m/^Adjust(ed)? Content-Length to \d+/) {
 855
 856         # Adjusted Content-Length to 2132
 857         # Adjust Content-Length to 33533
 858         $c =~ s@(?<=Content-Length to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
 859         $c = highlight_known_headers($c);
 860
 861     } elsif ($c =~ m/^Destination extracted from "Host:" header. New request URL:/) {
 862
 863         # Destination extracted from "Host:" header. New request URL: http://www.cccmz.de/~ridcully/blog/
 864         $c = highlight_matched_url($c, '(?<=New request URL: ).*');
 865
 866     } elsif ($c =~ m/^Couldn\'t parse:/) {
 867
 868         # XXX: These should probable be logged with LOG_LEVEL_ERROR
 869         # Couldn't parse: If-Modified-Since: Wed, 21 Mar 2007 16:34:50 GMT (crunching!)
 870         # Couldn't parse: at, 24 Mar 2007 13:46:21 GMT in If-Modified-Since: Sat, 24 Mar 2007 13:46:21 GMT (crunching!)
 871         $c =~ s@^(Couldn\'t parse)@$h{'error'}$1$h{'Standard'}@;
 872
 873     } elsif ($c =~ /^Tagger \'([^\']*)\' added tag \'([^\']*)\'/ or
 874              $c =~ m/^Adding tag \'([^\']*)\' created by header tagger \'([^\']*)\'/) {
 875
 876         # Adding tag 'GET request' created by header tagger 'method-man' (XXX: no longer used)
 877         # Tagger 'revalidation' added tag 'REVALIDATION-REQUEST'. No action bit update necessary.
 878         # Tagger 'revalidation' added tag 'REVALIDATION-REQUEST'. Action bits updated accordingly.
 879
 880         # XXX: Save tag and tagger
 881
 882         $c =~ s@(?<=^Tagger \')([^\']*)@$h{'tagger'}$1$h{'Standard'}@;
 883         $c =~ s@(?<=added tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
 884         $c =~ s@(?<=Action bits )(updated)@$h{'action-bits-update'}$1$h{'Standard'}@;
 885         $no_special_header_highlighting = 1;
 886
 887     } elsif ($c =~ /^Tagger \'([^\']*)\' didn['']t add tag \'([^\']*)\'/) {
 888
 889         # Tagger 'revalidation' didn't add tag 'REVALIDATION-REQUEST'. Tag already present
 890         # XXX: Save tag and tagger
 891
 892         $c =~ s@(?<=^Tagger \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
 893         $c =~ s@(?<=didn['']t add tag \')([^\']*)@$h{'tagger'}$1$h{'Standard'}@;
 894
 895     } elsif ($c =~ m/^(?:scan:|Randomiz|addh:|Adding:|Removing:|Referer:|Modified:|Accept-Language header|[Cc]ookie)/
 896           or $c =~ m/^(Text mode is already enabled|Denied request with NULL byte|Replaced:|add-unique:)/
 897           or $c =~ m/^(Crunched (incoming|outgoing) cookie|Suppressed offer|Accepted the client)/
 898           or $c =~ m/^(addh-unique|Referer forged to)/
 899           or $c =~ m/^Downgraded answer to HTTP\/1.0/
 900           or $c =~ m/^Parameter: \+hide-referrer\{[^\}]*\} is a bad idea, but I don\'t care./
 901           or $c =~ m/^Referer (?:overwritten|replaced) with: Referer: / #XXX: should this be highlighted?
 902           or $c =~ m/^Referer crunched!/
 903           or $c =~ m/^crunched x-forwarded-for!/
 904           or $c =~ m/^crunched From!/
 905           or $c =~ m/^ modified$/
 906           or $c =~ m/^Content filtering is enabled. Crunching:/
 907           or $c =~ m/^force-text-mode overruled the client/
 908           or $c =~ m/^Server time in the future\./
 909           or $c =~ m/^content-disposition header crunched and replaced with:/i
 910           or $c =~ m/^Reducing white space in /
 911           or $c =~ m/^Ignoring single quote in /
 912           or $c =~ m/^Converting tab to space in /
 913           or $c =~ m/A HTTP\/1\.1 response without/
 914           or $c =~ m/Disabled filter mode on behalf of the client/
 915           or $c =~ m/Keeping the (?:server|client) header /
 916           or $c =~ m/Content modified with no Content-Length header set/
 917           or $c =~ m/^Appended client IP address to/
 918           or $c =~ m/^Removing 'Connection: close' to imply keep-alive./
 919           or $c =~ m/^keep-alive support is disabled/
 920           or $c =~ m/^Continue hack in da house/
 921           or $c =~ m/^Merged multiple header lines to:/
 922           or $c =~ m/^Added header: /
 923           or $c =~ m/^Enlisting (?:sorted|left-over) header/
 924           or $c =~ m/^Multiple Content-Type headers detected. Removing and ignoring: Content-Type:/
 925             )
 926     {
 927         # XXX: Some of these may need highlighting
 928
 929         # Modified: User-Agent: Mozilla/5.0 (X11; U; SunOS i86pc; pl-PL; rv:1.8.1.1) Gecko/20070214 Firefox/2.0.0.1
 930         # Accept-Language header crunched and replaced with: Accept-Language: pl-pl
 931         # cookie 'Set-Cookie: eZSessionCookie=07bfec287c197440d299f81580593c3d; \
 932         #  expires=Thursday, 12-Apr-07 15:16:18 GMT; path=/' send by \
 933         #  http://wirres.net/article/articleview/4265/1/6/ appears to be using time format 1 (XXX: gone with the wind)
 934         # Cookie rewritten to a temporary one: Set-Cookie: NSC_gffe-iuuq-mc-wtfswfs=8efb33a53660;path=/
 935         # Text mode is already enabled
 936         # Denied request with NULL byte(s) turned into line break(s)
 937         # Replaced: 'Connection: Yo, home to Bel Air' with 'Connection: close'
 938         # addh-unique: Host: people.freebsd.org
 939         # Suppressed offer to compress content
 940         # Crunched incoming cookie -- yum!
 941         # Accepted the client's request to fetch without filtering.
 942         # Crunched outgoing cookie: Cookie: PREF=ID=6cf0abd347b30262:TM=1173357617:LM=1173357617:S=jZypyyJ7LPiwFi1_
 943         # addh-unique: Host: subkeys.pgp.net:11371
 944         # Referer forged to: Referer: http://10.0.0.1/
 945         # Downgraded answer to HTTP/1.0
 946         # Parameter: +hide-referrer{pille-palle} is a bad idea, but I don't care.
 947         # Referer overwritten with: Referer: pille-palle
 948         # Referer replaced with: Referer: pille-palle
 949         # crunched x-forwarded-for!
 950         # crunched From!
 951         #  modified # XXX: pretty stupid log message
 952         # Content filtering is enabled. Crunching: 'Range: 1234-5678' to prevent range-mismatch problems
 953         # force-text-mode overruled the client's request to fetch without filtering!
 954         # Server time in the future.
 955         # content-disposition header crunched and replaced with: content-disposition: filename=baz
 956         # Content-Disposition header crunched and replaced with: content-disposition: filename=baz
 957         # Reducing white space in 'X-LWS-Test: "This  is  quoted" this is not "this  is  " but " this again   is  not'
 958         # Ignoring single quote in 'X-LWS-Test: "This  is  quoted" this is not "this  is  " but "  this again   is  not'
 959         # Converting tab to space in 'X-LWS-Test:   "This  is  quoted" this   is  not "this  is  "  but  "\
 960         #  this again   is  not'
 961         # A HTTP/1.1 response without Connection header implies keep-alive.
 962         # Disabled filter mode on behalf of the client.
 963         # Keeping the server header 'Connection: keep-alive' around.
 964         # Keeping the client header 'Connection: close' around. The connection will not be kept alive.
 965         # Keeping the client header 'Connection: keep-alive' around. The connection will be kept alive if possible.
 966         # Content modified with no Content-Length header set. Creating a fake one for adjustment later on.
 967         # Appended client IP address to X-Forwarded-For: 10.0.0.2, 10.0.0.1
 968         # Removing 'Connection: close' to imply keep-alive.
 969         # keep-alive support is disabled. Crunching: Keep-Alive: 300.
 970         # Continue hack in da house.
 971         # Merged multiple header lines to: 'X-FORWARDED-PROTO: http X-HOST: 127.0.0.1'
 972         # Added header: Content-Encoding: deflate
 973         # Enlisting sorted header User-Agent: Mozilla/5.0 (X11; SunOS i86pc; rv:10.0.3) Gecko/20100101 Firefox/10.0.3
 974         # Enlisting left-over header Connection: close
 975         # Multiple Content-Type headers detected. Removing and ignoring: Content-Type: text/html
 976
 977     } elsif ($c =~ m/^scanning headers for:/) {
 978
 979         return '' unless SHOW_SCAN_INTRO;
 980
 981     } elsif ($c =~ m/^[Cc]runch(ing|ed)|crumble crunched:/) {
 982         # crunched User-Agent!
 983         # Crunching: Content-Encoding: gzip
 984
 985         $c =~ s@(Crunching|crunched)@$h{$1}$1$h{'Standard'}@;
 986
 987     } elsif ($c =~ m/^Offending request data with NULL bytes turned into \'°\' characters:/) {
 988
 989         # Offending request data with NULL bytes turned into '°' characters: °°n°°(°°°
 990
 991         $c = h('warning') . $c . h('Standard');
 992
 993     } elsif ($c =~ m/^(Transforming \")(.*?)(\" to \")(.*?)(\")/) {
 994
 995         # Transforming "Proxy-Authenticate: Basic realm="Correos Proxy Server"" to\
 996         #  "Proxy-Authenticate: Basic realm="Correos Proxy Server""
 997
 998        $c =~ s@(?<=^Transforming \")(.*)(?=\" to)@$h{'Header'}$1$h{'Standard'}@;
 999        $c =~ s@(?<=to \")(.*)(?=\")@$h{'Header'}$1$h{'Standard'}@;
1000
1001     } elsif ($c =~ m/^Removing empty header/) {
1002
1003         # Removing empty header
1004         # Ignore for now
1005
1006     } elsif ($c =~ m/^Content-Type: .* not replaced/) {
1007
1008         # Content-Type: application/octet-stream not replaced. It doesn't look like text.\
1009         #  Enable force-text-mode if you know what you're doing.
1010         # XXX: Could highlight more here.
1011         $c =~ s@(?<=^Content-Type: )(.*)(?= not replaced)@$h{'content-type'}$1$h{'Standard'}@;
1012
1013     } elsif ($c =~ m/^(Server|Client) keep-alive timeout is/) {
1014
1015        # Server keep-alive timeout is 5. Sticking with 10.
1016        # Client keep-alive timeout is 20. Sticking with 10.
1017
1018        $c =~ s@(?<=timeout is )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1019        $c =~ s@(?<=Sticking with )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1020
1021     } elsif ($c =~ m/^Reducing keep-alive timeout/) {
1022
1023        # Reducing keep-alive timeout from 60 to 10.
1024
1025        $c =~ s@(?<= from )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1026        $c =~ s@(?<= to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1027
1028     } elsif ($c =~ m/^Killed all-caps Host header line: HOST:/) {
1029
1030        # Killed all-caps Host header line: HOST: bestproxydb.com
1031        $c = highlight_matched_host($c, '(?<=HOST: )[^\s]+');
1032        $c = highlight_matched_pattern($c, 'HOST', 'HOST');
1033
1034     } else {
1035
1036         found_unknown_content($c);
1037     }
1038
1039     # Highlight headers
1040     unless ($c =~ m/^Transforming/) {
1041         $c = highlight_known_headers($c) unless $no_special_header_highlighting;
1042     }
1043
1044     return $c;
1045 }
1046
1047 sub handle_loglevel_re_filter($) {
1048
1049     my $content = shift;
1050     my $c = $content;
1051     my $key;
1052
1053     if ($c =~ m/^(?:re_)?filtering ([^\s]+) \(size (\d+)\) with (?:filter )?\'?([^\s]+?)\'? produced (\d+) hits \(new size (\d+)\)/) {
1054
1055         # XXX: only the second version gets highlighted properly.
1056         # re_filtering www.lfk.de/favicon.ico (size 209) with filter untrackable-hulk produced 0 hits (new size 209).
1057         # filtering aci.blogg.de/ (size 37988) with 'blogg.de' produced 3 hits (new size 38057)
1058         $req{$t}{'content_source'} = $1;
1059         $req{$t}{'content_size'}   = $2;
1060         $req{$t}{'content_filter'} = $3;
1061         $req{$t}{'content_hits'}   = $4;
1062         $req{$t}{'new_content_size'} = $5;
1063         $req{$t}{'content_size_change'} = $req{$t}{'new_content_size'} - $req{$t}{'content_size'};
1064         #return '' if ($req{$t}{'content_hits'} == 0 && !cli_option_is_set('show-ineffective-filters'));
1065         if ($req{$t}{'content_hits'} == 0 and
1066             not (cli_option_is_set('show-ineffective-filters')
1067                  or ($req{$t}{'content_filter'} =~ m/^privoxy-filter-test$/))) {
1068                 return '';
1069         }
1070
1071         $c =~ s@(?<=\(size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1072         $c =~ s@(?<=\(new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1073         $c =~ s@(?<=produced )(\d+)(?= hits)@$h{'Number'}$1$h{'Standard'}@;
1074
1075         $c =~ s@([^\s]+?)(\'? produced)@$h{'filter'}$1$h{'Standard'}$2@;
1076         $c = highlight_matched_host($c, '(?<=filtering )[^\s]+');
1077
1078         $c =~ s@\.$@ @;
1079         $c .= "(" . $h{'Number'};
1080         $c .= "+" if ($req{$t}{'content_size_change'} >= 0);
1081         $c .= $req{$t}{'content_size_change'} . $h{'Standard'} . ")";
1082         $content = $c;
1083
1084     } elsif ($c =~ m/^filtering request body from client /) {
1085
1086         # filtering request body from client 127.0.0.1 (size 958) with 'null-filter' produced 0 hits (new size 958).
1087
1088         $c =~ s@(?<=from client )([^\s]+)@$h{'ip-address'}$1$h{'Standard'}@;
1089         $c =~ s@(?<=\(size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1090         $c =~ s@([^\s]+?)(\'? produced)@$h{'filter'}$1$h{'Standard'}$2@;
1091         $c =~ s@(?<=\(new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1092         $c =~ s@(?<=produced )(\d+)(?= hits)@$h{'Number'}$1$h{'Standard'}@;
1093         $content = $c;
1094
1095   } elsif ($c =~ /\.{3}$/
1096         and $c =~ m/^(?:re_)?filtering \'?(.*?)\'? \(size (\d*)\) with (?:filter )?\'?([^\s]*?)\'? ?\.{3}$/) {
1097
1098         # Used by Privoxy 3.0.5 and 3.0.6:
1099         # XXX: Fill in ...
1100         # Used by Privoxy 3.0.7:
1101         # filtering 'Connection: close' (size 17) with 'generic-content-ads' ...
1102
1103         $req{$t}{'filtered_header'} = $1;
1104         $req{$t}{'old_header_size'} = $2;
1105         $req{$t}{'header_filter_name'} = $3;
1106
1107         unless (cli_option_is_set('show-ineffective-filters') or
1108                 $req{$t}{'header_filter_name'} =~ m/^privoxy-filter-test$/) {
1109             return '';
1110         }
1111         $content =~ s@(?<=\(size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1112         $content =~ s@($req{$t}{'header_filter_name'})@$h{'filter'}$1$h{'Standard'}@;
1113
1114     } elsif ($c =~ m/^ ?\.\.\. ?produced (\d*) hits \(new size (\d*)\)\./) {
1115
1116         # ...produced 0 hits (new size 23).
1117         #... produced 1 hits (new size 54).
1118
1119         $req{$t}{'header_filter_hits'} = $1;
1120         $req{$t}{'new_header_size'} = $2;
1121
1122         unless (cli_option_is_set('show-ineffective-filters') or
1123                 (defined($req{$t}{'header_filter_name'}) and
1124                  $req{$t}{'header_filter_name'} =~ m/^privoxy-filter-test$/)) {
1125
1126             if ($req{$t}{'header_filter_hits'} == 0 and
1127                 not (defined($req{$t}{'header_filter_name'}) and
1128                  $req{$t}{'header_filter_name'} =~ m/^privoxy-filter-test$/)) {
1129                 return '';
1130             }
1131             # Reformat including information from the intro
1132             $c = "'" . h('filter') . $req{$t}{'header_filter_name'} . h('Standard') . "'";
1133             $c .= " hit ";
1134             # XXX: Hide behind constant, it may be interesting if LOG_LEVEL_HEADER isn't enabled as well.
1135             # $c .= $req{$t}{'filtered_header'} . " ";
1136             $c .= h('Number') . $req{$t}{'header_filter_hits'}. h('Standard');
1137             $c .= ($req{$t}{'header_filter_hits'} == 1) ? " time, " : " times, ";
1138
1139             if ($req{$t}{'old_header_size'} !=  $req{$t}{'new_header_size'}) {
1140
1141                 $c .= "changing size from ";
1142                 $c .=  h('Number') . $req{$t}{'old_header_size'} . h('Standard');
1143                 $c .= " to ";
1144                 $c .= h('Number') . $req{$t}{'new_header_size'} . h('Standard');
1145                 $c .= ".";
1146
1147             } else {
1148
1149                 $c .= "keeping the size at " . $req{$t}{'old_header_size'};
1150
1151             }
1152
1153             # Highlight from last line (XXX: What?)
1154             # $c =~ s@(?<=produced )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1155             # $c =~ s@($req{$t}{'header_filter_name'})@$h{'filter'}$1$h{'Standard'}@;
1156
1157         } else {
1158
1159            # XXX: Untested
1160            $c =~ s@(?<=produced )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1161            $c =~ s@(?<=new size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1162
1163         }
1164         $content = $c;
1165
1166     } elsif ($c =~ m/^(Tagger|Filter) ([^\s]*) has empty joblist. Nothing to do./) {
1167
1168         # Filter privoxy-filter-test has empty joblist. Nothing to do.
1169         # Tagger variable-test has empty joblist. Nothing to do.
1170
1171         $content =~ s@(?<=$1 )([^\s]*)@$h{'filter'}$1$h{'Standard'}@;
1172
1173     } elsif ($c =~ m/^De-chunking successful. Shrunk from (\d+) to (\d+)/) {
1174
1175         $req{$t}{'chunked-size'} = $1;
1176         $req{$t}{'dechunked-size'} = $2;
1177         $req{$t}{'dechunk-change'} = $req{$t}{'dechunked-size'} - $req{$t}{'chunked-size'};
1178
1179         $content .= " (" . h('Number') . $req{$t}{'dechunk-change'} . h('Standard') . ")";
1180
1181         $content =~ s@(?<=from )($req{$t}{'chunked-size'})@$h{'Number'}$1$h{'Standard'}@;
1182         $content =~ s@(?<=to )($req{$t}{'dechunked-size'})@$h{'Number'}$1$h{'Standard'}@;
1183
1184     } elsif ($c =~ m/^Decompression successful. Old size: (\d+), new size: (\d+)./) {
1185
1186         # Decompression successful. Old size: 670, new size: 1166.
1187
1188         $req{$t}{'size-compressed'} = $1;
1189         $req{$t}{'size-decompressed'} = $2;
1190         $req{$t}{'decompression-gain'} = $req{$t}{'size-decompressed'} - $req{$t}{'size-compressed'};
1191
1192         $content =~ s@(?<=Old size: )($req{$t}{'size-compressed'})@$h{'Number'}$1$h{'Standard'}@;
1193         $content =~ s@(?<=new size: )($req{$t}{'size-decompressed'})@$h{'Number'}$1$h{'Standard'}@;
1194
1195         # XXX: Create sub get_percentage()
1196         if ($req{$t}{'size-decompressed'}) {
1197             $req{$t}{'decompression-gain-percent'} =
1198                 $req{$t}{'decompression-gain'} / $req{$t}{'size-decompressed'} * 100;
1199
1200             $content .= " (saved: ";
1201             #$content .= h('Number') . $req{$t}{'decompression-gain'} . h('Standard');
1202             #$content .= "/";
1203             $content .= h('Number') . sprintf("%.2f%%", $req{$t}{'decompression-gain-percent'}) . h('Standard');
1204             $content .= ")";
1205         }
1206
1207     } elsif ($c =~ m/^(Need to de-chunk first)/) {
1208
1209         # Need to de-chunk first
1210         return '' if SUPPRESS_NEED_TO_DE_CHUNK_FIRST;
1211
1212     } elsif ($c =~ m/^(Adding (?:dynamic )?re_filter job)/) {
1213
1214         return ''  if (SUPPRESS_SUCCEEDED_FILTER_ADDITIONS && m/succeeded/);
1215
1216         # Adding re_filter job ...
1217         # Adding dynamic re_filter job s@^(?:\w*)\s+.*\s+HTTP/\d\.\d\s*@IP-ADDRESS: $origin@D\
1218         #  to filter client-ip-address succeeded.
1219
1220     } elsif ($c =~ m/^Compressed content from /) {
1221
1222         # Compressed content from 29258 to 8630 bytes. Compression level: 3
1223         $content =~ s@(?<=from )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1224         $content =~ s@(?<=to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1225         $content =~ s@(?<=level: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1226
1227     } elsif ($c =~ m/^Reading in filter/) {
1228
1229         return '' unless SHOW_FILTER_READIN_IN;
1230
1231     } elsif ($c =~ m/^Decompression didn't result/) {
1232
1233         # Decompression didn't result in any content.
1234
1235         # Nothing to highlight.
1236
1237     } else {
1238
1239         found_unknown_content($content);
1240
1241     }
1242
1243     return $content;
1244 }
1245
1246 sub handle_loglevel_tagging($) {
1247
1248     my $c = shift;
1249
1250     if ($c =~ /^Tagger \'([^\']*)\' added tag \'([^\']*)\'/ or
1251         $c =~ m/^Adding tag \'([^\']*)\' created by header tagger \'([^\']*)\'/) {
1252
1253         # Adding tag 'GET request' created by header tagger 'method-man' (XXX: no longer used)
1254         # Tagger 'revalidation' added tag 'REVALIDATION-REQUEST'. No action bit update necessary.
1255         # Tagger 'revalidation' added tag 'REVALIDATION-REQUEST'. Action bits updated accordingly.
1256
1257         # XXX: Save tag and tagger
1258
1259         $c =~ s@(?<=^Tagger \')([^\']*)@$h{'tagger'}$1$h{'Standard'}@;
1260         $c =~ s@(?<=added tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
1261         $c =~ s@(?<=Action bits )(updated)@$h{'action-bits-update'}$1$h{'Standard'}@;
1262
1263     } elsif ($c =~ /^Enlisting tag/) {
1264
1265         # Enlisting tag 'forward-directly' for client 127.0.0.1.
1266
1267         $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
1268         $c = highlight_matched_host($c, '[^\s]+(?=\.$)');
1269
1270     } elsif ($c =~ /^Tag/) {
1271
1272         # Tag 'change-tor-socks-port' for client 127.0.0.1 expired 1 seconds ago. Deleting it.
1273
1274         $c =~ s@(?<=Tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
1275         $c =~ s@(?<=expired )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1276         $c = highlight_matched_host($c, '(?<=client )[^\s]+');
1277
1278     } elsif ($c =~ /^Evaluating/) {
1279
1280         # Evaluating tag 'change-tor-socks-port' for client 127.0.0.1. End of life 1613162302.
1281
1282         $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
1283         $c = highlight_matched_host($c, '(?<=client )[^\s]+(?=\.)');
1284         $c =~ s@(?<=life )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1285
1286     } elsif ($c =~ /^Client tag/) {
1287
1288         # Client tag 'forward-directly' matches
1289
1290         $c =~ s@(?<=tag \')([^\']*)@$h{'tag'}$1$h{'Standard'}@;
1291
1292     }
1293
1294     return $c;
1295 }
1296
1297 sub handle_loglevel_redirect($) {
1298
1299     my $c = shift;
1300
1301     if ($c =~ m/^Decoding "([^""]*)"/) {
1302
1303          $req{$t}{'original-destination'} = $1;
1304          $c = highlight_matched_path($c, '(?<=Decoding ")[^"]*');
1305          $c =~ s@\"@@g;
1306
1307     } elsif ($c =~ m/^Checking/) {
1308
1309          # Checking /_ylt=A0geu.Z76BRGR9k/**http://search.yahoo.com/search?p=view+odb+presentation+on+freebsd\
1310          #  &ei=UTF-8&xargs=0&pstart=1&fr=moz2&b=11 for redirects.
1311
1312          # TODO: Change colour if really url-decoded
1313          $req{$t}{'decoded-original-destination'} = $1;
1314          $c = highlight_matched_path($c, '(?<=Checking ")[^"]*');
1315          $c =~ s@\"@@g;
1316
1317     } elsif ($c =~ m/^pcrs command "([^""]*)" changed /) {
1318
1319         # pcrs command "s@&from=rss@@" changed \
1320         #  "http://it.slashdot.org/article.pl?sid=07/03/02/1657247&from=rss"\
1321         #  to "http://it.slashdot.org/article.pl?sid=07/03/02/1657247" (1 hit).
1322         $c =~ s@(?<=pcrs command )"([^""]*)"@$h{'filter'}$1$h{'Standard'}@;
1323         $c = highlight_matched_url($c, '(?<=changed ")[^""]*');
1324         $c =~ s@(?<=changed )"([^""]*)"@$1@; # Remove quotes
1325         $c = highlight_matched_url($c, '(?<=to ")[^""]*');
1326         $c =~ s@(?<=to )"([^""]*)"@$1@; # Remove quotes
1327         $c =~ s@(\d+)(?= hits?)@$h{'hits'}$1$h{'Standard'}@;
1328
1329     } elsif ($c =~ m/^pcrs command "([^""]*)" didn\'t change/) {
1330
1331         # pcrs command "s@^http://([^.]+?)/?$@http://www.bing.com/search?q=$1@" didn't \
1332         #  change "http://www.example.org/".
1333         $c =~ s@(?<=pcrs command )"([^""]*)"@$h{'filter'}$1$h{'Standard'}@;
1334         $c = highlight_matched_url($c, '(?<=change ")[^""]*');
1335
1336     } elsif ($c =~ m/(^New URL is: )(.*)/) {
1337
1338         # New URL is: http://it.slashdot.org/article.pl?sid=07/03/04/1511210
1339         # XXX: Use URL highlighter
1340         # XXX: Save?
1341         $c = $1 . h('rewritten-URL') . $2 . h('Standard');
1342
1343     } elsif ($c =~ m/No pcrs command recognized, assuming that/) {
1344         # No pcrs command recognized, assuming that "http://config.privoxy.org/user-manual/favicon.png"\
1345         #  is already properly formatted.
1346         # XXX: assume the same?
1347         $c = highlight_matched_url($c, '(?<=assuming that \")[^"]*');
1348
1349     } elsif ($c =~ m/^Percent-encoding redirect/) {
1350
1351         # Percent-encoding redirect URL: http://www.example.org/\x02
1352         $c = highlight_matched_url($c, '(?<=redirect URL: ).*');
1353
1354     } elsif ($c =~ m/^Rewrite detected:/) {
1355
1356         # Rewrite detected: GET http://10.0.0.2:88/blah.txt HTTP/1.1
1357         # Rewrite detected: GET https://www.electrobsd.org/CommonJS/ajax/libs/jquery/3.4.1/jquery.min.js HTTP/1.1
1358         $c = highlight_matched_request_line($c, '(?<=^Rewrite detected: ).*');
1359
1360     } elsif ($c =~ m/^Rewritten request line results in downgrade to http/) {
1361
1362         # Rewritten request line results in downgrade to http
1363         $c =~ s@(downgrade)@$h{'http-downgrade'}$1$h{'Standard'}@;
1364
1365     } else {
1366
1367         found_unknown_content($c);
1368
1369     }
1370
1371     return $c;
1372 }
1373
1374 sub handle_loglevel_gif_deanimate($) {
1375
1376     my $content = shift;
1377
1378     if ($content =~ m/Success! GIF shrunk from (\d+) bytes to (\d+)\./) {
1379
1380         my $bytes_from = $1;
1381         my $bytes_to = $2;
1382         # Gif-Deanimate: Success! GIF shrunk from 205 bytes to 133.
1383         $content =~ s@$bytes_from@$h{'Number'}$bytes_from$h{'Standard'}@;
1384         # XXX: Do we need g in case of ($1 == $2)?
1385         $content =~ s@$bytes_to@$h{'Number'}$bytes_to$h{'Standard'}@;
1386
1387     } elsif ($content =~ m/GIF (not) changed/) {
1388
1389         # Gif-Deanimate: GIF not changed.
1390         return '' if SUPPRESS_GIF_NOT_CHANGED;
1391         $content =~ s@($1)@$h{'not'}$1$h{'Standard'}@;
1392
1393     } elsif ($content =~ m/^failed! \(gif parsing\)/) {
1394
1395         # failed! (gif parsing)
1396         # XXX: Replace this error message with something less stupid
1397         $content =~ s@(failed!)@$h{'error'}$1$h{'Standard'}@;
1398
1399     } elsif ($content =~ m/^Need to de-chunk first/) {
1400
1401         # Need to de-chunk first
1402         return '' if SUPPRESS_NEED_TO_DE_CHUNK_FIRST;
1403
1404     } elsif ($content =~ m/^(?:No GIF header found|failed while parsing)/) {
1405
1406         # No GIF header found (XXX: Did I ever commit this?)
1407         # failed while parsing 195 134747048 (XXX: never committed)
1408
1409         # Ignore these for now
1410
1411     } else {
1412
1413         found_unknown_content($content);
1414
1415     }
1416
1417     return $content;
1418 }
1419
1420 sub handle_loglevel_request($) {
1421
1422     my $content = shift;
1423
1424     if ($content =~ m/crunch! /) {
1425
1426         # config.privoxy.org/send-stylesheet crunch! (CGI Call)
1427
1428         # Highlight crunch reasons
1429         foreach my $reason (keys %reason_colours) {
1430             $content =~ s@\(($reason)\)@$reason_colours{$reason}($1)$h{'Standard'}@g;
1431         }
1432         # Highlight request URL domain and ditch 'crunch!'
1433         $content = highlight_matched_pattern($content, 'request_', '[^ ]*(?= crunch!)');
1434         $content =~ s@ crunch!@@;
1435
1436     } elsif ($content =~ m/\[too long, truncated\]$/) {
1437
1438         # config.privoxy.org/edit-actions-submit?f=3&v=1176116716&s=7&Submit=Submit[...]&filter... [too long, truncated]
1439         $content = highlight_matched_pattern($content, 'request_', '^.*(?=\.\.\. \[too long, truncated\]$)');
1440
1441     } elsif ($content =~ m/(.*)/) { # XXX: Pretty stupid
1442
1443         # trac.vidalia-project.net/wiki/Volunteer?format=txt
1444         $content = h('request_') . $content . h('Standard');
1445
1446     } else {  # XXX: Nop
1447
1448         found_unknown_content($content);
1449
1450     }
1451
1452     return $content;
1453 }
1454
1455 sub handle_loglevel_crunch($) {
1456
1457     my $content = shift;
1458
1459     # Highlight crunch reason
1460     foreach my $reason (keys %reason_colours) {
1461         $content =~ s@($reason)@$reason_colours{$reason}$1$h{'Standard'}@g;
1462     }
1463
1464     if ($content =~ m/\[too long, truncated\]$/) {
1465
1466         # Blocked: config.privoxy.org/edit-actions-submit?f=3&v=1176116716&s=7&Submit=Submit\
1467         #  [...]&filter... [too long, truncated]
1468         $content = highlight_matched_pattern($content, 'request_', '^.*(?=\.\.\. \[too long, truncated\]$)');
1469
1470     } elsif ($content =~ m/Certificate error:/) {
1471
1472         # Certificate error: ASN date error, current date after: https://expired.badssl.com/
1473         $content = highlight_matched_pattern($content, 'request_', 'https://.*');
1474
1475     } else {
1476
1477         # Blocked: http://ads.example.org/
1478         $content = highlight_matched_pattern($content, 'request_', '(?<=: ).*');
1479     }
1480
1481     return $content;
1482 }
1483
1484 sub handle_loglevel_connect($) {
1485
1486     my $c = shift;
1487
1488     if ($c =~ m/^via [^\s]+ to: [^\s]+/) {
1489
1490         # Connect: via 10.0.0.1:8123 to: www.example.org.noconnect
1491
1492         $c = highlight_matched_host($c, '(?<=via )[^\s]+');
1493         $c = highlight_matched_host($c, '(?<=to: )[^\s]+');
1494
1495     } elsif ($c =~ m/^connect to: .* failed: .*/) {
1496
1497         # connect to: www.example.org.noconnect failed: Operation not permitted
1498
1499         $c = highlight_matched_host($c, '(?<=connect to: )[^\s]+');
1500
1501         $c =~ s@(?<=failed: )(.*)@$h{'error'}$1$h{'Standard'}@;
1502
1503     } elsif ($c =~ m/^to ([^\s]*)( successful)?$/) {
1504
1505         # Connect: to www.nzherald.co.nz successful
1506         # Connect: to archiv.radiotux.de
1507
1508         return '' if SUPPRESS_SUCCESSFUL_CONNECTIONS;
1509         $c = highlight_matched_host($c, '(?<=to )[^\s]+');
1510
1511     } elsif ($c =~ m/^to ([^\s]*)$/) {
1512
1513         # Connect: to lists.sourceforge.net:443
1514
1515         $c = highlight_matched_host($c, '(?<=to )[^\s]+');
1516
1517     } elsif ($c =~ m/^[Aa]ccepted connection from .*/ or
1518              $c =~ m/^OK/) {
1519
1520         # Privoxy 3.0.20:
1521         # Accepted connection from 10.0.0.1 on socket 5
1522         # Privoxy between 3.0.20 and 3.0.6:
1523         # accepted connection from 10.0.0.1( on socket 5)?
1524         # Privoxy 3.0.6 and earlier just say:
1525         # OK
1526         $c = highlight_matched_host($c, '(?<=connection from )[^ ]*');
1527         $c = highlight_matched_pattern($c, 'Number', '(?<=socket )\d+');
1528
1529     } elsif ($c =~ m/^Closing client socket/) {
1530
1531         # Closing client socket 5. Keep-alive: 0, Socket alive: 1. Data available: 0.
1532         # Privoxy 3.0.20 and later
1533         # Closing client socket 8. Keep-alive: 1. Socket alive: 0. Data available: 0. \
1534         #  Configuration file change detected: 0. Requests received: 11.
1535
1536         $c = highlight_matched_pattern($c, 'Number', '(?<=socket )\d+');
1537         $c = highlight_matched_pattern($c, 'Number', '(?<=Keep-alive: )\d+');
1538         $c = highlight_matched_pattern($c, 'Number', '(?<=Socket alive: )\d+');
1539         $c = highlight_matched_pattern($c, 'Number', '(?<=available: )\d+');
1540         $c = highlight_matched_pattern($c, 'Number', '(?<=detected: )\d+');
1541         $c = highlight_matched_pattern($c, 'Number', '(?<=received: )\d+');
1542
1543     } elsif ($c =~ m/^write header to: .* failed:/) {
1544
1545         # write header to: 10.0.0.1 failed: Broken pipe
1546
1547         $c = highlight_matched_host($c, '(?<=write header to: )[^\s]*');
1548         $c =~ s@(?<=failed: )(.*)@$h{'Error'}$1$h{'Standard'}@;
1549
1550     } elsif ($c =~ m/^write header to client failed:/) {
1551
1552         # write header to client failed: Broken pipe
1553         # XXX: Stil in use?
1554         $c =~ s@(?<=failed: )(.*)@$h{'Error'}$1$h{'Standard'}@;
1555
1556     } elsif ($c =~ m/^socks4_connect:/) {
1557
1558         # socks4_connect: SOCKS request rejected or failed.
1559         $c =~ s@(?<=socks4_connect: )(.*)@$h{'Error'}$1$h{'Standard'}@;
1560
1561     } elsif ($c =~ m/^Listening for new connections/ or
1562              $c =~ m/^accept connection/) {
1563         # XXX: Highlight?
1564         # Privoxy versions above 3.0.6 say:
1565         # Listening for new connections ...
1566         # earlier versions say:
1567         # accept connection ...
1568         return '';
1569
1570     } elsif ($c =~ m/^accept failed:/) {
1571
1572         $c =~ s@(?<=accept failed: )(.*)@$h{'Error'}$1$h{'Standard'}@;
1573
1574     } elsif ($c =~ m/^Overriding forwarding settings/) {
1575
1576         # Overriding forwarding settings based on 'forward 10.0.0.1:8123'
1577         $c =~ s@(?<=based on \')(.*)(?=\')@$h{'configuration-line'}$1$h{'Standard'}@;
1578
1579     } elsif ($c =~ m/^Denying suspicious CONNECT request from/) {
1580
1581         # Denying suspicious CONNECT request from 10.0.0.1
1582         $c = highlight_matched_host($c, '(?<=from )[^\s]+'); # XXX: not an URL
1583
1584     } elsif ($c =~ m/^socks5_connect:/) {
1585
1586         $c =~ s@(?<=socks5_connect: )(.*)@$h{'error'}$1$h{'Standard'}@;
1587
1588     } elsif ($c =~ m/^Created new connection to/) {
1589
1590         # Created new connection to www.privoxy.org:80 on socket 11.
1591         $c = highlight_matched_host($c, '(?<=connection to )[^\s]+');
1592         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1593
1594     } elsif ($c =~ m/^Found reusable socket/) {
1595
1596         # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
1597         # 3.0.15 and later:
1598         # Found reusable socket 8 for www.privoxy.org:80 in slot 2.\
1599         #  Timestamp made 0 seconds ago. Timeout: 1. Latency: 0.
1600         $c =~ s@(?<=Found reusable socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1601         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
1602         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1603         $c =~ s@(?<=made )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1604         $c =~ s@(?<=Timeout: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1605         $c =~ s@(?<=Latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1606
1607     } elsif ($c =~ m/^Marking open socket/) {
1608
1609         # Marking open socket 9 for www.privoxy.org:80 in slot 0 as unused.
1610         $c =~ s@(?<=Marking open socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1611         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
1612         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1613
1614     } elsif ($c =~ m/^No reusable/) {
1615
1616         # No reusable socket for addons.mozilla.org:443 found. Opening a new one.
1617         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
1618
1619     } elsif ($c =~ m/^(Remembering|Forgetting) socket/) {
1620
1621         # Remembering socket 13 for www.privoxy.org:80 in slot 0.
1622         # Forgetting socket 38 for www.privoxy.org:80 in slot 5.
1623
1624         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1625         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
1626         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1627
1628     } elsif ($c =~ m/^Socket \d+ (already|closed)/) {
1629
1630         # Socket 16 already forgotten or never remembered.
1631         # Socket 9 closed while waiting for client headers
1632         $c =~ s@(?<=Socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1633
1634     } elsif ($c =~ m/^The connection to/) {
1635
1636         # The connection to www.privoxy.org:80 in slot 6 timed out. Closing socket 19. Timeout is: 61.
1637         # 3.0.15 and later:
1638         # The connection to 1.bp.blogspot.com:80 in slot 0 timed out. Closing socket 5.\
1639         #  Timeout is: 1. Assumed latency: 4.
1640         # The connection to 10.0.0.1:80 in slot 0 is no longer usable. Closing socket 4.
1641         $c = highlight_matched_host($c, '(?<=connection to )[^\s]+');
1642         $c =~ s@(?<=in slot )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1643         $c =~ s@(?<=Closing socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1644         $c =~ s@(?<=Timeout is: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1645         $c =~ s@(?<=Assumed latency: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1646
1647     } elsif ($c =~ m/^Stopped waiting for the request line/ or
1648              $c =~ m/^No request line on socket \d+ received in time/ or
1649              $c =~ m/^The client side of the connection on socket \d/) {
1650
1651         # Stopped waiting for the request line. Timeout: 121.
1652         # Privoxy 3.0.19 and later:
1653         # No request line on socket 5 received in time. Timeout: 1.
1654         # The client side of the connection on socket 5 got closed \
1655         #  without sending a complete request line.
1656         $c =~ s@(?<=Timeout: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1657         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1658
1659     } elsif ($c =~ m/^Waiting for \d/) {
1660
1661         # Waiting for 1 connections to timeout.
1662         $c =~ s@(?<=^Waiting for )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1663
1664     } elsif ($c =~ m/^Initialized/) {
1665
1666         # Initialized 20 socket slots.
1667         $c =~ s@(?<=Initialized )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1668
1669     } elsif ($c =~ m/^Done reading from server/) {
1670
1671         # Done reading from server. Expected content length: 24892. \
1672         #  Actual content length: 24892. Most recently received: 4412.
1673         # 3.0.15 and later:
1674         # Done reading from server. Expected content length: 24892. \
1675         #  Actual content length: 24892. Bytes most recently read: 4412.
1676         # Done reading from server. Content length: 6018 as expected. \
1677         #  Bytes most recently read: 294.
1678         $c =~ s@(?<=ontent length: )(\d+)@$h{'Number'}$1$h{'Standard'}@g;
1679         $c =~ s@(?<=received: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1680         $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1681
1682     } elsif ($c =~ m/^Continuing buffering (?:server )?headers/) {
1683
1684         # Continuing buffering headers. byte_count: 19. header_offset: 517. len: 536.
1685         $c =~ s@(?<=byte_count: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1686         $c =~ s@(?<=header_offset: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1687         $c =~ s@(?<=len: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1688         # 3.0.15 up to 3.0.19:
1689         # Continuing buffering headers. Bytes most recently read: 498.
1690         $c =~ s@(?<=read: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1691         # 3.0.20 and later:
1692         # Continuing buffering server headers from socket 5. Bytes most recently read: 498.
1693         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1694
1695     } elsif ($c =~ m/^Received \d+ bytes while/) {
1696
1697         # Received 206 bytes while expecting 12103.
1698         $c =~ s@(?<=Received )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1699         $c =~ s@(?<=expecting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1700
1701     } elsif ($c =~ m/^(Rejecting c|C)onnection from/) {
1702
1703         # Connection from 81.163.28.218 dropped due to ACL
1704         # Rejecting connection from 178.63.152.227. Maximum number of connections reached.
1705         # Connection from 192.168.2.1 on 127.0.1.1:8118 (socket 3) dropped due to ACL
1706         $c = highlight_matched_host($c, '(?<=onnection from )[\d.:]+');
1707         $c = highlight_matched_host($c, '(?<=on )[\d.:]+');
1708         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1709
1710     } elsif ($c =~ m/^(?:Reusing|Closing) server socket / or
1711              $c =~ m/^No additional client request/) {
1712
1713         # Reusing server socket 4. Opened for 10.0.0.1.
1714         # Closing server socket 2. Opened for 10.0.0.1.
1715         # No additional client request received in time. \
1716         #  Closing server socket 4, initially opened for 10.0.0.1.
1717         # No additional client request received in time on socket 29.
1718         # Privoxy 3.0.20 and later
1719         # Reusing server socket 7 connected to www.privoxy.org. Total requests: 2.
1720         # Closing server socket 6 connected to d.asset.soup.io. Keep-alive: 0.\
1721         #  Tainted: 1. Socket alive: 1. Timeout: 60. Configuration file change detected: 0.
1722         # Reusing server socket 35 connected to nl.wikipedia.org. Requests already sent: 5.
1723
1724         $c =~ s@(?<= socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1725         $c = highlight_matched_host($c, '(?<=for )[^\s]+(?=\.)');
1726         $c = highlight_matched_host($c, '(?<=connected to )[^\s]+(?=\.)');
1727         for my $number_pattern ('requests', 'Keep-alive', 'Tainted', ' alive', 'Timeout', 'detected') {
1728             $c = highlight_matched_pattern($c, 'Number', '(?<='. $number_pattern . ': )\d+');
1729         }
1730         $c =~ s@(?<=already sent: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1731
1732     } elsif ($c =~ m/^Connected to /) {
1733
1734         # Connected to tor-jail[10.0.0.2]:9050.
1735
1736         $c = highlight_matched_host($c, '(?<=\[)[^\]]+');
1737         $c = highlight_matched_host($c, '(?<=Connected to )[^\[\s]+');
1738         $c =~ s@(?<=\]:)(\d+)@$h{'Number'}$1$h{'Standard'}@;
1739
1740     } elsif ($c =~ m/^Could not connect to /) {
1741
1742         # Could not connect to [10.0.0.1]:80.
1743
1744         $c = highlight_matched_host($c, '(?<=\[)[^\]]+');
1745         $c =~ s@(?<=\]:)(\d+)@$h{'Number'}$1$h{'Standard'}@;
1746
1747     } elsif ($c =~ m/^Waiting for the next client request/ or
1748              $c =~ m/^The connection on server socket/ or
1749              $c =~ m/^Client request (?:\d+ )?(?:arrived in time|has been pipelined) /) {
1750
1751         # Waiting for the next client request on socket 3. Keeping the server \
1752         #  socket 12 to a.fsdn.com open.
1753         # The connection on server socket 6 to upload.wikimedia.org isn't reusable. Closing.
1754         # Privoxy 3.0.20 and later:
1755         # Client request 4 arrived in time on socket 7.
1756         # Used by Privoxy 3.0.18 and 3.0.19:
1757         # Client request arrived in time on socket 21.
1758         # Used by earlier version:
1759         # Client request arrived in time or the client closed the connection on socket 12.
1760         # Client request 8 has been pipelined on socket 7 and the socket is still alive.
1761
1762         $c =~ s@(?<=request )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1763         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1764         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1765         $c = highlight_matched_host($c, '(?<=to )[^\s]+');
1766
1767     } elsif ($c =~ m/^Marking the server socket/) {
1768
1769         # Marking the server socket 7 tainted.
1770
1771         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1772
1773     } elsif ($c =~ m/^Reduced expected bytes to /) {
1774
1775         # Reduced expected bytes to 0 to account for the 1542 ones we already got.
1776         $c =~ s@(?<=bytes to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1777         $c =~ s@(?<=for the )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1778
1779     } elsif ($c =~ m/^The client closed socket /) {
1780
1781         # The client closed socket 2 while the server socket 4 is still open.
1782         $c =~ s@(?<=closed socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1783         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1784
1785     } elsif ($c =~ m/^Expected client content length set /) {
1786
1787         # Expected client content length set to 667325411 after reading 4999 bytes.
1788         $c =~ s@(?<=set to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1789         $c =~ s@(?<=reading )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1790
1791     } elsif ($c =~ m/^Reducing expected bytes to /) {
1792
1793         # Reducing expected bytes to 0. Marking the server socket tainted after throwing 4 bytes away.
1794         $c =~ s@(?<=bytes to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1795         $c =~ s@(?<=after throwing )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1796
1797     } elsif ($c =~ m/^Waiting for up to /) {
1798
1799         # Waiting for up to 4999 bytes from the client.
1800         $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1801
1802     } elsif ($c =~ m/^Optimistically sending /) {
1803
1804         # Optimistically sending 318 bytes of client headers intended for www.privoxy.org
1805         $c =~ s@(?<=sending )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1806         $c = highlight_matched_host($c, '(?<=for )[^\s]+');
1807
1808     } elsif ($c =~ m/^Stopping to watch the client socket/) {
1809
1810         # Stopping to watch the client socket. There's already another request waiting.
1811         # Privoxy 3.0.20 and later:
1812         # Stopping to watch the client socket 5. There's already another request waiting.
1813         $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1814
1815     } elsif ($c =~ m/^Drained \d+ bytes before closing/) {
1816
1817         # Drained 180 bytes before closing socket 6
1818         $c =~ s@(?<=Drained )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1819         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1820
1821     } elsif ($c =~ m/^Tainting client socket/ or
1822              $c =~ m/^Failed to shutdown socket/) {
1823
1824         # Tainting client socket 7 due to unread data.
1825         # Failed to shutdown socket 11: Connection reset by peer
1826
1827         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1828
1829     } elsif ($c =~ m/^Shifting \d+ pipelined bytes/) {
1830
1831         # Shifting 360 pipelined bytes by 360 bytes
1832         $c =~ s@(?<=Shifting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1833         $c =~ s@(?<=by )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1834
1835     } elsif ($c =~ m/^Flushed (\d+) bytes of request body while expecting (\d+)/) {
1836
1837         # Flushed 30 bytes of request body while expecting 30
1838         $c =~ s@(?<=Flushed )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1839         $c =~ s@(?<=expecting )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1840
1841     } elsif ($c =~ m/^Performing the TLS\/SSL handshake with client. Hash of host:/) {
1842
1843         # Performing the TLS/SSL handshake with client. Hash of host: bab5296b25e256c7b06b92b17b56bcae
1844         $c = highlight_matched_host($c, '(?<=Hash of host: ).+');
1845
1846     } elsif ($c =~ m/^Forwarding \d+ bytes of encrypted POST data/) {
1847
1848         # Forwarding 1954 bytes of encrypted POST data
1849         $c =~ s@(?<=Forwarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1850
1851     } elsif ($c =~ m/^Forwarded the last \d+ bytes/) {
1852
1853         # Forwarded the last 1954 bytes
1854         $c =~ s@(?<=the last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1855
1856     } elsif ($c =~ m/^Waiting for the next client connection. Currently active threads:/) {
1857
1858         # Waiting for the next client connection. Currently active threads: 30
1859         $c =~ s@(?<=threads: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1860
1861     } elsif ($c =~ m/^Data arrived in time on client socket/) {
1862
1863         # Data arrived in time on client socket 6. Requests so far: 3
1864         $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1865         $c =~ s@(?<=Requests so far: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1866
1867     } elsif ($c =~ m/^Dropping the client connection on socket/) {
1868
1869         # Dropping the client connection on socket 71. The server connection has not been established yet.
1870         # Dropping the client connection on socket 23 with server socket 24 connected to \
1871         #  www.reddit.com. The forwarder has changed.
1872         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1873         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1874         $c = highlight_matched_host($c, '(?<=connected to )[^ ]+(?=\.)');
1875
1876     } elsif ($c =~ m/^The client socket \d+ has become unusable while the server/) {
1877
1878         # The client socket 16 has become unusable while the server socket 24 is still open.
1879         $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1880         $c =~ s@(?<=server socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1881
1882     } elsif ($c =~ m/^The last \d+ bytes of the request body have been read/) {
1883
1884         # The last 12078 bytes of the request body have been read
1885         $c =~ s@(?<=The last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1886
1887     } elsif ($c =~ m/^Flushed \d+ bytes of request body/) {
1888
1889         # Flushed 3153 bytes of request body
1890         $c =~ s@(?<=Flushed )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1891
1892     } elsif ($c =~ m/^Complete client request followed by/) {
1893
1894         # Complete client request followed by 59 bytes of pipelined data received.
1895         $c =~ s@(?<=followed by )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1896
1897     } elsif ($c =~ m/^The peer notified us that the connection on socket/) {
1898
1899         # The peer notified us that the connection on socket 11 is going to be closed
1900         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1901
1902     } elsif ($c =~ m/^Client socket \d is no longer usable/) {
1903
1904         # Client socket 7 is no longer usable. The server socket has been closed.
1905         $c =~ s@(?<=socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1906
1907     } elsif ($c =~ m/^Socket timeout \d+ reached/) {
1908
1909         # Socket timeout 3 reached: http://127.0.0.1:20000/no-filter/chunked-content/36
1910         $c =~ s@(?<=timeout )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1911         $c = highlight_matched_url($c, "(?<=reached: ).*")
1912
1913     } elsif ($c =~ m/^Prepared to read up to /) {
1914
1915         # Prepared to read up to 157 bytes of encrypted request body from the client.
1916         $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1917
1918     } elsif ($c =~ m/^Forwarding \d+ bytes /) {
1919
1920         # Forwarding 157 bytes of encrypted request body.
1921         $c =~ s@(?<=Forwarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1922
1923     } elsif ($c =~ m/^Buffering encrypted client body/) {
1924
1925         # Buffering encrypted client body. Prepared to read up to 2236 bytes.
1926         $c =~ s@(?<=up to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1927
1928     } elsif ($c =~ m/^The last \d+ bytes of the encrypted request body have been read/) {
1929
1930         # The last 6945 bytes of the encrypted request body have been read.
1931         $c =~ s@(?<=The last )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1932
1933     } elsif ($c =~ m/^Reducing the chunk offset from/) {
1934
1935         # Reducing the chunk offset from 1096654 to 32704 after discarding 1063950 bytes to make room in the buffer.
1936         # Reducing the chunk offset from 16219 to 128 after flushing 16091 bytes.
1937         $c =~ s@(?<=\d to )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1938         $c =~ s@(?<=offset from )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1939         $c =~ s@(?<=after discarding )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1940         $c =~ s@(?<=after flushing )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1941
1942     } elsif ($c =~ m/^Client socket \d+ is no longer usable/) {
1943
1944         # Client socket 21 is no longer usable. The server socket has been closed.
1945         $c =~ s@(?<=Client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
1946
1947     } elsif ($c =~ m/^Looks like we / or
1948              $c =~ m/^Unsetting keep-alive flag/ or
1949              $c =~ m/^No connections to wait/ or
1950              $c =~ m/^Complete client request received/ or
1951              $c =~ m/^Possible pipeline attempt detected./ or
1952              $c =~ m/^POST request detected. The connection will not be kept alive./ or
1953              $c =~ m/^The server still wants to talk, but the client hung up on us./ or
1954              $c =~ m/^The server didn't specify how long the connection will stay open/ or
1955              $c =~ m/^There might be a request body. The connection will not be kept alive/ or
1956              $c =~ m/^There better be a request body./ or
1957              $c =~ m/^Done reading from the client\.$/) {
1958
1959         # Looks like we reached the end of the last chunk. We better stop reading.
1960         # Looks like we read the end of the last chunk together with the server \
1961         #  headers. We better stop reading.
1962         # Looks like we got the last chunk together with the server headers. \
1963         #  We better stop reading.
1964         # Unsetting keep-alive flag.
1965         # No connections to wait for left.
1966         # Client request arrived in time or the client closed the connection.
1967         # Complete client request received
1968         # Possible pipeline attempt detected. The connection will not be \
1969         #  kept alive and we will only serve the first request.
1970         # POST request detected. The connection will not be kept alive.
1971         # The server still wants to talk, but the client hung up on us.
1972         # The server didn't specify how long the connection will stay open. Assume it's only a second.
1973         # There might be a request body. The connection will not be kept alive.
1974         # Privoxy 3.0.20 and later
1975         # There better be a request body.
1976         # Done reading from the client.
1977
1978     } else {
1979
1980         found_unknown_content($c);
1981
1982     }
1983
1984     return $c;
1985 }
1986
1987
1988 sub handle_loglevel_info($) {
1989
1990     my $c = shift;
1991
1992     if ($c =~ m/^Rewrite detected:/) {
1993
1994         # Rewrite detected: GET http://10.0.0.2:88/blah.txt HTTP/1.1
1995         $c = highlight_matched_request_line($c, '(?<=^Rewrite detected: ).*');
1996
1997     } elsif ($c =~ m/^Decompress(ing deflated|ion didn)/ or
1998              $c =~ m/^Compressed content detected/ or
1999              $c =~ m/^SDCH-compressed content detected/ or
2000              $c =~ m/^Tagger/
2001             ) {
2002         # Decompressing deflated iob: 117
2003         # Decompression didn't result in any content.
2004         # Compressed content detected, content filtering disabled. Consider recompiling Privoxy\
2005         #  with zlib support or enable the prevent-compression action.
2006         # SDCH-compressed content detected, content filtering disabled.\
2007         #  Consider suppressing SDCH offers made by the client.
2008         # Tagger 'complete-url' created empty tag. Ignored.
2009
2010         # Ignored for now
2011
2012     } elsif ($c =~ m/^(Re)?loading configuration file /) {
2013
2014         # loading configuration file '/usr/local/etc/privoxy/config':
2015         # Reloading configuration file '/usr/local/etc/privoxy/config'
2016         $c =~ s@(?<=loading configuration file \')([^\']*)@$h{'file'}$1$h{'Standard'}@;
2017
2018     } elsif ($c =~ m/^Loading (actions|filter|trust) file: /) {
2019
2020         # Loading actions file: /usr/local/etc/privoxy/default.action
2021         # Loading filter file: /usr/local/etc/privoxy/default.filter
2022         # Loading trust file: /usr/local/etc/privoxy/trust
2023
2024         $c =~ s@(?<= file: )(.*)$@$h{'file'}$1$h{'Standard'}@;
2025
2026     } elsif ($c =~ m/^exiting by signal/) {
2027
2028         # exiting by signal 15 .. bye
2029         $c =~ s@(?<=exiting by signal )(\d+)@$h{'signal'}$1$h{'Standard'}@;
2030
2031     } elsif ($c =~ m/^Privoxy version/) {
2032
2033         # Privoxy version 3.0.7
2034         $c =~ s@(?<=^Privoxy version )(\d+\.\d+\.\d+)$@$h{'version'}$1$h{'Standard'}@;
2035
2036     } elsif ($c =~ m/^Program name: /) {
2037
2038         # Program name: /usr/local/sbin/privoxy
2039         $c =~ s@(?<=Program name: )(.*)@$h{'program-name'}$1$h{'Standard'}@;
2040
2041     } elsif ($c =~ m/^Listening on port /) {
2042
2043         # Listening on port 8118 on IP address 10.0.0.1
2044         $c =~ s@(?<=Listening on port )(\d+)@$h{'port'}$1$h{'Standard'}@;
2045         $c =~ s@(?<=on IP address )(.*)@$h{'ip-address'}$1$h{'Standard'}@;
2046
2047     } elsif ($c =~ m/^\(Re-\)Open(?:ing)? logfile/) {
2048
2049         # (Re-)Open logfile /var/log/privoxy/privoxy.log
2050         $c =~ s@(?<=Open logfile )(.*)@$h{'file'}$1$h{'Standard'}@;
2051
2052     } elsif ($c =~ m/^(Request from|Malformed server response detected)/) {
2053
2054         # Request from 10.0.0.1 denied. limit-connect{,} doesn't allow CONNECT requests to port 443.
2055         # Request from 10.0.0.1 marked for blocking. limit-connect{,} doesn't allow CONNECT requests to port 443.
2056         # 3.0.18 and later:
2057         # Request from 10.0.0.1 marked for blocking. limit-connect{0} doesn't allow CONNECT requests to www.example.org:443
2058         # Malformed server response detected. Downgrading to HTTP/1.0 impossible.
2059
2060         $c =~ s@(?<=Request from )([^\s]*)@$h{'ip-address'}$1$h{'Standard'}@;
2061         $c =~ s@(denied|blocking)@$h{'warning'}$1$h{'Standard'}@;
2062         $c =~ s@(CONNECT)@$h{'method'}$1$h{'Standard'}@;
2063         $c =~ s@(?<=to port )(\d+)@$h{'port'}$1$h{'Standard'}@;
2064         $c =~ s@(?<=to )([^\s]+)@$h{'request_'}$1$h{'Standard'}@;
2065
2066     } elsif ($c =~ m/^Status code/) {
2067
2068         # Status code 304 implies no body.
2069         $c =~ s@(?<=Status code )(\d+)@$h{'status-code'}$1$h{'Standard'}@;
2070
2071     } elsif ($c =~ m/^Method/) {
2072
2073         # Method HEAD implies no body.
2074         $c =~ s@(?<=Method )([^\s]+)@$h{'method'}$1$h{'Standard'}@;
2075
2076     } elsif ($c =~ m/^Buffer limit reached while extending /) {
2077
2078         # Buffer limit reached while extending the buffer (iob). Needed: 4197470. Limit: 4194304
2079         $c =~ s@(?<=Needed: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2080         $c =~ s@(?<=Limit: )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2081
2082     } elsif ($c =~ m/^File modification detected: /) {
2083
2084         # File modification detected: /usr/local/etc/privoxy/user-agent.action
2085         $c =~ s@(?<= detected: )(.*)$@$h{'file'}$1$h{'Standard'}@;
2086
2087     } elsif ($c =~ m/^No logfile configured/ or
2088              $c =~ m/^Malformerd HTTP headers detected and MS IIS5 hack enabled/ or
2089              $c =~ m/^Invalid \"chunked\" transfer/ or
2090              $c =~ m/^Support for/ or
2091              $c =~ m/^Flushing header and buffers/ or
2092              $c =~ m/^Can not resolve/
2093              ) {
2094
2095         # No logfile configured. Please enable it before reporting any problems.
2096         # Malformerd HTTP headers detected and MS IIS5 hack enabled. Expect an invalid \
2097         #  response or even no response at all.
2098         # No logfile configured. Logging disabled.
2099         # Invalid "chunked" transfer encoding detected and ignored.
2100         # Support for 'Connection: keep-alive' is experimental, incomplete and\
2101         #  known not to work properly in some situations.
2102         # Flushing header and buffers. Stepping back from filtering.
2103         # Can not resolve doesnotexist: hostname nor servname provided, or not known
2104
2105     } else {
2106
2107         found_unknown_content($c);
2108
2109     }
2110
2111     return $c;
2112 }
2113
2114 sub handle_loglevel_cgi($) {
2115
2116     my $c = shift;
2117
2118     if ($c =~ m/^Granting access to/) {
2119
2120         #Granting access to http://config.privoxy.org/send-stylesheet, referrer http://p.p/ is trustworthy.
2121
2122     } elsif ($c =~ m/^Substituting: s(.)/) {
2123
2124         # Substituting: s/@else-not-FEATURE_ZLIB@.*@endif-FEATURE_ZLIB@//sigTU
2125         # XXX: prone to span several lines
2126
2127         my $delimiter = $1;
2128         #$c =~ s@(?<=failed: )(.*)@$h{'error'}$1$h{'Standard'}@;
2129         $c =~ s@(?!<=\\)($delimiter)@$h{'pcrs-delimiter'}$1$h{'Standard'}@g; # XXX: Too aggressive
2130         #$c =~ s@(?!<=\\)($1)@$h{'pcrs-delimiter'}$1$h{'Standard'}@g;
2131     }
2132
2133     return $c;
2134 }
2135
2136 sub handle_loglevel_force($) {
2137
2138     my $c = shift;
2139
2140     if ($c =~ m/^Ignored force prefix in request:/) {
2141
2142         # Ignored force prefix in request: "GET http://10.0.0.1/PRIVOXY-FORCE/block HTTP/1.1"
2143         $c =~ s@^(Ignored)@$h{'ignored'}$1$h{'Standard'}@;
2144         $c = highlight_matched_request_line($c, '(?<=request: ")[^"]*');
2145
2146     } elsif ($c =~ m/^Enforcing request:/) {
2147
2148         # Enforcing request: "GET http://10.0.0.1/block HTTP/1.1".
2149         $c = highlight_matched_request_line($c, '(?<=request: ")[^"]*');
2150
2151     } else {
2152
2153         found_unknown_content($c);
2154
2155     }
2156
2157     return $c;
2158 }
2159
2160 sub handle_loglevel_error($) {
2161
2162     my $c = shift;
2163
2164     if ($c =~ m/^(?:Empty|No) server or forwarder response received on socket \d+\./) {
2165
2166         # Empty server or forwarder response received on socket 4.
2167         # Empty server or forwarder response received on socket 3. \
2168         #  Closing client socket 15 without sending data.
2169         # Used by Privoxy 3.0.18 and later:
2170         # No server or forwarder response received on socket 8. \
2171         #  Closing client socket 10 without sending data.
2172
2173         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2174         $c =~ s@(?<=client socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2175
2176     } elsif ($c =~ m/^Didn't receive data in time:/) {
2177
2178         # Didn't receive data in time: a.fsdn.com:443
2179         $c =~ s@(?<=in time: )(.*)@$h{'destination'}$1$h{'Standard'}@;
2180
2181     } elsif ($c =~ m/^Sending data on socket \d+ over TLS/) {
2182
2183         # Sending data on socket 33 over TLS/SSL failed: no TLS/SSL errors detected
2184         $c =~ s@(?<=on socket )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2185
2186     } elsif ($c =~ m/^Chunk size \d+ exceeds buffered data left/) {
2187
2188         # Chunk size 291 exceeds buffered data left. Already digested 69894 of 69957 buffered bytes.
2189         $c =~ s@(?<=size )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2190         $c =~ s@(?<=digested )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2191         $c =~ s@(?<=of )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2192
2193     } elsif ($c =~ m/^The socks connection timed out after/) {
2194
2195         # The socks connection timed out after 60 seconds.
2196         $c =~ s@(?<=after )(\d+)@$h{'Number'}$1$h{'Standard'}@;
2197     }
2198
2199     # XXX: There are probably more messages that deserve highlighting.
2200
2201     return $c;
2202 }
2203
2204
2205 sub handle_loglevel_ignore($) {
2206     return shift;
2207 }
2208
2209 sub gather_loglevel_clf_stats($) {
2210
2211     my $content = shift;
2212     my ($method, $resource, $http_version, $status_code, $size);
2213     our %stats;
2214     our %cli_options;
2215
2216     # +0200] "GET https://www.youtube.com/watch?v=JmcA9LIIXWw HTTP/1.1" 200 68004
2217     # +0200] "VERSION-CONTROL http://p.p/ HTTP/1.1" 200 2787
2218     $content =~ m/^[+-]\d{4}\] "([^ ]+) (.+) (HTTP\/\d\.\d)" (\d+) (\d+)/;
2219     $method       = $1;
2220     $resource     = $2;
2221     $http_version = $3;
2222     $status_code  = $4;
2223     $size         = $5;
2224
2225     $stats{requests_clf}++;
2226
2227     unless (defined $method) {
2228         # +0200] "Invalid request" 400 0
2229         return if ($content =~ m/^[+-]\d{4}\] "Invalid request"/);
2230         # +0100] "Failed reading chunked client body" 400 0
2231         return if ($content =~ m/^[+-]\d{4}\] "Failed reading chunked client body"/);
2232         # +0100] "GET https://securepubads.g.doubleclick.net/gampad/ads?gd[...]... [too long, truncated]
2233         if ($content =~ m/\[too long, truncated\]$/) {
2234             print("Skipped LOG_LEVEL_CLF message that got truncated by Privoxy. Statistics will be inprecise.\n");
2235         } else {
2236             print("Failed to parse: $content\n");
2237         }
2238         return;
2239     }
2240     $stats{'method'}{$method}++;
2241     if ($cli_options{'url-statistics-threshold'} != 0) {
2242         $stats{'resource'}{$resource}++;
2243     }
2244     $stats{'http-version'}{$http_version}++;
2245
2246     if ($cli_options{'host-statistics-threshold'} != 0) {
2247         $resource =~ m@(?:https?://)?([^/]+)/?@;
2248         $stats{'hosts'}{$1}++;
2249     }
2250     $stats{'content-size-total'} += $size;
2251     $stats{'status-code'}{$status_code}++;
2252 }
2253
2254 sub gather_loglevel_request_stats($$) {
2255     my $request_url = shift;
2256     my $thread = shift;
2257     our %stats;
2258     our %cli_options;
2259
2260     $stats{requests}++;
2261     if ($cli_options{'passed-request-statistics-threshold'} != 0) {
2262         # If the request get blocked we'll decrement
2263         # in gather_loglevel_crunch_stats()
2264         chomp $request_url;
2265         $stats{'passed-request-url'}{$request_url}++;
2266     }
2267 }
2268
2269 sub gather_loglevel_crunch_stats($$) {
2270     my $c = shift;
2271     my $thread = shift;
2272     our %stats;
2273     our %cli_options;
2274
2275     $stats{crunches}++;
2276
2277     if ($c =~ m/^Redirected:/) {
2278         # Redirected: http://www.example.org/http://p.p/
2279         $stats{'fast-redirections'}++;
2280
2281     } elsif ($c =~ m/^Blocked:/) {
2282         # Blocked: blogger.googleusercontent.com:443
2283         $stats{'blocked'}++;
2284
2285     } elsif ($c =~ m/^Connection timeout:/) {
2286         # Connection timeout: http://c.tile.openstreetmap.org/18/136116/87842.png
2287         $stats{'connection-timeout'}++;
2288
2289     } elsif ($c =~ m/^Connection failure:/) {
2290         # Connection failure: http://127.0.0.1:8080/
2291         $stats{'connection-failure'}++;
2292     }
2293     if ($cli_options{'passed-request-statistics-threshold'} != 0) {
2294         $c =~ m/^[^:]+: (.*)/;
2295         if ($stats{'passed-request-url'}{$1}) {
2296             $stats{'passed-request-url'}{$1}-- ;
2297             if ($stats{'passed-request-url'}{$1} == 0) {
2298                 delete($stats{'passed-request-url'}{$1});
2299             }
2300         }
2301     }
2302 }
2303
2304
2305 sub gather_loglevel_error_stats($$) {
2306
2307     my $c = shift;
2308     my $thread = shift;
2309     our %stats;
2310     our %thread_data;
2311
2312     if ($c =~ m/^Empty server or forwarder response received on socket \d+./) {
2313
2314         # Empty server or forwarder response received on socket 4.
2315         $stats{'empty-responses'}++;
2316         if ($thread_data{$thread}{'new_connection'}) {
2317             $stats{'empty-responses-on-new-connections'}++;
2318         } else {
2319             $stats{'empty-responses-on-reused-connections'}++;
2320         }
2321     }
2322 }
2323
2324 sub gather_loglevel_connect_stats($$) {
2325
2326     my ($c, $thread) = @_;
2327     our %thread_data;
2328     our %stats;
2329
2330     if ($c =~ m/^via ([^\s]+) to: [^\s]+/) {
2331
2332         # Connect: via 10.0.0.1:8123 to: www.example.org.noconnect
2333         $thread_data{$thread}{'forwarder'} = $1; # XXX: is this missue?
2334
2335     } elsif ($c =~ m/^to ([^\s]*)$/) {
2336
2337         # Connect: to lists.sourceforge.net:443
2338
2339         $thread_data{$thread}{'forwarder'} = 'direct connection';
2340
2341     } elsif ($c =~ m/^Created new connection to/) {
2342
2343         # Created new connection to www.privoxy.org:80 on socket 11.
2344
2345         $thread_data{$thread}{'new_connection'} = 1;
2346
2347     } elsif ($c =~ m/^Reusing server socket \d./ or
2348              $c =~ m/^Found reusable socket/) {
2349
2350         # Reusing server socket 4. Opened for 10.0.0.1.
2351         # Found reusable socket 9 for www.privoxy.org:80 in slot 0.
2352
2353         $thread_data{$thread}{'new_connection'} = 0;
2354         $stats{'reused-connections'}++;
2355
2356     } elsif ($c =~ m/^Closing client socket \d+. .* Requests received: (\d+)\.$/) {
2357
2358         # Closing client socket 12. Keep-alive: 1. Socket alive: 1. Data available: 0. \
2359         #  Configuration file change detected: 0. Requests received: 14.
2360
2361         $stats{'client-requests-on-connection'}{$1}++;
2362         $stats{'closed-client-connections'}++;
2363     }
2364 }
2365
2366 sub gather_loglevel_header_stats($$) {
2367
2368     my ($c, $thread) = @_;
2369     our %stats;
2370     our %cli_options;
2371
2372     if ($c =~ m/^A HTTP\/1\.1 response without/ or
2373         $c =~ m/^Keeping the server header 'Connection: keep-alive' around./)
2374     {
2375         # A HTTP/1.1 response without Connection header implies keep-alive.
2376         # Keeping the server header 'Connection: keep-alive' around.
2377         $stats{'server-keep-alive'}++;
2378     }
2379 }
2380
2381 sub init_stats() {
2382     our %stats = (
2383         requests => 0,
2384         requests_clf => 0,
2385         crunches => 0,
2386         'server-keep-alive' => 0,
2387         'reused-connections' => 0,
2388         'empty-responses' => 0,
2389         'empty-responses-on-new-connections' => 0,
2390         'empty-responses-on-reused-connections' => 0,
2391         'fast-redirections' => 0,
2392         'blocked' => 0,
2393         'connection-failure' => 0,
2394         'connection-timeout' => 0,
2395         'reused-connections' => 0,
2396         'server-keep-alive' => 0,
2397         'closed-client-connections' => 0,
2398         'content-size-total' => 0,
2399         );
2400         $stats{'client-requests-on-connection'}{1} = 0;
2401 }
2402
2403 sub get_percentage($$) {
2404     my $big = shift;
2405     my $small = shift;
2406
2407     # If small is 0 the percentage is always 0%.
2408     # Make sure it works even if big is 0 as well.
2409     return "0.00%" if ($small eq 0);
2410
2411     # Prevent division by zero.
2412     # XXX: Is this still supposed to be reachable?
2413     return "NaN" if ($big eq 0);
2414
2415     return sprintf("%.2f%%", $small / $big * 100);
2416 }
2417
2418 sub print_stats() {
2419
2420     our %stats;
2421     our %cli_options;
2422     my $new_connections = $stats{requests} - $stats{crunches} - $stats{'reused-connections'};
2423     my $client_requests_checksum = 0;
2424     my $requests_total;
2425
2426     if ($stats{requests_clf} && $stats{requests}
2427         && $stats{requests_clf} != $stats{requests}) {
2428         print "Inconsistent request counts: " . $stats{requests} . "/" . $stats{requests_clf} . "\n";
2429     }
2430
2431     # To get the total number of requests we can use either the number
2432     # of Common-Log-Format lines or the number of "Request:" messages.
2433     # We prefer the number of CLF lines if available because using
2434     # it works when analysing old log files from Privoxy versions before 3.0.29.
2435     # In Privoxy 3.0.28 and earlier "Request:" messages excluded
2436     # crunched messages.
2437     $requests_total = $stats{requests_clf} ? $stats{requests_clf} : $stats{requests};
2438
2439     if ($requests_total eq 0) {
2440         print "No requests yet.\n";
2441         return;
2442     }
2443
2444     print "Client requests total: " . $requests_total . "\n";
2445     if ($stats{crunches}) {
2446         my $outgoing_requests = $requests_total - $stats{crunches};
2447         print "Crunches: " . $stats{crunches} . " (" .
2448             get_percentage($requests_total, $stats{crunches}) . ")\n";
2449         print "Blocks: " . $stats{'blocked'} . " (" .
2450             get_percentage($requests_total, $stats{'blocked'}) . ")\n";
2451         print "Fast redirections: " . $stats{'fast-redirections'} . " (" .
2452             get_percentage($requests_total, $stats{'fast-redirections'}) . ")\n";
2453         print "Connection timeouts: " . $stats{'connection-timeout'} . " (" .
2454             get_percentage($requests_total, $stats{'connection-timeout'}) . ")\n";
2455         print "Connection failures: " . $stats{'connection-failure'} . " (" .
2456             get_percentage($requests_total, $stats{'connection-failure'}) . ")\n";
2457         print "Outgoing requests: " . $outgoing_requests . " (" .
2458             get_percentage($requests_total, $outgoing_requests) . ")\n";
2459     } else {
2460         print "No crunches detected. Is 'debug 1024' enabled?\n";
2461     }
2462
2463     print "Server keep-alive offers: " . $stats{'server-keep-alive'} . " (" .
2464         get_percentage($requests_total, $stats{'server-keep-alive'}) . ")\n";
2465     print "New outgoing connections: " . $new_connections . " (" .
2466         get_percentage($requests_total, $new_connections) . ")\n";
2467     print "Reused server connections: " . $stats{'reused-connections'} . " (" .
2468         get_percentage($requests_total, $stats{'reused-connections'}) .
2469         "; server offers accepted: " .
2470         get_percentage($stats{'server-keep-alive'}, $stats{'reused-connections'}) . ")\n";
2471     print "Empty responses: " . $stats{'empty-responses'} . " (" .
2472         get_percentage($requests_total, $stats{'empty-responses'}) . ")\n";
2473     print "Empty responses on new connections: "
2474          . $stats{'empty-responses-on-new-connections'} . " (" .
2475         get_percentage($requests_total, $stats{'empty-responses-on-new-connections'})
2476         . ")\n";
2477     print "Empty responses on reused connections: " .
2478         $stats{'empty-responses-on-reused-connections'} . " (" .
2479         get_percentage($requests_total, $stats{'empty-responses-on-reused-connections'}) .
2480         ")\n";
2481     print "Client connections: " .  $stats{'closed-client-connections'} . "\n";
2482     if ($stats{'content-size-total'}) {
2483         print "Bytes of content transferred to the client: " .  $stats{'content-size-total'} . "\n";
2484     }
2485     my $lines_printed = 0;
2486     print "Client requests per connection distribution:\n";
2487     foreach my $client_requests (sort {
2488         $stats{'client-requests-on-connection'}{$b} <=> $stats{'client-requests-on-connection'}{$a}}
2489                                   keys %{$stats{'client-requests-on-connection'}
2490                                   })
2491     {
2492         my $count = $stats{'client-requests-on-connection'}{$client_requests};
2493         $client_requests_checksum += $count * $client_requests;
2494         if ($cli_options{'show-complete-request-distribution'} or ($lines_printed < 10)) {
2495             printf "%8d: %d\n", $count, $client_requests;
2496             $lines_printed++;
2497         }
2498     }
2499     unless ($cli_options{'show-complete-request-distribution'}) {
2500         printf "Enable --show-complete-request-distribution to get less common numbers as well.\n";
2501     }
2502     # Due to log rotation we may not have a complete picture for all the requests
2503     printf "Improperly accounted requests: ~%d\n", abs($requests_total - $client_requests_checksum);
2504
2505     if (exists $stats{method}) {
2506         print "Method distribution:\n";
2507         foreach my $method (sort {$stats{'method'}{$b} <=> $stats{'method'}{$a}} keys %{$stats{'method'}}) {
2508             printf "%8d : %-8s\n", $stats{'method'}{$method}, $method;
2509         }
2510     } else {
2511         print "Method distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
2512     }
2513     if (exists $stats{'http-version'}) {
2514         print "Client HTTP versions:\n";
2515         foreach my $http_version (sort {$stats{'http-version'}{$b} <=> $stats{'http-version'}{$a}} keys %{$stats{'http-version'}}) {
2516             printf "%8d : %-8s\n",  $stats{'http-version'}{$http_version}, $http_version;
2517         }
2518     } else {
2519         print "HTTP version distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
2520     }
2521     if (exists $stats{'status-code'}) {
2522         print "HTTP status codes according to 'debug 512' (status codes sent by the server may differ):\n";
2523         foreach my $status_code (sort {$stats{'status-code'}{$b} <=> $stats{'status-code'}{$a}} keys %{$stats{'status-code'}}) {
2524             printf "%8d : %-8d\n",  $stats{'status-code'}{$status_code}, $status_code;
2525         }
2526     } else {
2527         print "Status code distribution unknown. No CLF message parsed yet. Is 'debug 512' enabled?\n";
2528     }
2529
2530     if ($cli_options{'url-statistics-threshold'} == 0) {
2531         print "URL statistics are disabled. Increase --url-statistics-threshold to enable them.\n";
2532     } else {
2533         print "Requested URLs:\n";
2534         foreach my $resource (sort {$stats{'resource'}{$b} <=> $stats{'resource'}{$a}} keys %{$stats{'resource'}}) {
2535             if ($stats{'resource'}{$resource} < $cli_options{'url-statistics-threshold'}) {
2536                 print "Skipped statistics for URLs below the treshold.\n";
2537                 last;
2538             }
2539             printf "%d : %s\n", $stats{'resource'}{$resource}, $resource;
2540         }
2541     }
2542
2543     if ($cli_options{'passed-request-statistics-threshold'} == 0) {
2544         print "Passed request statistics are disabled. Increase --passed-request-statistics-threshold to enable them.\n";
2545     } else {
2546         print "Requested requests that were passed:\n";
2547         foreach my $passed_url (sort {$stats{'passed-request-url'}{$b} <=> $stats{'passed-request-url'}{$a}}
2548                                 keys %{$stats{'passed-request-url'}}) {
2549             if ($stats{'passed-request-url'}{$passed_url} < $cli_options{'passed-request-statistics-threshold'}) {
2550                 print "Skipped statistics for passed URLs below the treshold.\n";
2551                 last;
2552             }
2553             printf "%d : %s\n", $stats{'passed-request-url'}{$passed_url}, $passed_url;
2554         }
2555     }
2556     if ($cli_options{'host-statistics-threshold'} == 0) {
2557         print "Host statistics are disabled. Increase --host-statistics-threshold to enable them.\n";
2558     } else {
2559         print "Requested Hosts:\n";
2560         foreach my $host (sort {$stats{'hosts'}{$b} <=> $stats{'hosts'}{$a}} keys %{$stats{'hosts'}}) {
2561             if ($stats{'hosts'}{$host} < $cli_options{'host-statistics-threshold'}) {
2562                 print "Skipped statistics for Hosts below the treshold.\n";
2563                 last;
2564             }
2565             printf "%d : %s\n", $stats{'hosts'}{$host}, $host;
2566         }
2567     }
2568 }
2569
2570
2571 ################################################################################
2572 # Functions that actually print stuff
2573 ################################################################################
2574
2575 sub print_clf_message() {
2576
2577     our ($ip, $timestamp, $request_line, $status_code, $size);
2578     my $output = '';
2579
2580     return if DEBUG_SUPPRESS_LOG_MESSAGES;
2581
2582     # Rebuild highlighted
2583     $output .= $h{'Number'} . $ip . $h{'Standard'};
2584     $output .= " - - ";
2585     $output .= "[" . $h{'Timestamp'} . $timestamp . $h{'Standard'} . "]";
2586     $output .= " ";
2587     $output .= "\"" . highlight_request_line("$request_line") . "\"";
2588     $output .= " ";
2589     $output .= $h{'Status'} . $status_code . $h{'Standard'};
2590     $output .= " ";
2591     $output .= $h{'Number'} . $size . $h{'Standard'};
2592     $output .= $line_end;
2593
2594     print $output;
2595 }
2596
2597 sub print_non_clf_message($) {
2598
2599     my $content = shift;
2600     my $date_string = $keep_date_mode ? $req{$t}{'day'} . ' ' : '';
2601     my $msec_string = $no_msecs_mode ? '' : '.' . $req{$t}{'msecs'};
2602     my $line_start = $html_output_mode ? '' : $h{"Standard"};
2603
2604     return if DEBUG_SUPPRESS_LOG_MESSAGES;
2605
2606     print $line_start
2607         . $date_string
2608         . $time_colours[$time_colour_index % 2]
2609         . $req{$t}{'time-stamp'}
2610         . $msec_string
2611         . $h{Standard} . " "
2612         . $thread_colours{$t}
2613         . $t
2614         . $h{Standard}
2615         . " "
2616         . $h{$req{$t}{'log-level'}}
2617         . $req{$t}{'log-level'}
2618         . $h{Standard}
2619         . ": "
2620         . $content
2621         . $line_end;
2622 }
2623
2624 sub shorten_thread_id($) {
2625
2626     my $thread_id = shift;
2627
2628     our %short_thread_ids;
2629     our $max_threadid;
2630
2631     unless (defined $short_thread_ids{$thread_id}) {
2632         $short_thread_ids{$thread_id} = sprintf "%.3d", $max_threadid++;
2633     }
2634
2635     return $short_thread_ids{$thread_id}
2636 }
2637
2638 sub parse_loop() {
2639
2640     my ($day, $time_stamp, $thread, $log_level, $content, $c, $msecs);
2641     my $last_msecs  = 0;
2642     my $last_thread = 0;
2643     my $last_timestamp = 0;
2644     my $filters_that_did_nothing;
2645     my $key;
2646     my $time_colour;
2647     $time_colour = paint_it('white');
2648
2649     my %log_level_handlers = (
2650         'Re-Filter'         => \&handle_loglevel_re_filter,
2651         'Header'            => \&handle_loglevel_header,
2652         'Connect'           => \&handle_loglevel_connect,
2653         'Redirect'          => \&handle_loglevel_redirect,
2654         'Request'           => \&handle_loglevel_request,
2655         'Crunch'            => \&handle_loglevel_crunch,
2656         'Gif-Deanimate'     => \&handle_loglevel_gif_deanimate,
2657         'Info'              => \&handle_loglevel_info,
2658         'CGI'               => \&handle_loglevel_cgi,
2659         'Force'             => \&handle_loglevel_force,
2660         'Error'             => \&handle_loglevel_error,
2661         'Fatal error'       => \&handle_loglevel_ignore,
2662         'Writing'           => \&handle_loglevel_ignore,
2663         'Received'          => \&handle_loglevel_ignore,
2664         'Tagging'           => \&handle_loglevel_tagging,
2665         'Actions'           => \&handle_loglevel_ignore,
2666         'Unknown log level' => \&handle_loglevel_ignore,
2667     );
2668
2669     while (<>) {
2670
2671         if (m/^(\d{4}-\d{2}-\d{2}|\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/) {
2672             $thread = $t = ($shorten_thread_ids) ? shorten_thread_id($4) : $4;
2673             $req{$t}{'day'} = $day = $1;
2674             $req{$t}{'time-stamp'} = $time_stamp = $2;
2675             $req{$t}{'msecs'} = $msecs = $3 ? $3 : 0; # Only the cool kids have micro second resolution;
2676             $req{$t}{'log-level'} = $log_level = $5;
2677             $req{$t}{'content'} = $content = $c = $6;
2678             $req{$t}{'log-message'} = $_;
2679             $no_special_header_highlighting = 0;
2680
2681             if (defined($log_level_handlers{$log_level})) {
2682
2683                 $content = $log_level_handlers{$log_level}($content);
2684
2685             } else {
2686
2687                 die "No handler found for log level \"$log_level\"\n";
2688             }
2689
2690             # Highlight Truncations
2691             if (length($_) > 4000) {
2692                 $content =~ s@(too long, truncated)]$@$h{'Truncation'}$1$h{'Standard'}]@g;
2693             }
2694
2695             next unless $content;
2696
2697             # Register threads to keep the colour constant
2698             if (!defined($thread_colours{$thread})) {
2699                 $thread_colours{$thread} = $all_colours[$thread_colour_index % @all_colours];
2700                 $thread_colour_index++;
2701             }
2702
2703             # Switch timestamp colour if timestamps differ
2704             if (($msecs ne $last_msecs) || ($time_stamp ne $last_timestamp)) {
2705                debug_message("Tick tack!") if DEBUG_TICKS;
2706                $time_colour = $time_colours[$time_colour_index % 2];
2707                $time_colour_index++;
2708                $last_msecs = $msecs;
2709                $last_timestamp = $time_stamp;
2710             }
2711
2712             $last_thread = $thread;
2713
2714             print_non_clf_message($content);
2715
2716         } elsif (m/^((?:\d+\.\d+\.\d+\.\d+|[:\d]+)) - - \[(.*)\] "(.*)" (\d+) (\d+)/) {
2717
2718             # LOG_LEVEL_CLF lines look like this
2719             # 61.152.239.32 - - [04/Mar/2007:18:28:23 +0100] "GET \
2720             #  http://ad.yieldmanager.com/imp?z=1&Z=120x600&s=109339&u=http%3A%2F%2Fwww.365loan.co.uk%2F&r=1\
2721             #  HTTP/1.1" 403 1730
2722             our ($ip, $timestamp, $request_line, $status_code, $size) = ($1, $2, $3, $4, $5);
2723
2724             print_clf_message();
2725
2726         } else {
2727
2728             # Some Privoxy log messages span more than one line,
2729             # usually to dump lots of content that doesn't need any syntax highlighting.
2730             # XXX: add mechanism to forward these lines to the right handler anyway.
2731             chomp();
2732             unless (DEBUG_SUPPRESS_LOG_MESSAGES or (SUPPRESS_EMPTY_LINES and m/^\s+$/)) {
2733                 print and print get_line_end(); # unless (SUPPRESS_EMPTY_LINES and m/^\s+$/);
2734             }
2735         }
2736     }
2737 }
2738
2739 sub stats_loop() {
2740
2741     my ($day, $time_stamp, $thread, $log_level, $content);
2742     my $strict_checks = cli_option_is_set('strict-checks');
2743     my %log_level_handlers = (
2744          'Connect:'           => \&gather_loglevel_connect_stats,
2745          'Crunch:'            => \&gather_loglevel_crunch_stats,
2746          'Error:'             => \&gather_loglevel_error_stats,
2747          'Header:'            => \&gather_loglevel_header_stats,
2748          'Request:'           => \&gather_loglevel_request_stats,
2749     );
2750     my %ignored_log_levels = (
2751          'Actions:'           => \&handle_loglevel_ignore,
2752          'CGI:'               => \&handle_loglevel_ignore,
2753          'Fatal error:'       => \&handle_loglevel_ignore,
2754          'Force:'             => \&handle_loglevel_ignore,
2755          'Gif-Deanimate:'     => \&handle_loglevel_ignore,
2756          'Info:'              => \&handle_loglevel_ignore,
2757          'Re-Filter:'         => \&handle_loglevel_ignore,
2758          'Received:'          => \&handle_loglevel_ignore,
2759          'Redirect:'          => \&handle_loglevel_ignore,
2760          'Unknown log level:' => \&handle_loglevel_ignore,
2761          'Writing:'           => \&handle_loglevel_ignore,
2762          'Tagging:'           => \&handle_loglevel_ignore,
2763     );
2764
2765     while (<>) {
2766         (undef, $time_stamp, $thread, $log_level, $content) = split(/ /, $_, 5);
2767
2768
2769         next if (not defined($log_level));
2770
2771         if ($time_stamp eq "-") {
2772
2773             gather_loglevel_clf_stats($content);
2774
2775         } elsif (defined($log_level_handlers{$log_level})) {
2776
2777             $content = $log_level_handlers{$log_level}($content, $thread);
2778
2779         } elsif ($strict_checks and not defined($ignored_log_levels{$log_level})) {
2780
2781             die "No handler found for: $_";
2782         }
2783     }
2784
2785     print_stats();
2786
2787 }
2788
2789 # Convert a timestamp like 18:07:28.733 into milliseconds
2790 sub time_stamp_to_msecs($) {
2791     my $time_stamp = shift;
2792
2793     if ($time_stamp =~ /(\d\d):(\d\d):(\d\d)\.(\d{3})/) {
2794         my ($hours, $minutes, $seconds, $msecs) = ($1, $2, $3, $4);
2795
2796         $msecs += $seconds * 1000;
2797         $msecs += $minutes * 1000 * 60;
2798         $msecs += $hours   * 1000 * 60 * 60;
2799
2800         return $msecs;
2801     }
2802     return undef;
2803 }
2804
2805 sub inactivity_detection_loop() {
2806
2807     our %cli_options;
2808     my ($date, $time_stamp, $thread, $log_level, $content);
2809     my ($msecs, $previous_msecs, $inactivity);
2810     my $inactivity_threshold = $cli_options{'inactivity-threshold'};
2811     my $previous_date;
2812     my $log_messages_out_of_order = 0;
2813
2814     while (<>) {
2815         ($date, $time_stamp, $thread, $log_level, $content) = split(/ /, $_, 5);
2816
2817         next if (not defined($log_level));
2818         next if ($time_stamp eq "-");
2819         $msecs = time_stamp_to_msecs($time_stamp);
2820         unless (defined $msecs) {
2821             print "Failed to convert $time_stamp into milliseconds\n";
2822             print "$_";
2823             next;
2824         }
2825         unless (defined $previous_msecs) {
2826             $previous_msecs = $msecs;
2827             $previous_date = $date;
2828             print "$_";
2829             next;
2830         }
2831         $inactivity = $msecs - $previous_msecs;
2832         if ($inactivity < 0) {
2833             # This can happen if there's a high load in which case
2834             # a Privoxy thread may be moved off schedule between
2835             # getting the timestamp for the log message and actually
2836             # writing it.
2837             $log_messages_out_of_order++;
2838         }
2839         if ($inactivity > $inactivity_threshold) {
2840             if ($previous_date eq $date) {
2841                 print "Detected inactivity: $inactivity msecs\n";
2842             } else {
2843                 # While we could include the date in the timestamp
2844                 # we currently don't.
2845                 print "Detected date change. Timestamp difference ignored.\n";
2846             }
2847         }
2848         print "$_";
2849         $previous_msecs = $msecs;
2850         $previous_date = $date;
2851     }
2852     if ($log_messages_out_of_order) {
2853         print "At least $log_messages_out_of_order messages were written out of the chronological order.\n";
2854         print "This can result in false positives. Consider sorting the log first.\n";
2855     }
2856 }
2857
2858 sub unbreak_lines_only_loop() {
2859     my $log_messages_reached = 0;
2860     while (<>) {
2861         chomp;
2862
2863             # Log level other than LOG_LEVEL_CLF?
2864         if (m/^(\d{4}-\d{2}-\d{2}|\w{3} \d{2}) (\d\d:\d\d:\d\d)\.?(\d+)? (?:Privoxy\()?([^\)\s]*)[\)]? ([\w -]*): (.*?)\r?$/ or
2865             # LOG_LEVEL_CLF?
2866             m/^((?:\d+\.\d+\.\d+\.\d+)) - - \[(.*)\] "(.*)" (\d+) (\d+)/) {
2867             $log_messages_reached = 1;
2868             print "\n";
2869
2870         } else {
2871             # Wrapped message
2872             $_ = "\n". $_  if /^(?:\d+\.\d+\.\d+\.\d+)/;
2873             $_ = " " . $_;
2874         }
2875         s@<BR>$@@;
2876         print;
2877         print "\n" unless $log_messages_reached;
2878     }
2879     print "\n";
2880 }
2881
2882 sub VersionMessage {
2883     my $version_message;
2884
2885     $version_message .= 'Privoxy-Log-Parser ' . PRIVOXY_LOG_PARSER_VERSION  . "\n";
2886     $version_message .= 'https://www.fabiankeil.de/sourcecode/privoxy-log-parser/' . "\n";
2887
2888     print $version_message;
2889 }
2890
2891 sub get_cli_options() {
2892
2893     our %cli_options = (
2894         'detect-inactivity'        => CLI_OPTION_DETECT_INACTIVITY,
2895         'inactivity-threshold'     => CLI_OPTION_INACTIVITY_THRESHOLD,
2896         'html-output'              => CLI_OPTION_DEFAULT_TO_HTML_OUTPUT,
2897         'title'                    => CLI_OPTION_TITLE,
2898         'keep-date'                => CLI_OPTION_KEEP_DATE,
2899         'no-syntax-highlighting'   => CLI_OPTION_NO_SYNTAX_HIGHLIGHTING,
2900         'no-embedded-css'          => CLI_OPTION_NO_EMBEDDED_CSS,
2901         'no-msecs'                 => CLI_OPTION_NO_MSECS,
2902         'shorten-thread-ids'       => CLI_OPTION_SHORTEN_THREAD_IDS,
2903         'show-ineffective-filters' => CLI_OPTION_SHOW_INEFFECTIVE_FILTERS,
2904         'statistics'               => CLI_OPTION_STATISTICS,
2905         'strict-checks'            => CLI_OPTION_STRICT_CHECKS,
2906         'url-statistics-threshold' => CLI_OPTION_URL_STATISTICS_THRESHOLD,
2907         'unbreak-lines-only'       => CLI_OPTION_UNBREAK_LINES_ONLY,
2908         'host-statistics-threshold'=> CLI_OPTION_HOST_STATISTICS_THRESHOLD,
2909         'passed-request-statistics-threshold' => CLI_OPTION_PASSED_REQUEST_STATISTICS_THRESHOLD,
2910         'show-complete-request-distribution' => CLI_OPTION_SHOW_COMPLETE_REQUEST_DISTRIBUTION,
2911     );
2912
2913     GetOptions (
2914         'detect-inactivity'        => \$cli_options{'detect-inactivity'},
2915         'inactivity-threshold=i'   => \$cli_options{'inactivity-threshold'},
2916         'html-output'              => \$cli_options{'html-output'},
2917         'title'                    => \$cli_options{'title'},
2918         'keep-date'                => \$cli_options{'keep-date'},
2919         'no-syntax-highlighting'   => \$cli_options{'no-syntax-highlighting'},
2920         'no-embedded-css'          => \$cli_options{'no-embedded-css'},
2921         'no-msecs'                 => \$cli_options{'no-msecs'},
2922         'shorten-thread-ids'       => \$cli_options{'shorten-thread-ids'},
2923         'show-ineffective-filters' => \$cli_options{'show-ineffective-filters'},
2924         'statistics'               => \$cli_options{'statistics'},
2925         'strict-checks'            => \$cli_options{'strict-checks'},
2926         'unbreak-lines-only'       => \$cli_options{'unbreak-lines-only'},
2927         'url-statistics-threshold=i'=> \$cli_options{'url-statistics-threshold'},
2928         'host-statistics-threshold=i'=> \$cli_options{'host-statistics-threshold'},
2929         'passed-request-statistics-threshold=i' => \$cli_options{'passed-request-statistics-threshold'},
2930         'show-complete-request-distribution' => \$cli_options{'show-complete-request-distribution'},
2931         'version'                  => sub { VersionMessage && exit(0) },
2932         'help'                     => \&help,
2933    ) or exit(1);
2934
2935    $html_output_mode = cli_option_is_set('html-output');
2936    $no_msecs_mode = cli_option_is_set('no-msecs');
2937    $keep_date_mode = cli_option_is_set('keep-date');
2938    $shorten_thread_ids = cli_option_is_set('shorten-thread-ids');
2939    $line_end = get_line_end();
2940 }
2941
2942 sub help() {
2943
2944     our %cli_options;
2945
2946     VersionMessage();
2947
2948     print << "    EOF"
2949
2950 Options and their default values if they have any:
2951     [--detect-innactivity]
2952     [--inactivity-threshold $cli_options{'inactivity-threshold'}]
2953     [--host-statistics-threshold $cli_options{'host-statistics-threshold'}]
2954     [--html-output]
2955     [--no-embedded-css]
2956     [--no-msecs]
2957     [--no-syntax-highlighting]
2958     [--shorten-thread-ids]
2959     [--show-ineffective-filters]
2960     [--show-complete-request-distribution]
2961     [--statistics]
2962     [--unbreak-lines-only]
2963     [--url-statistics-threshold $cli_options{'url-statistics-threshold'}]
2964     [--passed-request-statistics-threshold $cli_options{'passed-request-statistics-threshold'}]
2965     [--title $cli_options{'title'}]
2966     [--version]
2967 see "perldoc $0" for more information
2968     EOF
2969     ;
2970     exit(0);
2971 }
2972
2973 ################################################################################
2974 # main
2975 ################################################################################
2976 sub main() {
2977
2978     get_cli_options();
2979     set_background(DEFAULT_BACKGROUND);
2980     prepare_our_stuff();
2981
2982     # XXX: should explicitly reject incompatible argument combinations
2983     if (cli_option_is_set('unbreak-lines-only')) {
2984         unbreak_lines_only_loop();
2985     } elsif (cli_option_is_set('statistics')) {
2986         stats_loop();
2987     } elsif (cli_option_is_set('detect-inactivity')) {
2988         inactivity_detection_loop();
2989     } else {
2990         print_intro();
2991         parse_loop();
2992         print_outro();
2993     }
2994 }
2995
2996 main();
2997
2998 =head1 NAME
2999
3000 B<privoxy-log-parser> - A parser and syntax-highlighter for Privoxy log messages
3001
3002 =head1 SYNOPSIS
3003
3004 B<privoxy-log-parser> [B<--detect-inactivity>] [B<--inactivity-threshold msecs>]
3005 [B<--html-output>]
3006 [B<--no-msecs>] [B<--no-syntax-higlighting>] [B<--statistics>]
3007 [B<--shorten-thread-ids>] [B<--show-ineffective-filters>]
3008 [B<--url-statistics-threshold>] [B<--version>]
3009
3010 =head1 DESCRIPTION
3011
3012 B<privoxy-log-parser> reads Privoxy log messages and
3013
3014 - syntax-highlights recognized lines,
3015
3016 - reformats some of them for easier comprehension,
3017
3018 - filters out less useful messages, and
3019
3020 - (in some cases) calculates additional information,
3021   like the compression ratio or how a filter affected
3022   the content size.
3023
3024 With B<privoxy-log-parser> you should be able to increase Privoxy's log level
3025 without getting confused by the resulting amount of output. For example for
3026 "debug 64" B<privoxy-log-parser> will (by default) only show messages that
3027 affect the content. If a filter doesn't cause any hits, B<privoxy-log-parser>
3028 will hide the "filter foo caused 0 hits" message.
3029
3030 =head1 OPTIONS
3031
3032 [B<--detect-inactivity>] Instead of syntax highlighting, detect periods
3033 of log inactivity of more than the amount of milliseconds specified with
3034 the B<--inactivity-threshold> option. Mainly useful for debugging.
3035
3036 [B<--host-statistics-threshold>] Only show the request count for a host
3037 if it's above or equal to the given threshold. If the threshold is 0, host
3038 statistics are disabled.
3039
3040 [B<--html-output>] Use HTML and CSS when syntax highlighting. If this option is
3041 omitted, ANSI escape sequences are used unless B<--no-syntax-highlighting> is active.
3042 This option is only intended to make embedding log excerpts in web pages easier.
3043 It does not escape any input!
3044
3045 [B<--inactivity-threshold msecs>] Specifies the number of milliseconds between
3046 log messages to consider inactivity when running in [B<--detect-inactivity>]
3047 mode.
3048
3049 [B<--keep-date>] Don't remove the date when printing highlighted log messages.
3050 Useful when parsing multiple log files at once.
3051
3052 [B<--no-msecs>] Don't expect millisecond resolution
3053
3054 [B<--no-syntax-highlighting>] Disable syntax-highlighting. Useful when
3055 the filtered output is piped into less in which case the ANSI control
3056 codes don't work, or if the terminal itself doesn't support the control
3057 codes.
3058
3059 [B<--passed-request-statistics-threshold>] Only show the request count for
3060 a passed requests if it's above or equal to the given threshold. If the
3061 threshold is 0, passed request statistics are disabled.
3062
3063 [B<--shorten-thread-ids>] Shorten the thread ids to a three-digit decimal number.
3064 Note that the mapping from thread ids to shortened ids is created at run-time
3065 and thus varies with the input.
3066
3067 [B<--show-ineffective-filters>] Don't suppress log lines for filters
3068 that didn't modify the content.
3069
3070 [B<--show-complete-request-distribution>] Show the complete client request
3071 distribution in the B<--statistics> output. Without this option only the
3072 ten most common numbers are shown.
3073
3074 [B<--statistics>] Gather various statistics instead of syntax highlighting
3075 log messages. This is an experimental feature, if the results look wrong
3076 they very well might be. Also note that the results are pretty much guaranteed
3077 to be incorrect if Privoxy and Privoxy-Log-Parser aren't in sync.
3078
3079 [B<--strict-checks>] When generating statistics, look more careful at the
3080 input data and abort if it is unexpected, even if it doesn't affect the
3081 results. Significantly slows the parsing down and is not expected to catch
3082 any problems that matter.
3083 When highlighting, print warnings in case of unknown messages which can't be
3084 properly highlighted.
3085
3086 [B<--unbreak-lines-only>] Tries to fix lines that got messed up by a broken or
3087 interestingly configured mail client and thus are no longer recognized properly.
3088 Only fixes some breakage, but may be good enough or at least better than nothing.
3089 Doesn't do anything else, so you probably want to pipe the output into
3090 B<privoxy-log-parser> again.
3091
3092 [B<--url-statistics-threshold>] Only show the request count for a resource
3093 if it's above or equal to the given threshold. If the threshold is 0, URL
3094 statistics are disabled.
3095
3096 [B<--version>] Print version and exit.
3097
3098 =head1 EXAMPLES
3099
3100 To monitor a log file:
3101
3102 tail -F /usr/jails/privoxy-jail/var/log/privoxy/privoxy.log | B<privoxy-log-parser>
3103
3104 Replace '-F' with '-f' if your tail implementation lacks '-F' support
3105 or if the log won't get rotated anyway. The log file location depends
3106 on your system (Doh!).
3107
3108 To monitor Privoxy without having it write to a log file:
3109
3110 privoxy --no-daemon /usr/jails/privoxy-jail/usr/local/etc/privoxy/config 2>&1 | B<privoxy-log-parser>
3111
3112 Again, the config file location depends on your system. Output redirection
3113 depends on your shell, the above works with bourne shells.
3114
3115 To read a processed Privoxy log file from top to bottom, letting the content
3116 scroll by slightly faster than you can read:
3117
3118 B<privoxy-log-parser> < /usr/jails/privoxy-jail/var/log/privoxy/privoxy.log
3119
3120 This is probably only useful to fill screens in the background of haxor movies.
3121
3122 =head1 CAVEATS
3123
3124 Syntax highlighting with ANSI escape sequences will look strange
3125 if your background color isn't black.
3126
3127 Some messages aren't recognized yet and will not be fully highlighted.
3128
3129 B<privoxy-log-parser> is developed with Privoxy 3.0.7 or later in mind,
3130 using earlier Privoxy versions will probably result in an increased amount
3131 of unrecognized log lines.
3132
3133 Privoxy's log files tend to be rather large. If you use HTML
3134 highlighting some browsers can't handle them, get confused and
3135 will eventually crash because of segmentation faults or unexpected
3136 exceptions. This is a problem in the browser and not B<privoxy-log-parser>'s
3137 fault.
3138
3139 =head1 BUGS
3140
3141 Many settings can't be controlled through command line options yet.
3142
3143 =head1 SEE ALSO
3144
3145 privoxy(8)
3146
3147 =head1 AUTHOR
3148
3149 Fabian Keil <fk@fabiankeil.de>
3150
3151 =cut