X-Git-Url: https://git.exim.org/exim.git/blobdiff_plain/02721dcdf5dfcf96f62f6c657c9989b9ef991fa7..d6e20136b71dc5f3cd333a6342223f814ec2e7a2:/test/runtest?ds=inline diff --git a/test/runtest b/test/runtest index 57e2d8a10..1d7589a69 100755 --- a/test/runtest +++ b/test/runtest @@ -2,6 +2,9 @@ # We use env, because in some environments of our build farm # the Perl 5.010 interpreter is only reachable via $PATH +# Copyright (c) The Exim Maintainers 2024 +# SPDX-License-Identifier: GPL-2.0-or-later + ############################################################################### # This is the controlling script for the "new" test suite for Exim. It should # # be possible to export this suite for running on a wide variety of hosts, in # @@ -18,7 +21,6 @@ #use strict; use v5.10.1; use warnings; -use if $^V >= v5.19.11, experimental => 'smartmatch'; use Errno; use FileHandle; @@ -29,10 +31,11 @@ use File::Basename; use Pod::Usage; use Getopt::Long; use FindBin qw'$RealBin'; +use File::Copy; use lib "$RealBin/lib"; use Exim::Runtest; -use Exim::Utils qw(uniq numerically); +use Exim::Utils qw(uniq numerically cp); use if $ENV{DEBUG} && scalar($ENV{DEBUG} =~ /\bruntest\b/) => 'Smart::Comments' => '####'; use if $ENV{DEBUG} && scalar($ENV{DEBUG} =~ /\bruntest\b/) => 'Data::Dumper'; @@ -64,7 +67,7 @@ my $force_continue = 0; my $force_update = 0; my $log_failed_filename = 'failed-summary.log'; my $log_summary_filename = 'run-summary.log'; -my $more = 'less -XF'; +my @more = qw'less -XF'; my $optargs = ''; my $save_output = 0; my $server_opts = ''; @@ -112,9 +115,17 @@ $ENV{LC_ALL} = 'C'; $ENV{USER} = getpwuid($>) if not exists $ENV{USER}; my ($parm_configure_owner, $parm_configure_group); -my ($parm_ipv4, $parm_ipv6); +my ($parm_ipv4, $parm_ipv6, $parm_ipv6_stripped); my $parm_hostname; +# Convenience for regex' +# for tighter, see https://metacpan.org/dist/IO-Socket-IP/source/lib/IO/Socket/IP.pm#L37 +my $re_ipv4 = qr/\d{1,3}(?:\.\d{1,3}){3}/; +my $re_6g = qr/[[:xdigit:]]{1,4}/; +my $re_6s = qr/${re_6g}:/; +my $re_ipv6 = qr/${re_6s}{0,7}${re_6g}(?:::${re_6s}{0,5}${re_6g})?/; +my $re_ip = qr/(?:${re_ipv4}|${re_ipv6})/; + ############################################################################### ############################################################################### @@ -253,9 +264,11 @@ die "** runtest error: $_[1]\n"; sub new_value { my($oldid, $base, $sequence) = @_; my($newid) = $cache{$oldid}; +print ">> replace $oldid -> $newid\n" if ($debug && defined $newid); if (! defined $newid) { $newid = sprintf($base, $$sequence++); + print ">> new $oldid -> $newid\n" if $debug; $cache{$oldid} = $newid; } return $newid; @@ -341,7 +354,7 @@ return @yield; # into the same standard values throughout the data from a single test. # Message ids get this treatment (can't be made reliable for times), and # times in dumped retry databases are also handled in a special way, as are -# incoming port numbers. +# incoming port numbers and PIDs. # On entry to the subroutine, the file to write to is already opened with the # name MUNGED. The input file name is the only argument to the subroutine. @@ -368,6 +381,10 @@ my($is_mail) = $file =~ /mail/; $date = "\\d{2}-\\w{3}-\\d{4}\\s\\d{2}:\\d{2}:\\d{2}"; +# Debug time & pid + +$time_pid = "(?:\\d{2}:\\d{2}:\\d{2}\\s+\\d+\\s)"; + # Pattern for matching pids at start of stderr lines; initially something # that won't match. @@ -380,11 +397,23 @@ $spid = "xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx"; LINE: while() { RESET_AFTER_EXTRA_LINE_READ: + if ($munge_skip) + { + # Munging is a no-op, except for exim_msgdate specials. + # Useful when testing exim_msgdate so that + # we compare unmunged dates and message-ids. + s%^localhost \d+ from message-id != given number \d+ at \K/.+(?=/test/eximdir/exim_msgdate line 387.$)%DIR%; + + print MUNGED; + next; + } + # Custom munges if ($extra) { next if $extra =~ m%^/% && eval $extra; eval $extra if $extra =~ m/^s/; + eval substr($extra, 1) if $extra =~ m/^R/; } # Check for "*** truncated ***" @@ -404,11 +433,14 @@ RESET_AFTER_EXTRA_LINE_READ: # Replace the Exim version number (may appear in various places) # patchexim should have fixed this for us - #s/(Exim) \d+\.\d+[\w_-]*/$1 x.yz/i; + #s/Exim \K\d+[._]\d+[\w_-]*/x.yz/i; - # Replace Exim message ids by a unique series - s/((?:[^\W_]{6}-){2}[^\W_]{2}) - /new_value($1, "10Hm%s-0005vi-00", \$next_msgid)/egx; + # Replace Exim message ids by a unique series. + # Both old and new formats, with separate replace series, for now. + s/(\d[^\W_]{5}-[^\W_]{6}-[^\W_]{2}) + /new_value($1, "10Hm%s-0005vi-00", \$next_msgid_old)/egx; + s/(\d[^\W_]{5}-[^\W_]{11}-[^\W_]{4}) + /new_value($1, "10Hm%s-000000005vi-0000", \$next_msgid)/egx; # The names of lock files appear in some error and debug messages s/\.lock(\.[-\w]+)+(\.[\da-f]+){2}/.lock.test.ex.dddddddd.pppppppp/; @@ -427,6 +459,8 @@ RESET_AFTER_EXTRA_LINE_READ: # There are differences in error messages between OpenSSL versions s/SSL_CTX_set_cipher_list/SSL_connect/; + s/error=\Kauthority and subject key identifier mismatch/self signed certificate/; + s/error=\Kself-signed certificate/self signed certificate/; # One error test in expansions mentions base 62 or 36 s/is not a base (36|62) number/is not a base 36\/62 number/; @@ -435,13 +469,13 @@ RESET_AFTER_EXTRA_LINE_READ: s/forced fail after \d seconds/forced fail after d seconds/; # This message may contain a different DBM library name - s/Failed to open \S+( \([^\)]+\))? file/Failed to open DBM file/; + s/Failed to open \S+( \([^\)]+\))? file/Failed to open hintsdb file/; # The message for a non-listening FIFO varies s/:[^:]+: while opening named pipe/: Error: while opening named pipe/; # Debugging output of lists of hosts may have different sort keys - s/sort=\S+/sort=xx/ if /^\S+ (?:\d+\.){3}\d+ mx=\S+ sort=\S+/; + s/^\s*\S+ (?:\d+\.){3}\d+ mx=\S+ sort=\K\S+/xx/; # Random local part in callout cache testing s/myhost.test.ex-\d+-testing/myhost.test.ex-dddddddd-testing/; @@ -460,7 +494,11 @@ RESET_AFTER_EXTRA_LINE_READ: { my($date1,$date2,$date3,$expired) = ($1,$2,$3,$4); $expired = '' if !defined $expired; - my($increment) = date_seconds($date3) - date_seconds($date2); + + # Make time-difference minimum 2, and rounded up to even value + my($increment) = date_seconds($date3) - date_seconds($date2) + 1; + $increment = 2 if ($increment == 0); + $increment = ($increment >> 1) << 1; # We used to use globally unique replacement values, but timing # differences make this impossible. Just show the increment on the @@ -474,6 +512,16 @@ RESET_AFTER_EXTRA_LINE_READ: # more_errno values in exim_dumpdb output which are times s/T:(\S+)\s-22\s(\S+)\s/T:$1 -22 xxxx /; + # port numbers in dumpdb output + s/T:([a-z0-9.]+(:[0-9.]+|:\[[^]]+])?):$parm_port_n /T:$1:PORT_N /; + s/T:([a-z0-9.[\]]+(:[0-9.]+|:\[[^]]+])?):$parm_port_s /T:$1:PORT_S /; + # and exinext + s/Transport: (?:[a-z0-9.]+|\[[^\]]+]) (?:[0-9.]+|\[[^\]]+]):\K$parm_port_s /PORT_S /; + + # port numbers in stderr + s/^set_process_info: .*\]:\K$parm_port_d /PORT_D /; + s/^set_process_info: .*\]:\K$parm_port_s /PORT_S /; + # ======== Dates and times ======== @@ -483,20 +531,44 @@ RESET_AFTER_EXTRA_LINE_READ: # time used was fixed when I first started running automatic Exim tests. # Date/time in header lines and SMTP responses - s/[A-Z][a-z]{2},\s\d\d?\s[A-Z][a-z]{2}\s\d\d\d\d\s\d\d\:\d\d:\d\d\s[-+]\d{4} - /Tue, 2 Mar 1999 09:44:33 +0000/gx; + s/[A-Z][a-z]{2}, + (\s|\xE2\x96\x91) + \d\d? + (\s|\xE2\x96\x91) + [A-Z][a-z]{2} + (\s|\xE2\x96\x91) + \d{4} + (\s|\xE2\x96\x91) + \d\d\:\d\d:\d\d + (\s|\xE2\x96\x91) + [-+]\d{4} + /Tue,${1}2${2}Mar${3}1999${4}09:44:33${5}+0000/gx; + # and in a French locale + s/\S{4},\s\d\d?\s[^,]+\s\d{4}\s\d\d\:\d\d:\d\d\s[-+]\d{4} + /dim., 10 f\xE9vr 2019 20:05:49 +0000/gx; # Date/time in logs and in one instance of a filter test s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d(\s[+-]\d\d\d\d)?\s/1999-03-02 09:44:33 /gx; - s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}(\s[+-]\d\d\d\d)?\s/2017-07-30 18:51:05.712 /gx; + s/^\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}(?:\s(?:[+-]\d\d\d\d|[A-Z]{2}T))?\s/2017-07-30 18:51:05.712 /gx; s/^Logwrite\s"\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d/Logwrite "1999-03-02 09:44:33/gx; + # Date/time in syslog test + s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\s/2017-07-30 18:51:05 /gx; + s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}\s/2017-07-30 18:51:05.712 /gx; + s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\s[+-]\d\d\d\d\s/2017-07-30 18:51:05 +9999 /gx; + s/^SYSLOG:\s\'\K\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d\.\d{3}\s[+-]\d\d\d\d\s/2017-07-30 18:51:05.712 +9999 /gx; - s/((D|[QD]T)=)\d+s/$1qqs/g; - s/((D|[QD]T)=)\d\.\d{3}s/$1q.qqqs/g; + s/((D|[RQD]T)=)\d+s/$1qqs/g; + s/((D|[RQD]T)=)\d\.\d{3}s/$1q.qqqs/g; # Date/time in message separators - s/(?:[A-Z][a-z]{2}\s){2}\d\d\s\d\d:\d\d:\d\d\s\d\d\d\d - /Tue Mar 02 09:44:33 1999/gx; + s/(?:[A-Z][a-z]{2} + (\s|\xE2\x96\x91) + ){2}\d\d + (\s|\xE2\x96\x91) + \d\d:\d\d:\d\d + (\s|\xE2\x96\x91) + \d\d\d\d + /Tue${1}Mar${1}02${2}09:44:33${3}1999/gx; # Date of message arrival in spool file as shown by -Mvh s/^\d{9,10}\s0$/ddddddddd 0/; @@ -505,13 +577,13 @@ RESET_AFTER_EXTRA_LINE_READ: s/\d\d-\w\w\w-\d\d\d\d\s\d\d:\d\d:\d\d\s[-+]\d\d\d\d,/06-Sep-1999 15:52:48 +0100,/gx; # Dates/times in debugging output for writing retry records - if (/^ first failed=(\d+) last try=(\d+) next try=(\d+) (.*)$/) + if (/^(.+)first failed=(\d+) last try=(\d+) next try=(\d+) (.*)$/) { - my($next) = $3 - $2; - $_ = " first failed=dddd last try=dddd next try=+$next $4\n"; + my($next) = $4 - $3; + $_ = "$1first failed=dddd last try=dddd next try=+$next $5\n"; } - s/^(\s*)now=\d+ first_failed=\d+ next_try=\d+ expired=(\d)/$1now=tttt first_failed=tttt next_try=tttt expired=$2/; - s/^(\s*)received_time=\d+ diff=\d+ timeout=(\d+)/$1received_time=tttt diff=tttt timeout=$2/; + s/^(.*)now=\d+ first_failed=\d+ next_try=\d+ expired=(\w)/$1now=tttt first_failed=tttt next_try=tttt expired=$2/; + s/^(.*)received_time=\d+ diff=\d+ timeout=(\d+)/$1received_time=tttt diff=tttt timeout=$2/; # Time to retry may vary s/time to retry = \S+/time to retry = tttt/; @@ -530,62 +602,131 @@ RESET_AFTER_EXTRA_LINE_READ: s/(could not connect to .*: Connection) reset by peer$/$1 refused/; # ======== TLS certificate algorithms ======== + # + # In Received: headers, convert RFC 8314 style ciphersuite to + # the older (comment) style, keeping only the Auth element + # (discarding kex, cipher, mac). For TLS 1.3 there is no kex + # element (and no _WITH); insert a spurious "RSA". + # Also in $tls_X_cipher_std reporting. + + s/^\s+by \S+ with .+ \K \(TLS1(?:\.[0-3])?\) tls TLS_.*?([^_]+)_WITH.+$/(TLS1.x:ke-$1-AES256-SHAnnn:xxx)/; + s/^\s+by \S+ with .+ \K \(TLS1(?:\.[0-3])?\) tls TLS_.+$/(TLS1.x:ke-RSA-AES256-SHAnnn:xxx)/; + + s/ cipher_ TLS_.*?([^_]+)_WITH.+$/ cipher_ TLS1.x:ke_$1_WITH_ci_mac/; + s/ cipher_ TLS_.*$/ cipher_ TLS1.x:ke_RSA_WITH_ci_mac/; + # Test machines might have various different TLS library versions supporting # different protocols; can't rely upon TLS 1.2's AES256-GCM-SHA384, so we # treat the standard algorithms the same. + # + # TLSversion : KeyExchange? - Authentication/Signature - C_iph_er - MAC : bits + # # So far, have seen: # TLSv1:AES128-GCM-SHA256:128 # TLSv1:AES256-SHA:256 # TLSv1.1:AES256-SHA:256 # TLSv1.2:AES256-GCM-SHA384:256 # TLSv1.2:DHE-RSA-AES256-SHA:256 + # TLSv1.3:TLS_AES_256_GCM_SHA384:256 # TLS1.2:DHE_RSA_AES_128_CBC_SHA1:128 # We also need to handle the ciphersuite without the TLS part present, for # client-ssl's output. We also see some older forced ciphersuites, but # negotiating TLS 1.2 instead of 1.0. # Mail headers (...), log-lines X=..., client-ssl output ... # (and \b doesn't match between ' ' and '(' ) + # + # Retain the authentication algorith field as we want to test that. - s/( (?: (?:\b|\s) [\(=] ) | \s )TLSv1\.[12]:/$1TLSv1:/xg; - s/\bAES128-GCM-SHA256:128\b/AES256-SHA:256/g; - s/\bAES128-GCM-SHA256\b/AES256-SHA/g; - s/\bAES256-GCM-SHA384\b/AES256-SHA/g; - s/\bDHE-RSA-AES256-SHA\b/AES256-SHA/g; + s/( (?: (?:\b|\s) [\(=] ) | \s )TLS1(\.[123])?:/$1TLS1.x:/xg; + s/(?PSK)_)?((?RSA|ECDSA)_)? + (SECP(256|521)R1|X25519))?__?)? # key-exchange + ((?RSA|ECDSA)((_PSS_RSAE)?_SHA(512|256))?__?)? # authentication + (?WITH_)? # stdname-with + AES_(256|128)_(CBC|GCM) # cipher + (__?AEAD)? # pseudo-MAC + (__?SHA(1|256|384))? # PRF + :(256|128) # cipher strength + /"TLS1.x:ke-" + . (defined($+{psk}) ? $+{psk} : "") + . (defined($+{auth}) ? $+{auth} : "") + . (defined($+{with}) ? $+{with} : "") + . "-AES256-SHAnnn:xxx"/gex; + s/TLS1.2:RSA__CAMELLIA_256_GCM(_SHA384)?:256/TLS1.2:RSA_CAMELLIA_256_GCM-SHAnnn:256/g; + s/\b(ECDHE-(RSA|ECDSA)-AES256-SHA|DHE-RSA-AES256-SHA256)\b/ke-$2-AES256-SHAnnn/g; + + # Separate reporting of TLS version + s/ver: TLS1(\.[0-3])?$/ver: TLS1.x/; + s/ \(TLS1(\.[0-3])?\) / (TLS1.x) /; # GnuTLS library error message changes - s/No certificate was found/The peer did not send any certificate/g; + s/(No certificate was found|Certificate is required)/The peer did not send any certificate/g; #(dodgy test?) s/\(certificate verification failed\): invalid/\(gnutls_handshake\): The peer did not send any certificate./g; s/\(gnutls_priority_set\): No or insufficient priorities were set/\(gnutls_handshake\): Could not negotiate a supported cipher suite/g; + s/\(gnutls_handshake\): \KNo supported cipher suites have been found.$/Could not negotiate a supported cipher suite./; # (this new one is a generic channel-read error, but the testsuite # only hits it in one place) s/TLS error on connection \(gnutls_handshake\): Error in the pull function\./a TLS session is required but an attempt to start TLS failed/g; # (replace old with new, hoping that old only happens in one situation) - s/TLS error on connection to \d{1,3}(.\d{1,3}){3} \[\d{1,3}(.\d{1,3}){3}\] \(gnutls_handshake\): A TLS packet with unexpected length was received./a TLS session is required for ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4], but an attempt to start TLS failed/g; + s/TLS error on connection to ${re_ipv4} \[${re_ipv4}\] \(gnutls_handshake\): A TLS packet with unexpected length was received./a TLS session is required for ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4], but an attempt to start TLS failed/g; s/TLS error on connection from \[127.0.0.1\] \(recv\): A TLS packet with unexpected length was received./TLS error on connection from [127.0.0.1] (recv): The TLS connection was non-properly terminated./g; # signature algorithm names @@ -654,22 +795,26 @@ RESET_AFTER_EXTRA_LINE_READ: s/\bgid=\d+/gid=gggg/; s/\begid=\d+/egid=gggg/; - s/\bpid=\d+/pid=pppp/; + s/\b(?:pid=|pid\s|PID:\s|Process\s|child\s)\K(\d+)/new_value($1, "p%s", \$next_pid)/gxe; + s/ Ci=\K(\d+)/new_value($1, "p%s", \$next_pid)/gxe; s/\buid=\d+/uid=uuuu/; s/\beuid=\d+/euid=uuuu/; s/set_process_info:\s+\d+/set_process_info: pppp/; - s/queue run pid \d+/queue run pid ppppp/; s/process \d+ running as transport filter/process pppp running as transport filter/; s/process \d+ writing to transport filter/process pppp writing to transport filter/; s/reading pipe for subprocess \d+/reading pipe for subprocess pppp/; s/remote delivery process \d+ ended/remote delivery process pppp ended/; # Pid in temp file in appendfile transport - s"test-mail/temp\.\d+\."test-mail/temp.pppp."; + s"test-mail/(subdir/)?temp\K\.\d+\.".pppp."; # Optional pid in log lines - s/^(\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d)(\s[+-]\d\d\d\d|)(\s\[\d+\])/ - "$1$2 [" . new_value($3, "%s", \$next_pid) . "]"/gxe; + s/^(\d{4}-\d\d-\d\d\s\d\d:\d\d:\d\d)(\.\d{3}|)(\s[+-]\d{4}|)(\s\[\d+\])/ + "$1$2$3 [" . new_value($4, "%s", \$next_pid) . "]"/gxe; + + # Optional pid in syslog test lines + s/^(SYSLOG:\s\'([-0-9]{10}\s[:.0-9]{8,12}\s([-+]\d{4}\s)?|))(\[\d+\] )/ + "$1\[" . new_value($4, "%s", \$next_pid) . "]"/gxe; # Detect a daemon stderr line with a pid and save the pid for subsequent # removal from following lines. @@ -680,8 +825,9 @@ RESET_AFTER_EXTRA_LINE_READ: s/waiting for children of \d+/waiting for children of pppp/; s/waiting for (\S+) \(\d+\)/waiting for $1 (pppp)/; - # The spool header file name varies with PID - s%^(Writing spool header file: .*/hdr).[0-9]{1,5}%$1.pppp%; + # Most builds are without HAVE_LOCAL_SCAN + next if /^calling local_scan\(\); timeout=300$/; + next if /^local_scan\(\) returned 0 NULL$/; # ======== Port numbers ======== # Incoming port numbers may vary, but not in daemon startup line. @@ -690,14 +836,15 @@ RESET_AFTER_EXTRA_LINE_READ: s/\(port=(\d+)/"(port=" . new_value($1, "%s", \$next_port)/e; # This handles "connection from" and the like, when the port is given - if (!/listening for SMTP on/ && !/Connecting to/ && !/=>/ && !/->/ - && !/\*>/ && !/Connection refused/) - { - s/\[([a-z\d:]+|\d+(?:\.\d+){3})\]:(\d+)/"[".$1."]:".new_value($2,"%s",\$next_port)/ie; - } + s/(\[${re_ip}\]:)(\d+)/$1.new_value($2,"%s",\$next_port)/ie + unless ( /listening for SMTP on/ || /Connecting to/ + || /[=*-]>/ || /==/ || /\*\*/ + || /Connection refused/ || /in response to/ + || /T(?:ransport)?:/ + ); # Port in host address in spool file output from -Mvh - s/^-host_address (.*)\.\d+/-host_address $1.9999/; + s/^(--?host_address) (.*[:.])\d+$/$1 ${2}9999/; if ($dynamic_socket and $dynamic_socket->opened and my $port = $dynamic_socket->sockport) { s/^Connecting to 127\.0\.0\.1 port \K$port//; @@ -711,6 +858,12 @@ RESET_AFTER_EXTRA_LINE_READ: # Also, the length of space at the end of the host line is dependent # on the length of the longest line, so strip it also on otherwise # un-rewritten lines like localhost + # + # host 127.0.0.1 [127.0.0.1] + # host 10.0.0.1 [10.0.0.1]- + # + # host 127.0.0.1 [127.0.0.1]-- + # host 169.16.16.16 [169.16.16.10] s/^\s+host\s(\S+)\s+(\S+)/ host $1 $2/; s/^\s+(host\s\S+\s\S+)\s+(port=.*)/ host $1 $2/; @@ -719,9 +872,10 @@ RESET_AFTER_EXTRA_LINE_READ: s/host\s\Q$parm_ipv6\E\s\[\Q$parm_ipv6\E\]/host ip6:ip6:ip6:ip6:ip6:ip6:ip6:ip6 [ip6:ip6:ip6:ip6:ip6:ip6:ip6:ip6]/; s/\b\Q$parm_ipv4\E\b/ip4.ip4.ip4.ip4/g; s/(^|\W)\K\Q$parm_ipv6\E/ip6:ip6:ip6:ip6:ip6:ip6:ip6:ip6/g; + s/(^|\W)\K\Q$parm_ipv6_stripped\E/ip6:ip6:ip6:ip6:ip6:ip6:ip6:ip6/g; s/\b\Q$parm_ipv4r\E\b/ip4-reverse/g; s/(^|\W)\K\Q$parm_ipv6r\E/ip6-reverse/g; - s/^(\s+host\s\S+\s+\[\S+\]) +$/$1 /; + s/^\s+host\s\S+\s+\[\S+\]\K +$//; # strip, not collapse the trailing whitespace # ======== Test network IP addresses ======== @@ -731,11 +885,10 @@ RESET_AFTER_EXTRA_LINE_READ: # ======== IP error numbers and messages ======== # These vary between operating systems - s/Can't assign requested address/Network Error/; - s/Cannot assign requested address/Network Error/; + s/(?:Can(?:no|')t assign requested address|Address not available)/Netwk addr not available/; s/Operation timed out/Connection timed out/; s/Address family not supported by protocol family/Network Error/; - s/Network is unreachable/Network Error/; + s/Network(?: is)? unreachable/Network Error/; s/Invalid argument/Network Error/; s/\(\d+\): Network/(dd): Network/; @@ -771,7 +924,7 @@ RESET_AFTER_EXTRA_LINE_READ: s/([\s,])S=\d+\b/$1S=sss/; s/:S\d+\b/:Ssss/; - s/^(\s*\d+m\s+)\d+(\s+[a-z0-9-]{16} <)/$1sss$2/i if $is_stdout; + s/^(\s*\d+[mhd]\s+)\d+(\s+(?:[[:alnum:]-]{23}|[[:alnum:]-]{16}) <)/TTT sss$2/i if $is_stdout; s/\sSIZE=\d+\b/ SIZE=ssss/; s/\ssize=\d+\b/ size=sss/ if $is_stderr; s/old size = \d+\b/old size = sssss/; @@ -797,7 +950,7 @@ RESET_AFTER_EXTRA_LINE_READ: # The sizes of filter files may vary because of the substitution of local # filenames, logins, etc. - s/^\d+(?= bytes read from )/ssss/; + s/^\d+(?= (\(tainted\) )?bytes read from )/ssss/; # ======== OpenSSL error messages ======== @@ -805,12 +958,25 @@ 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. -#XXX This loses any trailing "deliving unencypted to" which is unfortunate +#XXX This loses any trailing "delivering unencypted to" which is unfortunate # but I can't work out how to deal with that. s/(TLS session: \(SSL_\w+\): error:)(.*)(?!: delivering)/$1 <>/; + s/TLS error on connection from .*\K\(SSL_accept\): error:.*:unexpected eof while reading$/(tls lib accept fn): TCP connection closed by peer/; s/(TLS error on connection from .* \(SSL_\w+\): error:)(.*)/$1 <>/; next if /SSL verify error: depth=0 error=certificate not trusted/; + # OpenSSL 3.2.1 + # OpenSSL 3.0.0 + s/TLS\ error\ \(D-H\ param\ setting\ .*\ error:\K + .* + (?:dh\ key\ too\ small|unknown\ security\ bits) + /xxxxxxxx:SSL routines::dh key too small/x; + + # OpenSSL 1.1.1 + s/error:\K0B080074:x509 certificate routines:X509_check_private_key(?=:key values mismatch$)/05800074:x509 certificate routines:/; + s/error:\K02001002:system library:fopen(?=:No such file or directory$)/80000002:system library:/; + s/error:\K0909006C:PEM routines:get_name(?=:no start line$)/0480006C:PEM routines:/; + # ======== Maildir things ======== # timestamp output in maildir processing s/(timestamp=|\(timestamp_only\): )\d+/$1ddddddd/g; @@ -821,7 +987,7 @@ RESET_AFTER_EXTRA_LINE_READ: s/renamed tmp\/\d+\.[^.]+\.(\S+) as new\/\d+\.[^.]+\.(\S+)/renamed tmp\/MAILDIR.$1 as new\/MAILDIR.$1/; # Maildir file names in general - s/\b\d+\.H\d+P\d+\b/dddddddddd.HddddddPddddd/; + s/\b\d+\.M\d+P\d+\b/dddddddddd.HddddddPddddd/; # Maildirsize data while (/^\d+S,\d+C\s*$/) @@ -837,14 +1003,17 @@ RESET_AFTER_EXTRA_LINE_READ: last if !defined $_; + # SRS timestamps and signatures vary by hostname and from run to run + + s/(?i)SRS0=....=.[^=]?=([^=]+)=([^@]+)\@([^ ]+)/SRS0=ZZZZ=YY=$1=$2\@$3/g; + + # ======== Output from the "fd" program about open descriptors ======== # The statuses seem to be different on different operating systems, but # at least we'll still be checking the number of open fd's. s/max fd = \d+/max fd = dddd/; - s/status=0 RDONLY/STATUS/g; - s/status=1 WRONLY/STATUS/g; - s/status=2 RDWR/STATUS/g; + s/status=[0-9a-f]+ (?:RDONLY|WRONLY|RDWR)/STATUS/g; # ======== Contents of spool files ======== @@ -853,16 +1022,13 @@ RESET_AFTER_EXTRA_LINE_READ: s/^\d\d\d(?=[PFS*])/ddd/; - # ========= Exim lookups ================== - # Lookups have a char which depends on the number of lookup types compiled in, - # in stderr output. Replace with a "0". Recognising this while avoiding - # other output is fragile; perhaps the debug output should be revised instead. - s%(?)/; + # 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/; # subsecond timstamp info in reported header-files - s/^(-received_time_usec \.)\d{6}$/$1uuuuuu/; + s/^-received_time_usec \.\K\d{6}$/uuuuuu/; + s/^-received_time_complete \K\d+\.\d{6}$/tttt.uuuuuu/; + + # Postgres server takes varible time to shut down; lives in various places + s/^waiting for server to shut down\.+ done$/waiting for server to shut down.... done/; + s/^\/.*postgres /POSTGRES /; + + # DMARC is not always supported by the build + next if /^dmarc_tld_file =/; + # timestamp in dmarc history file + s/received \K\d{10}$/1692480217/; + + # ARC is not always supported by the build + next if /^arc_sign =/; + + # LIMITS is not always supported by the build + next if /^limits_advertise_hosts =/; + + # PRDR + next if /^hosts_try_prdr = \*$/; + + # TLS resumption is not always supported by the build + next if /^tls_resumption_hosts =/; + next if /^-tls_resumption/; + next if /^host_name_extract = /; + + # gsasl library version may not support some methods + s/250-AUTH ANONYMOUS PLAIN SCRAM-SHA-1\K SCRAM-SHA-256//; + + # mailq times change with when the run is done, vs. static-source spoolfiles + s/\s*\d*[hd](?= 317 (?:[-0-9A-Za-z]{23}|[-0-9A-Za-z]{16}) )/DDd/; + # mailq sizes change with caller running the test + s/\s[01]m [34]\d\d(?= (?:[-0-9A-Za-z]{23}|[-0-9A-Za-z]{16}) )/ 1m 396/; + + # Not all builds include EXPERIMENTAL_DSN_INFO (1 of 2) + if (/^X-Exim-Diagnostic:/) + { + while () { + last if (/^$/ || !/^\s/); + } + goto RESET_AFTER_EXTRA_LINE_READ; + } } # ======== stderr ======== @@ -922,53 +1151,175 @@ RESET_AFTER_EXTRA_LINE_READ: elsif ($is_stderr) { # The very first line of debugging output will vary - s/^Exim version .*/Exim version x.yz ..../; - # Debugging lines for Exim terminations and process-generation + # Skip some lines that Exim puts out at the start of debugging output + # because they will be different in different binaries. + + next if /^$time_pid? + (?: .*\sBerkeley\ DB + | \sProbably\ (?:Berkeley\ DB|ndbm|GDBM) + | \sUsing\ (?:tdb|sqlite3) + | Authenticators: + | Lookups(?:\(built-in\))?: + | Support\ for: + | Routers\ \((?:built-in|dynamic)\): + | Transports: + | Malware: + | log\ selectors\ = + | cwd= + | Fixed\ never_users + | Configure\ owner + | Size\ of\ off_t: + ) + /x; + + # Hints DB use of lockfiles is provider-dependent + next if /lock(?:ing|ed) .*\/spool\/db\/[^.]+\.lockfile$/; + s/closed hints database\K and lockfile$//; + + # Hints DBs with transactions are provider-dependent, and flow changes + # to take advantage of them need different opens and different flags. + # Drop all the debug output for opens and closes. + if (/EXIM_DBOPEN(_MULTI)?: file <.*spool\/db\/retry>/) + { + $_ = ; + next if (/returned from EXIM_DBOPEN(_MULTI)?: 0x[[:xdigit:]]+$/); + $_ = ; + if (/returned from EXIM_DBOPEN(_MULTI)?: \(nil\)$/); + next; + } + if (/EXIM_DBCLOSE(_MULTI)?/) { ; next; } + next if /retaining retry hintsdb handle$/; + next if /using cached retry hintsdb (?:handle|nonpresence)$/; + if (/final close of cached retry db$/) { ; ; next; } + next if /dbfn_transaction_(?:start|commit)$/; + + # Various hintsdb backends + s/(?:bdb|tdb|gdbm|ndbm|sqlite) + _open\(flags\ 0x(\d) + \ mode\ 0640\) + \ (?:No\ such\ file\ or\ directory|unable\ to\ open\ database\ file)$ + /hintsdb_open(flags 0x$1 mode 0640) No such file or directory/x; - s/(?<=^>>>>>>>>>>>>>>>> Exim pid=)\d+(?= terminating)/pppp/; - s/^(proxy-proc \w{5}-pid) \d+$/$1 pppp/; + # Lines with a leading pid. Only handle >= 4-digit PIDs to avoid converting SMTP respose codes + s/^\s*(\d{4,})\s(?!(?:previous message|in\s|bytes remain in|SMTP accept process running))/new_value($1, "p%s", \$next_pid) . ' '/e; + + # Connection IDs + s/connection_id: \K(\d+)$/new_value($1, "conn%s", \$next_conn)/e; + + # Debugging lines for Exim terminations and process-generation + next if /(?:postfork: | fork(?:ing|ed) for )/; # IP address lookups use gethostbyname() when IPv6 is not supported, # and gethostbyname2() or getipnodebyname() when it is. s/\b(gethostbyname2?|\bgetipnodebyname)(\(af=inet\))?/get[host|ipnode]byname[2]/; + # Extra lookups done when ipv6 is supported + next if /^host_fake_gethostbyname\(af=inet6\) returned 1 \(HOST_NOT_FOUND\)$/; + # we don't care what TZ enviroment the testhost was running next if /^Reset TZ to/; + # port numbers + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_d/PORT_D/; + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_d2/PORT_D2/; + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_d3/PORT_D3/; + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_d4/PORT_D4/; + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_s/PORT_S/; + s/(?:\[[^\]]*\]:|V4NET\.0\.0\.0:|localhost::?|127\.0\.0\.1[.:]:?|port[= ])\K$parm_port_n/PORT_N/; + + # ========= Exim lookups ================== + # Lookups have a char which depends on the number of lookup types compiled in, + # in stderr output. Replace with a "0". Recognising this while avoiding + # other output is fragile; perhaps the debug output should be revised instead. + s%^\s+(:?closing )?\K[0-?]TESTSUITE/aux-fixed/%0TESTSUITE/aux-fixed/%g; + # drop gnutls version strings next if /GnuTLS compile-time version: \d+[\.\d]+$/; next if /GnuTLS runtime version: \d+[\.\d]+$/; + # and unwanted debug + next if /^GnuTLS<2>: FIPS140-2 (context is not set|operation mode switched from initial to not-approved)$/; + next if /^GnuTLS<3>: ASSERT: sign.c\[_gnutls_sign_is_secure2\]:\d+$/; + next if /^GnuTLS<3>: ASSERT: \.\.\/\.\.\/lib\/pkcs11.c\[find_multi_objs_cb\]:/; + next if /^GnuTLS<3>: ASSERT: \.\.\/\.\.\/lib\/pkcs11.c\[gnutls_pkcs11_obj_list_import_url3\]:/; # drop openssl version strings next if /OpenSSL compile-time version: OpenSSL \d+[\.\da-z]+/; next if /OpenSSL runtime version: OpenSSL \d+[\.\da-z]+/; + # this is timing-dependent + next if /^OpenSSL: creating STEK$/; + next if /^selfsign cert rotate$/; + + # TLS preload + # only OpenSSL speaks of these + next if /^TLS: (preloading (DH params \S+|ECDH curve \S+|CA bundle) for server|generating selfsigned server cert)/; + next if /^ Diffie-Hellman initialized from default/; + next if /^ ECDH OpenSSL (< )?[\d.+]+: temp key parameter settings:/; + next if /^ ECDH: .*'prime256v1'/; + next if /^tls_verify_certificates: system$/; + next if /^tls_set_watch: .*\/cert.pem/; + next if /^Generating 2048 bit RSA key/; + + # TLS preload + # only GnuTLS speaks of these + next if /^GnuTLS global init required$/; + next if /^TLS: basic cred init, server/; + next if /^TLS: preloading cipher list for server: NULL$/; + s/^GnuTLS using default session cipher\/priority "NORMAL"$/TLS: not preloading cipher list for server/; + next if /^GnuTLS<2>: added \d+ protocols, \d+ ciphersuites, \d+ sig algos and \d+ groups into priority list$/; + next if /^GnuTLS<2>: (Disabling X.509 extensions|signing structure using RSA-SHA256)/; + next if /^GnuTLS.*(wrap_nettle_mpi_print|gnutls_subject_alt_names_get|get_alt_name)/; + next if /^GnuTLS<[23]>: (p11|ASSERT: pkcs11.c|Initializing needed PKCS #11 modules)/; + next if /^GnuTLS<2>: Intel (AES|GCM) accelerator was detected/; + next if /^Added \d{3} certificate authorities/; + next if /^TLS: not preloading CRL for server/; + next if /^GnuTLS<3>: ASSERT: extensions.c\[_gnutls_get_extension/; + next if /^GnuTLS<3>: ASSERT: \.\.\/\.\.\/\.\.\/lib\/x509\//; + next if /^GnuTLS<2>: Initializing PKCS #11 modules/; + + + # only kevent platforms (FreeBSD, OpenBSD) say this + next if /^watch dir/; + next if /^watch file .*\/usr\/local/; + next if /^watch file .*\/etc\/ssl/; + next if /^closing watch fd:/; + + # TLS preload + # there happen in different orders for OpenSSL/GnuTLS/noTLS + next if /^TLS: generating selfsigned server cert/; + next if /^TLS: not preloading (CA bundle|cipher list) for server$/; + next if /^TLS: not preloading server certs$/; + + # some platforms are missing the standard CA bundle file + next if /^tls_set_watch\(\) fail on '\/usr\/(?:lib\/ssl|local\/openssl3\/etc\/pki\/tls)\/cert.pem': No such file or directory$/; + # drop lookups - next if /^Lookups \(built-in\):/; - next if /^Loading lookup modules from/; - next if /^Loaded \d+ lookup modules/; - next if /^Total \d+ lookups/; + next if /^$time_pid?(?: Lookups\ \((?:built-in|dynamic)\): + |Loaded\ "[^.]+\.so"\ \(\d+\ lookup\ types\) + | Loading\ lookup\ modules\ from + | Loaded\ \d+\ lookup\ modules + | Total\ \d+\ lookups)/x; # drop compiler information - next if /^Compiler:/; + next if /^$time_pid?Compiler:/; # and the ugly bit # different libraries will have different numbers (possibly 0) of follow-up # lines, indenting with more data - if (/^Library version:/) { + if (/^$time_pid?Library version:/) { while (1) { $_ = ; - next if /^\s/; + next if /^$time_pid?\s/; goto RESET_AFTER_EXTRA_LINE_READ; } } # drop other build-time controls emitted for debugging - next if /^WHITELIST_D_MACROS:/; - next if /^TRUSTED_CONFIG_LIST:/; + next if /^$time_pid?WHITELIST_D_MACROS:/; + next if /^$time_pid?TRUSTED_CONFIG_LIST:/; # As of Exim 4.74, we log when a setgid fails; because we invoke Exim # with -be, privileges will have been dropped, so this will always @@ -994,28 +1345,60 @@ RESET_AFTER_EXTRA_LINE_READ: if (/looked up these IP addresses/); next if /name=localhost address=::1/; - # drop pdkim debugging header - next if /^PDKIM <<<<<<<<<<<<<<<<<<<<<<<<<<<<<+$/; + # DKIM: Not all builds include + next if /^DKIM( <<<<<<<<<<<<<<<<<<<<<<<<<<<<<+|: no signatures)$/; + next if /try option acl_smtp_dkim$/; + # Some platforms have TIOCOUT, some do not + next if /\d+ bytes remain in socket output buffer$/; # Various other IPv6 lines must be omitted too next if /using host_fake_gethostbyname for \S+ \(IPv6\)/; next if /get\[host\|ipnode\]byname\[2\]\(af=inet6\)/; next if /DNS lookup of \S+ \(AAAA\) using fakens/; - next if / in dns_ipv4_lookup?/; + next if / writing neg-cache entry for .*AAAA/; + next if /^ *faking res_search\(AAAA\) response length as 65535/; + if (/ in dns_ipv4_lookup\?$/) + { + $_= ; + if (/ list element: \*$/) + { + $_= ; + next if / in dns_ipv4_lookup\? yes \(matched "\*"\)/; + } + goto RESET_AFTER_EXTRA_LINE_READ; + } if (/DNS lookup of \S+ \(AAAA\) gave NO_DATA/) { $_= ; # Gets "returning DNS_NODATA" next; } + # Non-TLS builds have a different default Recieved: header expansion + s/^((.*)\t}}}}by \$primary_hostname \$\{if def:received_protocol \{with \$received_protocol }})\(Exim \$version_number\)$/$1\${if def:tls_in_ver { (\$tls_in_ver)}}\${if def:tls_in_cipher_std { tls \$tls_in_cipher_std\n$2\t}}(Exim \$version_number)/; + s/^((\s*).*considering: with \$received_protocol }})\(Exim \$version_number\)$/$1\${if def:tls_in_ver { (\$tls_in_ver)}}\${if def:tls_in_cipher_std { tls \$tls_in_cipher_std\n$2\t}}(Exim \$version_number)/; + if (/condition: def:tls_in_ver$/) + { + $_= ; $_= ; $_= ; $_= ; + $_= ; $_= ; $_= ; $_= ; + $_= ; $_= ; $_= ; $_= ; + $_= ; $_= ; $_= ; $_= ; + $_= ; $_= ; $_= ; $_= ; $_= ; next; + } + + # Skip tls_advertise_hosts and hosts_require_tls checks when the options # are unset, because tls ain't always there. + next if /^((>>>)?\s*host)? in tls_advertise_hosts\?$/; next if /in\s(?:tls_advertise_hosts\?|hosts_require_tls\?) \sno\s\((option\sunset|end\sof\slist)\)/x; + # non-TLS builds cannot have DANE + + next if /lack of DNSSEC traceability precludes DANE$/; + # Skip auxiliary group lists because they will vary. next if /auxiliary group list:/; @@ -1035,17 +1418,6 @@ RESET_AFTER_EXTRA_LINE_READ: next if /failed to load readline:/; - # Some DBM libraries seem to make DBM files on opening with O_RDWR without - # O_CREAT; other's don't. In the latter case there is some debugging output - # which is not present in the former. Skip the relevant lines (there are - # two of them). - - if (/TESTSUITE\/spool\/db\/\S+ appears not to exist: trying to create/) - { - $_ = ; - next; - } - # Some tests turn on +expand debugging to check on expansions. # Unfortunately, the Received: expansion varies, depending on whether TLS # is compiled or not. So we must remove the relevant debugging if it is. @@ -1062,25 +1434,106 @@ RESET_AFTER_EXTRA_LINE_READ: # remote port numbers vary s/(Connection request from 127.0.0.1 port) \d{1,5}/$1 sssss/; + # Platform-dependent error strings + s/Operation timed out/Connection timed out/; + + # Platform differences on disconnect + s/unexpected disconnection while reading SMTP command from \[127.0.0.1\] \K\(error: Connection reset by peer\) //; + + # Platform-dependent resolver option bits + s/(?:writing|update) neg-cache entry for [^,]+-\K[0-9a-f]+, ttl/xxxx, ttl/; + + # timing variance, run-to-run + s/^time on queue = \K1s/0s/; + + # content-scan: file order can vary in directory + s%unspool_mbox\(\): unlinking 'TESTSUITE/spool/scan/[^/]*/\K[^\']*%FFFFFFFFF%; + # Skip hosts_require_dane checks when the options # are unset, because dane ain't always there. - next if /in\shosts_require_dane\?\sno\s\(option\sunset\)/x; - # SUPPORT_PROXY - next if /host in hosts_proxy\?/; + # daemon notifier socket + s% \@(?=[^ @]+/spool/exim_daemon_notify$)% %; + next if /unlinking notifier socket/; - # Experimental_International - next if / in smtputf8_advertise_hosts\? no \(option unset\)/; + # daemon notifier socket + # Timing variance over runs. Collapse repeated memssages. + if (/notify triggered queue run/) + { + my $line = $_; + while (/notify triggered queue run/) { $_ = ; } + $_ = $line . $_; + } + + # Different builds will have different lookup types included + s/search_type \K\d+ \((\w+)\) quoting -1 \(none\)$/NN ($1) quoting -1 (none)/; + # and different numbers of lookup types result in different type-code letters, + # so convert them all to "0" + s%(?>>)?\s*host in pipelining_connect_advertise_hosts\?$/ ) + { + $_ = ; + while ( /^(>>>)?\s*list element:/ ) { $_ = ; } + goto RESET_AFTER_EXTRA_LINE_READ; + } + next if / in (?:pipelining_connect_advertise_hosts|hosts_pipe_connect)?\? no /; + + # Experimental_International + next if / in smtputf8_advertise_hosts\? no \(option unset\)/; + + # Experimental_REQUIRETLS + next if / in tls_advertise_requiretls?\? no \(end of list\)/; + + # Experimental_LIMITS + if ( /^((>>>)?\s*host)? in limits_advertise_hosts\?$/ ) + { + $_ = ; + while ( /^(>>>)?\s*list element: !\*$/ ) { $_ = ; } + goto RESET_AFTER_EXTRA_LINE_READ; + } + next if / in limits_advertise_hosts?\? no \(matched "!\*"\)/; + + # Experimental_XCLIENT + next if / in hosts_xclient\? no \(option unset\)/; + + # Experimental_WELLKNOWN + next if / in hosts_wellknown\? no \(option unset\)/; + + # TCP Fast Open + next if /^(ppppp )?setsockopt FASTOPEN: Network Error/; + + # DISABLE_TLS_RESUME + # TLS resumption is not always supported by the build + next if /in tls_resumption_hosts\?/; + next if /RE '.outlook.com/; # Non-TLS builds have different expansions for received_header_text if (s/(with \$received_protocol)\}\} \$\{if def:tls_cipher \{\(\$tls_cipher\)\n$/$1/) @@ -1095,29 +1548,92 @@ RESET_AFTER_EXTRA_LINE_READ: } # Not all platforms build with DKIM enabled - next if /^PDKIM >> Body data for hash, canonicalized/; + next if /^DKIM >> Body data for hash, canonicalized/; + + # Not all platforms build with SPF enabled + next if /(^spf_conn_init|^SPF_dns_exim_new|spf_compile\.c)/; + next if /try option spf_smtp_comment_template$/; # Not all platforms have sendfile support next if /^cannot use sendfile for body: no support$/; # Parts of DKIM-specific debug output depend on the time/date next if /^date:\w+,\{SP\}/; - next if /^PDKIM \[[^[]+\] (Header hash|b) computed:/; + next if /^DKIM \[[^[]+\] (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$//) - { - $_ .= ; - s/ \.\.\. >>> / ... /; + next if /\S+ in hosts_try_fastopen\? (no \(option unset\)|no \(end of list\)|yes \(matched "\*"\))\n$/ ; + +# if (s/\S+ in hosts_try_fastopen\? (no \(option unset\)|no \(end of list\)|yes \(matched "\*"\))\n$//) +# { +# chomp; +# $_ .= ; +# s/ \.\.\. >>> / ... /; + if (s/ non-TFO mode connection attempt to 224.0.0.0, 0 data\b$//) { chomp; $_ .= ; } s/Address family not supported by protocol family/Network Error/; - s/Network is unreachable/Network Error/; - } + s/Network(?: is)? unreachable/Network Error/; +# } + next if /^(ppppp |\d+ )?setsockopt FASTOPEN: Protocol not available$/; + s/^(sending) \d+ (nonTFO early-data)$/$1 dd $2/; + + if (/^[0-9: ]* # possible timestamp + \ .*TFO\ mode\x20 + (sendto,\ no\ data:\ EINPROGRESS # Linux + |connection\ attempt\ to\ [^,]+,\ 0\ data) # MacOS & no-support + $/x) + { + $_ = ; + if (/^connected$/) + { + $_ .= ; + if (/^connected\n\s+SMTP(\(close\)>>|\(Connection refused\)<<)$/) + { + $_ = "failed: Connection refused\n" . ; + s/^\n\s+SMTP\(close\)>>$/$1/; + } + elsif (/^(connected\n)read response data: size=/) + { $_ = $1; } - next if /^(ppppp )?setsockopt FASTOPEN: Protocol not available$/; + # Date/time in SMTP banner + s/[A-Z][a-z]{2},\s\d\d?\s[A-Z][a-z]{2}\s\d{4}\s\d\d\:\d\d:\d\d\s[-+]\d{4} + /Tue, 2 Mar 1999 09:44:33 +0000/gx; + } + } # Specific pointer values reported for DB operations change from run to run - s/^(returned from EXIM_DBOPEN: )(0x)?[0-9a-f]+/${1}0xAAAAAAAA/; - s/^(EXIM_DBCLOSE.)(0x)?[0-9a-f]+/${1}0xAAAAAAAA/; + s/(returned from EXIM_DBOPEN: )(0x)?[0-9a-f]+/${1}0xAAAAAAAA/; + s/(EXIM_DBCLOSE.)(0x)?[0-9a-f]+/${1}0xAAAAAAAA/; + + # Platform-dependent output during MySQL startup + next if /PerconaFT file system space/; + next if /^Waiting for MySQL server to answer/; + next if /mysqladmin: CREATE DATABASE failed; .* database exists/; + + # Postgres version-dependent differences + s/^initdb: warning: (enabling "trust" authentication for local connections)$/\nWARNING: $1/; + # Postgre DB server PID + s/ \[\d+\] (?=(LOG: redirecting log|HINT: Future log output))/ [pppp] /; + + # Not all builds include DMARC + next if /^DMARC: no (dmarc_tld_file|sender_host_address)$/ ; + + # Platform differences in errno strings + s/ SMTP\(Operation timed out\)</; # When Exim is checking the size of directories for maildir, it uses # the check_dir_size() function to scan directories. Of course, the order @@ -1140,25 +1656,7 @@ RESET_AFTER_EXTRA_LINE_READ: @saved = (); } - # Skip some lines that Exim puts out at the start of debugging output - # because they will be different in different binaries. - - print MUNGED - unless (/^Berkeley DB: / || - /^Probably (?:Berkeley DB|ndbm|GDBM)/ || - /^Authenticators:/ || - /^Lookups:/ || - /^Support for:/ || - /^Routers:/ || - /^Transports:/ || - /^log selectors =/ || - /^cwd=/ || - /^Fixed never_users:/ || - /^Configure owner:/ || - /^Size of off_t:/ - ); - - + print MUNGED; } next; @@ -1172,10 +1670,103 @@ RESET_AFTER_EXTRA_LINE_READ: next if / Berkeley DB error: /; # CHUNKING: exact sizes depend on hostnames in headers - s/(=>.* K C="250- \d)\d+ (byte chunk, total \d)\d+/$1nn $2nn/; + s/(=>.* K (?:DKIM=\S+ )?C="250- \d)\d+ (byte chunk, total \d)\d+/$1nn $2nn/; + + # OpenSSL version variances + s/(TLS error on connection [^:]*: error:)[0-9A-F]{8}(:system library):(?:fopen|func\(4095\)|):(No such file or directory)$/$1xxxxxxxx$2:fopen:$3/; + next if /TLS error \(SSL_read\): .*error:0A000126:SSL routines::unexpected eof while reading$/ ; + s/EVDATA: \K\(SSL_accept\): error:0A000126:SSL routines::unexpected eof while reading/SSL_accept: TCP connection closed by peer/; + s/(DANE attempt failed.*error:)[0-9A-F]{8}(:SSL routines:)(?:(?i)ssl3_get_server_certificate|tls_process_server_certificate|CONNECT_CR_CERT|)(?=:certificate verify failed$)/$1xxxxxxxx$2ssl3_get_server_certificate/; + s/(DKIM: validation error: )error:[0-9A-F]{8}:rsa routines:(?:(?i)int_rsa_verify|CRYPTO_internal):(?:bad signature|algorithm mismatch)$/$1Public key signature verification has failed./; + s/ARC: AMS signing: privkey PEM-block import: error:\K[0-9A-F]{8}:(PEM routines):get_name:(no start line)/0906D06C:$1:PEM_read_bio:$2/; + + # GnuTLS version variances + if (/TLS error on connection \(recv\): .* (Decode error|peer did not send any certificate)/) + { + my $prev = $_; + $_ = ; + if (/error on first read/) + { + s/TLS session: \Kerror on first read:/(gnutls_handshake): A TLS fatal alert has been received.:/; + goto RESET_AFTER_EXTRA_LINE_READ; + } + else + { $_ = $prev; } + } + # translate GnuTLS error into the OpenSSL one + s/ARC: AMS signing: privkey PEM-block import: \KThe requested data were not available.$/error:0906D06C:PEM routines:PEM_read_bio:no start line/; + # and then both into the OpenSSL 3.x one + s/ARC: AMS signing: privkey PEM-block import: error:\K[0-9A-F]{8}:PEM routines:PEM_read_bio:no start line$/1E08010C:DECODER routines::unsupported/; - # openssl version variances - s/(TLS error on connection [^:]*: error:)[0-9A-F]{8}(:system library):(?:fopen|func\(4095\)):(No such file or directory)$/$1xxxxxxxx$2:fopen:$3/; + # DKIM timestamps + if ( /(DKIM: d=.*) t=([0-9]*) x=([0-9]*) \[/ ) + { + my ($prefix, $t_diff) = ($1, $3 - $2); + s/DKIM: d=.* t=[0-9]* x=[0-9]* /${prefix} t=T x=T+${t_diff} /; + } + else + { s/DKIM: d=.* \Kt=[0-9]* \[/t=T [/; } + # GnuTLS reports a different keysize vs. OpenSSL, for ed25519 keys + s/signer: [^ ]* bits:\K 256/ 253/; + s/public key too short:\K 256 bits/ 253 bits/; + + # with GnuTLS we cannot log single bad ALPN. So ignore the with-OpenSSL log line. + # next if /TLS ALPN (http) rejected$/; + + # port numbers + s/(?:\[[^\]]*\]:|port )\K$parm_port_d/PORT_D/; + s/(?:\[[^\]]*\]:|port )\K$parm_port_d2/PORT_D2/; + s/(?:\[[^\]]*\]:|port )\K$parm_port_d3/PORT_D3/; + s/(?:\[[^\]]*\]:|port )\K$parm_port_d4/PORT_D4/; + s/(?:\[[^\]]*\]:|port )\K$parm_port_s/PORT_S/; + s/(?:\[[^\]]*\]:|port )\K$parm_port_n/PORT_N/; + s/I=\[[^\]]*\]:\K\d+/ppppp/; + + # Platform differences for errno values (eg. Hurd). Leave 0 and negative numbers alone. + s/R=\w+ T=\w+ defer\K \([1-9]\d*\): / (EEE): /; + + # Platform differences in errno strings + s/Arg list too long/Argument list too long/; + + # OpenSSL vs. GnuTLS + s/session: \K\((SSL_connect|gnutls_handshake)\): timed out/(tls lib connect fn): timed out/; + s/TLS error on connection from .*\K\((SSL_accept|gnutls_handshake)\): timed out/(tls lib accept fn): timed out/; + s/TLS error on connection from .*\K(SSL_accept: TCP connection closed by peer|\(gnutls_handshake\): The TLS connection was non-properly terminated.)/(tls lib accept fn): TCP connection closed by peer/; + s/TLS session: \K\(gnutls_handshake\): rxd alert: No supported application protocol could be negotiated/(SSL_connect): error: <>/; + s/\(gnutls_handshake\): No common application protocol could be negotiated./(SSL_accept): error: <>/; + + # Not all buildfarm animals have ipv6 + next if / $/ ; + } + + # ======== mail ======== + + elsif ($is_mail) + { + # DKIM timestamps, and signatures depending thereon + if ( /^(\s+)t=([0-9]*); x=([0-9]*); b=[A-Za-z0-9+\/]+$/ ) + { + my ($indent, $t_diff) = ($1, $3 - $2); + s/.*/${indent}t=T; x=T+${t_diff}; b=bbbb;/; + ; + ; + } + elsif ( /^(\s+)t=([0-9]*); b=[A-Za-z0-9+\/]+$/ ) + { + my $indent = $1; + s/.*/${indent}t=T; b=bbbb;/; + ; + ; + } + + # Not all builds include EXPERIMENTAL_DSN_INFO (2 of 2) + if (/^X-Exim-Diagnostic:/) + { + while () { + last if (/^$/ || !/^\s/); + } + goto RESET_AFTER_EXTRA_LINE_READ; + } } # ======== All files other than stderr ======== @@ -1303,7 +1894,7 @@ 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 && $rf !~ /paniclog/ && $rsf !~ /paniclog/; + return 1 if /^c$/i && $rf !~ /paniclog/ && (!defined $rsf || $rsf !~ /paniclog/); last if (/^[sc]$/); } @@ -1314,7 +1905,7 @@ if (! -e $sf_current) print "\n"; print "------------ $f -----------\n" if (defined $rf && -s $rf && defined $rsf && -s $rsf); - system("$more '$f'"); + system @more => $f; } } @@ -1396,30 +1987,29 @@ if (-e $sf_current) } } - open(MUNGED, '>', $mf) || tests_exit(-1, "Failed to open $mf: $!"); - for ($i = 0; $i < @munged; $i++) - { print MUNGED $munged[$i]; } - close(MUNGED); + open(my $fh, '>', $mf) or tests_exit(-1, "Failed to open $mf: $!"); + print $fh @munged; } # Deal with log sorting if ($sortfile) { - my(@munged, $i, $j); - open(MUNGED, $mf) || tests_exit(-1, "Failed to open $mf: $!"); - @munged = ; - close(MUNGED); + my @munged = do { + open(my $fh, '<', $mf) or tests_exit(-1, "Failed to open $mf: $!"); + <$fh>; + }; - for ($i = 0; $i < @munged; $i++) + for (my $i = 0; $i < @munged; $i++) { - if ($munged[$i] =~ /^[-\d]{10}\s[:\d]{8}\s[-A-Za-z\d]{16}\s[-=*]>/) + if ($munged[$i] =~ /^[-\d]{10}\s[:\d]{8}(\.\d{3})?\s[-A-Za-z\d]{23}\s[-=*]>/) { + my $j; for ($j = $i + 1; $j < @munged; $j++) { last if $munged[$j] !~ - /^[-\d]{10}\s[:\d]{8}\s[-A-Za-z\d]{16}\s[-=*]>/; + /^[-\d]{10}\s[:\d]{8}(\.\d{3})?\s[-A-Za-z\d]{23}\s[-=*]>/; } @temp = splice(@munged, $i, $j - $i); @temp = sort(@temp); @@ -1427,11 +2017,9 @@ if (-e $sf_current) } } - open(MUNGED, ">$mf") || tests_exit(-1, "Failed to open $mf: $!"); - print MUNGED "**NOTE: The delivery lines in this file have been sorted.\n"; - for ($i = 0; $i < @munged; $i++) - { print MUNGED $munged[$i]; } - close(MUNGED); + open(my $fh, '>', $mf) or tests_exit(-1, "Failed to open $mf: $!"); + print $fh "**NOTE: The delivery lines in this file have been sorted.\n"; + print $fh @munged; } # Do the comparison @@ -1441,7 +2029,7 @@ if (-e $sf_current) # Handle comparison failure print "** Comparison of $mf with $sf_current failed"; - system("$more test-cf"); + system @more => 'test-cf'; print "\n"; for (;;) @@ -1465,15 +2053,14 @@ if (-e $sf_current) if (-s $mf) { my $sf = /^u/i ? $sf_current : $sf_flavour; - tests_exit(-1, "Failed to cp $mf $sf") if system("cp '$mf' '$sf'") != 0; + copy($mf, $sf) or tests_exit(-1, "Failed to copy $mf $sf"); } else { # if we deal with a flavour file, we can't delete it, because next time the generic # file would be used again if ($sf_current eq $sf_flavour) { - open(FOO, ">$sf_current"); - close(FOO); + open(my $fh, '>', $sf_current); } else { tests_exit(-1, "Failed to unlink $sf_current") if !unlink($sf_current); @@ -1492,7 +2079,8 @@ return 2; # Usable files are: # paniclog, rejectlog, mainlog, stdout, stderr, msglog, mail # Search strings starting with 's' do substitutions; -# with '/' do line-skips. +# with '/' do line-skips, +# with 'R' run given code. # Triggered by a scriptfile line "munge " ################################################## $munges = @@ -1505,6 +2093,11 @@ $munges = 'gnutls_handshake' => { 'mainlog' => 's/\(gnutls_handshake\): Error in the push function/\(gnutls_handshake\): A TLS packet with unexpected length was received/' }, + 'gnutls_bad_clientcert' => + { 'mainlog' => 's/\(certificate verification failed\): certificate invalid/\(gnutls_handshake\): The peer did not send any certificate./', + 'stdout' => 's/Succeeded in starting TLS/A TLS fatal alert has been received.\nFailed to start TLS' + }, + 'optional_events' => { 'stdout' => '/event_action =/' }, @@ -1524,23 +2117,37 @@ $munges = { 'stderr' => 's/(1[5-9]|23\d)\d\d msec/ssss msec/' }, 'tls_anycipher' => - { 'mainlog' => 's/ X=TLS\S+ / X=TLS_proto_and_cipher /' }, - - 'debug_pid' => - { 'stderr' => 's/(^\s{0,4}|(?<=Process )|(?<=child ))\d{1,5}/ppppp/g' }, + { 'mainlog' => 's! X=TLS\S+ ! X=TLS_proto_and_cipher !; + s! DN="C=! DN="/C=!; + s! DN="[^,"]*\K,!/!; + s! DN="[^,"]*\K,!/!; + s! DN="[^,"]*\K,!/!; + ', + 'rejectlog' => 's/ X=TLS\S+ / X=TLS_proto_and_cipher /', + }, 'optional_dsn_info' => - { 'mail' => '/^(X-(Remote-MTA-(smtp-greeting|helo-response)|Exim-Diagnostic|(body|message)-linecount):|Remote-MTA: X-ip;)/' + { 'mail' => 'Rif (/^(X-(Remote-MTA-(smtp-greeting|helo-response)|Exim-Diagnostic|(body|message)-linecount):|Remote-MTA: X-ip;)/) { + while (1) { + $_ = ; + next if /^ /; + goto RESET_AFTER_EXTRA_LINE_READ; + } + }' }, 'optional_config' => { 'stdout' => '/^( - dkim_(canon|domain|private_key|selector|sign_headers|strict|hash|identity) + dkim_(canon|domain|private_key|selector|sign_headers|strict|hash|identity|timestamps) |gnutls_require_(kx|mac|protocols) + |hosts_pipe_connect |hosts_(requ(est|ire)|try)_(dane|ocsp) + |dane_require_tls_ciphers |hosts_(avoid|nopass|noproxy|require|verify_avoid)_tls + |pipelining_connect_advertise_hosts |socks_proxy |tls_[^ ]* + |utf8_downconvert )($|[ ]=)/x' }, @@ -1551,15 +2158,10 @@ $munges = { 'mainlog' => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1/', 'rejectlog' => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1/'}, - 'debuglog_stdout' => - { 'stdout' => 's/^\d\d:\d\d:\d\d\s+\d+ //; - s/Process \d+ is ready for new message/Process pppp is ready for new message/' - }, - 'timeout_errno' => # actual errno differs Solaris vs. Linux - { 'mainlog' => 's/(host deferral .* errno) <\d+> /$1 /' }, + { 'mainlog' => 's/((?:host|message) deferral .* errno) <\d+> /$1 /' }, - 'peer_terminated_conn' => # actual error differs FreedBSD vs. Linux + 'peer_terminated_conn' => # actual error differs FreedBS/Solaris vs. Linux { 'stderr' => 's/^( SMTP\()Connection reset by peer(\)<<)$/$1closed$2/' }, 'perl_variants' => # result of hash-in-scalar-context changed from bucket-fill to keycount @@ -1656,7 +2258,7 @@ if (! $message_skip) foreach $mail (@mails) { - next if $mail eq "test-mail/oncelog"; + next if $mail =~ /^test-mail\/oncelog(.(dir|pag|db))?$/; $saved_mail = substr($mail, 10); # Remove "test-mail/" $saved_mail =~ s/^$parm_caller(\/|$)/CALLER/; # Convert caller name @@ -1740,9 +2342,15 @@ if (! $msglog_skip) foreach $msglog (@msglogs) { next if ($msglog eq "." || $msglog eq ".." || $msglog eq "CVS"); + ($munged_msglog = $msglog) =~ s/((?:[^\W_]{6}-){2}[^\W_]{2}) - /new_value($1, "10Hm%s-0005vi-00", \$next_msgid)/egx; + /new_value($1, "10Hm%s-0005vi-00", \$next_msgid_old)/egx; + + $munged_msglog =~ + s/([^\W_]{6}-[^\W_]{11}-[^\W_]{4}) + /new_value($1, "10Hm%s-000000005vi-0000", \$next_msgid)/egx; + $yield = max($yield, check_file("spool/msglog/$msglog", undef, "test-msglog-munged", "msglog/$testno.$munged_msglog", 0, $munge->{msglog})); @@ -1813,7 +2421,7 @@ if ($debug) $prcmd =~ s/; /;\n>> /; print ">> $prcmd\n"; } -system("$cmd"); +system($cmd); } @@ -1833,6 +2441,7 @@ system("$cmd"); # Arguments: the current test number # reference to the subtest number, holding previous value # reference to the expected return code value +# reference to flag for not-expected return value # reference to where to put the command name (for messages) # auxiliary information returned from a previous run # @@ -1848,16 +2457,18 @@ system("$cmd"); sub run_command{ my($testno) = $_[0]; my($subtestref) = $_[1]; -my($commandnameref) = $_[3]; -my($aux_info) = $_[4]; +my($commandnameref) = $_[4]; +my($aux_info) = $_[5]; my($yield) = 1; our %ENV = map { $_ => $ENV{$_} } grep { /^(?:USER|SHELL|PATH|TERM|EXIM_TEST_.*)$/ } keys %ENV; -if (/^(\d+)\s*$/) # Handle unusual return code +if (/^(~)?(\d+)\s*(?:([A-Z]+)=(\S+))?$/) # Handle unusual return code { - my($r) = $_[2]; - $$r = $1 << 8; + my($r, $rn) = ($_[2], $_[3]); + $$r = $2 << 8; + $$rn = 1 if (defined $1); + $ENV{$3} = $4 if (defined $3); $_ =