Fix too-often retry bug after 4xx with more hosts than hosts_max_retry.

13 files changed, 204 insertions, 46 deletions

diff --git a/test/confs/0543 b/test/confs/0543
new file mode 100644
index 000000000..e68280b0e
--- /dev/null
+++ b/test/confs/0543
@@ -0,0 +1,46 @@
+# Exim test configuration 0543
+
+exim_path = EXIM_PATH
+host_lookup_order = bydns
+rfc1413_query_timeout = 0s
+spool_directory = DIR/spool
+log_file_path = DIR/spool/log/%slog
+gecos_pattern = ""
+gecos_name = CALLER_NAME
+
+# ----- Main settings -----
+
+qualify_domain = test.ex
+queue_run_in_order
+
+
+# ----- Routers -----
+
+begin routers
+
+smarthost:
+  driver = accept
+  transport = smtp
+
+
+# ----- Transports -----
+
+begin transports
+
+smtp:
+  driver = smtp
+  hosts = thisloop.test.ex
+  hosts_max_try = 1
+  allow_localhost
+  port = PORT_S
+
+
+# ----- Retry -----
+
+
+begin retry
+
+* * F,5d,15m
+
+
+# End
diff --git a/test/log/0209 b/test/log/0209
index 7587794ef..696834136 100644
--- a/test/log/0209
+++ b/test/log/0209
@@ -19,17 +19,19 @@
 1999-03-02 09:44:33 Start queue run: pid=pppp
 1999-03-02 09:44:33 10HmaZ-0005vi-00 == userx@domain1 R=others T=smtp defer (-44): SMTP error from remote mail server after RCPT TO:<userx@domain1>: host 127.0.0.1 [127.0.0.1]: 450 Temporary error
 1999-03-02 09:44:33 10HmaZ-0005vi-00 => usery@domain1 R=others T=smtp H=127.0.0.1 [127.0.0.1]
-1999-03-02 09:44:33 10HmbA-0005vi-00 == userx@domain1 R=others T=smtp defer (-44): SMTP error from remote mail server after RCPT TO:<userx@domain1>: host 127.0.0.1 [127.0.0.1]: 450 Temporary error
-1999-03-02 09:44:33 10HmbA-0005vi-00 => usery@domain1 R=others T=smtp H=127.0.0.1 [127.0.0.1]*
-1999-03-02 09:44:33 10HmaZ-0005vi-00 == userx@domain1 R=others T=smtp defer (-44): SMTP error from remote mail server after RCPT TO:<userx@domain1>: host 127.0.0.1 [127.0.0.1]: 450 Temporary error
 1999-03-02 09:44:33 10HmbA-0005vi-00 == userx@domain1 routing defer (-51): retry time not reached
+1999-03-02 09:44:33 10HmbA-0005vi-00 == usery@domain1 R=others T=smtp defer (-44): SMTP error from remote mail server after RCPT TO:<usery@domain1>: host 127.0.0.1 [127.0.0.1]: 450 Temporary error
+1999-03-02 09:44:33 10HmbA-0005vi-00 == userx@domain1 routing defer (-51): retry time not reached
+1999-03-02 09:44:33 10HmbA-0005vi-00 == usery@domain1 routing defer (-51): retry time not reached
 1999-03-02 09:44:33 End queue run: pid=pppp
 1999-03-02 09:44:33 Start queue run: pid=pppp
 1999-03-02 09:44:33 10HmaZ-0005vi-00 == userx@domain1 routing defer (-51): retry time not reached
 1999-03-02 09:44:33 10HmbA-0005vi-00 == userx@domain1 routing defer (-51): retry time not reached
+1999-03-02 09:44:33 10HmbA-0005vi-00 == usery@domain1 routing defer (-51): retry time not reached
 1999-03-02 09:44:33 End queue run: pid=pppp
 1999-03-02 09:44:33 Start queue run: pid=pppp
 1999-03-02 09:44:33 10HmbA-0005vi-00 == userx@domain1 routing defer (-51): retry time not reached
+1999-03-02 09:44:33 10HmbA-0005vi-00 == usery@domain1 routing defer (-51): retry time not reached
 1999-03-02 09:44:33 End queue run: pid=pppp
 1999-03-02 09:44:33 10HmaZ-0005vi-00 127.0.0.1 [127.0.0.1] Connection refused
 1999-03-02 09:44:33 10HmaZ-0005vi-00 == userx@domain1 R=others T=smtp defer (dd): Connection refused
