Log queue_time and queue_time_overall exclusive of receive time. Bug 2672
[exim.git] / src / src / deliver.c
index dd922c72828c79819b3dd4edf1e9b00312078ad3..0cddec7584a38cf6c635d0fa23b87ed06f9c5bc5 100644 (file)
@@ -460,6 +460,9 @@ TRUE if the lists refer to the same hosts in the same order, except that
 This enables Exim to use a single SMTP transaction for sending to two entirely
 different domains that happen to end up pointing at the same hosts.
 
+We do not try to batch up different A-record host names that refer to the
+same IP.
+
 Arguments:
   one       points to the first host list
   two       points to the second host list
@@ -789,6 +792,9 @@ g = string_append(g, 3, US" [", h->address, US"]");
 if (LOGGING(outgoing_port))
   g = string_fmt_append(g, ":%d", h->port);
 
+if (continue_sequence > 1)             /*XXX this is wrong for a dropped proxyconn.  Would have to pass back from transport */
+  g = string_catn(g, US"*", 1);
+
 #ifdef SUPPORT_SOCKS
 if (LOGGING(proxy) && proxy_local_address)
   {
@@ -1192,8 +1198,6 @@ else
   if (addr->host_used)
     {
     g = d_hostlog(g, addr);
-    if (continue_sequence > 1)
-      g = string_catn(g, US"*", 1);
 
 #ifndef DISABLE_EVENT
     deliver_host_address = addr->host_used->address;
@@ -1265,8 +1269,8 @@ if (  LOGGING(smtp_confirmation)
 /* Time on queue and actual time taken to deliver */
 
 if (LOGGING(queue_time))
-  g = string_append(g, 2, US" QT=",
-    string_timesince(&received_time));
+  g = string_append(g, 2, US" QT=", string_timesince(
+    LOGGING(queue_time_exclusive) ? &received_time_complete : &received_time));
 
 if (LOGGING(deliver_time))
   g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time));
@@ -1322,20 +1326,10 @@ else if (driver_kind)
 g = string_fmt_append(g, " defer (%d)", addr->basic_errno);
 
 if (addr->basic_errno > 0)
-  g = string_append(g, 2, US": ",
-    US strerror(addr->basic_errno));
+  g = string_append(g, 2, US": ", US strerror(addr->basic_errno));
 
 if (addr->host_used)
-  {
-  g = string_append(g, 5,
-                   US" H=", addr->host_used->name,
-                   US" [",  addr->host_used->address, US"]");
-  if (LOGGING(outgoing_port))
-    {
-    int port = addr->host_used->port;
-    g = string_fmt_append(g, ":%d", port == PORT_NONE ? 25 : port);
-    }
-  }
+  g = d_hostlog(g, addr);
 
 if (LOGGING(deliver_time))
   g = string_append(g, 2, US" DT=", string_timediff(&addr->delivery_time));
@@ -1586,6 +1580,12 @@ if (addr->return_file >= 0 && addr->return_filename)
   (void)close(addr->return_file);
   }
 
+/* Check if the transport notifed continue-conn status explicitly, and
+update our knowlege. */
+
+if (testflag(addr, af_new_conn))       continue_sequence = 1;
+else if (testflag(addr, af_cont_conn)) continue_sequence++;
+
 /* The success case happens only after delivery by a transport. */
 
 if (result == OK)
@@ -3191,6 +3191,7 @@ const uschar *listptr = remote_sort_domains;
 uschar *pattern;
 uschar patbuf[256];
 
+/*XXX The list is used before expansion. Not sure how that ties up with the docs */
 while (  *aptr
       && (pattern = string_nextinlist(&listptr, &sep, patbuf, sizeof(patbuf)))
       )
@@ -3576,7 +3577,13 @@ while (!done)
 
       switch (*subid)
        {
-  #ifdef SUPPORT_SOCKS
+       case 3:         /* explicit notification of continued-connection (non)use;
+                       overrides caller's knowlege. */
+         if (*ptr & BIT(1))      setflag(addr, af_new_conn);
+         else if (*ptr & BIT(2)) setflag(addr, af_cont_conn);
+         break;
+
+#ifdef SUPPORT_SOCKS
        case '2':       /* proxy information; must arrive before A0 and applies to that addr XXX oops*/
          proxy_session = TRUE; /*XXX should this be cleared somewhere? */
          if (*ptr == 0)
@@ -3589,9 +3596,9 @@ while (!done)
            ptr += sizeof(proxy_local_port);
            }
          break;
-  #endif
+#endif
 
-  #ifdef EXPERIMENTAL_DSN_INFO
+#ifdef EXPERIMENTAL_DSN_INFO
        case '1':       /* must arrive before A0, and applies to that addr */
                        /* Two strings: smtp_greeting and helo_response */
          addr->smtp_greeting = string_copy(ptr);
@@ -3599,7 +3606,7 @@ while (!done)
          addr->helo_response = string_copy(ptr);
          while(*ptr++);
          break;
-  #endif
+#endif
 
        case '0':
          DEBUG(D_deliver) debug_printf("A0 %s tret %d\n", addr->address, *ptr);
@@ -4270,6 +4277,10 @@ for (int delivery_count = 0; addr_remote; delivery_count++)
       }
     }
 
