Testsuite: in force-continue mode, always dump any unexpected paniclog files
[exim.git] / test / runtest
index 088c742be5ff0532712a4a6139542594ee6d8620..745b360cf5e6e14528cd2f1ee47af3c0c9281c7a 100755 (executable)
@@ -50,7 +50,7 @@ my $cf = 'bin/cf -exact';
 my $cr = "\r";
 my $debug = 0;
 my $flavour = do {
-  my $f = Exim::Runtest::flavour();
+  my $f = Exim::Runtest::flavour() // '';
   (grep { $f eq $_ } Exim::Runtest::flavours()) ? $f : 'FOO';
 };
 my $force_continue = 0;
@@ -61,6 +61,7 @@ my $more = 'less -XF';
 my $optargs = '';
 my $save_output = 0;
 my $server_opts = '';
+my $slow = 0;
 my $valgrind = 0;
 
 my $have_ipv4 = 1;
@@ -358,6 +359,7 @@ open(IN, "$file") || tests_exit(-1, "Failed to open $file: $!");
 my($is_log) = $file =~ /log/;
 my($is_stdout) = $file =~ /stdout/;
 my($is_stderr) = $file =~ /stderr/;
+my($is_mail) = $file =~ /mail/;
 
 # Date pattern
 
@@ -420,12 +422,6 @@ RESET_AFTER_EXTRA_LINE_READ:
   s?prvs=([^/]+)/[\da-f]{10}@?prvs=$1/xxxxxxxxxx@?g;    # Old form
   s?prvs=[\da-f]{10}=([^@]+)@?prvs=xxxxxxxxxx=$1@?g;    # New form
 
-  # Error lines on stdout from SSL contain process id values and file names.
-  # They also contain a source file name and line number, which may vary from
-  # release to release.
-  s/^\d+:error:/pppp:error:/;
-  s/:(?:\/[^\s:]+\/)?([^\/\s]+\.c):\d+:/:$1:dddd:/;
-
   # There are differences in error messages between OpenSSL versions
   s/SSL_CTX_set_cipher_list/SSL_connect/;
 
@@ -805,7 +801,10 @@ RESET_AFTER_EXTRA_LINE_READ:
   # numbers, or handle specific bad conditions in different ways, leading to
   # different wording in the error messages, so we cannot compare them.
 
-  s/(TLS error on connection (?:from .* )?\(SSL_\w+\): error:)(.*)/$1 <<detail omitted>>/;
+#XXX This loses any trailing "deliving unencypted to" which is unfortunate
+#    but I can't work out how to deal with that.
+  s/(TLS session: \(SSL_\w+\): error:)(.*)(?!: delivering)/$1 <<detail omitted>>/;
+  s/(TLS error on connection from .* \(SSL_\w+\): error:)(.*)/$1 <<detail omitted>>/;
   next if /SSL verify error: depth=0 error=certificate not trusted/;
 
   # ======== Maildir things ========
@@ -889,15 +888,25 @@ RESET_AFTER_EXTRA_LINE_READ:
         }
       }
 
+    # remote IPv6 addrs vary
+    s/^(Connection request from) \[.*:.*:.*\]$/$1 \[ipv6\]/;
+
     # openssl version variances
-    next if /^SSL info: unknown state/;
-    next if /^SSL info: SSLv2\/v3 write client hello A/;
-    next if /^SSL info: SSLv3 read server key exchange A/;
+  # Error lines on stdout from SSL contain process id values and file names.
+  # They also contain a source file name and line number, which may vary from
+  # release to release.
+
+    next if /^SSL info:/;
     next if /SSL verify error: depth=0 error=certificate not trusted/;
     s/SSL3_READ_BYTES/ssl3_read_bytes/i;
+    s/^\d+:error:\d+(:SSL routines:ssl3_read_bytes:[^:]+:).*(:SSL alert number \d\d)$/pppp:error:dddddddd$1\[...\]$2/;
 
     # gnutls version variances
     next if /^Error in the pull function./;
+
+    # optional IDN2 variant conversions.  Accept either IDN1 or IDN2
+    s/conversion  strasse.de/conversion  xn--strae-oqa.de/;
+    s/conversion: german.xn--strae-oqa.de/conversion: german.straße.de/;
     }
 
   # ======== stderr ========
@@ -963,7 +972,7 @@ RESET_AFTER_EXTRA_LINE_READ:
     }
     next if /^tls_validate_require_cipher child \d+ ended: status=0x0/;
 
-    # We invoke Exim with -D, so we hit this new messag as of Exim 4.73:
+    # We invoke Exim with -D, so we hit this new message as of Exim 4.73:
     next if /^macros_trusted overridden to true by whitelisting/;
 
     # We have to omit the localhost ::1 address so that all is well in
