TLS: Fix excessive calling of smtp_auth_acl under AUTH_TLS. Bug 2203
[exim.git] / src / src / smtp_in.c
index 3d5ad863f7d4e41228cd56b891f44667887c262e..1f1e7ddd4ac9e9964068f8cb3100c1c3f72b772b 100644 (file)
@@ -187,7 +187,7 @@ static smtp_cmd_list cmd_list[] = {
   { "auth",       sizeof("auth")-1,       AUTH_CMD, TRUE,  TRUE  },
   #ifdef SUPPORT_TLS
   { "starttls",   sizeof("starttls")-1,   STARTTLS_CMD, FALSE, FALSE },
-  { "tls_auth",   0,                      TLS_AUTH_CMD, FALSE, TRUE },
+  { "tls_auth",   0,                      TLS_AUTH_CMD, FALSE, FALSE },
   #endif
 
 /* If you change anything above here, also fix the definitions below. */
@@ -339,8 +339,10 @@ int fd, rc;
 fd_set fds;
 struct timeval tzero;
 
+#ifdef SUPPORT_TLS
 if (tls_in.active >= 0)
  return !tls_could_read();
+#endif
 
 if (smtp_inptr < smtp_inend)
   return FALSE;
@@ -563,11 +565,12 @@ for(;;)
     incomplete_transaction_log(US"sync failure");
     log_write(0, LOG_MAIN|LOG_REJECT, "SMTP protocol synchronization error "
       "(next input sent too soon: pipelining was not advertised): "
-      "rejected \"%s\" %s next input=\"%s\"",
+      "rejected \"%s\" %s next input=\"%s\"%s",
       smtp_cmd_buffer, host_and_ident(TRUE),
-      string_printing(string_copyn(smtp_inptr, n)));
-      (void) synprot_error(L_smtp_protocol_error, 554, NULL,
-       US"SMTP synchronization error");
+      string_printing(string_copyn(smtp_inptr, n)),
+      smtp_inend - smtp_inptr > n ? "..." : "");
+    (void) synprot_error(L_smtp_protocol_error, 554, NULL,
+      US"SMTP synchronization error");
     goto repeat_until_rset;
     }
 
@@ -678,8 +681,11 @@ return buf;
 void
 bdat_flush_data(void)
 {
-unsigned n = chunking_data_left;
-(void) bdat_getbuf(&n);
+while (chunking_data_left)
+{
+  unsigned n = chunking_data_left;
+  (void) bdat_getbuf(&n);
+}
 
 receive_getc = lwr_receive_getc;
 receive_getbuf = lwr_receive_getbuf;
@@ -839,7 +845,7 @@ if (!yield)
   {
   log_write(0, LOG_MAIN|LOG_PANIC, "string too large in smtp_printf()");
   smtp_closedown(US"Unexpected error");
-  exim_exit(EXIT_FAILURE);
+  exim_exit(EXIT_FAILURE, NULL);
   }
 
 /* If this is the first output for a (non-batch) RCPT command, see if all RCPTs
@@ -919,7 +925,7 @@ if (smtp_batched_input)
   moan_smtp_batch(NULL, "421 SMTP command timeout");  /* Does not return */
 smtp_notquit_exit(US"command-timeout", US"421",
   US"%s: SMTP command timeout - closing connection", smtp_active_hostname);
-exim_exit(EXIT_FAILURE);
+exim_exit(EXIT_FAILURE, US"receiving");
 }
 
 
@@ -943,7 +949,7 @@ if (smtp_batched_input)
   moan_smtp_batch(NULL, "421 SIGTERM received");  /* Does not return */
 smtp_notquit_exit(US"signal-exit", US"421",
   US"%s: Service not available - closing connection", smtp_active_hostname);
-exim_exit(EXIT_FAILURE);
+exim_exit(EXIT_FAILURE, US"receiving");
 }
 
 
