Close logfile after a while waiting for non-smtp input. Bug 1891
[exim.git] / src / src / log.c
index 11b3edfdfc4303b6a4b39f49c61439daf146dc2e..6eb57ca750fe8bc6c7ea860ce2ea537b67009375 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. */
 
 /* Functions for writing log files. The code for maintaining datestamped
@@ -48,7 +48,77 @@ static int    logging_mode = LOG_MODE_FILE;
 static uschar *file_path = US"";
 
 
-
+/* These should be kept in-step with the private delivery error
+number definitions in macros.h */
+
+static const uschar * exim_errstrings[] = {
+  US"",
+  US"unknown error",
+  US"user slash",
+  US"exist race",
+  US"not regular",
+  US"not directory",
+  US"bad ugid",
+  US"bad mode",
+  US"inode changed",
+  US"lock failed",
+  US"bad address2",
+  US"forbid pipe",
+  US"forbid file",
+  US"forbid reply",
+  US"missing pipe",
+  US"missing file",
+  US"missing reply",
+  US"bad redirect",
+  US"smtp closed",
+  US"smtp format",
+  US"spool format",
+  US"not absolute",
+  US"Exim-imposed quota",
+  US"held",
+  US"Delivery filter process failure",
+  US"Delivery add/remove header failure",
+  US"Delivery write incomplete error",
+  US"Some expansion failed",
+  US"Failed to get gid",
+  US"Failed to get uid",
+  US"Unset or non-existent transport",
+  US"MBX length mismatch",
+  US"Lookup failed routing or in smtp tpt",
+  US"Can't match format in appendfile",
+  US"Creation outside home in appendfile",
+  US"Can't check a list; lookup defer",
+  US"DNS lookup defer",
+  US"Failed to start TLS session",
+  US"Mandatory TLS session not started",
+  US"Failed to chown a file",
+  US"Failed to create a pipe",
+  US"When verifying",
+  US"When required by client",
+  US"Used internally in smtp transport",
+  US"RCPT gave 4xx error",
+  US"MAIL gave 4xx error",
+  US"DATA gave 4xx error",
+  US"Negotiation failed for proxy configured host",
+  US"Authenticator 'other' failure",
+  US"target not supporting SMTPUTF8",
+  US"",
+
+  US"Not time for routing",
+  US"Not time for local delivery",
+  US"Not time for any remote host",
+  US"Local-only delivery",
+  US"Domain in queue_domains",
+  US"Transport concurrency limit",
+};
+
+
+/************************************************/
+const uschar *
+exim_errstr(int err)
+{
+return err < 0 ? exim_errstrings[-err] : CUS strerror(err);
+}
 
 /*************************************************
 *              Write to syslog                   *
@@ -182,7 +252,11 @@ Returns:       a file descriptor, or < 0 on failure (errno set)
 int
 log_create(uschar *name)
 {
-int fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
+int fd = Uopen(name,
+#ifdef O_CLOEXEC
+       O_CLOEXEC |
+#endif
+       O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
 
 /* If creation failed, attempt to build a log directory in case that is the
 problem. */
@@ -196,7 +270,11 @@ if (fd < 0 && errno == ENOENT)
   DEBUG(D_any) debug_printf("%s log directory %s\n",
     created? "created" : "failed to create", name);
   *lastslash = '/';
-  if (created) fd = Uopen(name, O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
+  if (created) fd = Uopen(name,
+#ifdef O_CLOEXEC
+                       O_CLOEXEC |
+#endif
+                       O_CREAT|O_APPEND|O_WRONLY, LOG_MODE);
   }
 
 return fd;
@@ -246,7 +324,11 @@ if (pid == 0)
 /* If we created a subprocess, wait for it. If it succeeded, try the open. */
 
 while (pid > 0 && waitpid(pid, &status, 0) != pid);
-if (status == 0) fd = Uopen(name, O_APPEND|O_WRONLY, LOG_MODE);
+if (status == 0) fd = Uopen(name,
+#ifdef O_CLOEXEC
+                       O_CLOEXEC |
+#endif
+                       O_APPEND|O_WRONLY, LOG_MODE);
 
 /* If we failed to create a subprocess, we are in a bad way. We return
 with fd still < 0, and errno set, letting the caller handle the error. */
@@ -368,11 +450,17 @@ if (!ok)
 /* We now have the file name. Try to open an existing file. After a successful
 open, arrange for automatic closure on exec(), and then return. */
 
