Testsuite: longer timing for OpenSSL resumption tests
authorJeremy Harris <jgh146exb@wizmail.org>
Sat, 31 Dec 2022 18:32:37 +0000 (18:32 +0000)
committerJeremy Harris <jgh146exb@wizmail.org>
Sat, 31 Dec 2022 21:20:50 +0000 (21:20 +0000)
src/src/tls-openssl.c
test/confs/5892
test/log/5892
test/scripts/5892-Resume-OpenSSL/5892
test/scripts/5893-Resume-OpenSSL-OCSP/5893
test/scripts/5895-Resume-OpenSSL-TLS1.3-OCSP/5895
test/stderr/5410

index 3b060cc9c695561637b7a439891df80034399ccb..ae0986aacd75d726edbd6d3ecf58f0d7dc56caf9 100644 (file)
@@ -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;
index 0aec9bfafea2b8fb35000e3972451007f139f765..15b09fcff9072d1eae744ad7cd7f5c7c72080c08 100644 (file)
@@ -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
index ce8b0ea7d14097650fa003440854e9ef96d5e185..b128749aebf33515af199f464921b207c838302b 100644 (file)
@@ -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
 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: <abcd@test.ex> 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: <hostnotresume@test.ex> 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
 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: <timeout@test.ex> 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: <aftertimeout@test.ex> 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
index e09fc6398eed32d7da69ba4b45a010030513391a..77b93704bb3a45aabaadd469a63cd688b5602b77 100644 (file)
@@ -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
index 2c525d838255934651c18db049e2060c03b902a4..2c103c788223adb65729e1aedab464eb5c07aeb6 100644 (file)
@@ -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.
 ****
index 5709b4a786777cd1297ef55d0162cca9b6d5b07b..e548038963b226cfd4f7fbe6281a8dac722ec02a 100644 (file)
@@ -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.
 ****
index 7d0961733fec1d3fd4599af3cd293eabb87b66ee..8e65e3febf8ec6fbb01e1ac7309c8bb15a46e143 100644 (file)
@@ -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