@@ -1708,37 +1714,22 @@ return string_sprintf("SMTP connection from %s", hostname);
 /* Append TLS-related information to a log line
 
 Arguments:
-  s            String under construction: allocated string to extend, or NULL
-  sizep                Pointer to current allocation size (update on return), or NULL
-  ptrp         Pointer to index for new entries in string (update on return), or NULL
+  g            String under construction: allocated string to extend, or NULL
 
 Returns:       Allocated string or NULL
 */
-static uschar *
-s_tlslog(uschar * s, int * sizep, int * ptrp)
+static gstring *
+s_tlslog(gstring * g)
 {
-  int size = sizep ? *sizep : 0;
-  int ptr = ptrp ? *ptrp : 0;
-
-  if (LOGGING(tls_cipher) && tls_in.cipher != NULL)
-    s = string_append(s, &size, &ptr, 2, US" X=", tls_in.cipher);
-  if (LOGGING(tls_certificate_verified) && tls_in.cipher != NULL)
-    s = string_append(s, &size, &ptr, 2, US" CV=",
-      tls_in.certificate_verified? "yes":"no");
-  if (LOGGING(tls_peerdn) && tls_in.peerdn != NULL)
-    s = string_append(s, &size, &ptr, 3, US" DN=\"",
-      string_printing(tls_in.peerdn), US"\"");
-  if (LOGGING(tls_sni) && tls_in.sni != NULL)
-    s = string_append(s, &size, &ptr, 3, US" SNI=\"",
-      string_printing(tls_in.sni), US"\"");
-
-  if (s)
-    {
-    s[ptr] = '\0';
-    if (sizep) *sizep = size;
-    if (ptrp) *ptrp = ptr;
-    }
-  return s;
+if (LOGGING(tls_cipher) && tls_in.cipher)
+  g = string_append(g, 2, US" X=", tls_in.cipher);
+if (LOGGING(tls_certificate_verified) && tls_in.cipher)
+  g = string_append(g, 2, US" CV=", tls_in.certificate_verified? "yes":"no");
+if (LOGGING(tls_peerdn) && tls_in.peerdn)
+  g = string_append(g, 3, US" DN=\"", string_printing(tls_in.peerdn), US"\"");
+if (LOGGING(tls_sni) && tls_in.sni)
+  g = string_append(g, 3, US" SNI=\"", string_printing(tls_in.sni), US"\"");
+return g;
 }
 #endif
 
@@ -1757,49 +1748,43 @@ Returns:     nothing
 void
 smtp_log_no_mail(void)
 {
-int size, ptr, i;
-uschar *s, *sep;
+int i;
+uschar * sep, * s;
+gstring * g = NULL;
 
 if (smtp_mailcmd_count > 0 || !LOGGING(smtp_no_mail))
   return;
 
-s = NULL;
-size = ptr = 0;
-
 if (sender_host_authenticated != NULL)
   {
-  s = string_append(s, &size, &ptr, 2, US" A=", sender_host_authenticated);
-  if (authenticated_id != NULL)
-    s = string_append(s, &size, &ptr, 2, US":", authenticated_id);
+  g = string_append(g, 2, US" A=", sender_host_authenticated);
+  if (authenticated_id) g = string_append(g, 2, US":", authenticated_id);
   }
 
 #ifdef SUPPORT_TLS
-s = s_tlslog(s, &size, &ptr);
+g = s_tlslog(g);
 #endif
 
-sep = (smtp_connection_had[SMTP_HBUFF_SIZE-1] != SCH_NONE)?
-  US" C=..." : US" C=";
+sep = smtp_connection_had[SMTP_HBUFF_SIZE-1] != SCH_NONE ?  US" C=..." : US" C=";
+
 for (i = smtp_ch_index; i < SMTP_HBUFF_SIZE; i++)
-  {
   if (smtp_connection_had[i] != SCH_NONE)
     {
-    s = string_append(s, &size, &ptr, 2, sep,
-      smtp_names[smtp_connection_had[i]]);
+    g = string_append(g, 2, sep, smtp_names[smtp_connection_had[i]]);
     sep = US",";
     }
-  }
 
 for (i = 0; i < smtp_ch_index; i++)
   {
-  s = string_append(s, &size, &ptr, 2, sep, smtp_names[smtp_connection_had[i]]);
+  g = string_append(g, 2, sep, smtp_names[smtp_connection_had[i]]);
   sep = US",";
   }
 
-if (s) s[ptr] = 0; else s = US"";
-log_write(0, LOG_MAIN, "no MAIL in SMTP connection from %s D=%s%s",
-  host_and_ident(FALSE),
-  readconf_printtime( (int) ((long)time(NULL) - (long)smtp_connection_start)),
-  s);
+if (!(s = string_from_gstring(g))) s = US"";
+
+log_write(0, LOG_MAIN, "no MAIL in %sSMTP connection from %s D=%s%s",
+  tcp_in_fastopen ? US"TFO " : US"",
+  host_and_ident(FALSE), string_timesince(&smtp_connection_start), s);
 }
 
 
