Logging: Receive duration on <= lines. Bug 353
[exim.git] / src / src / receive.c
index 9561a4baf79bcdc1f577be207ab5ee73d8ebd14f..8c7e2b5256c27b052e3ab4f21ef2b8dc168c0807 100644 (file)
@@ -190,7 +190,7 @@ if (STATVFS(CS path, &statbuf) != 0)
     log_write(0, LOG_MAIN|LOG_PANIC, "cannot accept message: failed to stat "
       "%s directory %s: %s", name, path, strerror(errno));
     smtp_closedown(US"spool or log directory problem");
-    exim_exit(EXIT_FAILURE);
+    exim_exit(EXIT_FAILURE, NULL);
     }
 
 *inodeptr = (statbuf.F_FILES > 0)? statbuf.F_FAVAIL : -1;
@@ -343,7 +343,7 @@ if (!already_bombing_out)
 
 /* Exit from the program (non-BSMTP cases) */
 
-exim_exit(EXIT_FAILURE);
+exim_exit(EXIT_FAILURE, NULL);
 }
 
 
@@ -1023,7 +1023,8 @@ int ch;
 
 /* Remember that this message uses wireformat. */
 
-DEBUG(D_receive) debug_printf("CHUNKING: writing spoolfile in wire format\n");
+DEBUG(D_receive) debug_printf("CHUNKING: %s\n",
+       fout ? "writing spoolfile in wire format" : "flushing input");
 spool_file_wireformat = TRUE;
 
 for (;;)
@@ -1077,9 +1078,10 @@ Returns:     nothing
 void
 receive_swallow_smtp(void)
 {
-/*XXX CHUNKING: not enough.  read chunks until RSET? */
 if (message_ended >= END_NOTENDED)
-  message_ended = read_message_data_smtp(NULL);
+  message_ended = chunking_state <= CHUNKING_OFFERED
+     ? read_message_data_smtp(NULL)
+     : read_message_bdat_smtp_wire(NULL);
 }
 
 
@@ -1142,7 +1144,7 @@ if (error_handling == ERRORS_SENDER)
 else
   fprintf(stderr, "exim: %s%s\n", text2, text1);  /* Sic */
 (void)fclose(f);
-exim_exit(error_rc);
+exim_exit(error_rc, US"");
 }
 
 
@@ -1291,31 +1293,34 @@ the calling host to a string that is being built dynamically.
 
 Arguments:
   s           the dynamic string
-  sizeptr     points to the size variable
-  ptrptr      points to the pointer variable
 
 Returns:      the extended string
 */
 
