-/* $Cambridge: exim/src/src/log.c,v 1.1 2004/10/07 10:39:01 ph10 Exp $ */
+/* $Cambridge: exim/src/src/log.c,v 1.15 2010/06/06 00:27:52 pdp Exp $ */
/*************************************************
* Exim - an Internet mail transport agent *
*************************************************/
-/* Copyright (c) University of Cambridge 1995 - 2004 */
+/* Copyright (c) University of Cambridge 1995 - 2009 */
/* See the file NOTICE for conditions of use and distribution. */
/* Functions for writing log files. The code for maintaining datestamped
#define LOG_MODE_FILE 1
#define LOG_MODE_SYSLOG 2
-enum { lt_main, lt_reject, lt_panic, lt_process };
+enum { lt_main, lt_reject, lt_panic, lt_debug, lt_process };
-static uschar *log_names[] = { US"main", US"reject", US"panic", US"process" };
+static uschar *log_names[] = { US"main", US"reject", US"panic", US"debug", US"process" };
static uschar mainlog_name[LOG_NAME_SIZE];
static uschar rejectlog_name[LOG_NAME_SIZE];
+static uschar debuglog_name[LOG_NAME_SIZE];
static uschar *mainlog_datestamp = NULL;
static uschar *rejectlog_datestamp = NULL;
/* The given string is split into sections according to length, or at embedded
newlines, and syslogged as a numbered sequence if it is overlong or if there is
-more than one line.
+more than one line. However, if we are running in the test harness, do not do
+anything. (The test harness doesn't use syslog - for obvious reasons - but we
+can get here if there is a failure to open the panic log.)
Arguments:
priority syslog priority
int len, pass;
int linecount = 0;
+if (running_in_test_harness) return;
+
if (!syslog_timestamp) s += log_timezone? 26 : 20;
len = Ustrlen(s);
/* This is called when Exim is dying as a result of something going wrong in
the logging, or after a log call with LOG_PANIC_DIE set. Optionally write a
message to debug_file or a stderr file, if they exist. Then, if in the middle
-of accepting a message, throw it away tidily; this will attempt to send an SMTP
-response if appropriate. Otherwise, try to close down an outstanding SMTP call
-tidily.
+of accepting a message, throw it away tidily by calling receive_bomb_out();
+this will attempt to send an SMTP response if appropriate. Passing NULL as the
+first argument stops it trying to run the NOTQUIT ACL (which might try further
+logging and thus cause problems). Otherwise, try to close down an outstanding
+SMTP call tidily.
Arguments:
s1 Error message to write to debug_file and/or stderr and syslog
if (log_stderr != NULL && log_stderr != debug_file)
fprintf(log_stderr, "%s\n", s1);
}
-if (receive_call_bombout) receive_bomb_out(s2); /* does not return */
+if (receive_call_bombout) receive_bomb_out(NULL, s2); /* does not return */
if (smtp_input) smtp_closedown(s2);
exim_exit(EXIT_FAILURE);
}
Arguments:
fd where to return the resulting file descriptor
- type lt_main, lt_reject, lt_panic, or lt_process
+ type lt_main, lt_reject, lt_panic, lt_debug or lt_process
+ tag optional tag to include in the name (only hooked up for debug)
Returns: nothing
*/
static void
-open_log(int *fd, int type)
+open_log(int *fd, int type, uschar *tag)
{
uid_t euid;
-BOOL ok;
+BOOL ok, ok2;
uschar buffer[LOG_NAME_SIZE];
/* Sort out the file name. This depends on the type of log we are opening. The
rejectlog_datestamp = rejectlog_name + string_datestamp_offset;
}
+ /* and deal with the debug log (which keeps the datestamp, but does not
+ update it) */
+
+ else if (type == lt_debug)
+ {
+ Ustrcpy(debuglog_name, buffer);
+ if (tag)
+ {
+ /* this won't change the offset of the datestamp */
+ ok2 = string_format(buffer, sizeof(buffer), "%s%s",
+ debuglog_name, tag);
+ if (ok2)
+ Ustrcpy(debuglog_name, buffer);
+ }
+ }
+
/* Remove any datestamp if this is the panic log. This is rare, so there's no
need to optimize getting the datestamp length. We remove one non-alphanumeric
char afterwards if at the start, otherwise one before. */
if (*fd >= 0)
{
- fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
+ (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
return;
}
/* Open was not successful: try creating the file. If this is a root process,
we must do the creating in a subprocess set to exim:exim in order to ensure
that the file is created with the right ownership. Otherwise, there can be a
-race if an exim process is trying to write to the log at the same time. The use
-of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous writing. */
+race if another Exim process is trying to write to the log at the same time.
+The use of SIGUSR1 by the exiwhat utility can provoke a lot of simultaneous
+writing. */
euid = geteuid();
_exit((create_log(buffer) < 0)? 1 : 0);
}
- /* Wait for the subprocess. If it succeeded retry the open. */
+ /* If we created a subprocess, wait for it. If it succeeded retry the open. */
- while (waitpid(pid, &status, 0) != pid);
- if (status == 0) *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
+ if (pid > 0)
+ {
+ while (waitpid(pid, &status, 0) != pid);
+ if (status == 0) *fd = Uopen(buffer, O_APPEND|O_WRONLY, LOG_MODE);
+ }
+
+ /* If we failed to create a subprocess, we are in a bad way. We fall through
+ with *fd still < 0, and errno set, letting the code below handle the error. */
}
/* If we now have an open file, set the close-on-exec flag and return. */
if (*fd >= 0)
{
- fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
+ (void)fcntl(*fd, F_SETFD, fcntl(*fd, F_GETFD) | FD_CLOEXEC);
return;
}
return;
}
+/* Handle disabled reject log */
+
+if (!write_rejectlog) flags &= ~LOG_REJECT;
+
/* Create the main message in the log buffer, including the message
id except for the process log and when called by a utility. */
ptr = log_buffer;
+sprintf(CS ptr, "%s ", tod_stamp(tod_log));
+while(*ptr) ptr++;
+
+if ((log_extra_selector & LX_pid) != 0)
+ {
+ sprintf(CS ptr, "[%d] ", (int)getpid());
+ while (*ptr) ptr++;
+ }
+
if (really_exim && (flags & LOG_PROCESS) == 0 && message_id[0] != 0)
- sprintf(CS ptr, "%s %s ", tod_stamp(tod_log), message_id);
-else sprintf(CS ptr, "%s ", tod_stamp(tod_log));
+ {
+ sprintf(CS ptr, "%s ", message_id);
+ while(*ptr) ptr++;
+ }
-while(*ptr) ptr++;
if ((flags & LOG_CONFIG) != 0) ptr = log_config_info(ptr, flags);
va_start(ap, format);
this way because it kind of fits with LOG_RECIPIENTS. */
if ((flags & LOG_SENDER) != 0 &&
- ptr < log_buffer + LOG_BUFFER_SIZE - 8 - Ustrlen(raw_sender))
+ ptr < log_buffer + LOG_BUFFER_SIZE - 10 - Ustrlen(raw_sender))
{
sprintf(CS ptr, " from <%s>", raw_sender);
while (*ptr) ptr++;
uschar *nowstamp = tod_stamp(tod_log_datestamp);
if (Ustrncmp (mainlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
{
- close(mainlogfd); /* Close the file */
+ (void)close(mainlogfd); /* Close the file */
mainlogfd = -1; /* Clear the file descriptor */
mainlog_inode = 0; /* Unset the inode */
mainlog_datestamp = NULL; /* Clear the datestamp */
{
if (Ustat(mainlog_name, &statbuf) < 0 || statbuf.st_ino != mainlog_inode)
{
- close(mainlogfd);
+ (void)close(mainlogfd);
mainlogfd = -1;
mainlog_inode = 0;
}
if (mainlogfd < 0)
{
- open_log(&mainlogfd, lt_main); /* No return on error */
+ open_log(&mainlogfd, lt_main, NULL); /* No return on error */
if (fstat(mainlogfd, &statbuf) >= 0) mainlog_inode = statbuf.st_ino;
}
}
}
-/* Handle the log for rejected messages. This can be globally disabled. If
-there are any header lines (i.e. if the rejection is happening after the DATA
-phase), log the recipients and the headers. */
+/* Handle the log for rejected messages. This can be globally disabled, in
+which case the flags are altered above. If there are any header lines (i.e. if
+the rejection is happening after the DATA phase), log the recipients and the
+headers. */
-if (write_rejectlog && (flags & LOG_REJECT) != 0)
+if ((flags & LOG_REJECT) != 0)
{
header_line *h;
uschar *nowstamp = tod_stamp(tod_log_datestamp);
if (Ustrncmp (rejectlog_datestamp, nowstamp, Ustrlen(nowstamp)) != 0)
{
- close(rejectlogfd); /* Close the file */
+ (void)close(rejectlogfd); /* Close the file */
rejectlogfd = -1; /* Clear the file descriptor */
rejectlog_inode = 0; /* Unset the inode */
rejectlog_datestamp = NULL; /* Clear the datestamp */
if (Ustat(rejectlog_name, &statbuf) < 0 ||
statbuf.st_ino != rejectlog_inode)
{
- close(rejectlogfd);
+ (void)close(rejectlogfd);
rejectlogfd = -1;
rejectlog_inode = 0;
}
if (rejectlogfd < 0)
{
- open_log(&rejectlogfd, lt_reject); /* No return on error */
+ open_log(&rejectlogfd, lt_reject, NULL); /* No return on error */
if (fstat(rejectlogfd, &statbuf) >= 0) rejectlog_inode = statbuf.st_ino;
}
if ((flags & LOG_PROCESS) != 0)
{
int processlogfd;
- open_log(&processlogfd, lt_process); /* No return on error */
+ open_log(&processlogfd, lt_process, NULL); /* No return on error */
if ((rc = write(processlogfd, log_buffer, length)) != length)
{
log_write_failed(US"process log", length, rc);
/* Handle the panic log, which is not kept open like the others. If it fails to
open, there will be a recursive call to log_write(). We detect this above and
attempt to write to the system log as a last-ditch try at telling somebody. In
-all cases, try to write to log_stderr. */
+all cases except mua_wrapper, try to write to log_stderr. */
if ((flags & LOG_PANIC) != 0)
{
- if (log_stderr != NULL && log_stderr != debug_file)
+ if (log_stderr != NULL && log_stderr != debug_file && !mua_wrapper)
fprintf(log_stderr, "%s", CS log_buffer);
if ((logging_mode & LOG_MODE_SYSLOG) != 0)
if ((logging_mode & LOG_MODE_FILE) != 0)
{
panic_recurseflag = TRUE;
- open_log(&paniclogfd, lt_panic); /* Won't return on failure */
+ open_log(&paniclogfd, lt_panic, NULL); /* Won't return on failure */
panic_recurseflag = FALSE;
if (panic_save_buffer != NULL)
flags |= LOG_PANIC_DIE;
}
- close(paniclogfd);
+ (void)close(paniclogfd);
}
/* Give up if the DIE flag is set */
log_close_all(void)
{
if (mainlogfd >= 0)
- { close(mainlogfd); mainlogfd = -1; }
+ { (void)close(mainlogfd); mainlogfd = -1; }
if (rejectlogfd >= 0)
- { close(rejectlogfd); rejectlogfd = -1; }
+ { (void)close(rejectlogfd); rejectlogfd = -1; }
closelog();
syslog_open = FALSE;
}
+
+
+/*************************************************
+* Decode bit settings for log/debug *
+*************************************************/
+
+/* This function decodes a string containing bit settings in the form of +name
+and/or -name sequences, and sets/unsets bits in a bit string accordingly. It
+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 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
+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
+ string the configured string
+ options the table of option names
+ count size of table
+ which "log" or "debug"
+ flags DEBUG_FROM_CONFIG
+
+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)
+{
+uschar *errmsg;
+if (string == NULL) return;
+
+if (*string == '=')
+ {
+ char *end; /* Not uschar */
+ *selector1 = strtoul(CS string+1, &end, 0);
+ if (*end == 0) return;
+ errmsg = string_sprintf("malformed numeric %s_selector setting: %s", which,
+ string);
+ goto ERROR_RETURN;
+ }
+
+/* Handle symbolic setting */
+
+else for(;;)
+ {
+ BOOL adding;
+ uschar *s;
+ int len;
+ bit_table *start, *end;
+
+ while (isspace(*string)) string++;
+ if (*string == 0) return;
+
+ if (*string != '+' && *string != '-')
+ {
+ errmsg = string_sprintf("malformed %s_selector setting: "
+ "+ or - expected but found \"%s\"", which, string);
+ goto ERROR_RETURN;
+ }
+
+ adding = *string++ == '+';
+ s = string;
+ while (isalnum(*string) || *string == '_') string++;
+ len = string - s;
+
+ start = options;
+ end = options + count;
+
+ while (start < end)
+ {
+ bit_table *middle = start + (end - start)/2;
+ int c = Ustrncmp(s, middle->name, len);
+ if (c == 0)
+ {
+ 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;
+ }
+ break; /* Out of loop to match selector name */
+ }
+ }
+ if (c < 0) end = middle; else start = middle + 1;
+ } /* Loop to match selector name */
+
+ if (start >= end)
+ {
+ errmsg = string_sprintf("unknown %s_selector setting: %c%.*s", which,
+ adding? '+' : '-', len, s);
+ goto ERROR_RETURN;
+ }
+ } /* Loop for selector names */
+
+/* Handle disasters */
+
+ERROR_RETURN:
+if (Ustrcmp(which, "debug") == 0)
+ {
+ if (flags & DEBUG_FROM_CONFIG)
+ {
+ log_write(0, LOG_CONFIG|LOG_PANIC, "%s", errmsg);
+ return;
+ }
+ fprintf(stderr, "exim: %s\n", errmsg);
+ exit(EXIT_FAILURE);
+ }
+else log_write(0, LOG_CONFIG|LOG_PANIC_DIE, "%s", errmsg);
+}
+
+
+
+/*************************************************
+* Activate a debug logfile (late) *
+*************************************************/
+
+/* Normally, debugging is activated from the command-line; it may be useful
+within the configuration to activate debugging later, based on certain
+conditions. If debugging is already in progress, we return early, no action
+taken (besides debug-logging that we wanted debug-logging).
+
+Failures in options are not fatal but will result in paniclog entries for the
+misconfiguration.
+
+The first use of this is in ACL logic, "control = debug/tag=foo/opts=+expand"
+which can be combined with conditions, etc, to activate extra logging only
+for certain sources. */
+
+void
+debug_logging_activate(uschar *tag_name, uschar *opts)
+{
+int fd = -1;
+
+if (debug_file)
+ {
+ debug_printf("DEBUGGING ACTIVATED FROM WITHIN CONFIG.\n"
+ "DEBUG: Tag=\"%s\" Opts=\"%s\"\n", tag_name, opts);
+ return;
+ }
+
+if (tag_name != NULL && (Ustrchr(tag_name, '/') != NULL))
+ {
+ log_write(0, LOG_MAIN|LOG_PANIC, "debug tag may not contain a '/' in: %s",
+ tag_name);
+ return;
+ }
+
+debug_selector = D_default;
+if (opts)
+ {
+ decode_bits(&debug_selector, NULL, D_memory, 0, opts,
+ debug_options, debug_options_count, US"debug", DEBUG_FROM_CONFIG);
+ }
+
+open_log(&fd, lt_debug, tag_name);
+
+if (fd != -1)
+ debug_file = fdopen(fd, "w");
+else
+ log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log");
+}
+
+
/* End of log.c */