@@ -1808,17 +1793,19 @@ log_write(0, LOG_MAIN, "no MAIL in SMTP connection from %s D=%s%s",
 uschar *
 smtp_cmd_hist(void)
 {
-uschar * list = NULL;
-int size = 0, len = 0, i;
+int  i;
+gstring * list = NULL;
+uschar * s;
 
 for (i = smtp_ch_index; i < SMTP_HBUFF_SIZE; i++)
   if (smtp_connection_had[i] != SCH_NONE)
-    list = string_append_listele(list, &size, &len, ',',
-      smtp_names[smtp_connection_had[i]]);
+    list = string_append_listele(list, ',', smtp_names[smtp_connection_had[i]]);
+
 for (i = 0; i < smtp_ch_index; i++)
-  list = string_append_listele(list, &size, &len, ',',
-    smtp_names[smtp_connection_had[i]]);
-return list ? list : US"";
+  list = string_append_listele(list, ',', smtp_names[smtp_connection_had[i]]);
+
+s = string_from_gstring(list);
+return s ? s : US"";
 }
 
 
@@ -1941,17 +1928,17 @@ while (v > smtp_cmd_data && *v != '=' && !isspace(*v))
 
 n = v;
 if (*v == '=')
-{
+  {
   while(isalpha(n[-1])) n--;
   /* RFC says SP, but TAB seen in wild and other major MTAs accept it */
   if (!isspace(n[-1])) return FALSE;
   n[-1] = 0;
-}
+  }
 else
-{
+  {
   n++;
   if (v == smtp_cmd_data) return FALSE;
-}
+  }
 *v++ = 0;
 *name = n;
 *value = v;
@@ -2331,6 +2318,28 @@ return FALSE;
 }
 
 
+
+
+#ifdef TCP_FASTOPEN
+static void
+tfo_in_check(void)
+{
+# ifdef TCP_INFO
+struct tcp_info tinfo;
+socklen_t len = sizeof(tinfo);
+
+if (  getsockopt(fileno(smtp_out), IPPROTO_TCP, TCP_INFO, &tinfo, &len) == 0
+   && tinfo.tcpi_state == TCP_SYN_RECV
+   )
+  {
+  DEBUG(D_receive) debug_printf("TCP_FASTOPEN mode connection (state TCP_SYN_RECV)\n");
+  tcp_in_fastopen = TRUE;
+  }
+# endif
+}
+#endif
+
+
 /*************************************************
 *          Start an SMTP session                 *
 *************************************************/
