Testsuite: handle slow test-hosts more intelligently
authorJeremy Harris <jgh146exb@wizmail.org>
Thu, 24 Oct 2019 11:58:19 +0000 (12:58 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Thu, 24 Oct 2019 11:58:19 +0000 (12:58 +0100)
src/src/deliver.c
src/src/functions.h
src/src/queue.c
src/src/spool_in.c
test/confs/0206
test/confs/0618
test/log/0618
test/rejectlog/0618
test/scripts/0000-Basic/0206
test/scripts/0000-Basic/0618

index 0055ad4..34990b7 100644 (file)
@@ -5474,6 +5474,26 @@ fprintf(f, "Action: %s\n"
 }
 
 
+
+/* When running in the test harness, there's an option that allows us to
+fudge this time so as to get repeatability of the tests. Take the first
+time off the list. In queue runs, the list pointer gets updated in the
+calling process. */
+
+int
+test_harness_fudged_queue_time(int actual_time)
+{
+int qt;
+if (  f.running_in_test_harness && *fudged_queue_times
+   && (qt = readconf_readtime(fudged_queue_times, '/', FALSE)) >= 0)
+  {
+  DEBUG(D_deliver) debug_printf("fudged queue_times = %s\n",
+    fudged_queue_times);
+  return qt;
+  }
+return actual_time;
+}
+
 /*************************************************
 *              Deliver one message               *
 *************************************************/
@@ -6164,7 +6184,8 @@ if (process_recipients != RECIP_IGNORE)
         new->onetime_parent = recipients_list[r->pno].address;
 
       /* If DSN support is enabled, set the dsn flags and the original receipt
-         to be passed on to other DSN enabled MTAs */
+      to be passed on to other DSN enabled MTAs */
+
       new->dsn_flags = r->dsn_flags & rf_dsnflags;
       new->dsn_orcpt = r->orcpt;
       DEBUG(D_deliver) debug_printf("DSN: set orcpt: %s  flags: 0x%x\n",
@@ -7284,10 +7305,9 @@ for (address_item * a = addr_succeed; a; a = a->next)
       );
 
   /* send report if next hop not DSN aware or a router flagged "last DSN hop"
-     and a report was requested */
-  if (  (  a->dsn_aware != dsn_support_yes
-       || a->dsn_flags & rf_dsnlasthop
-        )
+  and a report was requested */
+
+  if (  (a->dsn_aware != dsn_support_yes || a->dsn_flags & rf_dsnlasthop)
      && a->dsn_flags & rf_notify_success
      )
     {
@@ -8131,21 +8151,7 @@ else if (addr_defer != (address_item *)(+1))
     int show_time;
     int queue_time = time(NULL) - received_time.tv_sec;
 
-    /* When running in the test harness, there's an option that allows us to
-    fudge this time so as to get repeatability of the tests. Take the first
-    time off the list. In queue runs, the list pointer gets updated in the
-    calling process. */
-
-    if (f.running_in_test_harness && fudged_queue_times[0] != 0)
-      {
-      int qt = readconf_readtime(fudged_queue_times, '/', FALSE);
-      if (qt >= 0)
-        {
-        DEBUG(D_deliver) debug_printf("fudged queue_times = %s\n",
-          fudged_queue_times);
-        queue_time = qt;
-        }
-      }
+    queue_time = test_harness_fudged_queue_time(queue_time);
 
     /* See how many warnings we should have sent by now */
 
index 35600ba..8905d02 100644 (file)
@@ -539,6 +539,7 @@ extern int     strcmpic(const uschar *, const uschar *);
 extern int     strncmpic(const uschar *, const uschar *, int);
 extern uschar *strstric(uschar *, uschar *, BOOL);
 
+extern int     test_harness_fudged_queue_time(int);
 #ifdef EXIM_TFO_PROBE
 extern void    tfo_probe(void);
 #endif
index d8c160a..670f51c 100644 (file)
@@ -664,8 +664,8 @@ for (int i = queue_run_in_order ? -1 : 0;
 
     if (f.running_in_test_harness && !f.queue_2stage)
       {
-      uschar *fqtnext = Ustrchr(fudged_queue_times, '/');
-      if (fqtnext != NULL) fudged_queue_times = fqtnext + 1;
+      uschar * fqtnext = Ustrchr(fudged_queue_times, '/');
+      if (fqtnext) fudged_queue_times = fqtnext + 1;
       }
     }                                  /* End loop for list of messages */
 
index f393d4d..7c60a12 100644 (file)
@@ -423,12 +423,16 @@ if (sscanf(CS big_buffer, TIME_T_FMT " %d", &received_time.tv_sec, &warning_coun
 received_time.tv_usec = 0;
 
 message_age = time(NULL) - received_time.tv_sec;
+#ifndef COMPILE_UTILITY
+if (f.running_in_test_harness)
+  message_age = test_harness_fudged_queue_time(message_age);
+#endif
 
 #ifndef COMPILE_UTILITY
 DEBUG(D_deliver) debug_printf("user=%s uid=%ld gid=%ld sender=%s\n",
   originator_login, (long int)originator_uid, (long int)originator_gid,
   sender_address);
-#endif  /* COMPILE_UTILITY */
+#endif
 
 /* Now there may be a number of optional lines, each starting with "-". If you
 add a new setting here, make sure you set the default above.
index 628d2ec..7b3180d 100644 (file)
@@ -7,8 +7,8 @@ primary_hostname = myhost.test.ex
 
 # ----- Main settings -----
 
-ignore_bounce_errors_after = 2s
-timeout_frozen_after = 5s
+ignore_bounce_errors_after = 4s
+timeout_frozen_after = 10s
 queue_run_in_order
 
 
index db4bd30..a461065 100644 (file)
@@ -11,7 +11,7 @@ primary_hostname = myhost.test.ex
 .ifdef OPT
 dsn_advertise_hosts = *
 .endif
-delay_warning = 3s : 24h
+delay_warning = 6s : 24h
 
 accept_8bitmime = false
 pipelining_advertise_hosts = :
@@ -89,5 +89,5 @@ tofile:
 
 begin retry
 
-*      *       F,1m,3s
+*      *       F,2m,10s
 # End
index a572e11..ad992d9 100644 (file)
 1999-03-02 09:44:33 End queue run: pid=pppp
 1999-03-02 09:44:33 playout
 1999-03-02 09:44:33 Start queue run: pid=pppp
-1999-03-02 09:44:33 10HmbB-0005vi-00 event tcp:connect
-1999-03-02 09:44:33 10HmbB-0005vi-00 event smtp:connect
-1999-03-02 09:44:33 10HmbB-0005vi-00 event smtp:ehlo
-1999-03-02 09:44:33 10HmbB-0005vi-00 event msg:rcpt:host:defer
-1999-03-02 09:44:33 10HmbB-0005vi-00 event msg:rcpt:defer
-1999-03-02 09:44:33 10HmbB-0005vi-00 event tcp:close
-1999-03-02 09:44:33 10HmbB-0005vi-00 == rmt_defer@test.ex R=r2 T=smtp defer (-44) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later
+1999-03-02 09:44:33 10HmbB-0005vi-00 == rmt_defer@test.ex routing defer (-51): retry time not reached
 1999-03-02 09:44:33 10HmbD-0005vi-00 <= <> R=10HmbB-0005vi-00 U=EXIMUSER P=local S=sss for c@dump.ex
-1999-03-02 09:44:33 10HmbC-0005vi-00 event tcp:connect
-1999-03-02 09:44:33 10HmbC-0005vi-00 event smtp:connect
-1999-03-02 09:44:33 10HmbC-0005vi-00 event smtp:ehlo
-1999-03-02 09:44:33 10HmbC-0005vi-00 event msg:rcpt:host:defer
-1999-03-02 09:44:33 10HmbC-0005vi-00 event msg:rcpt:defer
-1999-03-02 09:44:33 10HmbC-0005vi-00 event tcp:close
-1999-03-02 09:44:33 10HmbC-0005vi-00 == rmt_defer@test.ex R=r2 T=smtp defer (-44) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<rmt_defer@test.ex>: 451 Temporary local problem - please try later
+1999-03-02 09:44:33 10HmbC-0005vi-00 == rmt_defer@test.ex routing defer (-51): retry time not reached
 1999-03-02 09:44:33 End queue run: pid=pppp
 1999-03-02 09:44:33 10HmbB-0005vi-00 event msg:fail:internal
 1999-03-02 09:44:33 10HmbB-0005vi-00 event msg:complete
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<c@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
 1999-03-02 09:44:33 10HmbC-0005vi-00 <= d@dump.ex H=(testclient) [ip4.ip4.ip4.ip4] P=esmtp S=sss for rmt_defer@test.ex
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<d@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
-1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<c@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
-1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<d@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
 1999-03-02 09:44:33 10HmbE-0005vi-00 <= e@dump.ex H=(testclient) [ip4.ip4.ip4.ip4] P=esmtp S=sss for rmt_reject@test.ex
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<e@dump.ex> rejected RCPT <rmt_reject@test.ex>
index 3b9bea1..555a475 100644 (file)
@@ -3,6 +3,4 @@
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<a@dump.ex> rejected RCPT <rmt_reject@test.ex>
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<c@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<d@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
-1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<c@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
-1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<d@dump.ex> temporarily rejected RCPT <rmt_defer@test.ex>
 1999-03-02 09:44:33 H=localhost (myhost.test.ex) [127.0.0.1] F=<e@dump.ex> rejected RCPT <rmt_reject@test.ex>
index 64afd80..2739f29 100644 (file)
@@ -6,11 +6,11 @@ sudo exim -Mf $msg1
 ****
 # now 2 frozen, one of which is a bounce
 # check that ignore_bounce_errors_after finishes off the frozen bounce (only)
-millisleep 2500
-exim -qf
+#sleep 5
+exim -Tqt 5s/5s/ -qf
 ****
-sleep 3
+#sleep 6
 # check that timeout_frozen_after finishes off the (remaining) frozen
-exim -q
+exim -Tqt 11s/11s -q
 ****
 no_msglog_check
index 13d395f..69a53c6 100644 (file)
@@ -76,8 +76,9 @@ exim -q
 #
 # Client requests notification of deferral.  First time of trying, we get
 # a defer but queue-time probably has not hit the 1st retry time yet, so no DSN
-# will be sent and the message remains queued.  Later, after a sleep, we will
-# try again.
+# will be sent and the message remains queued.  Then, claiming time has elapsed,
+# we will look again (expecting a delay-DSN to be produced).  We won't see a
+# retry since the actual retry time has not passed.
 exim -z defer/delay
 ****
 client HOSTIPV4 PORT_D
@@ -126,7 +127,6 @@ QUIT
 ****
 exim -q
 ****
-sleep 3
 #
 #
 #
@@ -134,7 +134,7 @@ sleep 3
 # We should see the notify for c@dump.ex but not d@dump.ex
 exim -z playout
 ****
-exim -q
+exim -Tqt 10s/ -q
 ****
 sleep 1
 exim -Mrm $msg1 $msg2