debug tidying
[exim.git] / src / src / log.c
index 6d8fdd24d1ac518601a6e13757ea7a8edf312e85..2dd85c4842a19d94d49ba1ba8db038bfb9fdaa2b 100644 (file)
@@ -112,6 +112,7 @@ static const uschar * exim_errstrings[] = {
   US"Local-only delivery",
   US"Domain in queue_domains",
   US"Transport concurrency limit",
+  US"Event requests alternate response",
 };
 
 
@@ -142,7 +143,7 @@ Returns:         nothing
 static void
 write_syslog(int priority, const uschar *s)
 {
-int len, pass;
+int len;
 int linecount = 0;
 
 if (!syslog_pid && LOGGING(pid))
@@ -157,7 +158,7 @@ if (!syslog_timestamp)
 len = Ustrlen(s);
 
 #ifndef NO_OPENLOG
-if (!syslog_open && !running_in_test_harness)
+if (!syslog_open && !f.running_in_test_harness)
   {
 # ifdef SYSLOG_LOG_PID
   openlog(CS syslog_processname, LOG_PID|LOG_CONS, syslog_facility);
@@ -171,12 +172,10 @@ if (!syslog_open && !running_in_test_harness)
 /* First do a scan through the message in order to determine how many lines
 it is going to end up as. Then rescan to output it. */
 
-for (pass = 0; pass < 2; pass++)
+for (int pass = 0; pass < 2; pass++)
   {
-  int i;
-  int tlen;
   const uschar * ss = s;
-  for (i = 1, tlen = len; tlen > 0; i++)
+  for (int i = 1, tlen = len; tlen > 0; i++)
     {
     int plen = tlen;
     uschar *nlptr = Ustrchr(ss, '\n');
@@ -189,7 +188,7 @@ for (pass = 0; pass < 2; pass++)
 
     if (pass == 0)
       linecount++;
-    else if (running_in_test_harness)
+    else if (f.running_in_test_harness)
       if (linecount == 1)
         fprintf(stderr, "SYSLOG: '%.*s'\n", plen, ss);
       else
@@ -241,7 +240,7 @@ if (s1)
   if (log_stderr && log_stderr != debug_file)
     fprintf(log_stderr, "%s\n", s1);
   }
-if (receive_call_bombout) receive_bomb_out(NULL, s2);  /* does not return */
+if (f.receive_call_bombout) receive_bomb_out(NULL, s2);  /* does not return */
 if (smtp_input) smtp_closedown(s2);
 exim_exit(EXIT_FAILURE, NULL);
 }
@@ -314,7 +313,7 @@ Returns:       a file descriptor, or < 0 on failure (errno set)
 int
 log_create_as_exim(uschar *name)
 {
-pid_t pid = fork();
+pid_t pid = exim_fork(US"logfile-create");
 int status = 1;
 int fd = -1;
 
@@ -511,7 +510,7 @@ non-setuid binary with log_arguments set, called in certain ways.) Rather than
 just bombing out, force the log to stderr and carry on if stderr is available.
 */
 
-if (euid != root_uid && euid != exim_uid && log_stderr != NULL)
+if (euid != root_uid && euid != exim_uid && log_stderr)
   {
   *fd = fileno(log_stderr);
   return;
@@ -520,7 +519,9 @@ if (euid != root_uid && euid != exim_uid && log_stderr != NULL)
 /* Otherwise this is a disaster. This call is deliberately ONLY to the panic
 log. If possible, save a copy of the original line that was being logged. If we
 are recursing (can't open the panic log either), the pointer will already be
-set. */
+set.  Also, when we had to use a subprocess for the create we didn't retrieve
+errno from it, so get the error from the open attempt above (which is often
+meaningful enough, so leave it). */
 
 if (!panic_save_buffer)
   if ((panic_save_buffer = US malloc(LOG_BUFFER_SIZE)))
@@ -554,23 +555,18 @@ Arguments:
 Returns:      updated pointer
 */
 
-static uschar *
-log_config_info(uschar *ptr, int flags)
+static gstring *
+log_config_info(gstring * g, int flags)
 {
-Ustrcpy(ptr, "Exim configuration error");
-ptr += 24;
+g = string_cat(g, US"Exim configuration error");
 
-if ((flags & (LOG_CONFIG_FOR & ~LOG_CONFIG)) != 0)
-  {
-  Ustrcpy(ptr, " for ");
-  return ptr + 5;
-  }
+if (flags & (LOG_CONFIG_FOR & ~LOG_CONFIG))
+  return string_cat(g, US" for ");
 
-if ((flags & (LOG_CONFIG_IN & ~LOG_CONFIG)) != 0)
-  ptr += sprintf(CS ptr, " in line %d of %s", config_lineno, config_filename);
+if (flags & (LOG_CONFIG_IN & ~LOG_CONFIG))
+  g = string_fmt_append(g, " in line %d of %s", config_lineno, config_filename);
 
-Ustrcpy(ptr, ":\n  ");
-return ptr + 4;
+return string_catn(g, US":\n  ", 4);
 }
 
 
@@ -741,10 +737,10 @@ Returns:    nothing
 void
 log_write(unsigned int selector, int flags, const char *format, ...)
 {
-uschar * ptr;
-int length;
 int paniclogfd;
 ssize_t written_len;
+gstring gs = { .size = LOG_BUFFER_SIZE-1, .ptr = 0, .s = log_buffer };
+gstring * g;
 va_list ap;
 
 /* If panic_recurseflag is set, we have failed to open the panic log. This is
@@ -851,10 +847,8 @@ in one go so that it doesn't get split when multi-processing. */
 DEBUG(D_any|D_v)
   {
   int i;
-  ptr = log_buffer;
 
-  Ustrcpy(ptr, "LOG:");
-  ptr += 4;
+  g = string_catn(&gs, US"LOG:", 4);
 
   /* Show the selector that was passed into the call. */
 
@@ -862,31 +856,38 @@ DEBUG(D_any|D_v)
     {
     unsigned int bitnum = log_options[i].bit;
     if (bitnum < BITWORDSIZE && selector == BIT(bitnum))
-      {
-      *ptr++ = ' ';
-      Ustrcpy(ptr, log_options[i].name);
-      while (*ptr) ptr++;
-      }
+      g = string_fmt_append(g, " %s", log_options[i].name);
     }
 
-  ptr += sprintf(CS ptr, "%s%s%s%s\n  ",
+  g = string_fmt_append(g, "%s%s%s%s\n  ",
     flags & LOG_MAIN ?    " MAIN"   : "",
     flags & LOG_PANIC ?   " PANIC"  : "",
     (flags & LOG_PANIC_DIE) == LOG_PANIC_DIE ? " DIE" : "",
     flags & LOG_REJECT ?  " REJECT" : "");
 
-  if (flags & LOG_CONFIG) ptr = log_config_info(ptr, flags);
+  if (flags & LOG_CONFIG) g = log_config_info(g, flags);
+
+  /* We want to be able to log tainted info, but log_buffer is directly
+  malloc'd.  So use deliberately taint-nonchecking routines to build into
+  it, trusting that we will never expand the results. */
 
   va_start(ap, format);
-  if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
-    Ustrcpy(ptr, "**** log string overflowed log buffer ****");
+  i = g->ptr;
+  if (!string_vformat(g, SVFMT_TAINT_NOCHK, format, ap))
+    {
+    g->ptr = i;
+    g = string_cat(g, US"**** log string overflowed log buffer ****");
+    }
   va_end(ap);
 
-  while(*ptr) ptr++;
-  Ustrcat(ptr, "\n");
-  debug_printf("%s", log_buffer);
-  }
+  g->size = LOG_BUFFER_SIZE;
+  g = string_catn(g, US"\n", 1);
+  debug_printf("%s", string_from_gstring(g));
 
+  gs.size = LOG_BUFFER_SIZE-1; /* Having used the buffer for debug output, */
+  gs.ptr = 0;                  /* reset it for the real use. */
+  gs.s = log_buffer;
+  }
 /* If no log file is specified, we are in a mess. */
 
 if (!(flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT)))
@@ -895,7 +896,7 @@ if (!(flags & (LOG_MAIN|LOG_PANIC|LOG_REJECT)))
 
 /* There are some weird circumstances in which logging is disabled. */
 
-if (disable_logging)
+if (f.disable_logging)
   {
   DEBUG(D_any) debug_printf("log writing disabled\n");
   return;
@@ -908,60 +909,70 @@ if (!write_rejectlog) flags &= ~LOG_REJECT;
 /* Create the main message in the log buffer. Do not include the message id
 when called by a utility. */
 
-ptr = log_buffer;
-ptr += sprintf(CS ptr, "%s ", tod_stamp(tod_log));
+g = string_fmt_append(&gs, "%s ", tod_stamp(tod_log));
 
 if (LOGGING(pid))
   {
-  if (!syslog_pid) pid_position[0] = ptr - log_buffer; /* remember begin … */
-  ptr += sprintf(CS ptr, "[%d] ", (int)getpid());
-  if (!syslog_pid) pid_position[1] = ptr - log_buffer; /*  … and end+1 of the PID */
+  if (!syslog_pid) pid_position[0] = g->ptr;           /* remember begin … */
+  g = string_fmt_append(g, "[%d] ", (int)getpid());
+  if (!syslog_pid) pid_position[1] = g->ptr;           /*  … and end+1 of the PID */
   }
 
-if (really_exim && message_id[0] != 0)
-  ptr += sprintf(CS ptr, "%s ", message_id);
+if (f.really_exim && message_id[0] != 0)
+  g = string_fmt_append(g, "%s ", message_id);
 
-if (flags & LOG_CONFIG) ptr = log_config_info(ptr, flags);
+if (flags & LOG_CONFIG)
+  g = log_config_info(g, flags);
 
 va_start(ap, format);
-if (!string_vformat(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer)-1, format, ap))
-  Ustrcpy(ptr, "**** log string overflowed log buffer ****\n");
-while(*ptr) ptr++;
+  {
+  int i = g->ptr;
+
+  /* We want to be able to log tainted info, but log_buffer is directly
+  malloc'd.  So use deliberately taint-nonchecking routines to build into
+  it, trusting that we will never expand the results. */
+
+  if (!string_vformat(g, SVFMT_TAINT_NOCHK, format, ap))
+    {
+    g->ptr = i;
+    g = string_cat(g, US"**** log string overflowed log buffer ****\n");
+    }
+  }
 va_end(ap);
 
 /* Add the raw, unrewritten, sender to the message if required. This is done
 this way because it kind of fits with LOG_RECIPIENTS. */
 
 if (   flags & LOG_SENDER
-    && ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
-  ptr += sprintf(CS ptr, " from <%s>", raw_sender);
+   && g->ptr < LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
+  g = string_fmt_append_f(g, SVFMT_TAINT_NOCHK, " from <%s>", raw_sender);
 
 /* Add list of recipients to the message if required; the raw list,
 before rewriting, was saved in raw_recipients. There may be none, if an ACL
 discarded them all. */
 
 if (  flags & LOG_RECIPIENTS
-   && ptr < log_buffer + LOG_BUFFER_SIZE - 6
+   && g->ptr < LOG_BUFFER_SIZE - 6
    && raw_recipients_count > 0)
   {
   int i;
-  ptr += sprintf(CS ptr, " for");
+  g = string_fmt_append_f(g, SVFMT_TAINT_NOCHK, " for", NULL);
   for (i = 0; i < raw_recipients_count; i++)
     {
     uschar * s = raw_recipients[i];
-    if (log_buffer + LOG_BUFFER_SIZE - ptr < Ustrlen(s) + 3) break;
-    ptr += sprintf(CS ptr, " %s", s);
+    if (LOG_BUFFER_SIZE - g->ptr < Ustrlen(s) + 3) break;
+    g = string_fmt_append_f(g, SVFMT_TAINT_NOCHK, " %s", s);
     }
   }
 
-ptr += sprintf(CS  ptr, "\n");
-length = ptr - log_buffer;
+g = string_catn(g, US"\n", 1);
+string_from_gstring(g);
 
 /* Handle loggable errors when running a utility, or when address testing.
 Write to log_stderr unless debugging (when it will already have been written),
 or unless there is no log_stderr (expn called from daemon, for example). */
 
-if (!really_exim || log_testing_mode)
+if (!f.really_exim || f.log_testing_mode)
   {
   if (  !debug_selector
      && log_stderr
@@ -1028,10 +1039,10 @@ if (  flags & LOG_MAIN
 
     /* Failing to write to the log is disastrous */
 
-    written_len = write_to_fd_buf(mainlogfd, log_buffer, length);
-    if (written_len != length)
+    written_len = write_to_fd_buf(mainlogfd, g->s, g->ptr);
+    if (written_len != g->ptr)
       {
-      log_write_failed(US"main log", length, written_len);
+      log_write_failed(US"main log", g->ptr, written_len);
       /* That function does not return */
       }
     }
@@ -1044,66 +1055,62 @@ headers. */
 
 if (flags & LOG_REJECT)
   {
-  header_line *h;
-
   if (header_list && LOGGING(rejected_header))
     {
+    gstring * g2;
+    int i;
+
     if (recipients_count > 0)
       {
-      int i;
-
       /* List the sender */
 
-      string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
-        "Envelope-from: <%s>\n", sender_address);
-      while (*ptr) ptr++;
+      g2 = string_fmt_append_f(g, SVFMT_TAINT_NOCHK,
+                       "Envelope-from: <%s>\n", sender_address);
+      if (g2) g = g2;
 
       /* List up to 5 recipients */
 
-      string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
-        "Envelope-to: <%s>\n", recipients_list[0].address);
-      while (*ptr) ptr++;
+      g2 = string_fmt_append_f(g, SVFMT_TAINT_NOCHK,
+                       "Envelope-to: <%s>\n", recipients_list[0].address);
+      if (g2) g = g2;
 
       for (i = 1; i < recipients_count && i < 5; i++)
         {
-        string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer), "    <%s>\n",
-          recipients_list[i].address);
-        while (*ptr) ptr++;
+        g2 = string_fmt_append_f(g, SVFMT_TAINT_NOCHK,
+                       "    <%s>\n", recipients_list[i].address);
+       if (g2) g = g2;
         }
 
       if (i < recipients_count)
         {
-        (void)string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
-          "    ...\n");
-        while (*ptr) ptr++;
+        g2 = string_fmt_append_f(g, SVFMT_TAINT_NOCHK, "    ...\n", NULL);
+       if (g2) g = g2;
         }
       }
 
     /* A header with a NULL text is an unfilled in Received: header */
 
-    for (h = header_list; h; h = h->next) if (h->text)
+    for (header_line * h = header_list; h; h = h->next) if (h->text)
       {
-      BOOL fitted = string_format(ptr, LOG_BUFFER_SIZE - (ptr-log_buffer),
-        "%c %s", h->type, h->text);
-      while(*ptr) ptr++;
-      if (!fitted)         /* Buffer is full; truncate */
+      g2 = string_fmt_append_f(g, SVFMT_TAINT_NOCHK,
+                       "%c %s", h->type, h->text);
+      if (g2)
+       g = g2;
+      else             /* Buffer is full; truncate */
         {
-        ptr -= 100;        /* For message and separator */
-        if (ptr[-1] == '\n') ptr--;
-        Ustrcpy(ptr, "\n*** truncated ***\n");
-        while (*ptr) ptr++;
+        g->ptr -= 100;        /* For message and separator */
+        if (g->s[g->ptr-1] == '\n') g->ptr--;
+        g = string_cat(g, US"\n*** truncated ***\n");
         break;
         }
       }
-
-    length = ptr - log_buffer;
     }
 
   /* Write to syslog or to a log file */
 
   if (  logging_mode & LOG_MODE_SYSLOG
      && (syslog_duplication || !(flags & LOG_PANIC)))
-    write_syslog(LOG_NOTICE, log_buffer);
+    write_syslog(LOG_NOTICE, string_from_gstring(g));
 
   /* Check for a change to the rejectlog file name when datestamping is in
   operation. This happens at midnight, at which point we want to roll over
@@ -1147,10 +1154,10 @@ if (flags & LOG_REJECT)
       if (fstat(rejectlogfd, &statbuf) >= 0) rejectlog_inode = statbuf.st_ino;
       }
 
-    written_len = write_to_fd_buf(rejectlogfd, log_buffer, length);
-    if (written_len != length)
+    written_len = write_to_fd_buf(rejectlogfd, g->s, g->ptr);
+    if (written_len != g->ptr)
       {
-      log_write_failed(US"reject log", length, written_len);
+      log_write_failed(US"reject log", g->ptr, written_len);
       /* That function does not return */
       }
     }