@@ -2347,13 +2356,13 @@ Returns:       FALSE if the session can not continue; something has
 BOOL
 smtp_start_session(void)
 {
-int size = 256;
-int ptr, esclen;
+int esclen;
 uschar *user_msg, *log_msg;
 uschar *code, *esc;
-uschar *p, *s, *ss;
+uschar *p, *s;
+gstring * ss;
 
-smtp_connection_start = time(NULL);
+gettimeofday(&smtp_connection_start, NULL);
 for (smtp_ch_index = 0; smtp_ch_index < SMTP_HBUFF_SIZE; smtp_ch_index++)
   smtp_connection_had[smtp_ch_index] = SCH_NONE;
 smtp_ch_index = 0;
@@ -2420,7 +2429,7 @@ else
 /* Set up the buffer for inputting using direct read() calls, and arrange to
 call the local functions instead of the standard C ones. */
 
-if (!(smtp_inbuffer = (uschar *)malloc(IN_BUFFER_SIZE)))
+if (!(smtp_inbuffer = US malloc(IN_BUFFER_SIZE)))
   log_write(0, LOG_MAIN|LOG_PANIC_DIE, "malloc() failed for SMTP input buffer");
 
 receive_getc = smtp_getc;
@@ -2526,7 +2535,7 @@ if (!sender_host_unknown)
 
     DEBUG(D_receive) debug_printf("checking for IP options\n");
 
-    if (getsockopt(fileno(smtp_out), IPPROTO_IP, IP_OPTIONS, (uschar *)(ipopt),
+    if (getsockopt(fileno(smtp_out), IPPROTO_IP, IP_OPTIONS, US (ipopt),
           &optlen) < 0)
       {
       if (errno != ENOPROTOOPT)
@@ -2552,11 +2561,11 @@ if (!sender_host_unknown)
       struct in_addr addr;
 
       #if OPTSTYLE == 1
-      uschar *optstart = (uschar *)(ipopt->__data);
+      uschar *optstart = US (ipopt->__data);
       #elif OPTSTYLE == 2
-      uschar *optstart = (uschar *)(ipopt->ip_opts);
+      uschar *optstart = US (ipopt->ip_opts);
       #else
-      uschar *optstart = (uschar *)(ipopt->ipopt_list);
+      uschar *optstart = US (ipopt->ipopt_list);
       #endif
 
       DEBUG(D_receive) debug_printf("IP options exist\n");
@@ -2565,7 +2574,7 @@ if (!sender_host_unknown)
       p += Ustrlen(p);
 
       for (opt = optstart; opt != NULL &&
-           opt < (uschar *)(ipopt) + optlen;)
+           opt < US (ipopt) + optlen;)
         {
         switch (*opt)
           {
@@ -2817,8 +2826,12 @@ if (check_proxy_protocol_host())
   smtps port for use with older style SSL MTAs. */
 
 #ifdef SUPPORT_TLS
-  if (tls_in.on_connect && tls_server_start(tls_require_ciphers, &user_msg) != OK)
-    return smtp_log_tls_fail(user_msg);
+  if (tls_in.on_connect)
+    {
+    if (tls_server_start(tls_require_ciphers, &user_msg) != OK)
+      return smtp_log_tls_fail(user_msg);
+    cmd_list[CMD_LIST_TLS_AUTH].is_mail_cmd = TRUE;
+    }
 #endif
 
 /* Run the connect ACL if it exists */
@@ -2875,35 +2888,32 @@ command. Sigh. To try to avoid this, build the complete greeting message
 first, and output it in one fell swoop. This gives a better chance of it
 ending up as a single packet. */
 
-ss = store_get(size);
-ptr = 0;
+ss = string_get(256);
 
 p = s;
 do       /* At least once, in case we have an empty string */
   {
   int len;
   uschar *linebreak = Ustrchr(p, '\n');
-  ss = string_catn(ss, &size, &ptr, code, 3);
+  ss = string_catn(ss, code, 3);
   if (linebreak == NULL)
     {
     len = Ustrlen(p);
-    ss = string_catn(ss, &size, &ptr, US" ", 1);
+    ss = string_catn(ss, US" ", 1);
     }
   else
     {
     len = linebreak - p;
-    ss = string_catn(ss, &size, &ptr, US"-", 1);
+    ss = string_catn(ss, US"-", 1);
     }
-  ss = string_catn(ss, &size, &ptr, esc, esclen);
-  ss = string_catn(ss, &size, &ptr, p, len);
-  ss = string_catn(ss, &size, &ptr, US"\r\n", 2);
+  ss = string_catn(ss, esc, esclen);
+  ss = string_catn(ss, p, len);
+  ss = string_catn(ss, US"\r\n", 2);
   p += len;
   if (linebreak != NULL) p++;
   }
 while (*p != 0);
 
-ss[ptr] = 0;  /* string_cat leaves room for this */
-
 /* Before we write the banner, check that there is no input pending, unless
 this synchronisation check is disabled. */
 
@@ -2922,7 +2932,15 @@ if (!check_sync())
 
 /* Now output the banner */
 
-smtp_printf("%s", FALSE, ss);
+smtp_printf("%s", FALSE, string_from_gstring(ss));
+
+/* Attempt to see if we sent the banner before the last ACK of the 3-way
+handshake arrived.  If so we must have managed a TFO. */
+
+#ifdef TCP_FASTOPEN
+tfo_in_check();
+#endif
+
 return TRUE;
 }
 
@@ -3292,7 +3310,8 @@ is closing if required and return 2.  */
 if (log_reject_target != 0)
   {
 #ifdef SUPPORT_TLS
-  uschar * tls = s_tlslog(NULL, NULL, NULL);
+  gstring * g = s_tlslog(NULL);
+  uschar * tls = string_from_gstring(g);
   if (!tls) tls = US"";
 #else
   uschar * tls = US"";
@@ -3785,7 +3804,6 @@ cmd_list[CMD_LIST_HELO].is_mail_cmd = TRUE;
 cmd_list[CMD_LIST_EHLO].is_mail_cmd = TRUE;
 #ifdef SUPPORT_TLS
 cmd_list[CMD_LIST_STARTTLS].is_mail_cmd = TRUE;
-cmd_list[CMD_LIST_TLS_AUTH].is_mail_cmd = TRUE;
 #endif
 
 /* Set the local signal handler for SIGTERM - it tries to end off tidily */
@@ -3815,11 +3833,12 @@ while (done <= 0)
   void (*oldsignal)(int);
   pid_t pid;
   int start, end, sender_domain, recipient_domain;
-  int ptr, size, rc;
+  int rc;
   int c;
   auth_instance *au;
   uschar *orcpt = NULL;
   int flags;
+  gstring * g;
 
 #ifdef AUTH_TLS
   /* Check once per STARTTLS or SSL-on-connect for a TLS AUTH */
@@ -4115,15 +4134,13 @@ while (done <= 0)
         sender_ident ? sender_ident : US"",
         sender_ident ? US" at " : US"",
         sender_host_name ? sender_host_name : sender_helo_name);
-
-      ptr = Ustrlen(s);
-      size = ptr + 1;
+      g = string_cat(NULL, s);
 
       if (sender_host_address)
         {
-        s = string_catn(s, &size, &ptr, US" [", 2);
-        s = string_cat (s, &size, &ptr, sender_host_address);
-        s = string_catn(s, &size, &ptr, US"]", 1);
+        g = string_catn(g, US" [", 2);
+        g = string_cat (g, sender_host_address);
+        g = string_catn(g, US"]", 1);
         }
       }
 
@@ -4143,18 +4160,17 @@ while (done <= 0)
           "newlines: message truncated: %s", string_printing(s));
         *ss = 0;
         }
-      ptr = Ustrlen(s);
-      size = ptr + 1;
+      g = string_cat(NULL, s);
       }
 
