X-Git-Url: https://git.exim.org/users/heiko/exim.git/blobdiff_plain/02721dcdf5dfcf96f62f6c657c9989b9ef991fa7..2f06ffd252140e2cb71050aa8a9d45a75bc3437b:/test/runtest diff --git a/test/runtest b/test/runtest index 57e2d8a10..45ee6e208 100755 --- a/test/runtest +++ b/test/runtest @@ -460,7 +460,9 @@ 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); + + # Round the time-difference up to nearest even value + my($increment) = ((date_seconds($date3) - date_seconds($date2) + 1) >> 1) << 1; # We used to use globally unique replacement values, but timing # differences make this impossible. Just show the increment on the @@ -474,6 +476,13 @@ 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-z.]+(:[0-9.]+)?):$parm_port_n /T:$1:PORT_N /; + + # 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,16 +492,24 @@ 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} + 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; + # 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/^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 @@ -510,7 +527,7 @@ RESET_AFTER_EXTRA_LINE_READ: my($next) = $3 - $2; $_ = " first failed=dddd last try=dddd next try=+$next $4\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*)now=\d+ first_failed=\d+ next_try=\d+ expired=(\w)/$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/; # Time to retry may vary @@ -530,55 +547,112 @@ 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". + + s/^\s+by .+ with .+ \K tls TLS_.*?([^_]+)_WITH.+$/(TLS1.x:ke-$1-AES256-SHAnnn:xxx)/; + s/^\s+by .+ with .+ \K tls TLS_.+$/(TLS1.x:ke-RSA-AES256-SHAnnn:xxx)/; + # 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 : ??? + # # 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 )TLSv1(\.[123])?:/$1TLS1.x:/xg; + s/(?PSK)_)?((?RSA|ECDSA)_)? + (SECP(256|521)R1|X25519))?__?)? # key-exchange + ((?RSA|ECDSA)((_PSS_RSAE)?_SHA(512|256))?__?)? # authentication + 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} : "") + . "-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; # 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) @@ -654,7 +728,7 @@ RESET_AFTER_EXTRA_LINE_READ: s/\bgid=\d+/gid=gggg/; s/\begid=\d+/egid=gggg/; - s/\bpid=\d+/pid=pppp/; + s/\b(pid=|PID: )\d+/$1pppp/; s/\buid=\d+/uid=uuuu/; s/\beuid=\d+/euid=uuuu/; s/set_process_info:\s+\d+/set_process_info: pppp/; @@ -668,8 +742,12 @@ RESET_AFTER_EXTRA_LINE_READ: s"test-mail/temp\.\d+\."test-mail/temp.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,9 +758,6 @@ 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%; - # ======== Port numbers ======== # Incoming port numbers may vary, but not in daemon startup line. @@ -697,7 +772,7 @@ RESET_AFTER_EXTRA_LINE_READ: } # 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//; @@ -905,6 +980,7 @@ RESET_AFTER_EXTRA_LINE_READ: s/SSL3_READ_BYTES/ssl3_read_bytes/i; s/CONNECT_CR_FINISHED/ssl3_read_bytes/i; s/^\d+:error:\d+(?:E\d+)?(:SSL routines:ssl3_read_bytes:[^:]+:).*(:SSL alert number \d\d)$/pppp:error:dddddddd$1\[...\]$2/; + s/^error:[^:]*:(SSL routines:ssl3_read_bytes:(tls|ssl)v\d+ alert)/error:dddddddd:$1/; # gnutls version variances next if /^Error in the pull function./; @@ -915,6 +991,20 @@ RESET_AFTER_EXTRA_LINE_READ: # subsecond timstamp info in reported header-files s/^(-received_time_usec \.)\d{6}$/$1uuuuuu/; + + # 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 =/; + + # ARC is not always supported by the build + next if /^arc_sign =/; + + # TLS resumption is not always supported by the build + next if /^tls_resumption_hosts =/; + next if /^-tls_resumption/; } # ======== stderr ======== @@ -995,7 +1085,7 @@ RESET_AFTER_EXTRA_LINE_READ: next if /name=localhost address=::1/; # drop pdkim debugging header - next if /^PDKIM <<<<<<<<<<<<<<<<<<<<<<<<<<<<<+$/; + next if /^DKIM( <<<<<<<<<<<<<<<<<<<<<<<<<<<<<+|: no signatures)$/; # Various other IPv6 lines must be omitted too @@ -1003,6 +1093,7 @@ RESET_AFTER_EXTRA_LINE_READ: 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/; if (/DNS lookup of \S+ \(AAAA\) gave NO_DATA/) { @@ -1038,12 +1129,14 @@ RESET_AFTER_EXTRA_LINE_READ: # 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). + # three of them). - if (/TESTSUITE\/spool\/db\/\S+ appears not to exist: trying to create/) + if (/returned from EXIM_DBOPEN: \(nil\)/) { - $_ = ; - next; + $_ .= ; + s?\Q$parm_cwd\E?TESTSUITE?g; + if (/TESTSUITE\/spool\/db\/\S+ appears not to exist: trying to create/) + { $_ = ; next; } } # Some tests turn on +expand debugging to check on expansions. @@ -1062,17 +1155,37 @@ 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-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/; + # 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; + # DISABLE_OCSP + next if /in hosts_requ(est|ire)_ocsp\? (no|yes)/; + # SUPPORT_PROXY next if /host in hosts_proxy\?/; + # PIPE_CONNECT + 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\)/; + + # TCP Fast Open + next if /^(ppppp )?setsockopt FASTOPEN: Network Error/; + # Environment cleaning next if /\w+ in keep_environment\? (yes|no)/; @@ -1095,29 +1208,74 @@ 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)/; # 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$//) + if (s/\S+ in hosts_try_fastopen\? (no \(option unset\)|yes \(matched "\*"\))\n$//) { $_ .= ; s/ \.\.\. >>> / ... /; + if (s/ non-TFO mode connection attempt to 224.0.0.0, 0 data\b$//) { $_ .= ; } s/Address family not supported by protocol family/Network Error/; s/Network is unreachable/Network Error/; } - next if /^(ppppp )?setsockopt FASTOPEN: Protocol not available$/; + s/^(Connecting to .* \.\.\. sending) \d+ (nonTFO early-data)$/$1 dd $2/; + + if (/^([0-9: ]* # possible timestamp + Connecting\ to\ [^ ]+\ [^ ]+(\ from\ [^ ]+)?)\ \.\.\. + \ .*TFO\ mode\x20 + (sendto,\ no\ data:\ EINPROGRESS # Linux + |connection\ attempt\ to\ [^,]+,\ 0\ data) # MacOS & no-support + $/x) + { + $_ = $1 . " ... " . ; + s/^(.* \.\.\.) [0-9: ]*connected$/$1 connected/; + + if (/^Connecting to .* \.\.\. connected$/) + { + $_ .= ; + if (/^(Connecting to .* \.\.\. )connected\n\s+SMTP(\(close\)>>|\(Connection refused\)<<)$/) + { + $_ = $1 . "failed: Connection refused\n" . ; + s/^(Connecting .*)\n\s+SMTP\(close\)>>$/$1/; + } + elsif (/^(Connecting to .* \.\.\. connected\n)read response data: size=/) + { $_ = $1; } + + # 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/^(\s*returned from EXIM_DBOPEN: )(0x)?[0-9a-f]+/${1}0xAAAAAAAA/; + s/^(\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/; + + # Not all builds include DMARC + next if /^DMARC: no (dmarc_tld_file|sender_host_address)$/ ; + + # TLS resumption is not always supported by the build + next if /in tls_resumption_hosts\?/; + + # Platform differences in errno strings + s/ SMTP\(Operation timed out\)<; + 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/; + + # 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} /; + } + + # 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/; + + } + + # ======== 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;/; + ; + ; + } } # ======== All files other than stderr ======== @@ -1505,6 +1714,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,7 +1738,17 @@ $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 /' }, + { '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 /', + 'mail' => 's/^\s+by .+ with .+ \K tls TLS_.+$/(TLS_proto_and_cipher)/; + s/ \(TLS[^)]*\)/ (TLS_proto_and_cipher)/; + ', + }, 'debug_pid' => { 'stderr' => 's/(^\s{0,4}|(?<=Process )|(?<=child ))\d{1,5}/ppppp/g' }, @@ -1535,12 +1759,16 @@ $munges = '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' }, @@ -2090,7 +2318,7 @@ elsif (/^millisleep\s+(.*)$/) # The "munge" command selects one of a hardwired set of test-result modifications -# to be made before result compares are run agains the golden set. This lets +# to be made before result compares are run against the golden set. This lets # us account for test-system dependent things which only affect a few, but known, # test-cases. # Currently only the last munge takes effect. @@ -2420,6 +2648,7 @@ elsif (/^background$/) $_ =