From ed7f7860402395aedcb9e9c0cbade291c675a12f Mon Sep 17 00:00:00 2001 From: Phil Pennock Date: Sun, 6 Jun 2010 00:25:46 +0000 Subject: [PATCH] Implement "control = debug" ACL control. Fixes: #937 --- doc/doc-docbook/spec.xfpt | 19 ++- doc/doc-txt/ChangeLog | 5 +- doc/doc-txt/NewStuff | 14 ++- src/src/acl.c | 30 ++++- src/src/exim.c | 157 +----------------------- src/src/functions.h | 5 +- src/src/log.c | 248 ++++++++++++++++++++++++++++++++++++-- src/src/macros.h | 5 +- 8 files changed, 314 insertions(+), 169 deletions(-) diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index 003ae6db8..02020dc50 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -1,4 +1,4 @@ -. $Cambridge: exim/doc/doc-docbook/spec.xfpt,v 1.79 2010/06/05 23:50:18 pdp Exp $ +. $Cambridge: exim/doc/doc-docbook/spec.xfpt,v 1.80 2010/06/06 00:25:46 pdp Exp $ . . ///////////////////////////////////////////////////////////////////////////// . This is the primary source of the Exim Manual. It is an xfpt document that is @@ -25772,6 +25772,23 @@ warn control = caseful_local_part Notice that we put back the lower cased version afterwards, assuming that is what is wanted for subsequent tests. +.vitem &*control&~=&~debug/*&<&'options'&> +.cindex "&ACL;" "enabling debug logging" +.cindex "debugging" "enabling from an ACL" +This control turns on debug logging, almost as though Exim had been invoked +with &`-d`&, with the output going to a new logfile, by default called +&'debuglog'&. The filename can be adjusted with the &'tag'& option, which +may access any variables already defined. The logging may be adjusted with +the &'opts'& option, which takes the same values as the &`-d`& command-line +option. Some examples (which depend on variables that don't exist in all +contexts): +.code + control = debug + control = debug/tag=.$sender_host_address + control = debug/opts=+expand+acl + control = debug/tag=.$message_exim_id/opts=+expand +.endd + .vitem &*control&~=&~enforce_sync*& &&& &*control&~=&~no_enforce_sync*& .cindex "SMTP" "synchronization checking" diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog index 0591e4115..b89d1b44c 100644 --- a/doc/doc-txt/ChangeLog +++ b/doc/doc-txt/ChangeLog @@ -1,9 +1,10 @@ -$Cambridge: exim/doc/doc-txt/ChangeLog,v 1.622 2010/06/05 23:50:18 pdp Exp $ +$Cambridge: exim/doc/doc-txt/ChangeLog,v 1.623 2010/06/06 00:27:52 pdp Exp $ Change log file for Exim from version 4.21 ------------------------------------------- Exim version 4.73 +----------------- PP/01 Date: & Message-Id: revert to normally being appended to a message, only prepend for the Resent-* case. Fixes regression introduced in @@ -33,6 +34,8 @@ PP/08 Bugzilla 926: switch ClamAV to use the new zINSTREAM API for content PP/09 Implemented reverse_ip expansion operator. +PP/10 Bugzilla 937: provide a "debug" ACL control. + Exim version 4.72 ----------------- diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff index 35ed9a399..a8606870c 100644 --- a/doc/doc-txt/NewStuff +++ b/doc/doc-txt/NewStuff @@ -1,4 +1,4 @@ -$Cambridge: exim/doc/doc-txt/NewStuff,v 1.169 2010/06/05 23:50:18 pdp Exp $ +$Cambridge: exim/doc/doc-txt/NewStuff,v 1.170 2010/06/06 00:27:52 pdp Exp $ New Features in Exim -------------------- @@ -51,6 +51,18 @@ Version 4.73 ${reverse_ip:2001:0db8:c42:9:1:abcd:192.0.2.3} -> 3.0.2.0.0.0.0.c.d.c.b.a.1.0.0.0.9.0.0.0.2.4.c.0.8.b.d.0.1.0.0.2 + 6. There is a new ACL control called "debug", to enable debug logging. + This allows selective logging of certain incoming transactions within + production environments, with some care. It takes two options, "tag" + and "opts"; "tag" is included in the filename of the log and "opts" + is used as per the -d command-line option. Examples, which + don't all make sense in all contexts: + + control = debug + control = debug/tag=.$sender_host_address + control = debug/opts=+expand+acl + control = debug/tag=.$message_exim_id/opts=+expand + Version 4.72 ------------ diff --git a/src/src/acl.c b/src/src/acl.c index 8825a8f13..4ad2b01b9 100644 --- a/src/src/acl.c +++ b/src/src/acl.c @@ -1,4 +1,4 @@ -/* $Cambridge: exim/src/src/acl.c,v 1.87 2009/11/16 19:50:36 nm4 Exp $ */ +/* $Cambridge: exim/src/src/acl.c,v 1.88 2010/06/06 00:27:52 pdp Exp $ */ /************************************************* * Exim - an Internet mail transport agent * @@ -171,6 +171,7 @@ enum { #ifdef EXPERIMENTAL_BRIGHTMAIL CONTROL_BMI_RUN, #endif + CONTROL_DEBUG, #ifndef DISABLE_DKIM CONTROL_DKIM_VERIFY, #endif @@ -204,6 +205,7 @@ static uschar *controls[] = { #ifdef EXPERIMENTAL_BRIGHTMAIL US"bmi_run", #endif + US"debug", #ifndef DISABLE_DKIM US"dkim_disable_verify", #endif @@ -517,6 +519,8 @@ static unsigned int control_forbids[] = { 0, /* bmi_run */ #endif + 0, /* debug */ + #ifndef DISABLE_DKIM (1<next) } break; + case CONTROL_DEBUG: + while (*p == '/') + { + if (Ustrncmp(p, "/tag=", 5) == 0) + { + uschar *pp = p + 5; + while (*pp != '\0' && *pp != '/') pp++; + debug_tag = string_copyn(p+5, pp-p-5); + p = pp; + } + else if (Ustrncmp(p, "/opts=", 6) == 0) + { + uschar *pp = p + 6; + while (*pp != '\0' && *pp != '/') pp++; + debug_opts = string_copyn(p+6, pp-p-6); + p = pp; + } + } + debug_logging_activate(debug_tag, debug_opts); + break; + case CONTROL_SUPPRESS_LOCAL_FIXUPS: suppress_local_fixups = TRUE; break; diff --git a/src/src/exim.c b/src/src/exim.c index c54470bd6..7d1c3b6a6 100644 --- a/src/src/exim.c +++ b/src/src/exim.c @@ -1,4 +1,4 @@ -/* $Cambridge: exim/src/src/exim.c,v 1.66 2010/06/05 11:13:29 pdp Exp $ */ +/* $Cambridge: exim/src/src/exim.c,v 1.67 2010/06/06 00:27:52 pdp Exp $ */ /************************************************* * Exim - an Internet mail transport agent * @@ -681,155 +681,6 @@ else -/************************************************* -* 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 =, 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. - -A bad value for a debug setting is treated as an unknown option - error message -to stderr and die. For log settings, which come from the configuration file, -we write to the log on the way out... - -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" - -Returns: nothing on success - bomb out on failure -*/ - -static void -decode_bits(unsigned int *selector1, unsigned int *selector2, int notall1, - int notall2, uschar *string, bit_table *options, int count, uschar *which) -{ -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) - { - fprintf(stderr, "exim: %s\n", errmsg); - exit(EXIT_FAILURE); - } -else log_write(0, LOG_CONFIG|LOG_PANIC_DIE, "%s", errmsg); -} - - - /************************************************* * Show supported features * *************************************************/ @@ -2080,7 +1931,7 @@ for (i = 1; i < argc; i++) } if (*argrest != 0) decode_bits(&selector, NULL, D_memory, 0, argrest, debug_options, - debug_options_count, US"debug"); + debug_options_count, US"debug", 0); debug_selector = selector; } break; @@ -3249,8 +3100,8 @@ readconf_main(); /* Handle the decoding of logging options. */ -decode_bits(&log_write_selector, &log_extra_selector, 0, 0, log_selector_string, - log_options, log_options_count, US"log"); +decode_bits(&log_write_selector, &log_extra_selector, 0, 0, + log_selector_string, log_options, log_options_count, US"log", 0); DEBUG(D_any) { diff --git a/src/src/functions.h b/src/src/functions.h index 00f8bb7ba..90c2b1269 100644 --- a/src/src/functions.h +++ b/src/src/functions.h @@ -1,4 +1,4 @@ -/* $Cambridge: exim/src/src/functions.h,v 1.50 2010/06/05 23:50:18 pdp Exp $ */ +/* $Cambridge: exim/src/src/functions.h,v 1.51 2010/06/06 00:27:52 pdp Exp $ */ /************************************************* * Exim - an Internet mail transport agent * @@ -72,11 +72,14 @@ extern void daemon_go(void); extern int dcc_process(uschar **); #endif +extern void debug_logging_activate(uschar *, uschar *); extern void debug_print_argv(uschar **); extern void debug_print_ids(uschar *); extern void debug_print_string(uschar *); extern void debug_print_tree(tree_node *); extern void debug_vprintf(char *, va_list); +extern void decode_bits(unsigned int *, unsigned int *, + int, int, uschar *, bit_table *, int, uschar *, int); extern address_item *deliver_make_addr(uschar *, BOOL); extern int deliver_message(uschar *, BOOL, BOOL); extern void deliver_msglog(const char *, ...); diff --git a/src/src/log.c b/src/src/log.c index a5cd10075..1d2c8f5e0 100644 --- a/src/src/log.c +++ b/src/src/log.c @@ -1,4 +1,4 @@ -/* $Cambridge: exim/src/src/log.c,v 1.14 2009/11/16 19:50:37 nm4 Exp $ */ +/* $Cambridge: exim/src/src/log.c,v 1.15 2010/06/06 00:27:52 pdp Exp $ */ /************************************************* * Exim - an Internet mail transport agent * @@ -19,9 +19,9 @@ log files was originally contributed by Tony Sheen. */ #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" }; @@ -31,6 +31,7 @@ static uschar *log_names[] = { US"main", US"reject", US"panic", 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; @@ -226,16 +227,17 @@ avoid races. 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 @@ -282,6 +284,22 @@ else 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. */ @@ -860,7 +878,7 @@ if ((flags & LOG_MAIN) != 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; } @@ -984,7 +1002,7 @@ if ((flags & LOG_REJECT) != 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; } @@ -1005,7 +1023,7 @@ written to a file - never to syslog. */ 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); @@ -1036,7 +1054,7 @@ if ((flags & LOG_PANIC) != 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) @@ -1079,4 +1097,214 @@ 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 =, 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 */ diff --git a/src/src/macros.h b/src/src/macros.h index 4db115533..ed90b2535 100644 --- a/src/src/macros.h +++ b/src/src/macros.h @@ -1,4 +1,4 @@ -/* $Cambridge: exim/src/src/macros.h,v 1.39 2009/11/16 19:50:37 nm4 Exp $ */ +/* $Cambridge: exim/src/src/macros.h,v 1.40 2010/06/06 00:27:52 pdp Exp $ */ /************************************************* * Exim - an Internet mail transport agent * @@ -707,6 +707,9 @@ local_scan.h */ #define LOG_CONFIG_FOR (256+128) /* Add " for" instead of ":\n" */ #define LOG_CONFIG_IN (512+128) /* Add " in line x[ of file y]" */ +/* and for debug_bits() logging action control: */ +#define DEBUG_FROM_CONFIG 0x0001 + /* SMTP command identifiers for the smtp_connection_had field that records the most recent SMTP commands. Must be kept in step with the list of names in smtp_in.c that is used for creating the smtp_no_mail logging action. SCH_NONE -- 2.25.1