-    s = string_catn(s, &size, &ptr, US"\r\n", 2);
+    g = string_catn(g, US"\r\n", 2);
 
     /* If we received EHLO, we must create a multiline response which includes
     the functions supported. */
 
     if (esmtp)
       {
-      s[3] = '-';
+      g->s[3] = '-';
 
       /* I'm not entirely happy with this, as an MTA is supposed to check
       that it has enough room to accept a message of maximum size before
@@ -4166,12 +4182,12 @@ while (done <= 0)
         {
         sprintf(CS big_buffer, "%.3s-SIZE %d\r\n", smtp_code,
           thismessage_size_limit);
-        s = string_cat(s, &size, &ptr, big_buffer);
+        g = string_cat(g, big_buffer);
         }
       else
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-SIZE\r\n", 7);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-SIZE\r\n", 7);
         }
 
       /* Exim does not do protocol conversion or data conversion. It is 8-bit
@@ -4183,15 +4199,15 @@ while (done <= 0)
 
       if (accept_8bitmime)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-8BITMIME\r\n", 11);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-8BITMIME\r\n", 11);
         }
 
       /* Advertise DSN support if configured to do so. */
       if (verify_check_host(&dsn_advertise_hosts) != FAIL)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-DSN\r\n", 6);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-DSN\r\n", 6);
         dsn_advertised = TRUE;
         }
 
