From 4ca005cdf526b0c6803c29a154bd85dc112bc6a3 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Tue, 10 Mar 2020 17:06:26 +0000 Subject: [PATCH] Early-pipe: retry without pipelining on first-response failure --- doc/doc-txt/ChangeLog | 4 ++ src/src/transports/smtp.c | 6 ++- test/confs/4060 | 2 +- test/log/4062 | 52 +++++++++++++++--------- test/scripts/4062-pipe-conn-openssl/4062 | 20 +++++++-- 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: R=server +2017-07-30 18:51:05.712 10HmaY-0005vi-00 => :blackhole: 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: R=server +2017-07-30 18:51:05.712 10HmbA-0005vi-00 => :blackhole: 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: R=server +2017-07-30 18:51:05.712 10HmbC-0005vi-00 => :blackhole: 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: R=server +2017-07-30 18:51:05.712 10HmbE-0005vi-00 => :blackhole: 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: R=server +2017-07-30 18:51:05.712 10HmbG-0005vi-00 => :blackhole: 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: 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 -- 2.25.1