Early-pipe: retry without pipelining on first-response failure

5 files changed, 59 insertions, 25 deletions

diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog
index 7e0fbf726..001f919d7 100644
--- a/doc/doc-txt/ChangeLog
+++ b/doc/doc-txt/ChangeLog
@@ -143,6 +143,10 @@ JH/28 Bug 2533: Fix expansion of ${tr } item.  When called in some situations
 JH/29 Bug 2537: Fix $mime_part_count.  When a single connection had a non-mime
       message following a mime one, the variable was not reset.
 
+JH/30 When an pipelined-connect fails at the first response, assume incorrect
+      cached capability (perhaps the peer reneged?) and immediately retry in
+      non-pipelined mode.
+
 
 Exim version 4.93
 -----------------
diff --git a/src/src/transports/smtp.c b/src/src/transports/smtp.c
index 13410b839..6f999097a 100644
--- a/src/src/transports/smtp.c
+++ b/src/src/transports/smtp.c
@@ -2079,6 +2079,7 @@ if (!continue_hostname)
     else DEBUG(D_transport)
       debug_printf("helo needs $sending_ip_address\n");
 
+PIPE_CONNECT_RETRY:
   if (sx->early_pipe_active)
     sx->outblock.conn_args = &sx->conn_args;
   else
@@ -2425,7 +2426,10 @@ if (  smtp_peer_options & OPTION_TLS
     {
     HDEBUG(D_transport)
       debug_printf("failed reaping pipelined cmd responses\n");
-    goto RESPONSE_FAILED;
+    close(sx->cctx.sock);
+    sx->cctx.sock = -1;
+    sx->early_pipe_active = FALSE;
+    goto PIPE_CONNECT_RETRY;
     }
 #endif
 
diff --git a/test/confs/4060 b/test/confs/4060
index 191677073..f3aa84d66 100644
--- a/test/confs/4060
+++ b/test/confs/4060
@@ -34,7 +34,7 @@ tls_require_ciphers = NORMAL:-KX-ALL:+RSA
 tls_require_ciphers = DEFAULT:!kECDHE
 .endif
 
-pipelining_connect_advertise_hosts = *
+pipelining_connect_advertise_hosts = CONTROL
 log_selector = +received_recipients +millisec +pipelining
 queue_only
 
diff --git a/test/log/4062 b/test/log/4062
index f436a0d53..d3b90c476 100644
--- a/test/log/4062
+++ b/test/log/4062
@@ -1,54 +1,66 @@
-2017-07-30 18:51:05.712 10HmaX-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for a@test.ex
+2017-07-30 18:51:05.712 10HmaX-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for nocache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmaX-0005vi-00 => a@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L C="250 OK id=10HmaY-0005vi-00"
+2017-07-30 18:51:05.712 10HmaX-0005vi-00 => nocache@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L C="250 OK id=10HmaY-0005vi-00"
 2017-07-30 18:51:05.712 10HmaX-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmaZ-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for b@test.ex
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for hascache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmaZ-0005vi-00 => b@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L* C="250 OK id=10HmbA-0005vi-00"
+2017-07-30 18:51:05.712 10HmaZ-0005vi-00 => hascache@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L* C="250 OK id=10HmbA-0005vi-00"
 2017-07-30 18:51:05.712 10HmaZ-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbB-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for c@test.ex
+2017-07-30 18:51:05.712 10HmbB-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for client_no@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbB-0005vi-00 => c@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L C="250 OK id=10HmbC-0005vi-00"
+2017-07-30 18:51:05.712 10HmbB-0005vi-00 => client_no@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L C="250 OK id=10HmbC-0005vi-00"
 2017-07-30 18:51:05.712 10HmbB-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbD-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for nocache@test.ex
+2017-07-30 18:51:05.712 10HmbD-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for server_oops@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbD-0005vi-00 => nocache@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbE-0005vi-00"
+2017-07-30 18:51:05.712 10HmbD-0005vi-00 => server_oops@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L C="250 OK id=10HmbE-0005vi-00"
 2017-07-30 18:51:05.712 10HmbD-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbF-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for chunking@test.ex
+2017-07-30 18:51:05.712 10HmbF-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for nocache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbF-0005vi-00 => chunking@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L* K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbG-0005vi-00"
+2017-07-30 18:51:05.712 10HmbF-0005vi-00 => nocache@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbG-0005vi-00"
 2017-07-30 18:51:05.712 10HmbF-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
+2017-07-30 18:51:05.712 10HmbH-0005vi-00 <= CALLER@the.local.host.name U=CALLER P=local S=sss for chunking@test.ex
+2017-07-30 18:51:05.712 Start queue run: pid=pppp
+2017-07-30 18:51:05.712 10HmbH-0005vi-00 => chunking@test.ex R=client T=smtp H=127.0.0.1 [127.0.0.1] X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no L* K C="250- 3nn byte chunk, total 3nn\\n250 OK id=10HmbI-0005vi-00"
+2017-07-30 18:51:05.712 10HmbH-0005vi-00 Completed
+2017-07-30 18:51:05.712 End queue run: pid=pppp
 
 ******** SERVER ********
 2017-07-30 18:51:05.712 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
-2017-07-30 18:51:05.712 10HmaY-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaX-0005vi-00@the.local.host.name for a@test.ex
+2017-07-30 18:51:05.712 10HmaY-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaX-0005vi-00@the.local.host.name for nocache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmaY-0005vi-00 => :blackhole: <a@test.ex> R=server
+2017-07-30 18:51:05.712 10HmaY-0005vi-00 => :blackhole: <nocache@test.ex> R=server
 2017-07-30 18:51:05.712 10HmaY-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbA-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L* X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaZ-0005vi-00@the.local.host.name for b@test.ex
+2017-07-30 18:51:05.712 10HmbA-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L* X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmaZ-0005vi-00@the.local.host.name for hascache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbA-0005vi-00 => :blackhole: <b@test.ex> R=server
+2017-07-30 18:51:05.712 10HmbA-0005vi-00 => :blackhole: <hascache@test.ex> R=server
 2017-07-30 18:51:05.712 10HmbA-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbC-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbB-0005vi-00@the.local.host.name for c@test.ex
+2017-07-30 18:51:05.712 10HmbC-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbB-0005vi-00@the.local.host.name for client_no@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbC-0005vi-00 => :blackhole: <c@test.ex> R=server
+2017-07-30 18:51:05.712 10HmbC-0005vi-00 => :blackhole: <client_no@test.ex> R=server
 2017-07-30 18:51:05.712 10HmbC-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
 2017-07-30 18:51:05.712 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
-2017-07-30 18:51:05.712 10HmbE-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbD-0005vi-00@the.local.host.name for nocache@test.ex
+2017-07-30 18:51:05.712 SMTP protocol synchronization error (input sent without waiting for greeting): rejected connection from H=[127.0.0.1] input="EHLO the.local.host.name\r\nSTARTTLS\r\n"
+2017-07-30 18:51:05.712 10HmbE-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no S=sss id=E10HmbD-0005vi-00@the.local.host.name for server_oops@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbE-0005vi-00 => :blackhole: <nocache@test.ex> R=server
+2017-07-30 18:51:05.712 10HmbE-0005vi-00 => :blackhole: <server_oops@test.ex> R=server
 2017-07-30 18:51:05.712 10HmbE-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbG-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L* X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbF-0005vi-00@the.local.host.name for chunking@test.ex
+2017-07-30 18:51:05.712 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
+2017-07-30 18:51:05.712 10HmbG-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L. X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbF-0005vi-00@the.local.host.name for nocache@test.ex
 2017-07-30 18:51:05.712 Start queue run: pid=pppp
-2017-07-30 18:51:05.712 10HmbG-0005vi-00 => :blackhole: <chunking@test.ex> R=server
+2017-07-30 18:51:05.712 10HmbG-0005vi-00 => :blackhole: <nocache@test.ex> R=server
 2017-07-30 18:51:05.712 10HmbG-0005vi-00 Completed
 2017-07-30 18:51:05.712 End queue run: pid=pppp
+2017-07-30 18:51:05.712 10HmbI-0005vi-00 <= CALLER@the.local.host.name H=localhost (the.local.host.name) [127.0.0.1] P=esmtps L* X=TLS1.x:ke-RSA-AES256-SHAnnn:xxx CV=no K S=sss id=E10HmbH-0005vi-00@the.local.host.name for chunking@test.ex
+2017-07-30 18:51:05.712 Start queue run: pid=pppp
+2017-07-30 18:51:05.712 10HmbI-0005vi-00 => :blackhole: <chunking@test.ex> R=server
+2017-07-30 18:51:05.712 10HmbI-0005vi-00 Completed
+2017-07-30 18:51:05.712 End queue run: pid=pppp
diff --git a/test/scripts/4062-pipe-conn-openssl/4062 b/test/scripts/4062-pipe-conn-openssl/4062
index bd0fe5725..6f1dfcb5c 100644
--- a/test/scripts/4062-pipe-conn-openssl/4062
+++ b/test/scripts/4062-pipe-conn-openssl/4062
@@ -4,7 +4,7 @@
 exim -bd -DSERVER=server -oX PORT_D
 ****
 #
-exim a@test.ex
+exim nocache@test.ex
 Subject test 1
 
 ****
@@ -16,7 +16,7 @@ exim -DNOTDAEMON -DSERVER=server -q
 #
 #
 # Go for it.  This one should do early-pipelinng.
-exim b@test.ex
+exim hascache@test.ex
 Subject test 2
 
 ****
@@ -28,7 +28,7 @@ exim -DNOTDAEMON -DSERVER=server -q
 #
 # Check that client doesn't try when not told to, even now there is
 # a cache entry
-exim c@test.ex
+exim client_no@test.ex
 Subject test 3
 
 ****
@@ -40,6 +40,20 @@ exim -DNOTDAEMON -DSERVER=server -q
 #
 killdaemon
 #
+# Check what happens when the server suddenly does not support it
+# and we have cached info saying it does
+exim -bd -DSERVER=server -DCONTROL=: -oX PORT_D
+****
+exim server_oops@test.ex
+Subject test 3_2
+
+****
+exim -q
+****
+exim -DNOTDAEMON -DSERVER=server -q
+****
+killdaemon
+#
 #
 # And again with CHUNKING
 sudo rm DIR/spool/db/misc