@@ -1076,6 +1085,10 @@ RESET_AFTER_EXTRA_LINE_READ:
     # Not all platforms build with DKIM enabled
     next if /^PDKIM >> Body data for hash, canonicalized/;
 
+    #  Parts of DKIM-specific debug output depend on the time/date
+    next if /^date:\w+,\{SP\}/;
+    next if /^PDKIM \[[^[]+\] (Header hash|b) computed:/;
+
     # Not all platforms support TCP Fast Open, and the compile omits the check
     if (s/\S+ in hosts_try_fastopen\? no \(option unset\)\n$//)
       {
@@ -1265,8 +1278,8 @@ if (! -e $sf_current)
       log_failure($log_failed_filename, $testno, $rf);
       log_test($log_summary_filename, $testno, 'F') if ($force_continue);
     }
-    return 1 if /^c$/i;
-    last if (/^s$/);
+    return 1 if /^c$/i && $rf !~ /paniclog/ && $rsf !~ /paniclog/;
+    last if (/^[sc]$/);
     }
 
   foreach $f ($rf, $rsf)
@@ -1506,7 +1519,7 @@ $munges =
                   )($|[ ]=)/x' },
 
     'sys_bindir' =>
-    { 'mainlog' => 's%/(usr/)?bin/%SYSBINDIR/%' },
+    { 'mainlog' => 's%/(usr/(local/)?)?bin/%SYSBINDIR/%' },
 
     'sync_check_data' =>
     { 'mainlog'   => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1<suppressed>/',
@@ -1780,7 +1793,7 @@ system("$cmd");
 # The <SCRIPT> file is open for us to read an optional return code line,
 # followed by the command line and any following data lines for stdin. The
 # command line can be continued by the use of \. Data lines are not continued
-# in this way. In all lines, the following substutions are made:
+# in this way. In all lines, the following substitutions are made:
 #
 # DIR    => the current directory
 # CALLER => the caller of this script
@@ -1789,14 +1802,14 @@ system("$cmd");
 #            reference to the subtest number, holding previous value
 #            reference to the expected return code value
 #            reference to where to put the command name (for messages)
-#            auxilliary information returned from a previous run
+#            auxiliary information returned from a previous run
 #
-# Returns:   0 the commmand was executed inline, no subprocess was run
+# Returns:   0 the command was executed inline, no subprocess was run
 #            1 a non-exim command was run and waited for
 #            2 an exim command was run and waited for
 #            3 a command was run and not waited for (daemon, server, exim_lock)
 #            4 EOF was encountered after an initial return code line
-# Optionally alse a second parameter, a hash-ref, with auxilliary information:
+# Optionally also a second parameter, a hash-ref, with auxiliary information:
 #            exim_pid: pid of a run process
 #            munge: name of a post-script results munger
 
@@ -2257,14 +2270,20 @@ elsif (/^((?i:[A-Z\d_]+=\S+\s+)+)?(\d+)?\s*(sudo(?:\s+-u\s+(\w+))?\s+)?exim(_\S+
 
   if ($args =~ /\$msg/)
     {
-    my($listcmd) = "$parm_cwd/eximdir/exim -bp " .
-                   "-DEXIM_PATH=$parm_cwd/eximdir/exim " .
-                   "-C $parm_cwd/test-config |";
-    print ">> Getting queue list from:\n>>    $listcmd\n" if ($debug);
-    open (QLIST, $listcmd) || tests_exit(-1, "Couldn't run \"exim -bp\": $!\n");
-    my(@msglist) = ();
-    while (<QLIST>) { push (@msglist, $1) if /^\s*\d+[smhdw]\s+\S+\s+(\S+)/; }
-    close(QLIST);
+    my @listcmd  = ("$parm_cwd/eximdir/exim", '-bp',
+                   "-DEXIM_PATH=$parm_cwd/eximdir/exim",
+                   -C => "$parm_cwd/test-config");
+    print ">> Getting queue list from:\n>>    @listcmd\n" if $debug;
+    # We need the message ids sorted in ascending order.
+    # Message id is: <timestamp>-<pid>-<fractional-time>. On some systems (*BSD) the
+    # PIDs are randomized, so sorting just the whole PID doesn't work.
+    # We do the Schartz' transformation here (sort on
+    # <timestamp><fractional-time>). Thanks to Kirill Miazine
+    my @msglist =
+      map { $_->[1] }                                   # extract the values
+      sort { $a->[0] cmp $b->[0] }                      # sort by key
+      map { [join('.' => (split /-/, $_)[0,2]) => $_] } # key (timestamp.fractional-time) => value(message_id)
+      map { /^\s*\d+[smhdw]\s+\S+\s+(\S+)/ } `@listcmd` or tests_exit(-1, "No output from `exim -bp` (@listcmd)\n");
 
     # Done backwards just in case there are more than 9
 
@@ -2532,6 +2551,7 @@ while (@ARGV > 0 && $ARGV[0] =~ /^-/)
     if ($arg eq "-NOIPV4") { $have_ipv4 = 0; next; }
     if ($arg eq "-NOIPV6") { $have_ipv6 = 0; next; }
     if ($arg eq "-KEEP")   { $save_output = 1; next; }
+    if ($arg eq "-SLOW")   { $slow = 1; next; }
     if ($arg eq "-VALGRIND")   { $valgrind = 1; next; }
     if ($arg =~ /^-FLAVOU?R$/) { $flavour = shift; next; }
     }
@@ -2612,10 +2632,13 @@ close(IN);
 close(OUT);
 
 print("Probing with config file: $parm_cwd/test-config\n");
-open(EXIMINFO, "$parm_exim -d -C $parm_cwd/test-config -DDIR=$parm_cwd " .
-               "-bP exim_user exim_group 2>&1|") ||
-  die "** Cannot run $parm_exim: $!\n";
-while(<EXIMINFO>)
+
+my $eximinfo = "$parm_exim -d -C $parm_cwd/test-config -DDIR=$parm_cwd -bP exim_user exim_group";
+chomp(my @eximinfo = `$eximinfo 2>&1`);
+die "$0: Can't run $eximinfo\n" if $? == -1;
+
+warn 'Got ' . $?>>8 . " from $eximinfo\n" if $?;
+foreach (@eximinfo)
   {
   if (my ($version) = /^Exim version (\S+)/) {
     my $git = `git describe --dirty=-XX --match 'exim-4*'`;
@@ -2641,21 +2664,21 @@ ___
        if /^Configure owner:\s*(\d+):(\d+)/;
   print if /wrong owner/;
   }
-close(EXIMINFO);
 
-if (defined $parm_eximuser)
-  {
-  if ($parm_eximuser =~ /^\d+$/) { $parm_exim_uid = $parm_eximuser; }
-    else { $parm_exim_uid = getpwnam($parm_eximuser); }
-  }
-else
-  {
-  print "Unable to extract exim_user from binary.\n";
-  print "Check if Exim refused to run; if so, consider:\n";
-  print "  TRUSTED_CONFIG_LIST ALT_CONFIG_PREFIX WHITELIST_D_MACROS\n";
-  print "If debug permission denied, are you in the exim group?\n";
-  die "Failing to get information from binary.\n";
-  }
+if (not defined $parm_eximuser) {
+  die <<XXX, map { "|$_\n" } @eximinfo;
+Unable to extract exim_user from binary.
+Check if Exim refused to run; if so, consider:
+  TRUSTED_CONFIG_LIST ALT_CONFIG_PREFIX WHITELIST_D_MACROS
+If debug permission denied, are you in the exim group?
+Failing to get information from binary.
+Output from $eximinfo:
+XXX
+
+}
+
+if ($parm_eximuser =~ /^\d+$/) { $parm_exim_uid = $parm_eximuser; }
+else { $parm_exim_uid = getpwnam($parm_eximuser); }
 
 if (defined $parm_eximgroup)
   {
@@ -2796,7 +2819,7 @@ if (defined $parm_support{Content_Scanning})
     # This test for an active SpamAssassin is courtesy of John Jetmore.
     # The tests are hard coded to localhost:783, so no point in making
     # this test flexible like the clamav test until the test scripts are
-    # changed.  spamd doesn't have the nice PING/PONG protoccol that
+    # changed.  spamd doesn't have the nice PING/PONG protocol that
     # clamd does, but it does respond to errors in an informative manner,
     # so use that.
 
@@ -3830,13 +3853,13 @@ foreach $test (@test_list)
     # command was run and waited for, and 3 if a command
     # was run and not waited for (usually a daemon or server startup).
 
+    $0 = "[runtest $testno]";
+
     my($commandname) = '';
     my($expectrc) = 0;
     my($rc, $run_extra) = run_command($testno, \$subtestno, \$expectrc, \$commandname, $TEST_STATE);
     my($cmdrc) = $?;
 
-    $0 = "[runtest $testno]";
-
     if ($debug) {
       print ">> rc=$rc cmdrc=$cmdrc\n";
       if (defined $run_extra) {
@@ -3928,7 +3951,8 @@ foreach $test (@test_list)
       if ($? != 0)
         {
         if (($? & 0xff) == 0)
-          { printf("Server return code %d", $?/256); }
+          { printf("Server return code %d for test %d starting line %d", $?/256,
+               $testno, $subtest_startline); }
         elsif (($? & 0xff00) == 0)
           { printf("Server killed by signal %d", $? & 255); }
         else
@@ -3975,6 +3999,7 @@ foreach $test (@test_list)
 
   if ($docheck)
     {
+    sleep 1 if $slow;
     my $rc = check_output($TEST_STATE->{munge});
     log_test($log_summary_filename, $testno, 'P') if ($rc == 0);
     if ($rc < 2)