Transport: fix smtp under combo of mua_wrapper and limited max_rcpt
[exim.git] / src / src / transports / smtp.c
index e177ee9c31d8b197a8b8146fa58d17234b420aae..997281901b7b90d546e6899a1304074bdd18a00e 100644 (file)
@@ -87,6 +87,8 @@ optionlist smtp_transport_options[] = {
 #ifdef SUPPORT_TLS
   { "hosts_nopass_tls",     opt_stringptr,
       (void *)offsetof(smtp_transport_options_block, hosts_nopass_tls) },
+  { "hosts_noproxy_tls",    opt_stringptr,
+      (void *)offsetof(smtp_transport_options_block, hosts_noproxy_tls) },
 #endif
   { "hosts_override",       opt_bool,
       (void *)offsetof(smtp_transport_options_block, hosts_override) },
@@ -218,7 +220,10 @@ smtp_transport_options_block smtp_transport_option_defaults = {
   NULL,                /* hosts_verify_avoid_tls */
   NULL,                /* hosts_avoid_pipelining */
   NULL,                /* hosts_avoid_esmtp */
+#ifdef SUPPORT_TLS
   NULL,                /* hosts_nopass_tls */
+  US"*",              /* hosts_noproxy_tls */
+#endif
   5*60,                /* command_timeout */
   5*60,                /* connect_timeout; shorter system default overrides */
   5*60,                /* data timeout */
@@ -283,6 +288,8 @@ static uschar *smtp_command;                /* Points to last cmd for error messages */
 static uschar *mail_command;           /* Points to MAIL cmd for error messages */
 static uschar *data_command = US"";    /* Points to DATA cmd for error messages */
 static BOOL    update_waiting;         /* TRUE to update the "wait" database */
+
+/*XXX move to smtp_context */
 static BOOL    pipelining_active;      /* current transaction is in pipe mode */
 
 
@@ -789,7 +796,9 @@ with an address by scanning for the next address whose status is PENDING_DEFER.
 
 while (count-- > 0)
   {
-  while (addr->transport_return != PENDING_DEFER) addr = addr->next;
+  while (addr->transport_return != PENDING_DEFER)
+    if (!(addr = addr->next))
+      return -2;
 
   /* The address was accepted */
   addr->host_used = sx->host;
@@ -1340,15 +1349,22 @@ return checks;
 If given a nonzero size, first flush any buffered SMTP commands
 then emit the command.
 
-Reap previous SMTP command responses if requested.
-Reap one SMTP command response if requested.
+Reap previous SMTP command responses if requested, and always reap
+the response from a previous BDAT command.
+
+Args:
+ tctx          transport context
+ chunk_size    value for SMTP BDAT command
+ flags
+   tc_chunk_last       add LAST option to SMTP BDAT command
+   tc_reap_prev                reap response to previous SMTP commands
 
 Returns:       OK or ERROR
 */
 
 static int
-smtp_chunk_cmd_callback(int fd, transport_ctx * tctx,
-  unsigned chunk_size, unsigned flags)
+smtp_chunk_cmd_callback(transport_ctx * tctx, unsigned chunk_size,
+  unsigned flags)
 {
 smtp_transport_options_block * ob =
   (smtp_transport_options_block *)(tctx->tblock->options_block);
@@ -1409,7 +1425,7 @@ if (sx->pending_BDAT)
     if (errno == 0 && sx->buffer[0] == '4')
       {
       errno = ERRNO_DATA4XX;   /*XXX does this actually get used? */
-      sx->first_addr->more_errno |=
+      sx->addrlist->more_errno |=
        ((sx->buffer[1] - '0')*10 + sx->buffer[2] - '0') << 8;
       }
     return ERROR;
@@ -1551,7 +1567,7 @@ if (continue_hostname == NULL)
     uschar * msg = NULL;
     if (sx->verify)
       {
-      msg = strerror(errno);
+      msg = US strerror(errno);
       HDEBUG(D_verify) debug_printf("connect: %s\n", msg);
       }
     set_errno_nohost(sx->addrlist,
@@ -1796,9 +1812,11 @@ goto SEND_QUIT;
     }
   }
 
-/* For continuing deliveries down the same channel, the socket is the standard
-input, and we don't need to redo EHLO here (but may need to do so for TLS - see
-below). Set up the pointer to where subsequent commands will be left, for
+/* For continuing deliveries down the same channel, having re-exec'd  the socket
+is the standard input; for a socket held open from verify it is recorded
+in the cutthrough context block.  Either way we don't need to redo EHLO here
+(but may need to do so for TLS - see below).
+Set up the pointer to where subsequent commands will be left, for
 error messages. Note that smtp_peer_options will have been
 set from the command line if they were set in the process that passed the
 connection on. */
@@ -1810,10 +1828,33 @@ separate - we could match up by host ip+port as a bodge. */
 
 else
   {
-  sx->inblock.sock = sx->outblock.sock = fileno(stdin);
+  if (cutthrough.fd >= 0 && cutthrough.callout_hold_only)
+    {
+    sx->inblock.sock = sx->outblock.sock = cutthrough.fd;
+    sx->host->port = sx->port = cutthrough.host.port;
+    }
+  else
+    {
+    sx->inblock.sock = sx->outblock.sock = 0;  /* stdin */
+    sx->host->port = sx->port;    /* Record the port that was used */
+    }
   smtp_command = big_buffer;
-  sx->host->port = sx->port;    /* Record the port that was used */
   sx->helo_data = NULL;                /* ensure we re-expand ob->helo_data */
+
+  /* For a continued connection with TLS being proxied for us, or a
+  held-open verify connection with TLS, nothing more to do. */
+
+  if (  continue_proxy_cipher
+     || (cutthrough.fd >= 0 && cutthrough.callout_hold_only && cutthrough.is_tls)
+     )
+    {
+    sx->peer_offered = smtp_peer_options;
+    pipelining_active = !!(smtp_peer_options & PEER_OFFERED_PIPE);
+    HDEBUG(D_transport) debug_printf("continued connection, %s TLS\n",
+      continue_proxy_cipher ? "proxied" : "verify conn with");
+    return OK;
+    }
+  HDEBUG(D_transport) debug_printf("continued connection, no TLS\n");
   }
 
 /* If TLS is available on this connection, whether continued or not, attempt to
@@ -1863,11 +1904,12 @@ if (  smtp_peer_options & PEER_OFFERED_TLS
   TLS_NEGOTIATE:
     {
     address_item * addr;
-    int rc = tls_client_start(sx->inblock.sock, sx->host, sx->addrlist, sx->tblock
+    uschar * errstr;
+    int rc = tls_client_start(sx->inblock.sock, sx->host, sx->addrlist, sx->tblock,
 # ifdef EXPERIMENTAL_DANE
-                            , sx->dane ? &tlsa_dnsa : NULL
+                            sx->dane ? &tlsa_dnsa : NULL,
 # endif
-                            );
+                            &errstr);
 
     /* TLS negotiation failed; give an error. From outside, this function may
     be called again to try in clear on a new connection, if the options permit
@@ -1877,12 +1919,12 @@ if (  smtp_peer_options & PEER_OFFERED_TLS
       {
 # ifdef EXPERIMENTAL_DANE
       if (sx->dane) log_write(0, LOG_MAIN,
-         "DANE attempt failed; no TLS connection to %s [%s]",
-         sx->host->name, sx->host->address);
+         "DANE attempt failed; TLS connection to %s [%s]: %s",
+         sx->host->name, sx->host->address, errstr);
 # endif
 
       errno = ERRNO_TLSFAILURE;
-      message = US"failure while setting up TLS session";
+      message = string_sprintf("TLS session: %s", errstr);
       sx->send_quit = FALSE;
       goto TLS_FAILED;
       }
@@ -2166,7 +2208,7 @@ writing RSET might have failed, or there may be other addresses whose hosts are
 specified in the transports, and therefore not visible at top level, in which
 case continue_more won't get set. */
 
-HDEBUG(D_transport|D_acl|D_v) debug_printf("  SMTP(close)>>\n");
+HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("  SMTP(close)>>\n");
 if (sx->send_quit)
   {
   shutdown(sx->outblock.sock, SHUT_WR);
@@ -2435,7 +2477,8 @@ for (addr = sx->first_addr, address_count = 0;
     ? dsn_support_yes : dsn_support_no;
 
   address_count++;
-  no_flush = pipelining_active && !sx->verify && (!mua_wrapper || addr->next);
+  no_flush = pipelining_active && !sx->verify
+         && (!mua_wrapper || addr->next && address_count < sx->max_rcpt);
 
   build_rcptcmd_options(sx, addr);
 
@@ -2488,6 +2531,94 @@ return 0;
 }
 
 
+#ifdef SUPPORT_TLS
+/*****************************************************
+* Proxy TLS connection for another transport process *
+******************************************************/
+/*
+Use the given buffer as a staging area, and select on both the given fd
+and the TLS'd client-fd for data to read (per the coding in ip_recv() and
+fd_ready() this is legitimate).  Do blocking full-size writes, and reads
+under a timeout.
+
+Arguments:
+  buf          space to use for buffering
+  bufsiz       size of buffer
+  proxy_fd     comms to proxied process
+  timeout      per-read timeout, seconds
+*/
+
+void
+smtp_proxy_tls(uschar * buf, size_t bsize, int proxy_fd, int timeout)
+{
+fd_set fds;
+int max_fd = MAX(proxy_fd, tls_out.active) + 1;
+int rc, i, fd_bits, nbytes;
+
+set_process_info("proxying TLS connection for continued transport");
+FD_ZERO(&fds);
+FD_SET(tls_out.active, &fds);
+FD_SET(proxy_fd, &fds);
+
+for (fd_bits = 3; fd_bits; )
+  {
+  time_t time_left = timeout;
+  time_t time_start = time(NULL);
+
+  /* wait for data */
+  do
+    {
+    struct timeval tv = { time_left, 0 };
+
+    rc = select(max_fd, (SELECT_ARG2_TYPE *)&fds, NULL, NULL, &tv);
+
+    if (rc < 0 && errno == EINTR)
+      if ((time_left -= time(NULL) - time_start) > 0) continue;
+
+    if (rc <= 0)
+      {
+      DEBUG(D_transport) if (rc == 0) debug_printf("%s: timed out\n", __FUNCTION__);
+      return;
+      }
+    }
+  while (rc < 0 || !(FD_ISSET(tls_out.active, &fds) || FD_ISSET(proxy_fd, &fds)));
+
+  /* handle inbound data */
+  if (FD_ISSET(tls_out.active, &fds))
+    if ((rc = tls_read(FALSE, buf, bsize)) <= 0)
+      {
+      fd_bits &= ~1;
+      FD_CLR(tls_out.active, &fds);
+      shutdown(proxy_fd, SHUT_WR);
+      }
+    else
+      {
+      for (nbytes = 0; rc - nbytes > 0; nbytes += i)
+       if ((i = write(proxy_fd, buf + nbytes, rc - nbytes)) < 0) return;
+      }
+  else if (fd_bits & 1)
+    FD_SET(tls_out.active, &fds);
+
+  /* handle outbound data */
+  if (FD_ISSET(proxy_fd, &fds))
+    if ((rc = read(proxy_fd, buf, bsize)) <= 0)
+      {
+      fd_bits &= ~2;
+      FD_CLR(proxy_fd, &fds);
+      shutdown(tls_out.active, SHUT_WR);
+      }
+    else
+      {
+      for (nbytes = 0; rc - nbytes > 0; nbytes += i)
+       if ((i = tls_write(FALSE, buf + nbytes, rc - nbytes)) < 0) return;
+      }
+  else if (fd_bits & 2)
+    FD_SET(proxy_fd, &fds);
+  }
+}
+#endif
+
+
 /*************************************************
 *       Deliver address list to given host       *
 *************************************************/
@@ -2573,17 +2704,14 @@ set it up. This cannot be done until the identify of the host is known. */
 
 if (tblock->filter_command)
   {
-  BOOL rc;
-  uschar fbuf[64];
-  sprintf(CS fbuf, "%.50s transport", tblock->name);
-  rc = transport_set_up_command(&transport_filter_argv, tblock->filter_command,
-    TRUE, DEFER, addrlist, fbuf, NULL);
   transport_filter_timeout = tblock->filter_timeout;
 
   /* On failure, copy the error to all addresses, abandon the SMTP call, and
   yield ERROR. */
 
-  if (!rc)
+  if (!transport_set_up_command(&transport_filter_argv,
+       tblock->filter_command, TRUE, DEFER, addrlist,
+       string_sprintf("%.50s transport", tblock->name), NULL))
     {
     set_errno_nohost(addrlist->next, addrlist->basic_errno, addrlist->message, DEFER,
       FALSE);
@@ -2602,6 +2730,7 @@ if (tblock->filter_command)
     }
   }
 
+sx.first_addr = addrlist;
 
 /* For messages that have more than the maximum number of envelope recipients,
 we want to send several transactions down the same SMTP connection. (See
@@ -2613,39 +2742,61 @@ transaction to handle. */
 
 SEND_MESSAGE:
 sx.from_addr = return_path;
-sx.first_addr = sx.sync_addr = addrlist;
+sx.sync_addr = sx.first_addr;
 sx.ok = FALSE;
 sx.send_rset = TRUE;
 sx.completed_addr = FALSE;
 
 
-/* Initiate a message transfer. */
+/* If we are a continued-connection-after-verify the MAIL and RCPT
+commands were already sent; do not re-send but do mark the addrs as
+having been accepted up to RCPT stage.  A traditional cont-conn
+always has a sequence number greater than one. */
 
-switch(smtp_write_mail_and_rcpt_cmds(&sx, &yield))
+if (continue_hostname && continue_sequence == 1)
   {
-  case 0:              break;
-  case -1: case -2:    goto RESPONSE_FAILED;
-  case -3:             goto END_OFF;
-  case -4:             goto SEND_QUIT;
-  default:             goto SEND_FAILED;
-  }
+  address_item * addr;
 
-/* If we are an MUA wrapper, abort if any RCPTs were rejected, either
-permanently or temporarily. We should have flushed and synced after the last
-RCPT. */
+  sx.peer_offered = smtp_peer_options;
+  sx.pending_MAIL = FALSE;
+  sx.ok = TRUE;
+  sx.next_addr = NULL;
 
-if (mua_wrapper)
+  for (addr = addrlist; addr; addr = addr->next)
+    addr->transport_return = PENDING_OK;
+  }
+else
   {
-  address_item *badaddr;
-  for (badaddr = sx.first_addr; badaddr; badaddr = badaddr->next)
-    if (badaddr->transport_return != PENDING_OK)
-      {
-      /*XXX could we find a better errno than 0 here? */
-      set_errno_nohost(addrlist, 0, badaddr->message, FAIL,
-       testflag(badaddr, af_pass_message));
-      sx.ok = FALSE;
-      break;
-      }
+  /* Initiate a message transfer. */
+
+  switch(smtp_write_mail_and_rcpt_cmds(&sx, &yield))
+    {
+    case 0:            break;
+    case -1: case -2:  goto RESPONSE_FAILED;
+    case -3:           goto END_OFF;
+    case -4:           goto SEND_QUIT;
+    default:           goto SEND_FAILED;
+    }
+
+  /* If we are an MUA wrapper, abort if any RCPTs were rejected, either
+  permanently or temporarily. We should have flushed and synced after the last
+  RCPT. */
+
+  if (mua_wrapper)
+    {
+    address_item * a;
+    unsigned cnt;
+
+    for (a = sx.first_addr, cnt = 0; a && cnt < sx.max_rcpt; a = a->next, cnt++)
+      if (a->transport_return != PENDING_OK)
+       {
+       /*XXX could we find a better errno than 0 here? */
+       set_errno_nohost(addrlist, 0, a->message, FAIL,
+         testflag(a, af_pass_message));
+       sx.ok = FALSE;
+       break;
+       }
+    }
   }
 
 /* If ok is TRUE, we know we have got at least one good recipient, and must now
@@ -2744,7 +2895,8 @@ else
   transport_count = 0;
 
 #ifndef DISABLE_DKIM
-  sx.ok = dkim_transport_write_message(sx.inblock.sock, &tctx, &sx.ob->dkim);
+  sx.ok = dkim_transport_write_message(sx.inblock.sock, &tctx, &sx.ob->dkim,
+           CUSS &message);
 #else
   sx.ok = transport_write_message(sx.inblock.sock, &tctx, 0);
 #endif
@@ -2761,7 +2913,8 @@ else
   Or, when CHUNKING, it can be a protocol-detected failure. */
 
   if (!sx.ok)
-    goto RESPONSE_FAILED;
+    if (message) goto SEND_FAILED;
+    else         goto RESPONSE_FAILED;
 
   /* We used to send the terminating "." explicitly here, but because of
   buffering effects at both ends of TCP/IP connections, you don't gain
@@ -2943,7 +3096,7 @@ else
         else
           sprintf(CS sx.buffer, "%.500s\n", addr->unique);
 
-        DEBUG(D_deliver) debug_printf("journalling %s\n", sx.buffer);
+        DEBUG(D_deliver) debug_printf("S:journalling %s\n", sx.buffer);
         len = Ustrlen(CS sx.buffer);
         if (write(journal_fd, sx.buffer, len) != len)
           log_write(0, LOG_MAIN|LOG_PANIC, "failed to write journal for "
@@ -3026,8 +3179,8 @@ if (!sx.ok)
     {
     save_errno = errno;
     code = '4';
-    message = US string_sprintf("send() to %s [%s] failed: %s",
-      host->name, host->address, strerror(save_errno));
+    message = string_sprintf("send() to %s [%s] failed: %s",
+      host->name, host->address, message ? message : US strerror(save_errno));
     sx.send_quit = FALSE;
     goto FAILED;
     }
@@ -3168,10 +3321,13 @@ if (sx.completed_addr && sx.ok && sx.send_quit)
 
   if (  sx.first_addr != NULL
      || continue_more
-     || (  (  tls_out.active < 0
+     || (
+#ifdef SUPPORT_TLS
+          (  tls_out.active < 0  &&  !continue_proxy_cipher
            || verify_check_given_host(&sx.ob->hosts_nopass_tls, host) != OK
           )
         &&
+#endif
            transport_check_waiting(tblock->name, host->name,
              tblock->connection_max_messages, new_message_id, &more,
             (oicf)smtp_are_same_identities, (void*)&t_compare)
@@ -3204,29 +3360,51 @@ if (sx.completed_addr && sx.ok && sx.send_quit)
 
     if (sx.ok)
       {
-      if (sx.first_addr != NULL)            /* More addresses still to be sent */
+      int pfd[2];
+      int socket_fd = sx.inblock.sock;
+
+
+      if (sx.first_addr != NULL)         /* More addresses still to be sent */
         {                                /*   in this run of the transport */
         continue_sequence++;             /* Causes * in logging */
         goto SEND_MESSAGE;
         }
       if (continue_more) return yield;   /* More addresses for another run */
 
-      /* Pass the socket to a new Exim process. Before doing so, we must shut
-      down TLS. Not all MTAs allow for the continuation of the SMTP session
-      when TLS is shut down. We test for this by sending a new EHLO. If we
-      don't get a good response, we don't attempt to pass the socket on. */
-
+      /* Pass the connection on to a new Exim process. */
 #ifdef SUPPORT_TLS
       if (tls_out.active >= 0)
-        {
-        tls_close(FALSE, TRUE);
-       smtp_peer_options = smtp_peer_options_wrap;
-       sx.ok = !sx.smtps
-          && smtp_write_command(&sx.outblock, FALSE,
-                                   "EHLO %s\r\n", sx.helo_data) >= 0
-         && smtp_read_response(&sx.inblock, sx.buffer, sizeof(sx.buffer),
-                                   '2', sx.ob->command_timeout);
-        }
+       if (verify_check_given_host(&sx.ob->hosts_noproxy_tls, host) == OK)
+         {
+         /* Pass the socket, for direct use, to a new Exim process. Before
+         doing so, we must shut down TLS. Not all MTAs allow for the
+         continuation of the SMTP session when TLS is shut down. We test for
+         this by sending a new EHLO. If we don't get a good response, we don't
+         attempt to pass the socket on. */
+
+         tls_close(FALSE, TRUE);
+         smtp_peer_options = smtp_peer_options_wrap;
+         sx.ok = !sx.smtps
+           && smtp_write_command(&sx.outblock, FALSE,
+                                     "EHLO %s\r\n", sx.helo_data) >= 0
+           && smtp_read_response(&sx.inblock, sx.buffer, sizeof(sx.buffer),
+                                     '2', sx.ob->command_timeout);
+         }
+       else
+         {
+         /* Set up a pipe for proxying TLS for the new transport process */
+
+         smtp_peer_options |= PEER_OFFERED_TLS;
+         if (sx.ok = (socketpair(AF_UNIX, SOCK_STREAM, 0, pfd) == 0))
+           socket_fd = pfd[1];
+         else
+           set_errno(sx.first_addr, errno, US"internal allocation problem",
+                   DEFER, FALSE, host
+# ifdef EXPERIMENTAL_DSN_INFO
+                   , sx.smtp_greeting, sx.helo_response
+# endif
+                   );
+         }
 #endif
 
       /* If the socket is successfully passed, we mustn't send QUIT (or
@@ -3236,13 +3414,42 @@ if (sx.completed_addr && sx.ok && sx.send_quit)
 propagate it from the initial
 */
       if (sx.ok && transport_pass_socket(tblock->name, host->name,
-           host->address, new_message_id, sx.inblock.sock))
+           host->address, new_message_id, socket_fd))
+       {
         sx.send_quit = FALSE;
+
+       /* If TLS is still active, we need to proxy it for the transport we
+       just passed the baton to.  Fork a child to to do it, and return to
+       get logging done asap.  Which way to place the work makes assumptions
+       about post-fork prioritisation which may not hold on all platforms. */
+#ifdef SUPPORT_TLS
+       if (tls_out.active >= 0)
+         {
+         int pid = fork();
+         if (pid > 0)          /* parent */
+           {
+           waitpid(pid, NULL, 0);
+           tls_close(FALSE, FALSE);
+           (void)close(sx.inblock.sock);
+           continue_transport = NULL;
+           continue_hostname = NULL;
+           return yield;
+           }
+         else if (pid == 0)    /* child; fork again to disconnect totally */
+           {
+           if ((pid = fork()))
+             _exit(pid ? EXIT_FAILURE : EXIT_SUCCESS);
+           smtp_proxy_tls(sx.buffer, sizeof(sx.buffer), pfd[0], sx.ob->command_timeout);
+           exim_exit(0);
+           }
+         }
+#endif
+       }
       }
 
     /* If RSET failed and there are addresses left, they get deferred. */
