logging
[exim.git] / src / src / deliver.c
index e67c0618326f68918c9a730c91575d75776dfd2a..1fd3d46c0b967d6e0247d980eec51af35421195d 100644 (file)
@@ -2,7 +2,7 @@
 *     Exim - an Internet mail transport agent    *
 *************************************************/
 
-/* Copyright (c) University of Cambridge 1995 - 2015 */
+/* Copyright (c) University of Cambridge 1995 - 2016 */
 /* See the file NOTICE for conditions of use and distribution. */
 
 /* The main code for delivering a message. */
@@ -285,9 +285,9 @@ int fd = Uopen(filename, O_WRONLY|O_APPEND|O_CREAT, mode);
 
 if (fd < 0 && errno == ENOENT)
   {
-  uschar temp[16];
-  sprintf(CS temp, "msglog/%s", message_subdir);
-  if (message_subdir[0] == 0) temp[6] = 0;
+  uschar * temp = string_sprintf("msglog%s%s%s%s",
+                   *queue_name ? "/" : "", queue_name,
+                   *message_subdir ? "/" : "", message_subdir);
   (void)directory_make(spool_directory, temp, MSGLOG_DIRECTORY_MODE, TRUE);
   fd = Uopen(filename, O_WRONLY|O_APPEND|O_CREAT, mode);
   }
@@ -703,7 +703,7 @@ if (LOGGING(incoming_interface) && LOGGING(outgoing_interface)
   s = LOGGING(outgoing_port)
     ? string_append(s, sizep, ptrp, 2, US"]:",
        string_sprintf("%d", sending_port))
-    : string_cat(s, sizep, ptrp, US"]", 1);
+    : string_catn(s, sizep, ptrp, US"]", 1);
   }
 return s;
 }
@@ -880,6 +880,9 @@ if (LOGGING(sender_on_delivery) || msg)
       sender_address,
   US">");
 
+if (*queue_name)
+  s = string_append(s, &size, &ptr, 2, US" Q=", queue_name);
+
 #ifdef EXPERIMENTAL_SRS
 if(addr->prop.srs_sender)
   s = string_append(s, &size, &ptr, 3, US" SRS=<", addr->prop.srs_sender, US">");
@@ -914,8 +917,7 @@ if (addr->transport->info->local)
     s = string_append(s, &size, &ptr, 2, US" H=", addr->host_list->name);
   s = d_log_interface(s, &size, &ptr);
   if (addr->shadow_message)
-    s = string_cat(s, &size, &ptr, addr->shadow_message,
-      Ustrlen(addr->shadow_message));
+    s = string_cat(s, &size, &ptr, addr->shadow_message);
   }
 
 /* Remote delivery */