diff --git a/test/log/0543 b/test/log/0543
new file mode 100644
index 000000000..208bf2694
--- /dev/null
+++ b/test/log/0543
@@ -0,0 +1,9 @@
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= CALLER@test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmaY-0005vi-00 <= CALLER@test.ex U=CALLER P=local S=sss
+1999-03-02 09:44:33 10HmaY-0005vi-00 SMTP error from remote mail server after RCPT TO:<usery@domain1>: host thisloop.test.ex [127.0.0.1]: 451 Later, please
+1999-03-02 09:44:33 10HmaY-0005vi-00 == usery@domain1 R=smarthost T=smtp defer (-44): SMTP error from remote mail server after RCPT TO:<usery@domain1>: host thisloop.test.ex [127.0.0.1]: 451 Later, please
+1999-03-02 09:44:33 Start queue run: pid=pppp
+1999-03-02 09:44:33 10HmaX-0005vi-00 => userx@domain1 R=smarthost T=smtp H=thisloop.test.ex [127.0.0.1]
+1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
+1999-03-02 09:44:33 10HmaY-0005vi-00 == usery@domain1 routing defer (-51): retry time not reached
+1999-03-02 09:44:33 End queue run: pid=pppp
diff --git a/test/scripts/0000-Basic/0209 b/test/scripts/0000-Basic/0209
index 3bb43f78f..30401c89c 100644
--- a/test/scripts/0000-Basic/0209
+++ b/test/scripts/0000-Basic/0209
@@ -48,16 +48,6 @@ MAIL FROM:
 250 Sender OK
 RCPT TO:
 450 Temporary error
-RCPT TO:
-250 OK
-DATA
-354 Go ahead
-.
-250 OK
-MAIL FROM:
-250 Sender OK
-RCPT TO:
-450 Temporary error
 QUIT
 250 OK
 ****
diff --git a/test/scripts/0000-Basic/0543 b/test/scripts/0000-Basic/0543
new file mode 100644
index 000000000..7ee6305f5
--- /dev/null
+++ b/test/scripts/0000-Basic/0543
@@ -0,0 +1,47 @@
+# 4xx retries with 2nd message down one SMTP connection
+need_ipv4
+#
+# Put a message on the queue
+exim -odq userx@domain1
+Test message 1
+****
+# Arrange a second message that's had a 4xx
+server PORT_S
+220 ESMTP
+EHLO
+250-OK
+250 HELP
+MAIL
+250 OK
+RCPT
+451 Later, please
+QUIT
+220 OK
+****
+exim -odi usery@domain1
+Test message 2
+****
+1
+dump wait-smtp
+# A queue run will try these in order, since queue_run_in_order is set.
+# Arrange that the first one is accepted, so it should fire up the second
+# on the same connection. But it should respect the retry time.
+server PORT_S
+220 ESMTP
+EHLO
+250-OK
+250 HELP
+MAIL
+250 OK
+RCPT
+250 OK
+DATA
+354 More...
+.
+250 OK
+QUIT
+250 OK
+****
+exim -q -d-all+route
+****
+no_msglog_check
diff --git a/test/stderr/0357 b/test/stderr/0357
index f7bc3f635..7a6ee4d3b 100644
--- a/test/stderr/0357
+++ b/test/stderr/0357
@@ -25,7 +25,6 @@ checking status of 127.0.0.1
 locking TESTSUITE/spool/db/retry.lockfile
 no retry data available
 added retry item for R:userx@test.ex: errno=-44 more_errno=dd,A flags=0
-locking TESTSUITE/spool/db/wait-t1.lockfile
 reading retry information for R:userx@test.ex from subprocess
   added retry item
 LOG: MAIN
@@ -67,7 +66,6 @@ locking TESTSUITE/spool/db/retry.lockfile
 no host retry record
 no message retry record
 added retry item for R:userx@test.ex: errno=-44 more_errno=dd,A flags=0
-locking TESTSUITE/spool/db/wait-t1.lockfile
 reading retry information for R:userx@test.ex from subprocess
   existing delete item dropped
   added retry item
@@ -117,7 +115,6 @@ locking TESTSUITE/spool/db/retry.lockfile
 no host retry record
 no message retry record
 added retry item for R:userx@test.ex: errno=-44 more_errno=dd,A flags=0
-locking TESTSUITE/spool/db/wait-t1.lockfile
 reading retry information for R:userx@test.ex from subprocess
   existing delete item dropped
   added retry item