-*fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
+*fd = Uopen(buffer,
+#ifdef O_CLOEXEC
+               O_CLOEXEC |
+#endif
+               O_APPEND|O_WRONLY, LOG_MODE);
 
 if (*fd >= 0)
   {
+#ifndef O_CLOEXEC
   (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
+#endif
   return;
   }
 
@@ -399,7 +487,9 @@ else if (euid == root_uid) *fd = log_create_as_exim(buffer);
 
 if (*fd >= 0)
   {
+#ifndef O_CLOEXEC
   (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
+#endif
   return;
   }
 
@@ -420,12 +510,9 @@ 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. */
 
-if (panic_save_buffer == NULL)
-  {
-  panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
-  if (panic_save_buffer != NULL)
+if (!panic_save_buffer)
+  if ((panic_save_buffer = US malloc(LOG_BUFFER_SIZE)))
     memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE);
-  }
 
 log_write(0, LOG_PANIC_DIE, "Cannot open %s log file \"%s\": %s: "
   "euid=%d egid=%d", log_names[type], buffer, strerror(errno), euid, getegid());
@@ -433,6 +520,13 @@ log_write(0, LOG_PANIC_DIE, "Cannot open %s log file \"%s\": %s: "
 }
 
 
+static void
+unlink_log(int type)
+{
+if (type == lt_debug) unlink(CS debuglog_name);
+}
+
+
 
 /*************************************************
 *     Add configuration file info to log line    *
@@ -498,12 +592,9 @@ log_write_failed(uschar *name, int length, int rc)
 {
 int save_errno = errno;
 
-if (panic_save_buffer == NULL)
-  {
-  panic_save_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
-  if (panic_save_buffer != NULL)
+if (!panic_save_buffer)
+  if ((panic_save_buffer = US malloc(LOG_BUFFER_SIZE)))
     memcpy(panic_save_buffer, log_buffer, LOG_BUFFER_SIZE);
-  }
 
 log_write(0, LOG_PANIC_DIE, "failed to write to %s: length=%d result=%d "
   "errno=%d (%s)", name, length, rc, save_errno,
@@ -572,6 +663,14 @@ while ((t = string_nextinlist(&tt, &sep, log_buffer, LOG_BUFFER_SIZE)))
 }
 
 
+void
+mainlog_close(void)
+{
+if (mainlogfd < 0) return;
+(void)close(mainlogfd);
+mainlogfd = -1;
+mainlog_inode = 0;
+}
 
 /*************************************************
 *            Write message to log file           *
@@ -613,7 +712,7 @@ If a message_id exists, we include it after the timestamp.
 
 Arguments:
   selector  write to main log or LOG_INFO only if this value is zero, or if
-              its bit is set in log_write_selector
+              its bit is set in log_selector[0]
   flags     each bit indicates some independent action:
               LOG_SENDER      add raw sender to the message
               LOG_RECIPIENTS  add raw recipients list to message
@@ -659,15 +758,12 @@ if (panic_recurseflag)
 /* Ensure we have a buffer (see comment above); this should never be obeyed
 when running Exim proper, only when running utilities. */
 
-if (log_buffer == NULL)
-  {
-  log_buffer = (uschar *)malloc(LOG_BUFFER_SIZE);
-  if (log_buffer == NULL)
+if (!log_buffer)
+  if (!(log_buffer = US malloc(LOG_BUFFER_SIZE)))
     {
     fprintf(stderr, "exim: failed to get store for log buffer\n");
     exim_exit(EXIT_FAILURE);
     }
-  }
 
 /* If we haven't already done so, inspect the setting of log_file_path to
 determine whether to log to files and/or to syslog. Bits in logging_mode
@@ -749,15 +845,12 @@ DEBUG(D_any|D_v)
   Ustrcpy(ptr, "LOG:");
   ptr += 4;
 
-  /* Show the options that were passed into the call. These are those whose
-  flag values do not have the 0x80000000 bit in them. Note that this
-  automatically exclude the "all" setting. */
+  /* Show the selector that was passed into the call. */
 
   for (i = 0; i < log_options_count; i++)
     {
-    unsigned int bit = log_options[i].bit;
-    if ((bit & 0x80000000) != 0) continue;
-    if ((selector & bit) != 0)
+    unsigned int bitnum = log_options[i].bit;
+    if (bitnum < BITWORDSIZE && selector == BIT(bitnum))
       {
       *ptr++ = ' ';
       Ustrcpy(ptr, log_options[i].name);
@@ -809,7 +902,7 @@ ptr = log_buffer;
 sprintf(CS ptr, "%s ", tod_stamp(tod_log));
 while(*ptr) ptr++;
 
-if ((log_extra_selector & LX_pid) != 0)
+if (LOGGING(pid))
   {
   sprintf(CS ptr, "[%d] ", (int)getpid());
   while (*ptr) ptr++;
@@ -869,7 +962,7 @@ or unless there is no log_stderr (expn called from daemon, for example). */
 if (!really_exim || log_testing_mode)
   {
   if (debug_selector == 0 && log_stderr != NULL &&
-      (selector == 0 || (selector & log_write_selector) != 0))
+      (selector == 0 || (selector & log_selector[0]) != 0))
     {
     if (host_checking)
       fprintf(log_stderr, "LOG: %s", CS(log_buffer + 20));  /* no timestamp */
@@ -886,14 +979,14 @@ been opened, but we don't want to keep on writing to it for too long after it
 has been renamed. Therefore, do a stat() and see if the inode has changed, and
 if so, re-open. */
 
-if ((flags & LOG_MAIN) != 0 &&
-    (selector == 0 || (selector & log_write_selector) != 0))
+if (  flags & LOG_MAIN
+   && (!selector ||  selector & log_selector[0]))
   {
-  if ((logging_mode & LOG_MODE_SYSLOG) != 0 &&
-      (syslog_duplication || (flags & (LOG_REJECT|LOG_PANIC)) == 0))
+  if (  logging_mode & LOG_MODE_SYSLOG
+     && (syslog_duplication || !(flags & (LOG_REJECT|LOG_PANIC))))
     write_syslog(LOG_INFO, log_buffer);
 
-  if ((logging_mode & LOG_MODE_FILE) != 0)
+  if (logging_mode & LOG_MODE_FILE)
     {
     struct stat statbuf;
 
@@ -919,14 +1012,8 @@ if ((flags & LOG_MAIN) != 0 &&
     happening. */
 
     if (mainlogfd >= 0)
-      {
       if (Ustat(mainlog_name, &statbuf) < 0 || statbuf.st_ino != mainlog_inode)
-        {
-        (void)close(mainlogfd);
-        mainlogfd = -1;
-        mainlog_inode = 0;
-        }
-      }
+       mainlog_close();
 
     /* If the log is closed, open it. Then write the line. */
 
@@ -956,7 +1043,7 @@ if ((flags & LOG_REJECT) != 0)
   {
   header_line *h;
 
-  if (header_list != NULL && (log_extra_selector & LX_rejected_header) != 0)
+  if (header_list != NULL && LOGGING(rejected_header))
     {
     if (recipients_count > 0)
       {
@@ -1141,6 +1228,35 @@ syslog_open = FALSE;
 
 
 
+/*************************************************
+*             Multi-bit set or clear             *
+*************************************************/
+
+/* These functions take a list of bit indexes (terminated by -1) and
+clear or set the corresponding bits in the selector.
+
+Arguments:
+  selector       address of the bit string
+  selsize        number of words in the bit string
+  bits           list of bits to set
+*/
+
+void
+bits_clear(unsigned int *selector, size_t selsize, int *bits)
+{
+for(; *bits != -1; ++bits)
+  BIT_CLEAR(selector, selsize, *bits);
+}
+
+void
+bits_set(unsigned int *selector, size_t selsize, int *bits)
+{
+for(; *bits != -1; ++bits)
+  BIT_SET(selector, selsize, *bits);
+}
+
+
+
 /*************************************************
 *         Decode bit settings for log/debug      *
 *************************************************/
@@ -1151,13 +1267,9 @@ also recognizes a numeric setting of the form =<number>, but this is not
 intended for user use. It's an easy way for Exim to pass the debug settings
 when it is re-exec'ed.
 
-The log options are held in two unsigned ints (because there became too many
-for one). The top bit in the table means "put in 2nd selector". This does not
-yet apply to debug options, so the "=" facility sets only the first selector.
-
-The "all" selector, which must be equal to 0xffffffff, is recognized specially.
-It sets all the bits in both selectors. However, there is a facility for then
-unsetting certain bits, because we want to turn off "memory" in the debug case.
+The option table is a list of names and bit indexes. The index -1
+means "set all bits, except for those listed in notall". The notall
+list is terminated by -1.
 
 The action taken for bad values varies depending upon why we're here.
 For log messages, or if the debugging is triggered from config, then we write
@@ -1165,10 +1277,9 @@ to the log on the way out.  For debug setting triggered from the command-line,
 we treat it as an unknown option: error message to stderr and die.
 
 Arguments:
-  selector1      address of the first bit string
-  selector2      address of the second bit string, or NULL
-  notall1        bits to exclude from "all" for selector1
-  notall2        bits to exclude from "all" for selector2
+  selector       address of the bit string
+  selsize        number of words in the bit string
+  notall         list of bits to exclude from "all"
   string         the configured string
   options        the table of option names
   count          size of table
@@ -1179,9 +1290,8 @@ Returns:         nothing on success - bomb out on failure
 */
 
 void
-decode_bits(unsigned int *selector1, unsigned int *selector2, int notall1,
-  int notall2, uschar *string, bit_table *options, int count, uschar *which,
-  int flags)
+decode_bits(unsigned int *selector, size_t selsize, int *notall,
+  uschar *string, bit_table *options, int count, uschar *which, int flags)
 {
 uschar *errmsg;
 if (string == NULL) return;
@@ -1189,7 +1299,8 @@ if (string == NULL) return;
 if (*string == '=')
   {
   char *end;    /* Not uschar */
-  *selector1 = strtoul(CS string+1, &end, 0);
+  memset(selector, 0, sizeof(*selector)*selsize);
+  *selector = strtoul(CS string+1, &end, 0);
   if (*end == 0) return;
   errmsg = string_sprintf("malformed numeric %s_selector setting: %s", which,
     string);
@@ -1232,40 +1343,22 @@ else for(;;)
       if (middle->name[len] != 0) c = -1; else
         {
         unsigned int bit = middle->bit;
-        unsigned int *selector;
-
-        /* The value with all bits set means "force all bits in both selectors"
-        in the case where two are being handled. However, the top bit in the
-        second selector is never set. When setting, some bits can be excluded.
-        */
-
-        if (bit == 0xffffffff)
-          {
-          if (adding)
-            {
-            *selector1 = 0xffffffff ^ notall1;
-            if (selector2 != NULL) *selector2 = 0x7fffffff ^ notall2;
-            }
-          else
-            {
-            *selector1 = 0;
-            if (selector2 != NULL) *selector2 = 0;
-            }
-          }
-
-        /* Otherwise, the 0x80000000 bit means "this value, without the top
-        bit, belongs in the second selector". */
 
-        else
-          {
-          if ((bit & 0x80000000) != 0)
-            {
-            selector = selector2;
-            bit &= 0x7fffffff;
-            }
-          else selector = selector1;
-          if (adding) *selector |= bit; else *selector &= ~bit;
-          }
+       if (bit == -1)
+         {
+         if (adding)
+           {
+           memset(selector, -1, sizeof(*selector)*selsize);
+           bits_clear(selector, selsize, notall);
+           }
+         else
+           memset(selector, 0, sizeof(*selector)*selsize);
+         }
+       else if (adding)
+         BIT_SET(selector, selsize, bit);
+       else
+         BIT_CLEAR(selector, selsize, bit);
+
         break;  /* Out of loop to match selector name */
         }
       }
@@ -1322,7 +1415,7 @@ int fd = -1;
 if (debug_file)
   {
   debug_printf("DEBUGGING ACTIVATED FROM WITHIN CONFIG.\n"
-      "DEBUG: Tag=\"%s\" Opts=\"%s\"\n", tag_name, opts ? opts : US"");
+      "DEBUG: Tag=\"%s\" opts=\"%s\"\n", tag_name, opts ? opts : US"");
   return;
   }
 
@@ -1335,10 +1428,8 @@ if (tag_name != NULL && (Ustrchr(tag_name, '/') != NULL))
 
 debug_selector = D_default;
 if (opts)
-  {
-  decode_bits(&debug_selector, NULL, D_memory, 0, opts,
+  decode_bits(&debug_selector, 1, debug_notall, opts,
       debug_options, debug_options_count, US"debug", DEBUG_FROM_CONFIG);
-  }
 
 /* When activating from a transport process we may never have logged at all
 resulting in certain setup not having been done.  Hack this for now so we
@@ -1355,4 +1446,16 @@ else
 }
 
 
+void
+debug_logging_stop(void)
+{
+if (!debug_file || !debuglog_name[0]) return;
+
+debug_selector = 0;
+fclose(debug_file);
+debug_file = NULL;
+unlink_log(lt_debug);
+}
+
+
 /* End of log.c */