@@ -926,7 +928,7 @@ else
     {
     s = d_hostlog(s, &size, &ptr, addr);
     if (continue_sequence > 1)
-      s = string_cat(s, &size, &ptr, US"*", 1);
+      s = string_catn(s, &size, &ptr, US"*", 1);
 
 #ifndef DISABLE_EVENT
     deliver_host_address = addr->host_used->address;
@@ -1077,21 +1079,9 @@ malformed, it won't ever have gone near LDAP.) */
 if (addr->message)
   {
   const uschar * s = string_printing(addr->message);
-  if (s != addr->message)
-    addr->message = US s;
-    /* deconst cast ok as string_printing known to have alloc'n'copied */
-  if (  (  Ustrstr(s, "failed to expand") != NULL
-       || Ustrstr(s, "expansion of ")    != NULL
-       )
-     && (  Ustrstr(s, "mysql")   != NULL
-        || Ustrstr(s, "pgsql")   != NULL
-       || Ustrstr(s, "redis")   != NULL
-       || Ustrstr(s, "sqlite")  != NULL
-       || Ustrstr(s, "ldap:")   != NULL
-       || Ustrstr(s, "ldapdn:") != NULL
-       || Ustrstr(s, "ldapm:")  != NULL
-     )  )
-    addr->message = string_sprintf("Temporary internal error");
+
+  /* deconst cast ok as string_printing known to have alloc'n'copied */
+  addr->message = expand_hide_passwords(US s);
   }
 
 /* If we used a transport that has one of the "return_output" options set, and
@@ -1278,7 +1268,10 @@ else if (result == DEFER || result == PANIC)
 
     log_address = string_log_address(addr, LOGGING(all_parents), result == OK);
 
-    s = string_cat(s, &size, &ptr, log_address, Ustrlen(log_address));
+    s = string_cat(s, &size, &ptr, log_address);
+
+    if (*queue_name)
+      s = string_append(s, &size, &ptr, 2, US" Q=", queue_name);
 
     /* Either driver_name contains something and driver_kind contains
     " router" or " transport" (note the leading space), or driver_name is
@@ -1298,7 +1291,7 @@ else if (result == DEFER || result == PANIC)
       s = string_append(s, &size, &ptr, 2, US" ", driver_kind);
 
     sprintf(CS ss, " defer (%d)", addr->basic_errno);
-    s = string_cat(s, &size, &ptr, ss, Ustrlen(ss));
+    s = string_cat(s, &size, &ptr, ss);
 
     if (addr->basic_errno > 0)
       s = string_append(s, &size, &ptr, 2, US": ",
@@ -1396,11 +1389,14 @@ else
 
   log_address = string_log_address(addr, LOGGING(all_parents), result == OK);
 
-  s = string_cat(s, &size, &ptr, log_address, Ustrlen(log_address));
+  s = string_cat(s, &size, &ptr, log_address);
 
   if (LOGGING(sender_on_delivery))
     s = string_append(s, &size, &ptr, 3, US" F=<", sender_address, US">");
 
+  if (*queue_name)
+    s = string_append(s, &size, &ptr, 2, US" Q=", queue_name);
+
   /* Return path may not be set if no delivery actually happened */
 
   if (used_return_path && LOGGING(return_path_on_delivery))
@@ -1959,7 +1955,8 @@ if (  !shadowing
   {
   uschar *error;
   addr->return_filename =
-    string_sprintf("%s/msglog/%s/%s-%d-%d", spool_directory, message_subdir,
+    string_sprintf("%s/msglog/%s/%s/%s-%d-%d",
+      spool_directory, queue_name, message_subdir,
       message_id, getpid(), return_count++);
   addr->return_file = open_msglog_file(addr->return_filename, 0400, &error);
   if (addr->return_file < 0)
@@ -2220,6 +2217,7 @@ for (addr2 = addr; addr2; addr2 = addr2->next)
       if (message_length > 0)
         {
         len = read(pfd[pipe_read], big_buffer, message_length);
+       big_buffer[big_buffer_size-1] = '\0';           /* guard byte */
         if (len > 0) *sptr = string_copy(big_buffer);
         }
       }
@@ -3855,7 +3853,8 @@ static void
 rmt_dlv_checked_write(int fd, char id, char subid, void * buf, int size)
 {
 uschar writebuffer[PIPE_HEADER_SIZE + BIG_BUFFER_SIZE];
-int     header_length;
+int header_length;
+int ret;
 
 /* we assume that size can't get larger then BIG_BUFFER_SIZE which currently is set to 16k */
 /* complain to log if someone tries with buffer sizes we can't handle*/
@@ -3885,8 +3884,7 @@ if (buf && size > 0)
   memcpy(writebuffer + PIPE_HEADER_SIZE, buf, size);
 
 size += PIPE_HEADER_SIZE;
-int ret = write(fd, writebuffer, size);
-if(ret != size)
+if ((ret = write(fd, writebuffer, size)) != size)
   log_write(0, LOG_MAIN|LOG_PANIC_DIE, "Failed writing transport result to pipe: %s\n",
     ret == -1 ? strerror(errno) : "short write");
 }
@@ -4243,7 +4241,7 @@ for (delivery_count = 0; addr_remote; delivery_count++)
         addr_fallback = addr;
         }
 
-      else
+      else if (next)
        {
        while (next->next) next = next->next;
        next->next = addr_defer;
@@ -4384,11 +4382,10 @@ for (delivery_count = 0; addr_remote; delivery_count++)
     a dup-with-new-file-pointer. */
 
     (void)close(deliver_datafile);
-    sprintf(CS spoolname, "%s/input/%s/%s-D", spool_directory, message_subdir,
-      message_id);
-    deliver_datafile = Uopen(spoolname, O_RDWR | O_APPEND, 0);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-D",
+      spool_directory, queue_name, message_subdir, message_id);
 
-    if (deliver_datafile < 0)
+    if ((deliver_datafile = Uopen(spoolname, O_RDWR | O_APPEND, 0)) < 0)
       log_write(0, LOG_MAIN|LOG_PANIC_DIE, "Failed to reopen %s for remote "
         "parallel delivery: %s", spoolname, strerror(errno));
 
@@ -4831,7 +4828,7 @@ if (!Ufgets(buffer, sizeof(buffer), f) || Ustrcmp(buffer, "****\n") == 0)
 para = store_get(size);
 for (;;)
   {
-  para = string_cat(para, &size, &ptr, buffer, Ustrlen(buffer));
+  para = string_cat(para, &size, &ptr, buffer);
   if (!Ufgets(buffer, sizeof(buffer), f) || Ustrcmp(buffer, "****\n") == 0)
     break;
   }
@@ -5226,7 +5223,7 @@ Any failures cause messages to be written to the log, except for missing files
 while queue running - another process probably completed delivery. As part of
 opening the data file, message_subdir gets set. */
 
-if (!spool_open_datafile(id))
+if ((deliver_datafile = spool_open_datafile(id)) < 0)
   return continue_closedown();  /* yields DELIVER_NOT_ATTEMPTED */
 
 /* The value of message_size at this point has been set to the data length,
@@ -5243,8 +5240,8 @@ if ((rc = spool_read_header(spoolname, TRUE, TRUE)) != spool_read_OK)
   if (errno == ERRNO_SPOOLFORMAT)
     {
     struct stat statbuf;
-    sprintf(CS big_buffer, "%s/input/%s/%s", spool_directory, message_subdir,
-      spoolname);
+    sprintf(CS big_buffer, "%s/input/%s/%s/%s",
+      spool_directory, queue_name, message_subdir, spoolname);
     if (Ustat(big_buffer, &statbuf) == 0)
       log_write(0, LOG_MAIN, "Format error in spool file %s: "
         "size=" OFF_T_FMT, spoolname, statbuf.st_size);
@@ -5269,13 +5266,17 @@ if ((rc = spool_read_header(spoolname, TRUE, TRUE)) != spool_read_OK)
 
   if (now - received_time > keep_malformed)
     {
-    sprintf(CS spoolname, "%s/msglog/%s/%s", spool_directory, message_subdir, id);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/msglog/%s/%s/%s",
+      spool_directory, queue_name, message_subdir, id);
     Uunlink(spoolname);
-    sprintf(CS spoolname, "%s/input/%s/%s-D", spool_directory, message_subdir, id);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-D",
+      spool_directory, queue_name, message_subdir, id);
     Uunlink(spoolname);
-    sprintf(CS spoolname, "%s/input/%s/%s-H", spool_directory, message_subdir, id);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-H",
+      spool_directory, queue_name, message_subdir, id);
     Uunlink(spoolname);
-    sprintf(CS spoolname, "%s/input/%s/%s-J", spool_directory, message_subdir, id);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-J",
+      spool_directory, queue_name, message_subdir, id);
     Uunlink(spoolname);
     log_write(0, LOG_MAIN, "Message removed because older than %s",
       readconf_printtime(keep_malformed));
@@ -5295,9 +5296,10 @@ existence, as it will get further successful deliveries added to it in this
 run, and it will be deleted if this function gets to its end successfully.
 Otherwise it might be needed again. */
 
-sprintf(CS spoolname, "%s/input/%s/%s-J", spool_directory, message_subdir, id);
-jread = Ufopen(spoolname, "rb");
-if (jread)
+snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-J",
+  spool_directory, queue_name, message_subdir, id);
+
+if ((jread = Ufopen(spoolname, "rb")))
   {
   while (Ufgets(big_buffer, big_buffer_size, jread))
     {
@@ -5416,10 +5418,10 @@ if (message_logs)
   uschar *error;
   int fd;
 
-  sprintf(CS spoolname, "%s/msglog/%s/%s", spool_directory, message_subdir, id);
-  fd = open_msglog_file(spoolname, SPOOL_MODE, &error);
-
-  if (fd < 0)
+  snprintf(CS spoolname, sizeof(spoolname), "%s/msglog/%s/%s/%s",
+    spool_directory, queue_name, message_subdir, id);
+  
+  if ((fd = open_msglog_file(spoolname, SPOOL_MODE, &error)) < 0)
     {
     log_write(0, LOG_MAIN|LOG_PANIC, "Couldn't %s message log %s: %s", error,
       spoolname, strerror(errno));
@@ -6650,10 +6652,10 @@ therein are added to the non-recipients. */
 
 if (addr_local || addr_remote)
   {
-  sprintf(CS spoolname, "%s/input/%s/%s-J", spool_directory, message_subdir, id);
-  journal_fd = Uopen(spoolname, O_WRONLY|O_APPEND|O_CREAT, SPOOL_MODE);
-
-  if (journal_fd < 0)
+  snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-J",
+    spool_directory, queue_name, message_subdir, id);
+  
+  if ((journal_fd = Uopen(spoolname, O_WRONLY|O_APPEND|O_CREAT, SPOOL_MODE)) <0)
     {
     log_write(0, LOG_MAIN|LOG_PANIC, "Couldn't open journal file %s: %s",
       spoolname, strerror(errno));
@@ -6840,16 +6842,13 @@ prevents actual delivery. */
 else if (!dont_deliver)
   retry_update(&addr_defer, &addr_failed, &addr_succeed);
 
-/* Send DSN for successful messages */
-addr_dsntmp = addr_succeed;
+/* Send DSN for successful messages if requested */
 addr_senddsn = NULL;
 
-while(addr_dsntmp)
+for (addr_dsntmp = addr_succeed; addr_dsntmp; addr_dsntmp = addr_dsntmp->next)
   {
   /* af_ignore_error not honored here. it's not an error */
-  DEBUG(D_deliver)
-    {
-    debug_printf("DSN: processing router : %s\n"
+  DEBUG(D_deliver) debug_printf("DSN: processing router : %s\n"
       "DSN: processing successful delivery address: %s\n"
       "DSN: Sender_address: %s\n"
       "DSN: orcpt: %s  flags: %d\n"
@@ -6864,7 +6863,6 @@ while(addr_dsntmp)
       addr_dsntmp->address,
       addr_dsntmp->dsn_aware
       );
-    }
 
   /* send report if next hop not DSN aware or a router flagged "last DSN hop"
      and a report was requested */
@@ -6884,8 +6882,6 @@ while(addr_dsntmp)
     }
   else
     DEBUG(D_deliver) debug_printf("DSN: not sending DSN success message\n");
-
-  addr_dsntmp = addr_dsntmp->next;
   }
 
 if (addr_senddsn)
@@ -6959,7 +6955,7 @@ if (addr_senddsn)
       if (auth_xtextdecode(dsn_envid, &xdec_envid) > 0)
         fprintf(f, "Original-Envelope-ID: %s\n", dsn_envid);
       else
-        fprintf(f, "X-Original-Envelope-ID: error decoding xtext formated ENVID\n");
+        fprintf(f, "X-Original-Envelope-ID: error decoding xtext formatted ENVID\n");
       }
     fputc('\n', f);
 
@@ -7345,7 +7341,7 @@ wording. */
         if (auth_xtextdecode(dsn_envid, &xdec_envid) > 0)
           fprintf(f, "Original-Envelope-ID: %s\n", dsn_envid);
         else
-          fprintf(f, "X-Original-Envelope-ID: error decoding xtext formated ENVID\n");
+          fprintf(f, "X-Original-Envelope-ID: error decoding xtext formatted ENVID\n");
         }
       fputc('\n', f);
 
@@ -7407,6 +7403,9 @@ wording. */
       if (dsn_ret == dsn_ret_hdrs)
         topt |= topt_no_body;
       else
+       {
+       struct stat statbuf;
+
         /* no full body return at all? */
         if (!bounce_return_body)
           {
@@ -7415,16 +7414,18 @@ wording. */
           if (dsn_ret == dsn_ret_full)
             dsnnotifyhdr = dsnlimitmsg;
           }
+       /* line length limited... return headers only if oversize */
         /* size limited ... return headers only if limit reached */
-        else if (bounce_return_size_limit > 0)
-          {
-          struct stat statbuf;
-          if (fstat(deliver_datafile, &statbuf) == 0 && statbuf.st_size > max)
-            {
-              topt |= topt_no_body;
-              dsnnotifyhdr = dsnlimitmsg;
-            }
+       else if (  max_received_linelength > bounce_return_linesize_limit
+               || (  bounce_return_size_limit > 0
+                  && fstat(deliver_datafile, &statbuf) == 0
+                  && statbuf.st_size > max
+               )  )
+         {
+         topt |= topt_no_body;
+         dsnnotifyhdr = dsnlimitmsg;
           }
+       }
 
 #ifdef SUPPORT_I18N
       if (message_smtputf8)
@@ -7518,12 +7519,13 @@ if (!addr_defer)
   {
   if (message_logs)
     {
-    sprintf(CS spoolname, "%s/msglog/%s/%s", spool_directory, message_subdir,
-      id);
+    snprintf(CS spoolname, sizeof(spoolname), "%s/msglog/%s/%s/%s",
+      spool_directory, queue_name, message_subdir, id);
     if (preserve_message_logs)
       {
       int rc;
-      sprintf(CS big_buffer, "%s/msglog.OLD/%s", spool_directory, id);
+      sprintf(CS big_buffer, "%s/msglog.OLD/%s/%s",
+       spool_directory, queue_name, id);
       if ((rc = Urename(spoolname, big_buffer)) < 0)
         {
         (void)directory_make(spool_directory, US"msglog.OLD",
@@ -7542,11 +7544,13 @@ if (!addr_defer)
 
   /* Remove the two message files. */
 
-  sprintf(CS spoolname, "%s/input/%s/%s-D", spool_directory, message_subdir, id);
+  snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-D",
+    spool_directory, queue_name, message_subdir, id);
   if (Uunlink(spoolname) < 0)
     log_write(0, LOG_MAIN|LOG_PANIC_DIE, "failed to unlink %s: %s",
       spoolname, strerror(errno));
-  sprintf(CS spoolname, "%s/input/%s/%s-H", spool_directory, message_subdir, id);
+  snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-H",
+    spool_directory, queue_name, message_subdir, id);
   if (Uunlink(spoolname) < 0)
     log_write(0, LOG_MAIN|LOG_PANIC_DIE, "failed to unlink %s: %s",
       spoolname, strerror(errno));
@@ -7754,6 +7758,7 @@ else if (addr_defer != (address_item *)(+1))
         FILE *wmf = NULL;
         FILE *f = fdopen(fd, "wb");
        uschar * bound;
+        int topt;
 
         if (warn_message_file)
           if (!(wmf = Ufopen(warn_message_file, "rb")))
@@ -7872,7 +7877,7 @@ else if (addr_defer != (address_item *)(+1))
           if (auth_xtextdecode(dsn_envid, &xdec_envid) > 0)
             fprintf(f,"Original-Envelope-ID: %s\n", dsn_envid);
           else
-            fprintf(f,"X-Original-Envelope-ID: error decoding xtext formated ENVID\n");
+            fprintf(f,"X-Original-Envelope-ID: error decoding xtext formatted ENVID\n");
           }
         fputc('\n', f);
 
@@ -7900,7 +7905,7 @@ else if (addr_defer != (address_item *)(+1))
 
         fflush(f);
         /* header only as required by RFC. only failure DSN needs to honor RET=FULL */
-        int topt = topt_add_return_path | topt_no_body;
+        topt = topt_add_return_path | topt_no_body;
         transport_filter_argv = NULL;   /* Just in case */
         return_path = sender_address;   /* In case not previously set */
         /* Write the original email out */
@@ -8015,7 +8020,8 @@ if (journal_fd >= 0) (void)close(journal_fd);
 
 if (remove_journal)
   {
-  sprintf(CS spoolname, "%s/input/%s/%s-J", spool_directory, message_subdir, id);
+  snprintf(CS spoolname, sizeof(spoolname), "%s/input/%s/%s/%s-J",
+    spool_directory, queue_name, message_subdir, id);
   if (Uunlink(spoolname) < 0 && errno != ENOENT)
     log_write(0, LOG_MAIN|LOG_PANIC_DIE, "failed to unlink %s: %s", spoolname,
       strerror(errno));
@@ -8091,8 +8097,17 @@ deliver_get_sender_address (uschar * id)
 int rc;
 uschar * new_sender_address,
        * save_sender_address;
+BOOL save_qr = queue_running;
+
+/* make spool_open_datafile non-noisy on fail */
+
+queue_running = TRUE;
+
+/* Side effect: message_subdir is set for the (possibly split) spool directory */
 
-if (!spool_open_datafile(id))
+deliver_datafile = spool_open_datafile(id);
+queue_running = save_qr;
+if (deliver_datafile < 0)
   return NULL;
 
 /* Save and restore the global sender_address.  I'm not sure if we should