diff --git a/test/stderr/0358 b/test/stderr/0358
index 2756de19a..40e38ca12 100644
--- a/test/stderr/0358
+++ b/test/stderr/0358
@@ -31,7 +31,6 @@ locking TESTSUITE/spool/db/retry.lockfile
 no retry data available
 added retry item for R:userx@test.ex: errno=-44 more_errno=dd,A flags=0
 added retry item for R:usery@test.ex: errno=-44 more_errno=dd,A flags=0
-locking TESTSUITE/spool/db/wait-t1.lockfile
 reading retry information for R:userx@test.ex from subprocess
   added retry item
 reading retry information for R:usery@test.ex from subprocess
@@ -90,7 +89,6 @@ no host retry record
 no message retry record
 added retry item for R:userx@test.ex: errno=-44 more_errno=dd,A flags=0
 added retry item for R:usery@test.ex: errno=-44 more_errno=dd,A flags=0
-locking TESTSUITE/spool/db/wait-t1.lockfile
 reading retry information for R:userx@test.ex from subprocess
   existing delete item dropped
   added retry item
diff --git a/test/stderr/0374 b/test/stderr/0374
index 641156ca0..2fafefb7e 100644
--- a/test/stderr/0374
+++ b/test/stderr/0374
@@ -369,7 +369,6 @@ locking TESTSUITE/spool/db/wait-ut4.lockfile
 LOG: MAIN
   => d1@myhost.test.ex R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1]
 locking TESTSUITE/spool/db/retry.lockfile
-locking TESTSUITE/spool/db/wait-ut4.lockfile
 LOG: MAIN
   == d2@myhost.test.ex R=ut4 T=ut4 defer (-44): SMTP error from remote mail server after RCPT TO:<d2@myhost.test.ex>: host 127.0.0.1 [127.0.0.1]: 450 soft error
 locking TESTSUITE/spool/db/retry.lockfile
diff --git a/test/stderr/0375 b/test/stderr/0375
index b780d95fd..628b5dfcb 100644
--- a/test/stderr/0375
+++ b/test/stderr/0375
@@ -805,7 +805,6 @@ LOG: MAIN
   => d1@myhost.test.ex P=<> R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1]
 log writing disabled
 locking TESTSUITE/spool/db/retry.lockfile
-locking TESTSUITE/spool/db/wait-ut4.lockfile
 LOG: MAIN
   == d2@myhost.test.ex R=ut4 T=ut4 defer (-44): SMTP error from remote mail server after RCPT TO:<d2@myhost.test.ex>: host 127.0.0.1 [127.0.0.1]: 450 soft error
 log writing disabled
@@ -825,7 +824,6 @@ LOG: MAIN
   => f1@myhost.test.ex P=<CALLER@myhost.test.ex> R=ut6 T=ut6 H=127.0.0.1 [127.0.0.1]
 log writing disabled
 locking TESTSUITE/spool/db/retry.lockfile
-locking TESTSUITE/spool/db/wait-ut6.lockfile
 LOG: MAIN
   == f2@myhost.test.ex R=ut6 T=ut6 defer (-44): SMTP error from remote mail server after RCPT TO:<f2@myhost.test.ex>: host 127.0.0.1 [127.0.0.1]: 450 soft error
 log writing disabled
diff --git a/test/stderr/0388 b/test/stderr/0388
index ab7d8ae32..dc12b2781 100644
--- a/test/stderr/0388
+++ b/test/stderr/0388
@@ -110,13 +110,6 @@ LOG: MAIN
   V4NET.0.0.0 [V4NET.0.0.0] Network Error
 set_process_info: pppp delivering 10HmaX-0005vi-00: just tried V4NET.0.0.0 [V4NET.0.0.0] for x@y: result DEFER
 added retry item for T:V4NET.0.0.0:V4NET.0.0.0:1224: errno=dd more_errno=dd,A flags=2
-locking TESTSUITE/spool/db/wait-smtp.lockfile
-locked TESTSUITE/spool/db/wait-smtp.lockfile
-EXIM_DBOPEN(TESTSUITE/spool/db/wait-smtp)
-returned from EXIM_DBOPEN
-opened hints database TESTSUITE/spool/db/wait-smtp: flags=O_RDWR
-dbfn_read: key=V4NET.0.0.0
-dbfn_write: key=V4NET.0.0.0
 set_process_info: pppp delivering 10HmaX-0005vi-00 (just run smtp for x@y in subprocess)
 search_tidyup called
 set_process_info: pppp delivering 10HmaX-0005vi-00: waiting for a remote delivery subprocess to finish
