Logging: better tracking of continued-connection use
[exim.git] / src / src / deliver.c
index 3dcd7f949c0f036ce528ffb0493eaec4f3a003f3..ef6eb22e2037cd19a8510ece30c6206d83d84e98 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;
@@ -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)
@@ -2125,7 +2125,7 @@ Arguments:
 Returns:     nothing
 */
 
-static void
+void
 deliver_local(address_item *addr, BOOL shadowing)
 {
 BOOL use_initgroups;
@@ -2152,18 +2152,16 @@ else
 
 if (tp->return_path)
   {
-  uschar *new_return_path = expand_string(tp->return_path);
-  if (!new_return_path)
-    {
-    if (!f.expand_string_forcedfail)
-      {
-      common_error(TRUE, addr, ERRNO_EXPANDFAIL,
-        US"Failed to expand return path \"%s\" in %s transport: %s",
-        tp->return_path, tp->name, expand_string_message);
-      return;
-      }
+  uschar * new_return_path = expand_string(tp->return_path);
+  if (new_return_path)
+    return_path = new_return_path;
+  else if (!f.expand_string_forcedfail)
+    {
+    common_error(TRUE, addr, ERRNO_EXPANDFAIL,
+      US"Failed to expand return path \"%s\" in %s transport: %s",
+      tp->return_path, tp->name, expand_string_message);
+    return;
     }
-  else return_path = new_return_path;
   }
 
 /* For local deliveries, one at a time, the value used for logging can just be
@@ -3193,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)))
       )
@@ -3578,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)
@@ -3591,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);
@@ -3601,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);
@@ -4272,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,
@@ -4350,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
@@ -4496,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
@@ -4882,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)
        {
@@ -5380,7 +5403,8 @@ Returns:       nothing
 static void
 print_dsn_diagnostic_code(const address_item *addr, FILE *f)
 {
-uschar *s = testflag(addr, af_pass_message) ? addr->message : NULL;
+uschar * s = testflag(addr, af_pass_message) ? addr->message : NULL;
+unsigned cnt;
 
 /* af_pass_message and addr->message set ? print remote host answer */
 if (s)
@@ -5392,19 +5416,32 @@ if (s)
   if (!(s = Ustrstr(addr->message, ": ")))
     return;                            /* not found, bail out */
   s += 2;  /* skip ": " */
-  fprintf(f, "Diagnostic-Code: smtp; ");
+  cnt = fprintf(f, "Diagnostic-Code: smtp; ");
   }
 /* no message available. do nothing */
 else return;
 
 while (*s)
+  {
+  if (cnt > 950)       /* RFC line length limit: 998 */
+    {
+    DEBUG(D_deliver) debug_printf("print_dsn_diagnostic_code() truncated line\n");
+    fputs("[truncated]", f);
+    break;
+    }
+
   if (*s == '\\' && s[1] == 'n')
     {
     fputs("\n ", f);    /* as defined in RFC 3461 */
     s += 2;
+    cnt += 2;
     }
   else
+    {
     fputc(*s++, f);
+    cnt++;
+    }
+  }
 
 fputc('\n', f);
 }
@@ -6797,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)
@@ -7052,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;
     }
@@ -7831,11 +7878,11 @@ wording. */
            fprintf(fp, "Remote-MTA: X-ip; [%s]%s\n", hu->address, p);
            }
          if ((s = addr->smtp_greeting) && *s)
-           fprintf(fp, "X-Remote-MTA-smtp-greeting: X-str; %s\n", s);
+           fprintf(fp, "X-Remote-MTA-smtp-greeting: X-str; %.900s\n", s);
          if ((s = addr->helo_response) && *s)
-           fprintf(fp, "X-Remote-MTA-helo-response: X-str; %s\n", s);
+           fprintf(fp, "X-Remote-MTA-helo-response: X-str; %.900s\n", s);
          if ((s = addr->message) && *s)
-           fprintf(fp, "X-Exim-Diagnostic: X-str; %s\n", s);
+           fprintf(fp, "X-Exim-Diagnostic: X-str; %.900s\n", s);
          }
 #endif
          print_dsn_diagnostic_code(addr, fp);
@@ -8389,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;
@@ -8522,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)