Improve code clarity by factoring log_and_die() out of l().
[privoxy.git] / tools / privoxy-regression-test.pl
index b2cba4e..92a0a10 100755 (executable)
@@ -7,7 +7,7 @@
 # A regression test "framework" for Privoxy. For documentation see:
 # perldoc privoxy-regression-test.pl
 #
-# $Id: privoxy-regression-test.pl,v 1.164 2009/02/23 09:40:24 fk Exp $
+# $Id: privoxy-regression-test.pl,v 1.179 2009/05/28 17:24:53 fk Exp $
 #
 # Wish list:
 #
@@ -40,51 +40,49 @@ use strict;
 use Getopt::Long;
 
 use constant {
-               PRT_VERSION => 'Privoxy-Regression-Test 0.3',
+    PRT_VERSION => 'Privoxy-Regression-Test 0.3',
  
-               CURL => 'curl',
-
-               # CLI option defaults
-               CLI_RETRIES   => 1,
-               CLI_LOOPS     => 1,
-               CLI_MAX_TIME  => 5,
-               CLI_MIN_LEVEL => 0,
-               # XXX: why limit at all.
-               CLI_MAX_LEVEL => 100,
-               CLI_FORKS     => 0,
-
-               PRIVOXY_CGI_URL => 'http://p.p/',
-               FELLATIO_URL    => 'http://127.0.0.1:8080/',
-               LEADING_LOG_DATE => 1,
-               LEADING_LOG_TIME => 1,
-
-               DEBUG_LEVEL_FILE_LOADING    => 0,
-               DEBUG_LEVEL_PAGE_FETCHING   => 0,
-
-               VERBOSE_TEST_DESCRIPTION    => 1,
-
-               DEBUG_LEVEL_VERBOSE_FAILURE => 1,
-               # XXX: Only partly implemented and mostly useless.
-               DEBUG_LEVEL_VERBOSE_SUCCESS => 0,
-               DEBUG_LEVEL_STATUS          => 1,
-
-               # Internal use, don't modify
-               # Available debug bits:
-               LL_ERROR                   =>  1,
-               LL_VERBOSE_FAILURE         =>  2,
-               LL_PAGE_FETCHING           =>  4,
-               LL_FILE_LOADING            =>  8,
-               LL_VERBOSE_SUCCESS         => 16,
-               LL_STATUS                  => 32,
-               LL_SOFT_ERROR              => 64,
-
-               CLIENT_HEADER_TEST         =>  1,
-               SERVER_HEADER_TEST         =>  2,
-               DUMB_FETCH_TEST            =>  3,
-               METHOD_TEST                =>  4,
-               STICKY_ACTIONS_TEST        =>  5,
-               TRUSTED_CGI_REQUEST        =>  6,
-               BLOCK_TEST                 =>  7,
+    CURL => 'curl',
+
+    # CLI option defaults
+    CLI_RETRIES   => 1,
+    CLI_LOOPS     => 1,
+    CLI_MAX_TIME  => 5,
+    CLI_MIN_LEVEL => 0,
+    # XXX: why limit at all?
+    CLI_MAX_LEVEL => 100,
+    CLI_FORKS     => 0,
+
+    PRIVOXY_CGI_URL  => 'http://p.p/',
+    FELLATIO_URL     => 'http://127.0.0.1:8080/',
+    LEADING_LOG_DATE => 1,
+    LEADING_LOG_TIME => 1,
+
+    DEBUG_LEVEL_FILE_LOADING    => 0,
+    DEBUG_LEVEL_PAGE_FETCHING   => 0,
+    DEBUG_LEVEL_VERBOSE_FAILURE => 1,
+    # XXX: Only partly implemented and mostly useless.
+    DEBUG_LEVEL_VERBOSE_SUCCESS => 0,
+    DEBUG_LEVEL_STATUS          => 1,
+
+    VERBOSE_TEST_DESCRIPTION    => 1,
+
+    # Internal use, don't modify
+    # Available debug bits:
+    LL_SOFT_ERROR       =>  1,
+    LL_VERBOSE_FAILURE  =>  2,
+    LL_PAGE_FETCHING    =>  4,
+    LL_FILE_LOADING     =>  8,
+    LL_VERBOSE_SUCCESS  => 16,
+    LL_STATUS           => 32,
+
+    CLIENT_HEADER_TEST  =>  1,
+    SERVER_HEADER_TEST  =>  2,
+    DUMB_FETCH_TEST     =>  3,
+    METHOD_TEST         =>  4,
+    STICKY_ACTIONS_TEST =>  5,
+    TRUSTED_CGI_REQUEST =>  6,
+    BLOCK_TEST          =>  7,
 };
 
 sub init_our_variables () {
@@ -110,9 +108,8 @@ sub get_default_log_level () {
     $log_level |= LL_VERBOSE_SUCCESS if DEBUG_LEVEL_VERBOSE_SUCCESS;
     $log_level |= LL_STATUS          if DEBUG_LEVEL_STATUS;
 
-    # These are intended to be always on.
+    # This one is supposed to be always on.
     $log_level |= LL_SOFT_ERROR;
-    $log_level |= LL_ERROR;
 
     return $log_level;
 }
@@ -141,14 +138,14 @@ sub parse_tag ($) {
 
 sub check_for_forbidden_characters ($) {
 
-    my $tag = shift; # XXX: also used to check values though.
-    my $allowed = '[-=\dA-Za-z~{}:.\/();\s,+@"_%\?&*^]';
+    my $string = shift;
+    my $allowed = '[-=\dA-Za-z~{}:./();\s,+@"_%?&*^]';
 
-    unless ($tag =~ m/^$allowed*$/) {
-        my $forbidden = $tag;
+    unless ($string =~ m/^$allowed*$/o) {
+        my $forbidden = $string;
         $forbidden =~ s@^$allowed*(.).*@$1@;
 
-        l(LL_ERROR, "'" . $tag . "' contains character '" . $forbidden. "' which is unacceptable.");
+        log_and_die("'" . $string . "' contains character '" . $forbidden. "' which is unacceptable.");
     }
 }
 
@@ -206,8 +203,8 @@ sub token_starts_new_test ($) {
     foreach my $new_test_directive (@new_test_directives) {
         return 1 if $new_test_directive eq $token;
     }
-    return 0;
 
+    return 0;
 }
 
 sub tokenize ($) {
@@ -224,7 +221,7 @@ sub tokenize ($) {
     s@&@&@g;
 
     # Tokenize
-    if (/^\#\s*([^=:]*?)\s*[=]\s*(.+?)\s*$/) {
+    if (/^\#\s*([^=:#]*?)\s*[=]\s*([^#]+)$/) {
 
         $token = $1;
         $value = $2;
@@ -236,7 +233,6 @@ sub tokenize ($) {
 
         $token = 'tag';
         $value = $1;
-
     }
 
     return ($token, $value);
@@ -289,7 +285,6 @@ sub enlist_new_test ($$$$$$) {
     } else {
 
         die "Incomplete '" . $token . "' support detected."; 
-
     }
 
     $$regression_tests[$si][$ri]{'type'} = $type;
@@ -369,9 +364,8 @@ sub load_action_files ($) {
                 # Will be used by each following Sticky URL.
                 $sticky_actions = $value;
                 if ($sticky_actions =~ /{[^}]*\s/) {
-                    l(LL_ERROR,
-                      "'Sticky Actions' with whitespace inside the " .
-                      "action parameters are currently unsupported.");
+                    log_and_die("'Sticky Actions' with whitespace inside the " .
+                                "action parameters are currently unsupported.");
                 }
             }
             
@@ -437,7 +431,7 @@ sub load_action_files ($) {
                     l(LL_FILE_LOADING, "Sticky actions: " . $sticky_actions);
                     $regression_tests[$si][$ri]{'sticky-actions'} = $sticky_actions;
                 } else {
-                    l(LL_ERROR, "Sticky URL without Sticky Actions: $value");
+                    log_and_die("Sticky URL without Sticky Actions: $value");
                 }
 
             } else {
@@ -513,7 +507,7 @@ sub execute_regression_tests () {
                 if (defined $skip_reason) {
 
                     my $message = "Skipping test " . $number . ": " . $skip_reason . ".";
-                    log_message($message) if cli_option_is_set('verbose');
+                    log_message($message) if (cli_option_is_set('show-skipped-tests'));
                     $skipped++;
 
                 } else {
@@ -537,7 +531,6 @@ sub execute_regression_tests () {
         $all_tests     += $tests;
         $all_failures  += $failures;
         $all_successes += $successes;
-
     }
 
     if (get_cli_option('loops') > 1) {
@@ -591,8 +584,10 @@ sub dependency_unsatisfied ($) {
 
         foreach (@privoxy_config) {
 
-             $dependency_problem = undef if (/$dependency/);
-             last; # XXX: this looks ... interesting.
+            if (/$dependency/) {
+                $dependency_problem = undef;
+                last;
+            }
         }
 
     } elsif (defined ($dependencies{$level}{'feature status'})) {
@@ -625,6 +620,9 @@ sub register_dependency ($$) {
 
         $dependencies{$level}{'feature status'} = $1;
 
+    } else {
+
+        log_and_die("Didn't recognize dependency: $dependency.");
     }
 }
 
@@ -663,7 +661,6 @@ sub execute_regression_test ($) {
     } else {
 
         die "Unsupported test type detected: " . $test{'type'};
-
     }
 
     return $result;
@@ -736,15 +733,18 @@ sub execute_sticky_actions_test ($) {
     my $final_results = get_final_results($url);
 
     foreach my $sticky_action (@sticky_actions) {
+
         if (defined $final_results->{$sticky_action}) {
             # Exact match
             $verified_actions++;
-        }elsif ($sticky_action =~ /-.*\{/ and
-                not defined $final_results->{$sticky_action}) {
+
+        } elsif ($sticky_action =~ /-.*\{/) {
+
             # Disabled multi actions aren't explicitly listed as
             # disabled and thus have to be checked by verifying
             # that they aren't enabled.
             $verified_actions++;
+
         } else {
             l(LL_VERBOSE_FAILURE,
               "Ooops. '$sticky_action' is not among the final results.");
@@ -823,7 +823,6 @@ sub check_status_code_result ($$) {
 
         l(LL_VERBOSE_FAILURE,
           "Ooops. We expected status code " . $expected_status_code . ", but received: " . $status_code . '.');
-
     }
     
     return $result;
@@ -879,7 +878,7 @@ sub check_header_result ($$) {
 
             $header = "REMOVAL" unless defined $header;
             l(LL_VERBOSE_FAILURE,
-              "Ooops. Got: " . $header . " while expecting: " . $expect_header);
+              "Ooops. Got: '" . $header . "' while expecting: '" . $expect_header . "'");
         }
 
     } elsif ($expect_header eq 'REMOVAL') {
@@ -887,14 +886,13 @@ sub check_header_result ($$) {
         if (defined($header) and $header eq $test{'data'}) {
 
             l(LL_VERBOSE_FAILURE,
-              "Ooops. Expected removal but: " . $header . " is still there.");
+              "Ooops. Expected removal but: '" . $header . "' is still there.");
 
         } else {
 
             # XXX: Use more reliable check here and make sure
             # the header has a different name.
             $success = 1;
-
         }
 
     } elsif ($expect_header eq 'SOME CHANGE') {
@@ -907,10 +905,9 @@ sub check_header_result ($$) {
 
             $header = "REMOVAL" unless defined $header;
             l(LL_VERBOSE_FAILURE,
-              "Ooops. Got: " . $header . " while expecting: SOME CHANGE");
+              "Ooops. Got: '" . $header . "' while expecting: SOME CHANGE");
         }
 
-
     } else {
 
         if (defined($header) and $header eq $expect_header) {
@@ -921,7 +918,7 @@ sub check_header_result ($$) {
 
             $header = "'No matching header'" unless defined $header; # XXX: No header detected to be precise
             l(LL_VERBOSE_FAILURE,
-              "Ooops. Got: " . $header . " while expecting: " . $expect_header);
+              "Ooops. Got: '" . $header . "' while expecting: '" . $expect_header . "'");
         }
     }
     return $success;
@@ -962,7 +959,6 @@ sub get_header ($$) {
      or  $expect_header eq 'SOME CHANGE') {
 
         $expect_header = $test{'data'};
-
     }
 
     $header_to_get = get_header_name($expect_header);
@@ -1011,7 +1007,7 @@ sub get_server_header ($$) {
     my $header_to_get;
 
     # XXX: Should be caught before starting to test.
-    l(LL_ERROR, "No expect header for test " . $test{'number'})
+    log_and_die("No expect header for test " . $test{'number'})
         unless defined $expect_header;
 
     if ($expect_header eq 'REMOVAL'
@@ -1019,7 +1015,6 @@ sub get_server_header ($$) {
      or $expect_header eq 'SOME CHANGE') {
 
         $expect_header = $test{'data'};
-
     }
 
     $header_to_get = get_header_name($expect_header);
@@ -1053,7 +1048,7 @@ sub get_status_code ($) {
 
             return '123' if cli_option_is_set('fuzzer-feeding');
             chomp;
-            l(LL_ERROR, 'Unexpected buffer line: "' . $_ . '"');
+            log_and_die('Unexpected buffer line: "' . $_ . '"');
         }
     }
 }
@@ -1107,7 +1102,7 @@ sub fuzz_header($) {
 
 sub check_for_curl () {
     my $curl = CURL;
-    l(LL_ERROR, "No curl found.") unless (`which $curl`);
+    log_and_die("No curl found.") unless (`which $curl`);
 }
 
 sub get_cgi_page_or_else ($) {
@@ -1129,8 +1124,7 @@ sub get_cgi_page_or_else ($) {
 
         } else {
 
-            l(LL_ERROR, $log_message);
-
+            log_and_die($log_message);
         }
     }
     
@@ -1226,9 +1220,8 @@ sub get_page_with_curl ($) {
     } while ($? && --$retries_left);
 
     unless ($retries_left) {
-        l(LL_ERROR,
-          "Running curl failed " . get_cli_option('retries') .
-          " times in a row. Last error: '" . $failure_reason . "'.");
+        log_and_die("Running curl failed " . get_cli_option('retries') .
+                    " times in a row. Last error: '" . $failure_reason . "'.");
     }
 
     return \@buffer;
@@ -1263,17 +1256,14 @@ sub l ($$) {
     my $this_level = shift;
     my $message = shift;
 
-    return unless ($log_level & $this_level);
-
-    if (LL_ERROR & $this_level) {
-        $message = 'Oh noes. ' . $message . ' Fatal error. Exiting.';
-    }
+    log_message($message) if ($log_level & $this_level);
+}
 
-    log_message($message);
+sub log_and_die ($) {
+    my $message = shift;
 
-    if (LL_ERROR & $this_level) {
-        exit;
-    }
+    log_message('Oh noes. ' . $message . ' Fatal error. Exiting.');
+    exit;
 }
 
 sub log_message ($) {
@@ -1382,7 +1372,6 @@ sub log_result ($$) {
         } else {
 
             die "Incomplete support for test type " . $test{'type'} .  " detected.";
-
         }
     }
 
@@ -1420,6 +1409,7 @@ Options and their default values if they have any:
     [--min-level $cli_options{'min-level'}]
     [--privoxy-address]
     [--retries $cli_options{'retries'}]
+    [--show-skipped-tests]
     [--test-number]
     [--verbose]
     [--version]
@@ -1434,13 +1424,13 @@ sub init_cli_options () {
     our %cli_options;
     our $log_level;
 
-    $cli_options{'min-level'} = CLI_MIN_LEVEL;
+    $cli_options{'debug'}     = $log_level;
+    $cli_options{'forks'}     = CLI_FORKS;
+    $cli_options{'loops'}     = CLI_LOOPS;
     $cli_options{'max-level'} = CLI_MAX_LEVEL;
-    $cli_options{'debug'}  = $log_level;
-    $cli_options{'loops'}  = CLI_LOOPS;
     $cli_options{'max-time'}  = CLI_MAX_TIME;
-    $cli_options{'retries'}  = CLI_RETRIES;
-    $cli_options{'forks'}    = CLI_FORKS;
+    $cli_options{'min-level'} = CLI_MIN_LEVEL;
+    $cli_options{'retries'}   = CLI_RETRIES;
 }
 
 sub parse_cli_options () {
@@ -1451,22 +1441,23 @@ sub parse_cli_options () {
     init_cli_options();
 
     GetOptions (
-                'debug=s' => \$cli_options{'debug'},
-                'forks=s' => \$cli_options{'forks'},
-                'help'     => sub { help },
-                'header-fuzzing' => \$cli_options{'header-fuzzing'},
-                'min-level=s' => \$cli_options{'min-level'},
-                'max-level=s' => \$cli_options{'max-level'},
-                'privoxy-address=s' => \$cli_options{'privoxy-address'},
-                'fuzzer-address=s' => \$cli_options{'fuzzer-address'},
-                'level=s' => \$cli_options{'level'},
-                'loops=s' => \$cli_options{'loops'},
-                'test-number=s' => \$cli_options{'test-number'},
-                'fuzzer-feeding' => \$cli_options{'fuzzer-feeding'},
-                'retries=s' => \$cli_options{'retries'},
-                'max-time=s' => \$cli_options{'max-time'},
-                'verbose' => \$cli_options{'verbose'},
-                'version'  => sub { print_version && exit(0) }
+        'debug=s'            => \$cli_options{'debug'},
+        'forks=s'            => \$cli_options{'forks'},
+        'fuzzer-address=s'   => \$cli_options{'fuzzer-address'},
+        'fuzzer-feeding'     => \$cli_options{'fuzzer-feeding'},
+        'header-fuzzing'     => \$cli_options{'header-fuzzing'},
+        'help'               => sub {help},
+        'level=s'            => \$cli_options{'level'},
+        'loops=s'            => \$cli_options{'loops'},
+        'max-level=s'        => \$cli_options{'max-level'},
+        'max-time=s'         => \$cli_options{'max-time'},
+        'min-level=s'        => \$cli_options{'min-level'},
+        'privoxy-address=s'  => \$cli_options{'privoxy-address'},
+        'retries=s'          => \$cli_options{'retries'},
+        'show-skipped-tests' => \$cli_options{'show-skipped-tests'},
+        'test-number=s'      => \$cli_options{'test-number'},
+        'verbose'            => \$cli_options{'verbose'},
+        'version'            => sub {print_version && exit(0)}
     );
     $log_level |= $cli_options{'debug'};
 }
@@ -1503,14 +1494,13 @@ sub init_proxy_settings($) {
         if (cli_option_is_set('privoxy-address')) {
             $proxy .=  get_cli_option('privoxy-address');
         }
-
     }
 }
 
 sub start_forks($) {
     my $forks = shift;
 
-    l(LL_ERROR, "Invalid --fork value: " . $forks . ".") if ($forks < 0); 
+    log_and_die("Invalid --fork value: " . $forks . ".") if ($forks < 0);
 
     foreach my $fork (1 .. $forks) {
         log_message("Starting fork $fork");
@@ -1545,7 +1535,8 @@ B<privoxy-regression-test> [B<--debug bitmask>] [B<--forks> forks]
 [B<--fuzzer-feeding>] [B<--fuzzer-feeding>] [B<--help>] [B<--level level>]
 [B<--loops count>] [B<--max-level max-level>] [B<--max-time max-time>]
 [B<--min-level min-level>] B<--privoxy-address proxy-address>
-[B<--retries retries>] [B<--test-number test-number>] [B<--verbose>]
+[B<--retries retries>] [B<--test-number test-number>]
+[B<--show-skipped-tests>] [B<--verbose>]
 [B<--version>]
 
 =head1 DESCRIPTION
@@ -1694,7 +1685,10 @@ B<--retries retries> Retry B<retries> times.
 B<--test-number test-number> Only run the test with the specified
 number.
 
-B<--verbose> Also log succesful test runs.
+B<--show-skipped-tests> Log skipped tests even if verbose mode is off.
+
+B<--verbose> Log succesful tests as well. By default only
+the failures are logged.
 
 B<--version> Print version and exit.