@@ -4200,18 +4216,18 @@ while (done <= 0)
 
       if (acl_smtp_etrn)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-ETRN\r\n", 7);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-ETRN\r\n", 7);
         }
       if (acl_smtp_vrfy)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-VRFY\r\n", 7);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-VRFY\r\n", 7);
         }
       if (acl_smtp_expn)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-EXPN\r\n", 7);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-EXPN\r\n", 7);
         }
 
       /* Exim is quite happy with pipelining, so let the other end know that
@@ -4220,8 +4236,8 @@ while (done <= 0)
       if (pipelining_enable &&
           verify_check_host(&pipelining_advertise_hosts) == OK)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-PIPELINING\r\n", 13);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-PIPELINING\r\n", 13);
         sync_cmd_limit = NON_SYNC_CMD_PIPELINING;
         pipelining_advertised = TRUE;
         }
@@ -4262,29 +4278,29 @@ while (done <= 0)
              int saveptr;
              if (first)
                {
-               s = string_catn(s, &size, &ptr, smtp_code, 3);
-               s = string_catn(s, &size, &ptr, US"-AUTH", 5);
+               g = string_catn(g, smtp_code, 3);
+               g = string_catn(g, US"-AUTH", 5);
                first = FALSE;
                auth_advertised = TRUE;
                }
-             saveptr = ptr;
-             s = string_catn(s, &size, &ptr, US" ", 1);
-             s = string_cat (s, &size, &ptr, au->public_name);
-             while (++saveptr < ptr) s[saveptr] = toupper(s[saveptr]);
+             saveptr = g->ptr;
+             g = string_catn(g, US" ", 1);
+             g = string_cat (g, au->public_name);
+             while (++saveptr < g->ptr) g->s[saveptr] = toupper(g->s[saveptr]);
              au->advertised = TRUE;
              }
            }
          }
 
-       if (!first) s = string_catn(s, &size, &ptr, US"\r\n", 2);
+       if (!first) g = string_catn(g, US"\r\n", 2);
        }
 
       /* RFC 3030 CHUNKING */
 
       if (verify_check_host(&chunking_advertise_hosts) != FAIL)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-CHUNKING\r\n", 11);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-CHUNKING\r\n", 11);
        chunking_offered = TRUE;
        chunking_state = CHUNKING_OFFERED;
         }
@@ -4298,8 +4314,8 @@ while (done <= 0)
       if (tls_in.active < 0 &&
           verify_check_host(&tls_advertise_hosts) != FAIL)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-STARTTLS\r\n", 11);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-STARTTLS\r\n", 11);
         tls_advertised = TRUE;
         }
 #endif
