From: Jeremy Harris Date: Sat, 31 Dec 2022 18:32:37 +0000 (+0000) Subject: Testsuite: longer timing for OpenSSL resumption tests X-Git-Tag: exim-4.97-RC0~155 X-Git-Url: https://git.exim.org/exim.git/commitdiff_plain/313dcd5968cd8a02995322fa771f4d56b9f15e49 Testsuite: longer timing for OpenSSL resumption tests --- diff --git a/src/src/tls-openssl.c b/src/src/tls-openssl.c index 3b060cc9c..ae0986aac 100644 --- a/src/src/tls-openssl.c +++ b/src/src/tls-openssl.c @@ -155,6 +155,7 @@ change this guard and punt the issue for a while longer. */ # endif #endif +#define TESTSUITE_TICKET_LIFE 10 /* seconds */ /************************************************* * OpenSSL option parse * *************************************************/ @@ -2044,7 +2045,7 @@ if (exim_tk.name[0]) exim_tk_old = exim_tk; } -if (f.running_in_test_harness) ssl_session_timeout = 6; +if (f.running_in_test_harness) ssl_session_timeout = TESTSUITE_TICKET_LIFE; DEBUG(D_tls) debug_printf("OpenSSL: %s STEK\n", exim_tk.name[0] ? "rotating" : "creating"); if (RAND_bytes(exim_tk.aes_key, sizeof(exim_tk.aes_key)) <= 0) return; @@ -3908,16 +3909,17 @@ if (tlsp->host_resumable) #ifdef EXIM_HAVE_SESSION_TICKET SSL_SESSION_get_ticket_lifetime_hint(ss); #else /* Use, fairly arbitrilarily, what we as server would */ - f.running_in_test_harness ? 6 : ssl_session_timeout; + f.running_in_test_harness ? TESTSUITE_TICKET_LIFE : ssl_session_timeout; #endif - if (lifetime + dt->time_stamp < time(NULL)) + time_t now = time(NULL), expires = lifetime + dt->time_stamp; + if (expires < now) { - DEBUG(D_tls) debug_printf("session expired\n"); + DEBUG(D_tls) debug_printf("session expired (by " TIME_T_FMT "s from %lus)\n", now - expires, lifetime); dbfn_delete(dbm_file, tlsp->resume_index); } else if (SSL_set_session(ssl, ss)) { - DEBUG(D_tls) debug_printf("good session\n"); + DEBUG(D_tls) debug_printf("good session (" TIME_T_FMT "s left of %lus)\n", expires - now, lifetime); tlsp->resumption |= RESUME_CLIENT_SUGGESTED; tlsp->verify_override = dt->verify_override; tlsp->ocsp = dt->ocsp; diff --git a/test/confs/5892 b/test/confs/5892 index 0aec9bfaf..15b09fcff 100644 --- a/test/confs/5892 +++ b/test/confs/5892 @@ -30,6 +30,7 @@ tls_certificate = CDIR/server1.example.com/server1.example.com.chain.pem tls_privatekey = CDIR/server1.example.com/server1.example.com.unlocked.key tls_resumption_hosts = 127.0.0.1 +remote_max_parallel = 1 # ------ ACL ------ @@ -70,7 +71,7 @@ begin routers client: driver = accept condition = ${if eq {SERVER}{server}{no}{yes}} - transport = send_to_server${if eq{$local_part}{abcd}{2}{1}} + transport = send_to_server${if eq{$local_part}{hostnotresume}{2}{1}} server: driver = redirect diff --git a/test/log/5892 b/test/log/5892 index ce8b0ea7d..b128749ae 100644 --- a/test/log/5892 +++ b/test/log/5892 @@ -8,7 +8,7 @@ 1999-03-02 09:44:33 10HmaX-0005vi-00 bits 256 1999-03-02 09:44:33 10HmaX-0005vi-00 => getticket@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmaY-0005vi-00" 1999-03-02 09:44:33 10HmaX-0005vi-00 Completed -1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for resume@test.ex abcd@test.ex xyz@test.ex +1999-03-02 09:44:33 10HmaZ-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for resume@test.ex hostnotresume@test.ex xyz@test.ex 1999-03-02 09:44:33 10HmaZ-0005vi-00 tls_out_resumption session resumed 1999-03-02 09:44:33 10HmaZ-0005vi-00 our cert subject 1999-03-02 09:44:33 10HmaZ-0005vi-00 peer cert subject CN=server1.example.com @@ -16,6 +16,8 @@ 1999-03-02 09:44:33 10HmaZ-0005vi-00 peer dn /CN=server1.example.com 1999-03-02 09:44:33 10HmaZ-0005vi-00 cipher TLS1.x:ke-RSA-AES256-SHAnnn:xxx 1999-03-02 09:44:33 10HmaZ-0005vi-00 bits 256 +1999-03-02 09:44:33 10HmaZ-0005vi-00 => resume@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx* CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00" +1999-03-02 09:44:33 10HmaZ-0005vi-00 -> xyz@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx* CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00" 1999-03-02 09:44:33 10HmaZ-0005vi-00 tls_out_resumption not requested or offered 1999-03-02 09:44:33 10HmaZ-0005vi-00 our cert subject 1999-03-02 09:44:33 10HmaZ-0005vi-00 peer cert subject CN=server1.example.com @@ -23,9 +25,7 @@ 1999-03-02 09:44:33 10HmaZ-0005vi-00 peer dn /CN=server1.example.com 1999-03-02 09:44:33 10HmaZ-0005vi-00 cipher TLS1.x:ke-RSA-AES256-SHAnnn:xxx 1999-03-02 09:44:33 10HmaZ-0005vi-00 bits 256 -1999-03-02 09:44:33 10HmaZ-0005vi-00 => resume@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx* CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00" -1999-03-02 09:44:33 10HmaZ-0005vi-00 -> xyz@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx* CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbA-0005vi-00" -1999-03-02 09:44:33 10HmaZ-0005vi-00 => abcd@test.ex R=client T=send_to_server2 H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbB-0005vi-00" +1999-03-02 09:44:33 10HmaZ-0005vi-00 => hostnotresume@test.ex R=client T=send_to_server2 H=ip4.ip4.ip4.ip4 [ip4.ip4.ip4.ip4] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbB-0005vi-00" 1999-03-02 09:44:33 10HmaZ-0005vi-00 Completed 1999-03-02 09:44:33 10HmbC-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for renewal@test.ex 1999-03-02 09:44:33 10HmbC-0005vi-00 tls_out_resumption session resumed @@ -47,7 +47,7 @@ 1999-03-02 09:44:33 10HmbE-0005vi-00 bits 256 1999-03-02 09:44:33 10HmbE-0005vi-00 => postrenewal@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx* CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbF-0005vi-00" 1999-03-02 09:44:33 10HmbE-0005vi-00 Completed -1999-03-02 09:44:33 10HmbG-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for timeout@test.ex +1999-03-02 09:44:33 10HmbG-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for aftertimeout@test.ex 1999-03-02 09:44:33 10HmbG-0005vi-00 tls_out_resumption client requested new ticket, server provided 1999-03-02 09:44:33 10HmbG-0005vi-00 our cert subject 1999-03-02 09:44:33 10HmbG-0005vi-00 peer cert subject CN=server1.example.com @@ -55,7 +55,7 @@ 1999-03-02 09:44:33 10HmbG-0005vi-00 peer dn /CN=server1.example.com 1999-03-02 09:44:33 10HmbG-0005vi-00 cipher TLS1.x:ke-RSA-AES256-SHAnnn:xxx 1999-03-02 09:44:33 10HmbG-0005vi-00 bits 256 -1999-03-02 09:44:33 10HmbG-0005vi-00 => timeout@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbH-0005vi-00" +1999-03-02 09:44:33 10HmbG-0005vi-00 => aftertimeout@test.ex R=client T=send_to_server1 H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=yes DN="/CN=server1.example.com" C="250 OK id=10HmbH-0005vi-00" 1999-03-02 09:44:33 10HmbG-0005vi-00 Completed 1999-03-02 09:44:33 10HmbI-0005vi-00 <= CALLER@myhost.test.ex U=CALLER P=local S=sss for notreq@test.ex 1999-03-02 09:44:33 10HmbI-0005vi-00 tls_out_resumption not requested or offered @@ -159,8 +159,8 @@ 1999-03-02 09:44:33 peer dn 1999-03-02 09:44:33 cipher TLS1.x:ke-RSA-AES256-SHAnnn:xxx 1999-03-02 09:44:33 bits 256 -1999-03-02 09:44:33 10HmbB-0005vi-00 <= CALLER@myhost.test.ex H=the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaZ-0005vi-00@myhost.test.ex for abcd@test.ex -1999-03-02 09:44:33 10HmbB-0005vi-00 => :blackhole: R=server +1999-03-02 09:44:33 10HmbB-0005vi-00 <= CALLER@myhost.test.ex H=the.local.host.name (myhost.test.ex) [ip4.ip4.ip4.ip4] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaZ-0005vi-00@myhost.test.ex for hostnotresume@test.ex +1999-03-02 09:44:33 10HmbB-0005vi-00 => :blackhole: R=server 1999-03-02 09:44:33 10HmbB-0005vi-00 Completed 1999-03-02 09:44:33 tls_in_resumption session resumed, also new ticket 1999-03-02 09:44:33 our cert subject CN=server1.example.com @@ -189,8 +189,8 @@ 1999-03-02 09:44:33 peer dn 1999-03-02 09:44:33 cipher TLS1.x:ke-RSA-AES256-SHAnnn:xxx 1999-03-02 09:44:33 bits 256 -1999-03-02 09:44:33 10HmbH-0005vi-00 <= CALLER@myhost.test.ex H=(helo.data.changed) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbG-0005vi-00@myhost.test.ex for timeout@test.ex -1999-03-02 09:44:33 10HmbH-0005vi-00 => :blackhole: R=server +1999-03-02 09:44:33 10HmbH-0005vi-00 <= CALLER@myhost.test.ex H=(helo.data.changed) [127.0.0.1] P=esmtps X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbG-0005vi-00@myhost.test.ex for aftertimeout@test.ex +1999-03-02 09:44:33 10HmbH-0005vi-00 => :blackhole: R=server 1999-03-02 09:44:33 10HmbH-0005vi-00 Completed 1999-03-02 09:44:33 tls_in_resumption no client request 1999-03-02 09:44:33 our cert subject CN=server1.example.com diff --git a/test/scripts/5892-Resume-OpenSSL/5892 b/test/scripts/5892-Resume-OpenSSL/5892 index e09fc6398..77b93704b 100644 --- a/test/scripts/5892-Resume-OpenSSL/5892 +++ b/test/scripts/5892-Resume-OpenSSL/5892 @@ -4,21 +4,21 @@ exim -DSERVER=server -DOPTION=+no_tlsv1_3 -bd -oX PORT_D **** exim -DVALUE=resume -odf getticket@test.ex -Test message. Contains FF: ÿ +Test message. **** -exim -DVALUE=resume -odf resume@test.ex abcd@test.ex xyz@test.ex +exim -DVALUE=resume -odf resume@test.ex hostnotresume@test.ex xyz@test.ex Test message to two different hosts, one does not support resume **** # allow time for ticket to hit renewal time -sleep 3 +sleep 5 exim -DVALUE=resume -odf renewal@test.ex Test message. **** exim -DVALUE=resume -odf postrenewal@test.ex Test message. **** -sleep 3 -exim -DVALUE=resume -odf timeout@test.ex +sleep 5 +exim -DVALUE=resume -odf aftertimeout@test.ex Test message. **** exim -odf notreq@test.ex diff --git a/test/scripts/5893-Resume-OpenSSL-OCSP/5893 b/test/scripts/5893-Resume-OpenSSL-OCSP/5893 index 2c525d838..2c103c788 100644 --- a/test/scripts/5893-Resume-OpenSSL-OCSP/5893 +++ b/test/scripts/5893-Resume-OpenSSL-OCSP/5893 @@ -10,14 +10,14 @@ exim -DVALUE=resume -odf resume@test.ex abcd@test.ex xyz@test.ex Test message to two different hosts, one does not support resume **** # allow time for ticket to hit renewal time -sleep 3 +sleep 5 exim -DVALUE=resume -odf renewal@test.ex Test message. **** exim -DVALUE=resume -odf postrenewal@test.ex Test message. **** -sleep 3 +sleep 5 exim -DVALUE=resume -odf timeout@test.ex Test message. **** diff --git a/test/scripts/5895-Resume-OpenSSL-TLS1.3-OCSP/5895 b/test/scripts/5895-Resume-OpenSSL-TLS1.3-OCSP/5895 index 5709b4a78..e54803896 100644 --- a/test/scripts/5895-Resume-OpenSSL-TLS1.3-OCSP/5895 +++ b/test/scripts/5895-Resume-OpenSSL-TLS1.3-OCSP/5895 @@ -10,14 +10,14 @@ exim -DVALUE=resume -odf resume@test.ex abcd@test.ex xyz@test.ex Test message to two different hosts, one does not support resume **** # allow time for ticket to hit renewal time -sleep 3 +sleep 5 exim -DVALUE=resume -odf renewal@test.ex Test message. **** exim -DVALUE=resume -odf postrenewal@test.ex Test message. **** -sleep 3 +sleep 5 exim -DVALUE=resume -odf timeout@test.ex Test message. **** diff --git a/test/stderr/5410 b/test/stderr/5410 index 7d0961733..8e65e3feb 100644 --- a/test/stderr/5410 +++ b/test/stderr/5410 @@ -16,15 +16,12 @@ LOG: smtp_connection MAIN ├considering: $tod_full ├──expanding: $smtp_active_hostname ESMTP Exim $version_number $tod_full ╰─────result: myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000 - in limits_advertise_hosts? - list element: !* in dsn_advertise_hosts? no (option unset) in pipelining_advertise_hosts? list element: * in pipelining_advertise_hosts? yes (matched "*") in chunking_advertise_hosts? in chunking_advertise_hosts? no (end of list) - in tls_advertise_hosts? list element: * in tls_advertise_hosts? yes (matched "*") ╭considering: ${if eq {SERVER}{server}{queue}{cutthrough}} @@ -121,9 +118,6 @@ cmd buf flush ddd bytes ├considering: }} {match{$item}{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: .outlook.com\$ ╰─────result: .outlook.com$ - compiled RE '.outlook.com$' not found in local cache - compiling RE '.outlook.com$' - compiled RE '.outlook.com$' saved in local cache ╭───scanning: $item}{\N^250-([\w.]+)\s\N}}} {$1}} ├───scanning: }{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: $item @@ -614,15 +608,12 @@ LOG: smtp_connection MAIN ├considering: $tod_full ├──expanding: $smtp_active_hostname ESMTP Exim $version_number $tod_full ╰─────result: myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000 - in limits_advertise_hosts? - list element: !* in dsn_advertise_hosts? no (option unset) in pipelining_advertise_hosts? list element: * in pipelining_advertise_hosts? yes (matched "*") in chunking_advertise_hosts? in chunking_advertise_hosts? no (end of list) - in tls_advertise_hosts? list element: * in tls_advertise_hosts? yes (matched "*") ╭considering: ${if eq {SERVER}{server}{queue}{cutthrough}} @@ -719,9 +710,6 @@ cmd buf flush ddd bytes ├considering: }} {match{$item}{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: .outlook.com\$ ╰─────result: .outlook.com$ - compiled RE '.outlook.com$' not found in local cache - compiling RE '.outlook.com$' - compiled RE '.outlook.com$' saved in local cache ╭───scanning: $item}{\N^250-([\w.]+)\s\N}}} {$1}} ├───scanning: }{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: $item @@ -1165,15 +1153,12 @@ LOG: smtp_connection MAIN ├considering: $tod_full ├──expanding: $smtp_active_hostname ESMTP Exim $version_number $tod_full ╰─────result: myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000 - in limits_advertise_hosts? - list element: !* in dsn_advertise_hosts? no (option unset) in pipelining_advertise_hosts? list element: * in pipelining_advertise_hosts? yes (matched "*") in chunking_advertise_hosts? in chunking_advertise_hosts? no (end of list) - in tls_advertise_hosts? list element: * in tls_advertise_hosts? yes (matched "*") ╭considering: ${if eq {SERVER}{server}{queue}{cutthrough}} @@ -1270,9 +1255,6 @@ cmd buf flush ddd bytes ├considering: }} {match{$item}{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: .outlook.com\$ ╰─────result: .outlook.com$ - compiled RE '.outlook.com$' not found in local cache - compiling RE '.outlook.com$' - compiled RE '.outlook.com$' saved in local cache ╭───scanning: $item}{\N^250-([\w.]+)\s\N}}} {$1}} ├───scanning: }{\N^250-([\w.]+)\s\N}}} {$1}} ├──expanding: $item