diff --git a/test/stderr/0543 b/test/stderr/0543
new file mode 100644
index 000000000..655762d0a
--- /dev/null
+++ b/test/stderr/0543
@@ -0,0 +1,54 @@
+Exim version x.yz ....
+configuration file is TESTSUITE/test-config
+admin user
+LOG: queue_run MAIN
+  Start queue run: pid=pppp
+locking TESTSUITE/spool/db/retry.lockfile
+>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+Considering: userx@domain1
+unique = userx@domain1
+userx@domain1: queued for routing
+>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+routing userx@domain1
+--------> smarthost router <--------
+local_part=userx domain=domain1
+calling smarthost router
+smarthost router called for userx@domain1
+  domain = domain1
+set transport smtp
+queued for smtp transport: local_part = userx
+domain = domain1
+  errors_to=NULL
+  domain_data=NULL localpart_data=NULL
+routed by smarthost router
+  envelope to: userx@domain1
+  transport: smtp
+>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+After routing:
+  Local deliveries:
+  Remote deliveries:
+    userx@domain1
+  Failed addresses:
+  Deferred addresses:
+locking TESTSUITE/spool/db/retry.lockfile
+locking TESTSUITE/spool/db/wait-smtp.lockfile
+LOG: MAIN
+  => userx@domain1 R=smarthost T=smtp H=thisloop.test.ex [127.0.0.1]
+LOG: MAIN
+  Completed
+locking TESTSUITE/spool/db/retry.lockfile
+>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+Considering: usery@domain1
+unique = usery@domain1
+LOG: retry_defer MAIN
+  == usery@domain1 routing defer (-51): retry time not reached
+>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+After routing:
+  Local deliveries:
+  Remote deliveries:
+  Failed addresses:
+  Deferred addresses:
+    usery@domain1
+LOG: queue_run MAIN
+  End queue run: pid=pppp
+>>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
diff --git a/test/stdout/0209 b/test/stdout/0209
index cdb29fe7d..90a59b259 100644
--- a/test/stdout/0209
+++ b/test/stdout/0209
@@ -41,25 +41,7 @@ Test message 1
 250 OK
 MAIL FROM:<CALLER@test.ex>
 250 Sender OK
-RCPT TO:<userx@domain1>
-450 Temporary error
 RCPT TO:<usery@domain1>
-250 OK
-DATA
-354 Go ahead
-Received: from CALLER by the.local.host.name with local (Exim x.yz)
-	(envelope-from <CALLER@test.ex>)
-	id 10HmbA-0005vi-00; Tue, 2 Mar 1999 09:44:33 +0000
-Message-Id: <E10HmbA-0005vi-00@the.local.host.name>
-From: CALLER_NAME <CALLER@test.ex>
-Date: Tue, 2 Mar 1999 09:44:33 +0000
-
-Test message 2
-.
-250 OK
-MAIL FROM:<CALLER@test.ex>
-250 Sender OK
-RCPT TO:<userx@domain1>
 450 Temporary error
 QUIT
 250 OK
diff --git a/test/stdout/0543 b/test/stdout/0543
new file mode 100644
index 000000000..6b6a6067f
--- /dev/null
+++ b/test/stdout/0543
@@ -0,0 +1,43 @@
++++++++++++++++++++++++++++
+** Failed to open database lock file TESTSUITE/spool/db/wait-smtp.lockfile: No such file or directory
+
+******** SERVER ********
+Listening on port 1224 ... 
+Connection request from [127.0.0.1]
+220 ESMTP
+EHLO the.local.host.name
+250-OK
+250 HELP
+MAIL FROM:<CALLER@test.ex>
+250 OK
+RCPT TO:<usery@domain1>
+451 Later, please
+QUIT
+220 OK
+End of script
+Listening on port 1224 ... 
+Connection request from [127.0.0.1]
+220 ESMTP
+EHLO the.local.host.name
+250-OK
+250 HELP
+MAIL FROM:<CALLER@test.ex>
+250 OK
+RCPT TO:<userx@domain1>
+250 OK
+DATA
+354 More...
+Received: from CALLER by the.local.host.name with local (Exim x.yz)
+	(envelope-from <CALLER@test.ex>)
+	id 10HmaX-0005vi-00
+	for userx@domain1; Tue, 2 Mar 1999 09:44:33 +0000
+Message-Id: <E10HmaX-0005vi-00@the.local.host.name>
+From: CALLER_NAME <CALLER@test.ex>
+Date: Tue, 2 Mar 1999 09:44:33 +0000
+
+Test message 1
+.
+250 OK
+QUIT
+250 OK
+End of script