@@ -4308,8 +4324,8 @@ while (done <= 0)
       /* Per Recipient Data Response, draft by Eric A. Hall extending RFC */
       if (prdr_enable)
         {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-PRDR\r\n", 7);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-PRDR\r\n", 7);
        }
 #endif
 
@@ -4317,36 +4333,36 @@ while (done <= 0)
       if (  accept_8bitmime
          && verify_check_host(&smtputf8_advertise_hosts) != FAIL)
        {
-        s = string_catn(s, &size, &ptr, smtp_code, 3);
-        s = string_catn(s, &size, &ptr, US"-SMTPUTF8\r\n", 11);
+        g = string_catn(g, smtp_code, 3);
+        g = string_catn(g, US"-SMTPUTF8\r\n", 11);
         smtputf8_advertised = TRUE;
        }
 #endif
 
       /* Finish off the multiline reply with one that is always available. */
 
-      s = string_catn(s, &size, &ptr, smtp_code, 3);
-      s = string_catn(s, &size, &ptr, US" HELP\r\n", 7);
+      g = string_catn(g, smtp_code, 3);
+      g = string_catn(g, US" HELP\r\n", 7);
       }
 
     /* Terminate the string (for debug), write it, and note that HELO/EHLO
     has been seen. */
 
-    s[ptr] = 0;
-
 #ifdef SUPPORT_TLS
-    if (tls_in.active >= 0) (void)tls_write(TRUE, s, ptr, FALSE); else
+    if (tls_in.active >= 0) (void)tls_write(TRUE, g->s, g->ptr, FALSE); else
 #endif
 
       {
-      int i = fwrite(s, 1, ptr, smtp_out); i = i; /* compiler quietening */
+      int i = fwrite(g->s, 1, g->ptr, smtp_out); i = i; /* compiler quietening */
       }
     DEBUG(D_receive)
       {
       uschar *cr;
-      while ((cr = Ustrchr(s, '\r')) != NULL)   /* lose CRs */
-        memmove(cr, cr + 1, (ptr--) - (cr - s));
-      debug_printf("SMTP>> %s", s);
+
+      (void) string_from_gstring(g);
+      while ((cr = Ustrchr(g->s, '\r')) != NULL)   /* lose CRs */
+        memmove(cr, cr + 1, (g->ptr--) - (cr - g->s));
+      debug_printf("SMTP>> %s", g->s);
       }
     helo_seen = TRUE;
 
@@ -5459,15 +5475,22 @@ while (done <= 0)
     just drop the call rather than sending QUIT, and it clutters up the logs.
     */
 
-    if (sender_address != NULL || recipients_count > 0)
-      log_write(L_lost_incoming_connection,
-          LOG_MAIN,
-          "unexpected %s while reading SMTP command from %s%s",
-          sender_host_unknown? "EOF" : "disconnection",
-          host_and_ident(FALSE), smtp_read_error);
+    if (sender_address || recipients_count > 0)
+      log_write(L_lost_incoming_connection, LOG_MAIN,
+       "unexpected %s while reading SMTP command from %s%s%s D=%s",
+       sender_host_unknown ? "EOF" : "disconnection",
+       tcp_in_fastopen && !tcp_in_fastopen_logged ? US"TFO " : US"",
+       host_and_ident(FALSE), smtp_read_error,
+       string_timesince(&smtp_connection_start)
+       );
 
-    else log_write(L_smtp_connection, LOG_MAIN, "%s lost%s",
-      smtp_get_connection_info(), smtp_read_error);
+    else
+      log_write(L_smtp_connection, LOG_MAIN, "%s %slost%s D=%s",
+        smtp_get_connection_info(),
+       tcp_in_fastopen && !tcp_in_fastopen_logged ? US"TFO " : US"",
+       smtp_read_error,
+       string_timesince(&smtp_connection_start)
+       );
 
     done = 1;
     break;