-static uschar *
-add_host_info_for_log(uschar * s, int * sizeptr, int * ptrptr)
+static gstring *
+add_host_info_for_log(gstring * g)
 {
 if (sender_fullhost)
   {
   if (LOGGING(dnssec) && sender_host_dnssec)   /*XXX sender_helo_dnssec? */
-    s = string_cat(s, sizeptr, ptrptr, US" DS");
-  s = string_append(s, sizeptr, ptrptr, 2, US" H=", sender_fullhost);
+    g = string_catn(g, US" DS", 3);
+  g = string_append(g, 2, US" H=", sender_fullhost);
   if (LOGGING(incoming_interface) && interface_address != NULL)
     {
-    s = string_cat(s, sizeptr, ptrptr,
+    g = string_cat(g,
       string_sprintf(" I=[%s]:%d", interface_address, interface_port));
     }
   }
-if (sender_ident != NULL)
-  s = string_append(s, sizeptr, ptrptr, 2, US" U=", sender_ident);
-if (received_protocol != NULL)
-  s = string_append(s, sizeptr, ptrptr, 2, US" P=", received_protocol);
-return s;
+if (tcp_in_fastopen && !tcp_in_fastopen_logged)
+  {
+  g = string_catn(g, US" TFO", 4);
+  tcp_in_fastopen_logged = TRUE;
+  }
+if (sender_ident)
+  g = string_append(g, 2, US" U=", sender_ident);
+if (received_protocol)
+  g = string_append(g, 2, US" P=", received_protocol);
+return g;
 }
 
 
@@ -1343,7 +1348,7 @@ run_mime_acl(uschar *acl, BOOL *smtp_yield_ptr, uschar **smtp_reply_ptr,
   uschar **blackholed_by_ptr)
 {
 FILE *mbox_file;
-uschar rfc822_file_path[2048];
+uschar * rfc822_file_path = NULL;
 unsigned long mbox_size;
 header_line *my_headerlist;
 uschar *user_msg, *log_msg;
@@ -1351,8 +1356,6 @@ int mime_part_count_buffer = -1;
 uschar * mbox_filename;
 int rc = OK;
 
-memset(CS rfc822_file_path,0,2048);
-
 /* check if it is a MIME message */
 
 for (my_headerlist = header_list; my_headerlist; my_headerlist = my_headerlist->next)
@@ -1392,7 +1395,7 @@ mime_part_count = -1;
 rc = mime_acl_check(acl, mbox_file, NULL, &user_msg, &log_msg);
 (void)fclose(mbox_file);
 
-if (Ustrlen(rfc822_file_path) > 0)
+if (rfc822_file_path)
   {
   mime_part_count = mime_part_count_buffer;
 
@@ -1400,36 +1403,31 @@ if (Ustrlen(rfc822_file_path) > 0)
     {
     log_write(0, LOG_PANIC,
          "acl_smtp_mime: can't unlink RFC822 spool file, skipping.");
-      goto END_MIME_ACL;
+    goto END_MIME_ACL;
     }
+  rfc822_file_path = NULL;
   }
 
 /* check if we must check any message/rfc822 attachments */
 if (rc == OK)
   {
-  uschar * scandir;
+  uschar * scandir = string_copyn(mbox_filename,
+             Ustrrchr(mbox_filename, '/') - mbox_filename);
   struct dirent * entry;
   DIR * tempdir;
 
-  scandir = string_copyn(mbox_filename, Ustrrchr(mbox_filename, '/') - mbox_filename);
-
-  tempdir = opendir(CS scandir);
-  for (;;)
-    {
-    if (!(entry = readdir(tempdir)))
-      break;
+  for (tempdir = opendir(CS scandir); entry = readdir(tempdir); )
     if (strncmpic(US entry->d_name, US"__rfc822_", 9) == 0)
       {
-      (void) string_format(rfc822_file_path, sizeof(rfc822_file_path),
-       "%s/%s", scandir, entry->d_name);
-      DEBUG(D_receive) debug_printf("RFC822 attachment detected: running MIME ACL for '%s'\n",
-       rfc822_file_path);
+      rfc822_file_path = string_sprintf("%s/%s", scandir, entry->d_name);
+      DEBUG(D_receive)
+       debug_printf("RFC822 attachment detected: running MIME ACL for '%s'\n",
+         rfc822_file_path);
       break;
       }
-    }
   closedir(tempdir);
 
-  if (entry)
+  if (rfc822_file_path)
     {
     if ((mbox_file = Ufopen(rfc822_file_path, "rb")))
       {
@@ -1458,10 +1456,10 @@ else if (rc != OK)
 #ifdef EXPERIMENTAL_DCC
   dcc_ok = 0;
 #endif
-  if (  smtp_input
-     && smtp_handle_acl_fail(ACL_WHERE_MIME, rc, user_msg, log_msg) != 0)
+  if (smtp_input)
     {
-    *smtp_yield_ptr = FALSE;    /* No more messages after dropped connection */
+    if (smtp_handle_acl_fail(ACL_WHERE_MIME, rc, user_msg, log_msg) != 0)
+      *smtp_yield_ptr = FALSE;  /* No more messages after dropped connection */
     *smtp_reply_ptr = US"";     /* Indicate reply already sent */
     }
   message_id[0] = 0;            /* Indicate no message accepted */
@@ -1620,7 +1618,7 @@ int  process_info_len = Ustrlen(process_info);
 int  error_rc = (error_handling == ERRORS_SENDER)?
        errors_sender_rc : EXIT_FAILURE;
 int  header_size = 256;
-int  start, end, domain, size, sptr;
+int  start, end, domain;
 int  id_resolution;
 int  had_zero = 0;
 int  prevlines_length = 0;
@@ -1645,7 +1643,8 @@ error_block *bad_addresses = NULL;
 uschar *frozen_by = NULL;
 uschar *queued_by = NULL;
 
-uschar *errmsg, *s;
+uschar *errmsg;
+gstring * g;
 struct stat statbuf;
 
 /* Final message to give to SMTP caller, and messages from ACLs */
@@ -1745,7 +1744,7 @@ message id creation below. */
 second, and for that we use the global variable received_time. This is for
 things like ultimate message timeouts. */
 
-received_time = message_id_tv.tv_sec;
+received_time = message_id_tv;
 
 /* If SMTP input, set the special handler for timeouts. The alarm() calls
 happen in the smtp_getc() function when it refills its buffer. */
@@ -1806,8 +1805,8 @@ for (;;)
   (and sometimes lunatic messages can have ones that are 100s of K long) we
   call store_release() for strings that have been copied - if the string is at
   the start of a block (and therefore the only thing in it, because we aren't
-  doing any other gets), the block gets freed. We can only do this because we
-  know there are no other calls to store_get() going on. */
+  doing any other gets), the block gets freed. We can only do this release if
+  there were no allocations since the once that we want to free. */
 
   if (ptr >= header_size - 4)
     {
@@ -1815,12 +1814,7 @@ for (;;)
     /* header_size += 256; */
     header_size *= 2;
     if (!store_extend(next->text, oldsize, header_size))
-      {
-      uschar *newtext = store_get(header_size);
-      memcpy(newtext, next->text, ptr);
-      store_release(next->text);
-      next->text = newtext;
-      }
+      next->text = store_newblock(next->text, header_size, ptr);
     }
 
   /* Cope with receiving a binary zero. There is dispute about whether
@@ -1860,7 +1854,7 @@ for (;;)
   prevent further reading), and break out of the loop, having freed the
   empty header, and set next = NULL to indicate no data line. */
 
-  if (ptr == 0 && ch == '.' && (smtp_input || dot_ends))
+  if (ptr == 0 && ch == '.' && dot_ends)
     {
     ch = (receive_getc)(GETC_BUFFER_UNLIMITED);
     if (ch == '\r')
@@ -2047,32 +2041,30 @@ for (;;)
   these lines in SMTP messages. There is now an option to ignore them from
   specified hosts or networks. Sigh. */
 
-  if (header_last == header_list &&
-       (!smtp_input
-         ||
-         (sender_host_address != NULL &&
-           verify_check_host(&ignore_fromline_hosts) == OK)
-         ||
-         (sender_host_address == NULL && ignore_fromline_local)
-       ) &&
-       regex_match_and_setup(regex_From, next->text, 0, -1))
+  if (  header_last == header_list
+     && (  !smtp_input
+        || (  sender_host_address
+          && verify_check_host(&ignore_fromline_hosts) == OK
+          )
+        || (!sender_host_address && ignore_fromline_local)
+        )
+     && regex_match_and_setup(regex_From, next->text, 0, -1)
+     )
     {
     if (!sender_address_forced)
       {
       uschar *uucp_sender = expand_string(uucp_from_sender);
-      if (uucp_sender == NULL)
-        {
+      if (!uucp_sender)
         log_write(0, LOG_MAIN|LOG_PANIC,
           "expansion of \"%s\" failed after matching "
           "\"From \" line: %s", uucp_from_sender, expand_string_message);
-        }
       else
         {
         int start, end, domain;
         uschar *errmess;
         uschar *newsender = parse_extract_address(uucp_sender, &errmess,
           &start, &end, &domain, TRUE);
-        if (newsender != NULL)
+        if (newsender)
           {
           if (domain == 0 && newsender[0] != 0)
             newsender = rewrite_address_qualify(newsender, FALSE);
@@ -2167,13 +2159,11 @@ for (;;)
         }
 
       else
-        {
         give_local_error(ERRMESS_VLONGHDRLINE,
           string_sprintf("message header line longer than %d characters "
            "received: message not accepted", header_line_maxsize), US"",
            error_rc, stdin, header_list->next);
         /* Does not return */
-        }
       }
 
     /* Note if any resent- fields exist. */
@@ -2616,8 +2606,9 @@ letter and it is not used internally.
 NOTE: If ever the format of message ids is changed, the regular expression for
 checking that a string is in this format must be updated in a corresponding
 way. It appears in the initializing code in exim.c. The macro MESSAGE_ID_LENGTH
-must also be changed to reflect the correct string length. Then, of course,
-other programs that rely on the message id format will need updating too. */
+must also be changed to reflect the correct string length. The queue-sort code
+needs to know the layout. Then, of course, other programs that rely on the
+message id format will need updating too. */
 
 Ustrncpy(message_id, string_base62((long int)(message_id_tv.tv_sec)), 6);
 message_id[6] = '-';
@@ -2628,7 +2619,7 @@ checked when it was read, to ensure it isn't too big. The timing granularity is
 left in id_resolution so that an appropriate wait can be done after receiving
 the message, if necessary (we hope it won't be). */
 
-if (host_number_string != NULL)
+if (host_number_string)
   {
   id_resolution = (BASE_62 == 62)? 5000 : 10000;
   sprintf(CS(message_id + MESSAGE_ID_LENGTH - 3), "-%2s",
@@ -2664,9 +2655,8 @@ one, but only for local (without suppress_local_fixups) or submission mode
 messages. This can be user-configured if required, but we had better flatten
 any illegal characters therein. */
 
-if (msgid_header == NULL &&
-      ((sender_host_address == NULL && !suppress_local_fixups)
-        || submission_mode))
+if (  !msgid_header
+   && ((!sender_host_address && !suppress_local_fixups) || submission_mode))
   {
   uschar *p;
   uschar *id_text = US"";
@@ -2674,20 +2664,20 @@ if (msgid_header == NULL &&
 
   /* Permit only letters, digits, dots, and hyphens in the domain */
 
-  if (message_id_domain != NULL)
+  if (message_id_domain)
     {
     uschar *new_id_domain = expand_string(message_id_domain);
-    if (new_id_domain == NULL)
+    if (!new_id_domain)
       {
       if (!expand_string_forcedfail)
         log_write(0, LOG_MAIN|LOG_PANIC,
           "expansion of \"%s\" (message_id_header_domain) "
           "failed: %s", message_id_domain, expand_string_message);
       }
-    else if (*new_id_domain != 0)
+    else if (*new_id_domain)
       {
       id_domain = new_id_domain;
-      for (p = id_domain; *p != 0; p++)
+      for (p = id_domain; *p; p++)
         if (!isalnum(*p) && *p != '.') *p = '-';  /* No need to test '-' ! */
       }
     }
@@ -2695,21 +2685,20 @@ if (msgid_header == NULL &&
   /* Permit all characters except controls and RFC 2822 specials in the
   additional text part. */
 
-  if (message_id_text != NULL)
+  if (message_id_text)
     {
     uschar *new_id_text = expand_string(message_id_text);
-    if (new_id_text == NULL)
+    if (!new_id_text)
       {
       if (!expand_string_forcedfail)
         log_write(0, LOG_MAIN|LOG_PANIC,
           "expansion of \"%s\" (message_id_header_text) "
           "failed: %s", message_id_text, expand_string_message);
       }
-    else if (*new_id_text != 0)
+    else if (*new_id_text)
       {
       id_text = new_id_text;
-      for (p = id_text; *p != 0; p++)
-        if (mac_iscntrl_or_special(*p)) *p = '-';
+      for (p = id_text; *p; p++) if (mac_iscntrl_or_special(*p)) *p = '-';
       }
     }
 
@@ -2752,9 +2741,8 @@ possible addition of a Sender: header, because untrusted_set_sender allows an
 untrusted user to set anything in the envelope (which might then get info
 From:) but we still want to ensure a valid Sender: if it is required. */
 
-if (from_header == NULL &&
-    ((sender_host_address == NULL && !suppress_local_fixups)
-      || submission_mode))
+if (  !from_header
+   && ((!sender_host_address && !suppress_local_fixups) || submission_mode))
   {
   uschar *oname = US"";
 
@@ -2763,7 +2751,7 @@ if (from_header == NULL &&
   force its value or if we have a non-SMTP message for which -f was not used
   to set the sender. */
 
-  if (sender_host_address == NULL)
+  if (!sender_host_address)
     {
     if (!trusted_caller || sender_name_forced ||
          (!smtp_input && !sender_address_forced))
@@ -2773,46 +2761,38 @@ if (from_header == NULL &&
   /* For non-locally submitted messages, the only time we use the originator
   name is when it was forced by the /name= option on control=submission. */
 
-  else
-    {
-    if (submission_name != NULL) oname = submission_name;
-    }
+  else if (submission_name) oname = submission_name;
 
   /* Envelope sender is empty */
 
-  if (sender_address[0] == 0)
+  if (!*sender_address)
     {
     uschar *fromstart, *fromend;
 
-    fromstart = string_sprintf("%sFrom: %s%s", resent_prefix,
-      oname, (oname[0] == 0)? "" : " <");
-    fromend = (oname[0] == 0)? US"" : US">";
+    fromstart = string_sprintf("%sFrom: %s%s",
+      resent_prefix, oname, *oname ? " <" : "");
+    fromend = *oname ? US">" : US"";
 
     if (sender_local || local_error_message)
-      {
       header_add(htype_from, "%s%s@%s%s\n", fromstart,
         local_part_quote(originator_login), qualify_domain_sender,
         fromend);
-      }
-    else if (submission_mode && authenticated_id != NULL)
+
+    else if (submission_mode && authenticated_id)
       {
-      if (submission_domain == NULL)
-        {
+      if (!submission_domain)
         header_add(htype_from, "%s%s@%s%s\n", fromstart,
           local_part_quote(authenticated_id), qualify_domain_sender,
           fromend);
-        }
-      else if (submission_domain[0] == 0)  /* empty => whole address set */
-        {
+
+      else if (!*submission_domain)  /* empty => whole address set */
         header_add(htype_from, "%s%s%s\n", fromstart, authenticated_id,
           fromend);
-        }
+
       else
-        {
         header_add(htype_from, "%s%s@%s%s\n", fromstart,
-          local_part_quote(authenticated_id), submission_domain,
-          fromend);
-        }
+          local_part_quote(authenticated_id), submission_domain, fromend);
+
       from_header = header_last;    /* To get it checked for Sender: */
       }
     }
@@ -2825,10 +2805,9 @@ if (from_header == NULL &&
     {
     header_add(htype_from, "%sFrom: %s%s%s%s\n", resent_prefix,
       oname,
-      (oname[0] == 0)? "" : " <",
-      (sender_address_unrewritten == NULL)?
-        sender_address : sender_address_unrewritten,
-      (oname[0] == 0)? "" : ">");
+      *oname ? " <" : "",
+      sender_address_unrewritten ? sender_address_unrewritten : sender_address,
+      *oname ? ">" : "");
 
     from_header = header_last;    /* To get it checked for Sender: */
     }
@@ -2845,11 +2824,11 @@ trusted callers to forge From: without supplying -f, we have to test explicitly
 here. If the From: header contains more than one address, then the call to
 parse_extract_address fails, and a Sender: header is inserted, as required. */
 
-if (from_header != NULL &&
-     (active_local_from_check &&
-       ((sender_local && !trusted_caller && !suppress_local_fixups) ||
-        (submission_mode && authenticated_id != NULL))
-     ))
+if (  from_header
+   && (  active_local_from_check
+      && (  sender_local && !trusted_caller && !suppress_local_fixups
+        || submission_mode && authenticated_id
+   )  )  )
   {
   BOOL make_sender = TRUE;
   int start, end, domain;
@@ -2859,37 +2838,26 @@ if (from_header != NULL &&
       &start, &end, &domain, FALSE);
   uschar *generated_sender_address;
 
-  if (submission_mode)
-    {
-    if (submission_domain == NULL)
-      {
-      generated_sender_address = string_sprintf("%s@%s",
-        local_part_quote(authenticated_id), qualify_domain_sender);
-      }
-    else if (submission_domain[0] == 0)  /* empty => full address */
-      {
-      generated_sender_address = string_sprintf("%s",
-        authenticated_id);
-      }
-    else
-      {
-      generated_sender_address = string_sprintf("%s@%s",
-        local_part_quote(authenticated_id), submission_domain);
-      }
-    }
-  else
-    generated_sender_address = string_sprintf("%s@%s",
-      local_part_quote(originator_login), qualify_domain_sender);
+  generated_sender_address = submission_mode
+    ? !submission_domain
+    ? string_sprintf("%s@%s",
+       local_part_quote(authenticated_id), qualify_domain_sender)
+    : !*submission_domain                      /* empty => full address */
+    ? string_sprintf("%s", authenticated_id)
+    : string_sprintf("%s@%s",
+       local_part_quote(authenticated_id), submission_domain)
+    : string_sprintf("%s@%s",
+       local_part_quote(originator_login), qualify_domain_sender);
 
   /* Remove permitted prefixes and suffixes from the local part of the From:
   address before doing the comparison with the generated sender. */
 
-  if (from_address != NULL)
+  if (from_address)
     {
     int slen;
-    uschar *at = (domain == 0)? NULL : from_address + domain - 1;
+    uschar *at = domain ? from_address + domain - 1 : NULL;
 
-    if (at != NULL) *at = 0;
+    if (at) *at = 0;
     from_address += route_check_prefix(from_address, local_from_prefix);
     slen = route_check_suffix(from_address, local_from_suffix);
     if (slen > 0)
@@ -2897,10 +2865,10 @@ if (from_header != NULL &&
       memmove(from_address+slen, from_address, Ustrlen(from_address)-slen);
       from_address += slen;
       }
-    if (at != NULL) *at = '@';
+    if (at) *at = '@';
 
-    if (strcmpic(generated_sender_address, from_address) == 0 ||
-      (domain == 0 && strcmpic(from_address, originator_login) == 0))
+    if (  strcmpic(generated_sender_address, from_address) == 0
+       || (!domain && strcmpic(from_address, originator_login) == 0))
         make_sender = FALSE;
     }
 
@@ -2908,8 +2876,7 @@ if (from_header != NULL &&
   appropriate rewriting rules. */
 
   if (make_sender)
-    {
-    if (submission_mode && submission_name == NULL)
+    if (submission_mode && !submission_name)
       header_add(htype_sender, "%sSender: %s\n", resent_prefix,
         generated_sender_address);
     else
@@ -2917,14 +2884,13 @@ if (from_header != NULL &&
         resent_prefix,
         submission_mode? submission_name : originator_name,
         generated_sender_address);
-    }
 
   /* Ensure that a non-null envelope sender address corresponds to the
   submission mode sender address. */
 
-  if (submission_mode && sender_address[0] != 0)
+  if (submission_mode && *sender_address)
     {
-    if (sender_address_unrewritten == NULL)
+    if (!sender_address_unrewritten)
       sender_address_unrewritten = sender_address;
     sender_address = generated_sender_address;
     if (Ustrcmp(sender_address_unrewritten, generated_sender_address) != 0)
@@ -2937,8 +2903,7 @@ if (from_header != NULL &&
 /* If there are any rewriting rules, apply them to the sender address, unless
 it has already been rewritten as part of verification for SMTP input. */
 
-if (global_rewrite_rules != NULL && sender_address_unrewritten == NULL &&
-    sender_address[0] != 0)
+if (global_rewrite_rules && !sender_address_unrewritten && *sender_address)
   {
   sender_address = rewrite_address(sender_address, FALSE, TRUE,
     global_rewrite_rules, rewrite_existflags);
@@ -2987,9 +2952,8 @@ to be more confusing if Exim adds one to all remotely-originated messages.
 As per Message-Id, we prepend if resending, else append.
 */
 
-if (!date_header_exists &&
-      ((sender_host_address == NULL && !suppress_local_fixups)
-        || submission_mode))
+if (  !date_header_exists
+   && ((!sender_host_address && !suppress_local_fixups) || submission_mode))
   header_add_at_position(!resents_exist, NULL, FALSE, htype_other,
     "%sDate: %s\n", resent_prefix, tod_stamp(tod_full));
 
@@ -3001,7 +2965,7 @@ new Received:) has not yet been set. */
 DEBUG(D_receive)
   {
   debug_printf(">>Headers after rewriting and local additions:\n");
-  for (h = header_list->next; h != NULL; h = h->next)
+  for (h = header_list->next; h; h = h->next)
     debug_printf("%c %s", h->type, h->text);
   debug_printf("\n");
   }
@@ -3103,7 +3067,7 @@ format); write it (remembering that it might contain binary zeros). The result
 of fwrite() isn't inspected; instead we call ferror() below. */
 
 fprintf(data_file, "%s-D\n", message_id);
-if (next != NULL)
+if (next)
   {
   uschar *s = next->text;
   int len = next->slen;
@@ -3158,10 +3122,10 @@ if (!ferror(data_file) && !(receive_feof)() && message_ended != END_DOT)
       log_write(L_size_reject, LOG_MAIN|LOG_REJECT, "rejected from <%s>%s%s%s%s: "
        "message too big: read=%d max=%d",
        sender_address,
-       (sender_fullhost == NULL)? "" : " H=",
-       (sender_fullhost == NULL)? US"" : sender_fullhost,
-       (sender_ident == NULL)? "" : " U=",
-       (sender_ident == NULL)? US"" : sender_ident,
+       sender_fullhost ? " H=" : "",
+       sender_fullhost ? sender_fullhost : US"",
+       sender_ident ? " U=" : "",
+       sender_ident ? sender_ident : US"",
        message_size,
        thismessage_size_limit);
 
@@ -3214,7 +3178,7 @@ if (fflush(data_file) == EOF || ferror(data_file) ||
   uschar *msg = string_sprintf("%s error (%s) while receiving message from %s",
     input_error? "Input read" : "Spool write",
     msg_errno,
-    (sender_fullhost != NULL)? sender_fullhost : sender_ident);
+    sender_fullhost ? sender_fullhost : sender_ident);
 
   log_write(0, LOG_MAIN, "Message abandoned: %s", msg);
   Uunlink(spool_name);                /* Lose the data file */
@@ -3246,6 +3210,7 @@ if (fflush(data_file) == EOF || ferror(data_file) ||
 /* No I/O errors were encountered while writing the data file. */
 
 DEBUG(D_receive) debug_printf("Data file written for message %s\n", message_id);
+if (LOGGING(receive_time)) timesince(&received_time_taken, &received_time);
 
 
 /* If there were any bad addresses extracted by -t, or there were no recipients
@@ -3259,12 +3224,12 @@ recipients or stderr error writing, throw the data file away afterwards, and
 exit. (This can't be SMTP, which always ensures there's at least one
 syntactically good recipient address.) */
 
-if (extract_recip && (bad_addresses != NULL || recipients_count == 0))
+if (extract_recip && (bad_addresses || recipients_count == 0))
   {
   DEBUG(D_receive)
     {
     if (recipients_count == 0) debug_printf("*** No recipients\n");
-    if (bad_addresses != NULL)
+    if (bad_addresses)
       {
       error_block *eblock = bad_addresses;
       debug_printf("*** Bad address(es)\n");
@@ -3295,7 +3260,7 @@ if (extract_recip && (bad_addresses != NULL || recipients_count == 0))
     }
   else
     {
-    if (bad_addresses == NULL)
+    if (!bad_addresses)
       {
       if (extracted_ignored)
         fprintf(stderr, "exim: all -t recipients overridden by command line\n");
@@ -3319,7 +3284,7 @@ if (extract_recip && (bad_addresses != NULL || recipients_count == 0))
     {
     Uunlink(spool_name);
     (void)fclose(data_file);
-    exim_exit(error_rc);
+    exim_exit(error_rc, US"receiving");
     }
   }
 
@@ -3340,7 +3305,7 @@ Note: the checking for too many Received: headers is handled by the delivery
 code. */
 /*XXX eventually add excess Received: check for cutthrough case back when classifying them */
 
-if (received_header->text == NULL)     /* Non-cutthrough case */
+if (!received_header->text)    /* Non-cutthrough case */
   {
   received_header_gen();
 
@@ -3383,110 +3348,104 @@ else
 #ifndef DISABLE_DKIM
     if (!dkim_disable_verify)
       {
-      /* Finish verification, this will log individual signature results to
-         the mainlog */
+      /* Finish verification */
       dkim_exim_verify_finish();
 
       /* Check if we must run the DKIM ACL */
       if (acl_smtp_dkim && dkim_verify_signers && *dkim_verify_signers)
         {
-        uschar *dkim_verify_signers_expanded =
+        uschar * dkim_verify_signers_expanded =
           expand_string(dkim_verify_signers);
-        if (!dkim_verify_signers_expanded)
+       gstring * results = NULL;
+       int signer_sep = 0;
+       const uschar * ptr;
+       uschar * item;
+       gstring * seen_items = NULL;
+       int old_pool = store_pool;
+
+       store_pool = POOL_PERM;   /* Allow created variables to live to data ACL */
+
+        if (!(ptr = dkim_verify_signers_expanded))
           log_write(0, LOG_MAIN|LOG_PANIC,
             "expansion of dkim_verify_signers option failed: %s",
             expand_string_message);
 
-        else
-          {
-          int sep = 0;
-          const uschar *ptr = dkim_verify_signers_expanded;
-          uschar *item = NULL;
-          uschar *seen_items = NULL;
-          int     seen_items_size = 0;
-          int     seen_items_offset = 0;
-          /* Default to OK when no items are present */
-          rc = OK;
-          while ((item = string_nextinlist(&ptr, &sep, NULL, 0)))
-            {
-            /* Prevent running ACL for an empty item */
-            if (!item || !*item) continue;
-
-            /* Only run ACL once for each domain or identity,
-           no matter how often it appears in the expanded list. */
-            if (seen_items)
-              {
-              uschar *seen_item = NULL;
-              const uschar *seen_items_list = seen_items;
-              BOOL seen_this_item = FALSE;
-
-              while ((seen_item = string_nextinlist(&seen_items_list, &sep,
-                                                    NULL, 0)))
-               if (Ustrcmp(seen_item,item) == 0)
-                 {
-                 seen_this_item = TRUE;
-                 break;
-                 }
-
-              if (seen_this_item)
-                {
-                DEBUG(D_receive)
-                  debug_printf("acl_smtp_dkim: skipping signer %s, "
-                   "already seen\n", item);
-                continue;
-                }
-
-              seen_items = string_append(seen_items, &seen_items_size,
-               &seen_items_offset, 1, ":");
-              }
-
-            seen_items = string_append(seen_items, &seen_items_size,
-             &seen_items_offset, 1, item);
-            seen_items[seen_items_offset] = '\0';
-
-            DEBUG(D_receive)
-              debug_printf("calling acl_smtp_dkim for dkim_cur_signer=%s\n",
-               item);
-
-            dkim_exim_acl_setup(item);
-            rc = acl_check(ACL_WHERE_DKIM, NULL, acl_smtp_dkim,
-                 &user_msg, &log_msg);
-
-            if (rc != OK)
+       /* Default to OK when no items are present */
+       rc = OK;
+       while ((item = string_nextinlist(&ptr, &signer_sep, NULL, 0)))
+         {
+         /* Prevent running ACL for an empty item */
+         if (!item || !*item) continue;
+
+         /* Only run ACL once for each domain or identity,
+         no matter how often it appears in the expanded list. */
+         if (seen_items)
+           {
+           uschar * seen_item;
+           const uschar * seen_items_list = string_from_gstring(seen_items);
+           int seen_sep = ':';
+           BOOL seen_this_item = FALSE;
+
+           while ((seen_item = string_nextinlist(&seen_items_list, &seen_sep,
+                                                 NULL, 0)))
+             if (Ustrcmp(seen_item,item) == 0)
+               {
+               seen_this_item = TRUE;
+               break;
+               }
+
+           if (seen_this_item)
              {
              DEBUG(D_receive)
-               debug_printf("acl_smtp_dkim: acl_check returned %d on %s, "
-                 "skipping remaining items\n", rc, item);
-             cancel_cutthrough_connection(TRUE, US"dkim acl not ok");
-             break;
+               debug_printf("acl_smtp_dkim: skipping signer %s, "
+                 "already seen\n", item);
+             continue;
              }
-            }
-          add_acl_headers(ACL_WHERE_DKIM, US"DKIM");
-          if (rc == DISCARD)
-            {
-            recipients_count = 0;
-            blackholed_by = US"DKIM ACL";
-            if (log_msg != NULL)
-              blackhole_log_msg = string_sprintf(": %s", log_msg);
-            }
-          else if (rc != OK)
-            {
-            Uunlink(spool_name);
-            if (smtp_handle_acl_fail(ACL_WHERE_DKIM, rc, user_msg, log_msg) != 0)
-              smtp_yield = FALSE;    /* No more messages after dropped connection */
-            smtp_reply = US"";       /* Indicate reply already sent */
-            message_id[0] = 0;       /* Indicate no message accepted */
-            goto TIDYUP;             /* Skip to end of function */
-            }
-          }
+
+           seen_items = string_catn(seen_items, US":", 1);
+           }
+         seen_items = string_cat(seen_items, item);
+
+         rc = dkim_exim_acl_run(item, &results, &user_msg, &log_msg);
+         if (rc != OK)
+           {
+           DEBUG(D_receive)
+             debug_printf("acl_smtp_dkim: acl_check returned %d on %s, "
+               "skipping remaining items\n", rc, item);
+           cancel_cutthrough_connection(TRUE, US"dkim acl not ok");
+           break;
+           }
+         }
+       dkim_verify_status = string_from_gstring(results);
+       store_pool = old_pool;
+       add_acl_headers(ACL_WHERE_DKIM, US"DKIM");
+       if (rc == DISCARD)
+         {
+         recipients_count = 0;
+         blackholed_by = US"DKIM ACL";
+         if (log_msg)
+           blackhole_log_msg = string_sprintf(": %s", log_msg);
+         }
+       else if (rc != OK)
+         {
+         Uunlink(spool_name);
+         if (smtp_handle_acl_fail(ACL_WHERE_DKIM, rc, user_msg, log_msg) != 0)
+           smtp_yield = FALSE;    /* No more messages after dropped connection */
+         smtp_reply = US"";       /* Indicate reply already sent */
+         message_id[0] = 0;       /* Indicate no message accepted */
+         goto TIDYUP;             /* Skip to end of function */
+         }
         }
+      else
+       dkim_exim_verify_log_all();
       }
 #endif /* DISABLE_DKIM */
 
 #ifdef WITH_CONTENT_SCAN
-    if (recipients_count > 0 &&
-        acl_smtp_mime != NULL &&
-        !run_mime_acl(acl_smtp_mime, &smtp_yield, &smtp_reply, &blackholed_by))
+    if (  recipients_count > 0
+       && acl_smtp_mime
+       && !run_mime_acl(acl_smtp_mime, &smtp_yield, &smtp_reply, &blackholed_by)
+       )
       goto TIDYUP;
 #endif /* WITH_CONTENT_SCAN */
 
@@ -3606,9 +3565,10 @@ else
     {
 
 #ifdef WITH_CONTENT_SCAN
-    if (acl_not_smtp_mime != NULL &&
-        !run_mime_acl(acl_not_smtp_mime, &smtp_yield, &smtp_reply,
-          &blackholed_by))
+    if (  acl_not_smtp_mime
+       && !run_mime_acl(acl_not_smtp_mime, &smtp_yield, &smtp_reply,
+          &blackholed_by)
+       )
       goto TIDYUP;
 #endif /* WITH_CONTENT_SCAN */
 
@@ -3767,10 +3727,8 @@ multiline SMTP responses. */
 else
   {
   uschar *istemp = US"";
-  uschar *s = NULL;
   uschar *smtp_code;
-  int size = 0;
-  int sptr = 0;
+  gstring * g;
 
   errmsg = local_scan_data;
 
@@ -3778,38 +3736,37 @@ else
   switch(rc)
     {
     default:
-    log_write(0, LOG_MAIN, "invalid return %d from local_scan(). Temporary "
-      "rejection given", rc);
-    goto TEMPREJECT;
+      log_write(0, LOG_MAIN, "invalid return %d from local_scan(). Temporary "
+       "rejection given", rc);
+      goto TEMPREJECT;
 
     case LOCAL_SCAN_REJECT_NOLOGHDR:
-    BIT_CLEAR(log_selector, log_selector_size, Li_rejected_header);
-    /* Fall through */
+      BIT_CLEAR(log_selector, log_selector_size, Li_rejected_header);
+      /* Fall through */
 
     case LOCAL_SCAN_REJECT:
-    smtp_code = US"550";
-    if (errmsg == NULL) errmsg =  US"Administrative prohibition";
-    break;
+      smtp_code = US"550";
+      if (!errmsg) errmsg =  US"Administrative prohibition";
+      break;
 
     case LOCAL_SCAN_TEMPREJECT_NOLOGHDR:
-    BIT_CLEAR(log_selector, log_selector_size, Li_rejected_header);
-    /* Fall through */
+      BIT_CLEAR(log_selector, log_selector_size, Li_rejected_header);
+      /* Fall through */
 
     case LOCAL_SCAN_TEMPREJECT:
     TEMPREJECT:
-    smtp_code = US"451";
-    if (errmsg == NULL) errmsg = US"Temporary local problem";
-    istemp = US"temporarily ";
-    break;
+      smtp_code = US"451";
+      if (!errmsg) errmsg = US"Temporary local problem";
+      istemp = US"temporarily ";
+      break;
     }
 
-  s = string_append(s, &size, &sptr, 2, US"F=",
-    (sender_address[0] == 0)? US"<>" : sender_address);
-  s = add_host_info_for_log(s, &size, &sptr);
-  s[sptr] = 0;
+  g = string_append(NULL, 2, US"F=",
+    sender_address[0] == 0 ? US"<>" : sender_address);
+  g = add_host_info_for_log(g);
 
   log_write(0, LOG_MAIN|LOG_REJECT, "%s %srejected by local_scan(): %.256s",
-    s, istemp, string_printing(errmsg));
+    string_from_gstring(g), istemp, string_printing(errmsg));
 
   if (smtp_input)
     {
@@ -3943,58 +3900,53 @@ it first! Include any message id that is in the message - since the syntax of a
 message id is actually an addr-spec, we can use the parse routine to canonicalize
 it. */
 
-size = 256;
-sptr = 0;
-s = store_get(size);
+g = string_get(256);
 
-s = string_append(s, &size, &sptr, 2,
+g = string_append(g, 2,
   fake_response == FAIL ? US"(= " : US"<= ",
   sender_address[0] == 0 ? US"<>" : sender_address);
 if (message_reference)
-  s = string_append(s, &size, &sptr, 2, US" R=", message_reference);
+  g = string_append(g, 2, US" R=", message_reference);
 
-s = add_host_info_for_log(s, &size, &sptr);
+g = add_host_info_for_log(g);
 
 #ifdef SUPPORT_TLS
 if (LOGGING(tls_cipher) && tls_in.cipher)
-  s = string_append(s, &size, &sptr, 2, US" X=", tls_in.cipher);
+  g = string_append(g, 2, US" X=", tls_in.cipher);
 if (LOGGING(tls_certificate_verified) && tls_in.cipher)
-  s = string_append(s, &size, &sptr, 2, US" CV=",
-    tls_in.certificate_verified ? "yes":"no");
+  g = string_append(g, 2, US" CV=", tls_in.certificate_verified ? "yes":"no");
 if (LOGGING(tls_peerdn) && tls_in.peerdn)
-  s = string_append(s, &size, &sptr, 3, US" DN=\"",
-    string_printing(tls_in.peerdn), US"\"");
+  g = string_append(g, 3, US" DN=\"", string_printing(tls_in.peerdn), US"\"");
 if (LOGGING(tls_sni) && tls_in.sni)
-  s = string_append(s, &size, &sptr, 3, US" SNI=\"",
-    string_printing(tls_in.sni), US"\"");
+  g = string_append(g, 3, US" SNI=\"", string_printing(tls_in.sni), US"\"");
 #endif
 
 if (sender_host_authenticated)
   {
-  s = string_append(s, &size, &sptr, 2, US" A=", sender_host_authenticated);
+  g = string_append(g, 2, US" A=", sender_host_authenticated);
   if (authenticated_id)
     {
-    s = string_append(s, &size, &sptr, 2, US":", authenticated_id);
+    g = string_append(g, 2, US":", authenticated_id);
     if (LOGGING(smtp_mailauth) && authenticated_sender)
-      s = string_append(s, &size, &sptr, 2, US":", authenticated_sender);
+      g = string_append(g, 2, US":", authenticated_sender);
     }
   }
 
 #ifndef DISABLE_PRDR
 if (prdr_requested)
-  s = string_catn(s, &size, &sptr, US" PRDR", 5);
+  g = string_catn(g, US" PRDR", 5);
 #endif
 
 #ifdef SUPPORT_PROXY
 if (proxy_session && LOGGING(proxy))
-  s = string_append(s, &size, &sptr, 2, US" PRX=", proxy_local_address);
+  g = string_append(g, 2, US" PRX=", proxy_local_address);
 #endif
 
 if (chunking_state > CHUNKING_OFFERED)
-  s = string_catn(s, &size, &sptr, US" K", 2);
+  g = string_catn(g, US" K", 2);
 
 sprintf(CS big_buffer, "%d", msg_size);
-s = string_append(s, &size, &sptr, 2, US" S=", big_buffer);
+g = string_append(g, 2, US" S=", big_buffer);
 
 /* log 8BITMIME mode announced in MAIL_FROM
    0 ... no BODY= used
@@ -4003,11 +3955,19 @@ s = string_append(s, &size, &sptr, 2, US" S=", big_buffer);
 if (LOGGING(8bitmime))
   {
   sprintf(CS big_buffer, "%d", body_8bitmime);
-  s = string_append(s, &size, &sptr, 2, US" M8S=", big_buffer);
+  g = string_append(g, 2, US" M8S=", big_buffer);
   }
 
+#ifndef DISABLE_DKIM
+if (LOGGING(dkim) && dkim_verify_overall)
+  g = string_append(g, 2, US" DKIM=", dkim_verify_overall);
+#endif
+
+if (LOGGING(receive_time))
+  g = string_append(g, 2, US" RT=", string_timediff(&received_time_taken));
+
 if (*queue_name)
-  s = string_append(s, &size, &sptr, 2, US" Q=", queue_name);
+  g = string_append(g, 2, US" Q=", queue_name);
 
 /* If an addr-spec in a message-id contains a quoted string, it can contain
 any characters except " \ and CR and so in particular it can contain NL!
@@ -4023,13 +3983,13 @@ if (msgid_header)
     &errmsg, &start, &end, &domain, FALSE);
   allow_domain_literals = save_allow_domain_literals;
   if (old_id != NULL)
-    s = string_append(s, &size, &sptr, 2, US" id=", string_printing(old_id));
+    g = string_append(g, 2, US" id=", string_printing(old_id));
   }
 
 /* If subject logging is turned on, create suitable printing-character
 text. By expanding $h_subject: we make use of the MIME decoding. */
 
-if (LOGGING(subject) && subject_header != NULL)
+if (LOGGING(subject) && subject_header)
   {
   int i;
   uschar *p = big_buffer;
@@ -4046,20 +4006,20 @@ if (LOGGING(subject) && subject_header != NULL)
     }
   *p++ = '\"';
   *p = 0;
-  s = string_append(s, &size, &sptr, 2, US" T=", string_printing(big_buffer));
+  g = string_append(g, 2, US" T=", string_printing(big_buffer));
   }
 
 /* Terminate the string: string_cat() and string_append() leave room, but do
 not put the zero in. */
 
-s[sptr] = 0;
+(void) string_from_gstring(g);
 
 /* Create a message log file if message logs are being used and this message is
 not blackholed. Write the reception stuff to it. We used to leave message log
 creation until the first delivery, but this has proved confusing for some
 people. */
 
-if (message_logs && blackholed_by == NULL)
+if (message_logs && !blackholed_by)
   {
   int fd;
 
@@ -4076,11 +4036,8 @@ if (message_logs && blackholed_by == NULL)
     }
 
   if (fd < 0)
-    {
     log_write(0, LOG_MAIN|LOG_PANIC, "Couldn't open message log %s: %s",
       spool_name, strerror(errno));
-    }
-
   else
     {
     FILE *message_log = fdopen(fd, "a");
@@ -4093,7 +4050,7 @@ if (message_logs && blackholed_by == NULL)
     else
       {
       uschar *now = tod_stamp(tod_log);
-      fprintf(message_log, "%s Received from %s\n", now, s+3);
+      fprintf(message_log, "%s Received from %s\n", now, g->s+3);
       if (deliver_freeze) fprintf(message_log, "%s frozen by %s\n", now,
         frozen_by);
       if (queue_only_policy) fprintf(message_log,
@@ -4150,11 +4107,10 @@ if (smtp_input && sender_host_address != NULL && !sender_host_notsocket &&
 
       /* Re-use the log line workspace */
 
-      sptr = 0;
-      s = string_cat(s, &size, &sptr, US"SMTP connection lost after final dot");
-      s = add_host_info_for_log(s, &size, &sptr);
-      s[sptr] = 0;
-      log_write(0, LOG_MAIN, "%s", s);
+      g->ptr = 0;
+      g = string_cat(g, US"SMTP connection lost after final dot");
+      g = add_host_info_for_log(g);
+      log_write(0, LOG_MAIN, "%s", string_from_gstring(g));
 
       /* Delete the files for this aborted message. */
 
@@ -4218,7 +4174,7 @@ if(!smtp_reply)
   log_write(0, LOG_MAIN |
     (LOGGING(received_recipients)? LOG_RECIPIENTS : 0) |
     (LOGGING(received_sender)? LOG_SENDER : 0),
-    "%s", s);
+    "%s", g->s);
 
   /* Log any control actions taken by an ACL or local_scan(). */
 
@@ -4230,7 +4186,7 @@ if(!smtp_reply)
   }
 receive_call_bombout = FALSE;
 
-store_reset(s);   /* The store for the main log message can be reused */
+store_reset(g);   /* The store for the main log message can be reused */
 
 /* If the message is frozen, and freeze_tell is set, do the telling. */