-
-    else set_errno(sx.first_addr, errno, msg, DEFER, FALSE, host
+    else
+      set_errno(sx.first_addr, errno, msg, DEFER, FALSE, host
 #ifdef EXPERIMENTAL_DSN_INFO
                  , sx.smtp_greeting, sx.helo_response
 #endif
@@ -3287,7 +3494,7 @@ writing RSET might have failed, or there may be other addresses whose hosts are
 specified in the transports, and therefore not visible at top level, in which
 case continue_more won't get set. */
 
-HDEBUG(D_transport|D_acl|D_v) debug_printf("  SMTP(close)>>\n");
+HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("  SMTP(close)>>\n");
 if (sx.send_quit)
   {
   shutdown(sx.outblock.sock, SHUT_WR);
@@ -3451,8 +3658,10 @@ DEBUG(D_transport)
     for (host = hostlist; host; host = host->next)
       debug_printf("  %s:%d\n", host->name, host->port);
     }
-  if (continue_hostname) debug_printf("already connected to %s [%s]\n",
-      continue_hostname, continue_host_address);
+  if (continue_hostname)
+    debug_printf("already connected to %s [%s] (on fd %d)\n",
+      continue_hostname, continue_host_address,
+      cutthrough.fd >= 0 ? cutthrough.fd : 0);
   }
 
 /* Set the flag requesting that these hosts be added to the waiting
@@ -3717,7 +3926,7 @@ for (cutoff_retry = 0;
       commonly points to a configuration error, but the best action is still
       to carry on for the next host. */
 
-      if (rc == HOST_FIND_AGAIN || rc == HOST_FIND_FAILED)
+      if (rc == HOST_FIND_AGAIN || rc == HOST_FIND_SECURITY || rc == HOST_FIND_FAILED)
         {
         retry_add_item(addrlist, string_sprintf("R:%s", host->name), 0);
         expired = FALSE;
@@ -3730,8 +3939,11 @@ for (cutoff_retry = 0;
           {
           if (addr->transport_return != DEFER) continue;
           addr->basic_errno = ERRNO_UNKNOWNHOST;
-          addr->message =
-            string_sprintf("failed to lookup IP address for %s", host->name);
+          addr->message = string_sprintf(
+           rc == HOST_FIND_SECURITY
+             ? "lookup of IP address for %s was insecure"
+             : "failed to lookup IP address for %s",
+           host->name);
           }
         continue;
         }
@@ -3849,7 +4061,7 @@ for (cutoff_retry = 0;
       host_is_expired = retry_check_address(addrlist->domain, host, pistring,
         incl_ip, &retry_host_key, &retry_message_key);
 
-      DEBUG(D_transport) debug_printf("%s [%s]%s status = %s\n", host->name,
+      DEBUG(D_transport) debug_printf("%s [%s]%s retry-status = %s\n", host->name,
         (host->address == NULL)? US"" : host->address, pistring,
         (host->status == hstatus_usable)? "usable" :
         (host->status == hstatus_unusable)? "unusable" :
@@ -3870,6 +4082,7 @@ for (cutoff_retry = 0;
            {
            case hwhy_retry: hosts_retry++; break;
            case hwhy_failed:  hosts_fail++; break;
+           case hwhy_insecure:
            case hwhy_deferred: hosts_defer++; break;
            }
 
@@ -4053,8 +4266,9 @@ for (cutoff_retry = 0;
         && verify_check_given_host(&ob->hosts_require_tls, host) != OK
         )
         {
-        log_write(0, LOG_MAIN, "TLS session failure: delivering unencrypted "
-          "to %s [%s] (not in hosts_require_tls)", host->name, host->address);
+        log_write(0, LOG_MAIN,
+         "%s: delivering unencrypted to H=%s [%s] (not in hosts_require_tls)",
+         first_addr->message, host->name, host->address);
         first_addr = prepare_addresses(addrlist, host);
         rc = smtp_deliver(addrlist, thost, host_af, port, interface, tblock,
           &message_defer, TRUE);