@@ -1165,7 +1172,7 @@ all cases except mua_wrapper, try to write to log_stderr. */
 if (flags & LOG_PANIC)
   {
   if (log_stderr && log_stderr != debug_file && !mua_wrapper)
-    fprintf(log_stderr, "%s", CS log_buffer);
+    fprintf(log_stderr, "%s", CS string_from_gstring(g));
 
   if (logging_mode & LOG_MODE_SYSLOG)
     write_syslog(LOG_ALERT, log_buffer);
@@ -1185,14 +1192,14 @@ if (flags & LOG_PANIC)
       i = i;   /* compiler quietening */
       }
 
-    written_len = write_to_fd_buf(paniclogfd, log_buffer, length);
-    if (written_len != length)
+    written_len = write_to_fd_buf(paniclogfd, g->s, g->ptr);
+    if (written_len != g->ptr)
       {
       int save_errno = errno;
       write_syslog(LOG_CRIT, log_buffer);
       sprintf(CS log_buffer, "write failed on panic log: length=%d result=%d "
-        "errno=%d (%s)", length, (int)written_len, save_errno, strerror(save_errno));
-      write_syslog(LOG_CRIT, log_buffer);
+        "errno=%d (%s)", g->ptr, (int)written_len, save_errno, strerror(save_errno));
+      write_syslog(LOG_CRIT, string_from_gstring(g));
       flags |= LOG_PANIC_DIE;
       }