+/*XXX need to defeat this when DANE is used - but we don't know that yet.
+So look out for the place it gets used.
+*/
+
   /* Get the flag which specifies whether the transport can handle different
   domains that nevertheless resolve to the same set of hosts. If it needs
   expanding, get variables set: $address_data, $domain_data, $localpart_data,
@@ -4348,6 +4359,11 @@ for (int delivery_count = 0; addr_remote; delivery_count++)
   /************************************************************************/
 
 
+/*XXX don't know yet if DANE will be used.  So tpt will have to
+check at the point if gets next addr from list, and skip/defer any
+nonmatch domains
+*/
+
   /* Pick off all addresses which have the same transport, errors address,
   destination, and extra headers. In some cases they point to the same host
   list, but we also need to check for identical host lists generated from
@@ -4494,6 +4510,7 @@ for (int delivery_count = 0; addr_remote; delivery_count++)
   if (continue_transport)
     {
     BOOL ok = Ustrcmp(continue_transport, tp->name) == 0;
+/*XXX do we need to check for a DANEd conn vs. a change of domain? */
 
     /* If the transport is about to override the host list do not check
     it here but take the cost of running the transport process to discover
@@ -4880,6 +4897,14 @@ all pipes, so I do not see a reason to use non-blocking IO here
         rmt_dlv_checked_write(fd, 'R', '0', big_buffer, ptr - big_buffer);
         }
 
+      if (testflag(addr, af_new_conn) || testflag(addr, af_cont_conn))
+       {
+       DEBUG(D_deliver) debug_printf("%scontinued-connection\n",
+         testflag(addr, af_new_conn) ? "non-" : "");
+       big_buffer[0] = testflag(addr, af_new_conn) ? BIT(1) : BIT(2);
+        rmt_dlv_checked_write(fd, 'A', '3', big_buffer, 1);
+       }
+
 #ifdef SUPPORT_SOCKS
       if (LOGGING(proxy) && proxy_session)
        {
@@ -6809,7 +6834,7 @@ while (addr_new)           /* Loop until all addresses dealt with */
       addr_route = addr->next;
 
       deliver_domain = addr->domain;  /* set $domain */
-      if ((rc = match_isinlist(addr->domain, (const uschar **)&queue_domains, 0,
+      if ((rc = match_isinlist(addr->domain, CUSS &queue_domains, 0,
             &domainlist_anchor, addr->domain_cache, MCL_DOMAIN, TRUE, NULL))
               != OK)
         if (rc == DEFER)
@@ -7064,13 +7089,23 @@ if (  mua_wrapper
 
 
 /* If this is a run to continue deliveries to an external channel that is
-already set up, defer any local deliveries. */
+already set up, defer any local deliveries.
 
-if (continue_transport)
+jgh 2020/12/20: I don't see why; locals should be quick.
+The defer goes back to version 1.62 in 1997.  A local being still deliverable
+during a continued run might result from something like a defer during the
+original delivery, eg. in a DB lookup.  Unlikely but possible.
+
+To avoid delaying a local when combined with a callout-hold for a remote
+delivery, test continue_sequence rather than continue_transport. */
+
+if (continue_sequence > 1 && addr_local)
   {
+  DEBUG(D_deliver|D_retry|D_route)
+    debug_printf("deferring local deliveries due to continued-transport\n");
   if (addr_defer)
     {
-    address_item *addr = addr_defer;
+    address_item * addr = addr_defer;
     while (addr->next) addr = addr->next;
     addr->next = addr_local;
     }
@@ -8401,7 +8436,7 @@ else if (addr_defer != (address_item *)(+1))
   /* If this was a first delivery attempt, unset the first time flag, and
   ensure that the spool gets updated. */
 
-  if (f.deliver_firsttime)
+  if (f.deliver_firsttime && !f.queue_2stage)
     {
     f.deliver_firsttime = FALSE;
     update_spool = TRUE;
@@ -8534,52 +8569,6 @@ f.tcp_fastopen_ok = TRUE;
 }
 
 
-uschar *
-deliver_get_sender_address (uschar * id)
-{
-int rc;
-uschar * new_sender_address,
-       * save_sender_address;
-BOOL save_qr = f.queue_running;
-uschar * spoolname;
-
-/* make spool_open_datafile non-noisy on fail */
-
-f.queue_running = TRUE;
-
-/* Side effect: message_subdir is set for the (possibly split) spool directory */
-
-deliver_datafile = spool_open_datafile(id);
-f.queue_running = save_qr;
-if (deliver_datafile < 0)
-  return NULL;
-
-/* Save and restore the global sender_address.  I'm not sure if we should
-not save/restore all the other global variables too, because
-spool_read_header() may change all of them. But OTOH, when this
-deliver_get_sender_address() gets called, the current message is done
-already and nobody needs the globals anymore. (HS12, 2015-08-21) */
-
-spoolname = string_sprintf("%s-H", id);
-save_sender_address = sender_address;
-
-rc = spool_read_header(spoolname, TRUE, TRUE);
-
-new_sender_address = sender_address;
-sender_address = save_sender_address;
-
-if (rc != spool_read_OK)
-  return NULL;
-
-assert(new_sender_address);
-
-(void)close(deliver_datafile);
-deliver_datafile = -1;
-
-return new_sender_address;
-}
-
-
 
 void
 delivery_re_exec(int exec_type)