]> git.netwichtig.de Git - user/henk/code/exim.git/blobdiff - src/src/transports/smtp.c
TLS: harden error-detection in TLS proxy process
[user/henk/code/exim.git] / src / src / transports / smtp.c
index e8a9afbd0280c327d91047d73c0ed713d6225164..c6099f960b2c1b008e58ac677fe7a2998c9c8e42 100644 (file)
@@ -43,7 +43,7 @@ optionlist smtp_transport_options[] = {
   { "dane_require_tls_ciphers", opt_stringptr, LOFF(dane_require_tls_ciphers) },
 # endif
   { "data_timeout",         opt_time,     LOFF(data_timeout) },
-  { "delay_after_cutoff", opt_bool,       LOFF(delay_after_cutoff) },
+  { "delay_after_cutoff",   opt_bool,     LOFF(delay_after_cutoff) },
 #ifndef DISABLE_DKIM
   { "dkim_canon", opt_stringptr,          LOFF(dkim.dkim_canon) },
   { "dkim_domain", opt_stringptr,         LOFF(dkim.dkim_domain) },
@@ -380,7 +380,7 @@ if (ob->command_timeout <= 0 || ob->data_timeout <= 0 ||
 /* If hosts_override is set and there are local hosts, set the global
 flag that stops verify from showing router hosts. */
 
-if (ob->hosts_override && ob->hosts != NULL) tblock->overrides_hosts = TRUE;
+if (ob->hosts_override && ob->hosts) tblock->overrides_hosts = TRUE;
 
 /* If there are any fallback hosts listed, build a chain of host items
 for them, but do not do any lookups at this time. */
@@ -712,7 +712,17 @@ return count;
 static BOOL
 smtp_reap_banner(smtp_context * sx)
 {
-BOOL good_response = smtp_read_response(sx, sx->buffer, sizeof(sx->buffer),
+BOOL good_response;
+#if defined(__linux__) && defined(TCP_QUICKACK)
+  {    /* Hack to get QUICKACK disabled; has to be right after 3whs, and has to on->off */
+  int sock = sx->cctx.sock;
+  struct pollfd p = {.fd = sock, .events = POLLOUT};
+  int rc = poll(&p, 1, 1000);
+  (void) setsockopt(sock, IPPROTO_TCP, TCP_QUICKACK, US &on, sizeof(on));
+  (void) setsockopt(sock, IPPROTO_TCP, TCP_QUICKACK, US &off, sizeof(off));
+  }
+#endif
+good_response = smtp_read_response(sx, sx->buffer, sizeof(sx->buffer),
   '2', (SOB sx->conn_args.ob)->command_timeout);
 #ifdef EXPERIMENTAL_DSN_INFO
 sx->smtp_greeting = string_copy(sx->buffer);
@@ -805,7 +815,7 @@ else
   uschar * ehlo_resp_key = ehlo_cache_key(sx);
   dbdata_ehlo_resp * er;
 
-  if (!(er = dbfn_read(dbm_file, ehlo_resp_key)))
+  if (!(er = dbfn_read_enforce_length(dbm_file, ehlo_resp_key, sizeof(dbdata_ehlo_resp))))
     { DEBUG(D_transport) debug_printf("no ehlo-resp record\n"); }
   else if (time(NULL) - er->time_stamp > retry_data_expire)
     {
@@ -959,7 +969,7 @@ fail:
   (void) smtp_discard_responses(sx, sx->conn_args.ob, *countp);
   return rc;
 }
-#endif
+#endif /*!DISABLE_PIPE_CONNECT*/
 
 
 /*************************************************
@@ -1026,7 +1036,7 @@ if (sx->pending_MAIL)
   {
   DEBUG(D_transport) debug_printf("%s expect mail\n", __FUNCTION__);
   count--;
-  sx->pending_MAIL = FALSE;
+  sx->pending_MAIL = sx->RCPT_452 = FALSE;
   if (!smtp_read_response(sx, sx->buffer, sizeof(sx->buffer),
                          '2', ob->command_timeout))
     {
@@ -1072,7 +1082,7 @@ while (count-- > 0)
   /* The address was accepted */
   addr->host_used = sx->conn_args.host;
 
-  DEBUG(D_transport) debug_printf("%s expect rcpt\n", __FUNCTION__);
+  DEBUG(D_transport) debug_printf("%s expect rcpt for %s\n", __FUNCTION__, addr->address);
   if (smtp_read_response(sx, sx->buffer, sizeof(sx->buffer),
                          '2', ob->command_timeout))
     {
@@ -1166,7 +1176,7 @@ while (count-- > 0)
 
        if (addr->more_errno >> 8 == 52  &&  yield & 3)
          {
-         if (!sx->RCPT_452)
+         if (!sx->RCPT_452)            /* initialised at MAIL-ack above */
            {
            DEBUG(D_transport)
              debug_printf("%s: seen first 452 too-many-rcpts\n", __FUNCTION__);
@@ -1213,6 +1223,8 @@ while (count-- > 0)
        }
       }
     }
+  if (count && !(addr = addr->next))
+    return -2;
   }       /* Loop for next RCPT response */
 
 /* Update where to start at for the next block of responses, unless we
@@ -1488,7 +1500,9 @@ if (  sx->esmtp
 
 if (require_auth == OK && !f.smtp_authenticated)
   {
+#ifndef DISABLE_PIPE_CONNECT
   invalidate_ehlo_cache_entry(sx);
+#endif
   set_errno_nohost(sx->addrlist, ERRNO_AUTHFAIL,
     string_sprintf("authentication required but %s", fail_reason), DEFER,
     FALSE, &sx->delivery_start);
@@ -1623,8 +1637,9 @@ uschar * message_local_identity,
 current_local_identity =
   smtp_local_identity(s_compare->current_sender_address, s_compare->tblock);
 
-if (!(new_sender_address = deliver_get_sender_address(message_id)))
-    return FALSE;
+if (!(new_sender_address = spool_sender_from_msgid(message_id)))
+  return FALSE;
+
 
 message_local_identity =
   smtp_local_identity(new_sender_address, s_compare->tblock);
@@ -2098,7 +2113,12 @@ PIPE_CONNECT_RETRY:
   else
 #endif
     {
-    if ((sx->cctx.sock = smtp_connect(&sx->conn_args, NULL)) < 0)
+    blob lazy_conn = {.data = NULL};
+    /* For TLS-connect, a TFO lazy-connect is useful since the Client Hello
+    can go on the TCP SYN. */
+
+    if ((sx->cctx.sock = smtp_connect(&sx->conn_args,
+                           sx->smtps ? &lazy_conn : NULL)) < 0)
       {
       set_errno_nohost(sx->addrlist,
        errno == ETIMEDOUT ? ERRNO_CONNECTTIMEOUT : errno,
@@ -2107,6 +2127,10 @@ PIPE_CONNECT_RETRY:
       sx->send_quit = FALSE;
       return DEFER;
       }
+#ifdef TCP_QUICKACK
+    (void) setsockopt(sx->cctx.sock, IPPROTO_TCP, TCP_QUICKACK, US &off,
+                       sizeof(off));
+#endif
     }
   /* Expand the greeting message while waiting for the initial response. (Makes
   sense if helo_data contains ${lookup dnsdb ...} stuff). The expansion is
@@ -2152,10 +2176,6 @@ will be?  Somehow I doubt it. */
     else
 #endif
       {
-#ifdef TCP_QUICKACK
-      (void) setsockopt(sx->cctx.sock, IPPROTO_TCP, TCP_QUICKACK, US &off,
-                       sizeof(off));
-#endif
       if (!smtp_reap_banner(sx))
        goto RESPONSE_FAILED;
       }
@@ -2497,6 +2517,7 @@ if (  smtp_peer_options & OPTION_TLS
       sx->send_quit = FALSE;
       goto TLS_FAILED;
       }
+    sx->send_tlsclose = TRUE;
 
     /* TLS session is set up.  Check the inblock fill level.  If there is
     content then as we have not yet done a tls read it must have arrived before
@@ -2658,7 +2679,7 @@ so its response needs to be analyzed. If TLS is not active and this is a
 continued session down a previously-used socket, we haven't just done EHLO, so
 we skip this. */
 
-if (continue_hostname == NULL
+if (   !continue_hostname
 #ifndef DISABLE_TLS
     || tls_out.active.sock >= 0
 #endif
@@ -2930,7 +2951,11 @@ if (sx->send_quit)
 #ifndef DISABLE_TLS
 if (sx->cctx.tls_ctx)
   {
-  tls_close(sx->cctx.tls_ctx, TLS_SHUTDOWN_NOWAIT);
+  if (sx->send_tlsclose)
+    {
+    tls_close(sx->cctx.tls_ctx, TLS_SHUTDOWN_NOWAIT);
+    sx->send_tlsclose = FALSE;
+    }
   sx->cctx.tls_ctx = NULL;
   }
 #endif
@@ -3309,6 +3334,7 @@ smtp_proxy_tls(void * ct_ctx, uschar * buf, size_t bsize, int * pfd,
 fd_set rfds, efds;
 int max_fd = MAX(pfd[0], tls_out.active.sock) + 1;
 int rc, i;
+BOOL send_tls_shutdown = TRUE;
 
 close(pfd[1]);
 if ((rc = exim_fork(US"tls-proxy")))
@@ -3342,19 +3368,23 @@ for (int fd_bits = 3; fd_bits; )
       goto done;
       }
 
+    /* For errors where not readable, bomb out */
+
     if (FD_ISSET(tls_out.active.sock, &efds) || FD_ISSET(pfd[0], &efds))
       {
       DEBUG(D_transport) debug_printf("select: exceptional cond on %s fd\n",
        FD_ISSET(pfd[0], &efds) ? "proxy" : "tls");
-      goto done;
+      if (!(FD_ISSET(tls_out.active.sock, &rfds) || FD_ISSET(pfd[0], &rfds)))
+       goto done;
+      DEBUG(D_transport) debug_printf("- but also readable; no exit yet\n");
       }
     }
   while (rc < 0 || !(FD_ISSET(tls_out.active.sock, &rfds) || FD_ISSET(pfd[0], &rfds)));
 
   /* handle inbound data */
   if (FD_ISSET(tls_out.active.sock, &rfds))
-    if ((rc = tls_read(ct_ctx, buf, bsize)) <= 0)
-      {
+    if ((rc = tls_read(ct_ctx, buf, bsize)) <= 0)      /* Expect -1 for EOF; */
+    {                              /* that reaps the TLS Close Notify record */
       fd_bits &= ~1;
       FD_CLR(tls_out.active.sock, &rfds);
       shutdown(pfd[0], SHUT_WR);
@@ -3365,16 +3395,21 @@ for (int fd_bits = 3; fd_bits; )
       for (int nbytes = 0; rc - nbytes > 0; nbytes += i)
        if ((i = write(pfd[0], buf + nbytes, rc - nbytes)) < 0) goto done;
       }
-  else if (fd_bits & 1)
-    FD_SET(tls_out.active.sock, &rfds);
 
-  /* handle outbound data */
+  /* Handle outbound data.  We cannot combine payload and the TLS-close
+  due to the limitations of the (pipe) channel feeding us. */
   if (FD_ISSET(pfd[0], &rfds))
     if ((rc = read(pfd[0], buf, bsize)) <= 0)
       {
-      fd_bits = 0;
-      tls_close(ct_ctx, TLS_SHUTDOWN_NOWAIT);
-      ct_ctx = NULL;
+      fd_bits &= ~2;
+      FD_CLR(pfd[0], &rfds);
+
+# ifdef EXIM_TCP_CORK  /* Use _CORK to get TLS Close Notify in FIN segment */
+      (void) setsockopt(tls_out.active.sock, IPPROTO_TCP, EXIM_TCP_CORK, US &on, sizeof(on));
+# endif
+      tls_shutdown_wr(ct_ctx);
+      send_tls_shutdown = FALSE;
+      shutdown(tls_out.active.sock, SHUT_WR);
       }
     else
       {
@@ -3382,11 +3417,14 @@ for (int fd_bits = 3; fd_bits; )
        if ((i = tls_write(ct_ctx, buf + nbytes, rc - nbytes, FALSE)) < 0)
          goto done;
       }
-  else if (fd_bits & 2)
-    FD_SET(pfd[0], &rfds);
+
+  if (fd_bits & 1) FD_SET(tls_out.active.sock, &rfds);
+  if (fd_bits & 2) FD_SET(pfd[0], &rfds);
   }
 
 done:
+  if (send_tls_shutdown) tls_close(ct_ctx, TLS_SHUTDOWN_NOWAIT);
+  ct_ctx = NULL;
   testharness_pause_ms(100);   /* let logging complete */
   exim_exit(EXIT_SUCCESS);
 }
@@ -3459,6 +3497,7 @@ smtp_context * sx = store_get(sizeof(*sx), TRUE); /* tainted, for the data buffe
 #ifdef SUPPORT_DANE
 BOOL dane_held;
 #endif
+BOOL tcw_done = FALSE, tcw = FALSE;
 
 *message_defer = FALSE;
 
@@ -3748,6 +3787,46 @@ else
   report_time_since(&t0, US"dkim_exim_sign_init (delta)");
 # endif
   }
+#endif
+
+  /* See if we can pipeline QUIT.  Reasons not to are
+  - pipelining not active
+  - not ok to send quit
+  - errors in amtp transation responses
+  - more addrs to send for this message or this host
+  - this message was being retried
+  - more messages for this host
+  If we can, we want the message-write to not flush (the tail end of) its data out.  */
+
+  if (  sx->pipelining_used
+     && (sx->ok && sx->completed_addr || sx->peer_offered & OPTION_CHUNKING)
+     && sx->send_quit
+     && !(sx->first_addr || f.continue_more)
+     && f.deliver_firsttime
+     )
+    {
+    smtp_compare_t t_compare =
+      {.tblock = tblock, .current_sender_address = sender_address};
+
+    tcw_done = TRUE;
+    tcw =
+#ifndef DISABLE_TLS
+          (  tls_out.active.sock < 0  &&  !continue_proxy_cipher
+           || verify_check_given_host(CUSS &ob->hosts_nopass_tls, host) != OK
+          )
+        &&
+#endif
+           transport_check_waiting(tblock->name, host->name,
+             tblock->connection_max_messages, new_message_id,
+            (oicf)smtp_are_same_identities, (void*)&t_compare);
+    if (!tcw)
+      {
+      HDEBUG(D_transport) debug_printf("will pipeline QUIT\n");
+      tctx.options |= topt_no_flush;
+      }
+    }
+
+#ifndef DISABLE_DKIM
   sx->ok = dkim_transport_write_message(&tctx, &ob->dkim, CUSS &message);
 #else
   sx->ok = transport_write_message(&tctx, 0);
@@ -3776,6 +3855,48 @@ else
 
   smtp_command = US"end of data";
 
+  /* If we can pipeline a QUIT with the data them send it now.  If a new message
+  for this host appeared in the queue while data was being sent, we will not see
+  it and it will have to wait for a queue run.  If there was one but another
+  thread took it, we might attempt to send it - but locking of spoolfiles will
+  detect that. Use _MORE to get QUIT in FIN segment. */
+
+  if (tcw_done && !tcw)
+    {
+    /*XXX jgh 2021/03/10 google et. al screwup.  G, at least, sends TCP FIN in response to TLS
+    close-notify.  Under TLS 1.3, violating RFC.
+    However, TLS 1.2 does not have half-close semantics. */
+
+    if (     sx->cctx.tls_ctx
+#if 0 && !defined(DISABLE_TLS)
+          && Ustrcmp(tls_out.ver, "TLS1.3") != 0
+#endif
+       || !f.deliver_firsttime
+       )
+      {                                /* Send QUIT now and not later */
+      (void)smtp_write_command(sx, SCMD_FLUSH, "QUIT\r\n");
+      sx->send_quit = FALSE;
+      }
+    else
+      {                                /* add QUIT to the output buffer */
+      (void)smtp_write_command(sx, SCMD_MORE, "QUIT\r\n");
+      sx->send_quit = FALSE;   /* avoid sending it later */
+
+#ifndef DISABLE_TLS
+      if (sx->cctx.tls_ctx)    /* need to send TLS Cloe Notify */
+       {
+# ifdef EXIM_TCP_CORK          /* Use _CORK to get Close Notify in FIN segment */
+       (void) setsockopt(sx->cctx.sock, IPPROTO_TCP, EXIM_TCP_CORK, US &on, sizeof(on));
+# endif
+       tls_shutdown_wr(sx->cctx.tls_ctx);
+       sx->send_tlsclose = FALSE;      /* avoid later repeat */
+       }
+#endif
+      HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("  SMTP(shutdown)>>\n");
+      shutdown(sx->cctx.sock, SHUT_WR);        /* flush output buffer, with TCP FIN */
+      }
+    }
+
   if (sx->peer_offered & OPTION_CHUNKING && sx->cmd_count > 1)
     {
     /* Reap any outstanding MAIL & RCPT commands, but not a DATA-go-ahead */
@@ -3868,15 +3989,16 @@ else
           !sx->lmtp
        )
       {
-      const uschar *s = string_printing(sx->buffer);
+      const uschar * s = string_printing(sx->buffer);
       /* deconst cast ok here as string_printing was checked to have alloc'n'copied */
-      conf = (s == sx->buffer)? US string_copy(s) : US s;
+      conf = s == sx->buffer ? US string_copy(s) : US s;
       }
 
     /* Process all transported addresses - for LMTP or PRDR, read a status for
-    each one. */
+    each one. We used to drop out at first_addr, until someone returned a 452
+    followed by a 250... and we screwed up the accepted addresses. */
 
-    for (address_item * addr = addrlist; addr != sx->first_addr; addr = addr->next)
+    for (address_item * addr = addrlist; addr; addr = addr->next)
       {
       if (addr->transport_return != PENDING_OK) continue;
 
@@ -4049,7 +4171,8 @@ if (!sx->ok)
     {
     save_errno = errno;
     message = NULL;
-    sx->send_quit = check_response(host, &save_errno, addrlist->more_errno,
+    /* Clear send_quit flag if needed.  Do not set. */
+    sx->send_quit &= check_response(host, &save_errno, addrlist->more_errno,
       sx->buffer, &code, &message, &pass_message);
     goto FAILED;
     }
@@ -4141,8 +4264,8 @@ if (!sx->ok)
        if (ioctl(sx->cctx.sock, TIOCOUTQ, &n) == 0)
          debug_printf("%d bytes remain in socket output buffer\n", n);
        }
-      }
 #endif
+      }
     /* Otherwise, we have an I/O error or a timeout other than after MAIL or
     ".", or some other transportation error. We defer all addresses and yield
     DEFER, except for the case of failed add_headers expansion, or a transport
@@ -4210,13 +4333,12 @@ DEBUG(D_transport)
 
 if (sx->completed_addr && sx->ok && sx->send_quit)
   {
-  smtp_compare_t t_compare;
-
-  t_compare.tblock = tblock;
-  t_compare.current_sender_address = sender_address;
+  smtp_compare_t t_compare =
+    {.tblock = tblock, .current_sender_address = sender_address};
 
-  if (  sx->first_addr != NULL         /* more addrs for this message */
-     || f.continue_more                        /* more addrs for coninued-host */
+  if (  sx->first_addr                 /* more addrs for this message */
+     || f.continue_more                        /* more addrs for continued-host */
+     || tcw_done && tcw                        /* more messages for host */
      || (
 #ifndef DISABLE_TLS
           (  tls_out.active.sock < 0  &&  !continue_proxy_cipher
@@ -4261,8 +4383,7 @@ if (sx->completed_addr && sx->ok && sx->send_quit)
 #endif
       int socket_fd = sx->cctx.sock;
 
-
-      if (sx->first_addr != NULL)      /* More addresses still to be sent */
+      if (sx->first_addr)              /* More addresses still to be sent */
         {                              /*   for this message              */
         continue_sequence++;           /* Causes * in logging */
        pipelining_active = sx->pipelining_used;    /* was cleared at DATA */
@@ -4286,6 +4407,7 @@ if (sx->completed_addr && sx->ok && sx->send_quit)
          the socket on. */
 
          tls_close(sx->cctx.tls_ctx, TLS_SHUTDOWN_WAIT);
+         sx->send_tlsclose = FALSE;
          sx->cctx.tls_ctx = NULL;
          tls_out.active.sock = -1;
          smtp_peer_options = smtp_peer_options_wrap;
@@ -4375,36 +4497,26 @@ propagate it from the initial
   }
 
 /* End off tidily with QUIT unless the connection has died or the socket has
-been passed to another process. There has been discussion on the net about what
-to do after sending QUIT. The wording of the RFC suggests that it is necessary
-to wait for a response, but on the other hand, there isn't anything one can do
-with an error response, other than log it. Exim used to do that. However,
-further discussion suggested that it is positively advantageous not to wait for
-the response, but to close the session immediately. This is supposed to move
-the TCP/IP TIME_WAIT state from the server to the client, thereby removing some
-load from the server. (Hosts that are both servers and clients may not see much
-difference, of course.) Further discussion indicated that this was safe to do
-on Unix systems which have decent implementations of TCP/IP that leave the
-connection around for a while (TIME_WAIT) after the application has gone away.
-This enables the response sent by the server to be properly ACKed rather than
-timed out, as can happen on broken TCP/IP implementations on other OS.
-
-This change is being made on 31-Jul-98. After over a year of trouble-free
-operation, the old commented-out code was removed on 17-Sep-99. */
+been passed to another process. */
 
 SEND_QUIT:
-#ifdef TCP_CORK
-(void) setsockopt(sx->cctx.sock, IPPROTO_TCP, TCP_CORK, US &on, sizeof(on));
+if (sx->send_quit)
+  {                    /* Use _MORE to get QUIT in FIN segment */
+  (void)smtp_write_command(sx, SCMD_MORE, "QUIT\r\n");
+#ifndef DISABLE_TLS
+  if (sx->cctx.tls_ctx)
+    {
+# ifdef EXIM_TCP_CORK  /* Use _CORK to get TLS Close Notify in FIN segment */
+    (void) setsockopt(sx->cctx.sock, IPPROTO_TCP, EXIM_TCP_CORK, US &on, sizeof(on));
+# endif
+    tls_shutdown_wr(sx->cctx.tls_ctx);
+    sx->send_tlsclose = FALSE;
+    }
 #endif
-if (sx->send_quit) (void)smtp_write_command(sx, SCMD_FLUSH, "QUIT\r\n");
+  }
 
 END_OFF:
 
-#ifndef DISABLE_TLS
-tls_close(sx->cctx.tls_ctx, TLS_SHUTDOWN_NOWAIT);
-sx->cctx.tls_ctx = NULL;
-#endif
-
 /* Close the socket, and return the appropriate value, first setting
 works because the NULL setting is passed back to the calling process, and
 remote_max_parallel is forced to 1 when delivering over an existing connection,
@@ -4415,16 +4527,58 @@ 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_indent("  SMTP(close)>>\n");
 if (sx->send_quit)
   {
+  /* This flushes data queued in the socket, being the QUIT and any TLS Close,
+  sending them along with the client FIN flag.  Us (we hope) sending FIN first
+  means we (client) take the TIME_WAIT state, so the server (which likely has a
+  higher connection rate) does not have to. */
+
+  HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("  SMTP(shutdown)>>\n");
   shutdown(sx->cctx.sock, SHUT_WR);
+  }
+
+if (sx->send_quit || tcw_done && !tcw)
+  {
+  /* Wait for (we hope) ack of our QUIT, and a server FIN.  Discard any data
+  received, then discard the socket.  Any packet received after then, or receive
+  data still in the socket, will get a RST - hence the pause/drain. */
+
+  /* Reap the response to QUIT, timing out after one second */
+  (void) smtp_read_response(sx, sx->buffer, sizeof(sx->buffer), '2', 1);
+#ifndef DISABLE_TLS
+  if (sx->cctx.tls_ctx)
+    {
+    int n;
+
+    /* Reap the TLS Close Notify from the server, timing out after one second */
+    sigalrm_seen = FALSE;
+    ALARM(1);
+    do
+      n = tls_read(sx->cctx.tls_ctx, sx->inbuffer, sizeof(sx->inbuffer));
+    while (!sigalrm_seen && n > 0);
+    ALARM_CLR(0);
+
+# ifdef EXIM_TCP_CORK
+    (void) setsockopt(sx->cctx.sock, IPPROTO_TCP, EXIM_TCP_CORK, US &on, sizeof(on));
+# endif
+    tls_close(sx->cctx.tls_ctx, TLS_SHUTDOWN_WAIT);
+    sx->cctx.tls_ctx = NULL;
+    }
+#endif
   millisleep(20);
-  testharness_pause_ms(200);
   if (fcntl(sx->cctx.sock, F_SETFL, O_NONBLOCK) == 0)
-    for (int i = 16; read(sx->cctx.sock, sx->inbuffer, sizeof(sx->inbuffer)) > 0 && i > 0;)
-      i--;                             /* drain socket */
+    for (int i = 16, n;                                                /* drain socket */
+        (n = read(sx->cctx.sock, sx->inbuffer, sizeof(sx->inbuffer))) > 0 && i > 0;
+        i--) HDEBUG(D_transport|D_acl|D_v)
+      {
+      int m = MIN(n, 64);
+      debug_printf_indent("  SMTP(drain %d bytes)<< %.*s\n", n, m, sx->inbuffer);
+      for (m = 0; m < n; m++)
+       debug_printf("0x%02x\n", sx->inbuffer[m]);
+      }
   }
+HDEBUG(D_transport|D_acl|D_v) debug_printf_indent("  SMTP(close)>>\n");
 (void)close(sx->cctx.sock);
 
 #ifndef DISABLE_EVENT
@@ -4668,7 +4822,7 @@ if (!hostlist || (ob->hosts_override && ob->hosts))
     {
     uschar *s = ob->hosts;
 
-    if (Ustrchr(s, '$') != NULL)
+    if (Ustrchr(s, '$'))
       {
       if (!(expanded_hosts = expand_string(s)))
         {
@@ -5016,7 +5170,7 @@ retry_non_continued:
     because connections to the same host from a different interface should be
     treated separately. */
 
-    host_af = Ustrchr(host->address, ':') == NULL ? AF_INET : AF_INET6;
+    host_af = Ustrchr(host->address, ':') ? AF_INET6 : AF_INET;
       {
       uschar * s = ob->interface;
       if (s && *s)