From b0d68adc8b45e42b425c23e7dbf195b772878b9a Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Sat, 21 May 2016 21:14:05 +0100 Subject: [PATCH] Debug: "kill" option on ACL control=debug. Bug 1831 --- doc/doc-docbook/spec.xfpt | 7 ++++- doc/doc-txt/NewStuff | 3 ++ src/src/acl.c | 43 +++++++++++++++++--------- src/src/functions.h | 1 + src/src/log.c | 21 ++++++++++++- test/confs/0574 | 34 ++++++++++++++++++++ test/log/0574 | 4 +++ test/runtest | 4 +++ test/scripts/0000-Basic/0574 | 37 ++++++++++++++++++++++ test/stderr/0574 | 3 ++ test/stdout/0574 | 60 ++++++++++++++++++++++++++++++++++++ 11 files changed, 200 insertions(+), 17 deletions(-) create mode 100644 test/confs/0574 create mode 100644 test/log/0574 create mode 100644 test/scripts/0000-Basic/0574 create mode 100644 test/stderr/0574 create mode 100644 test/stdout/0574 diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt index 736a45800..d625d88b5 100644 --- a/doc/doc-docbook/spec.xfpt +++ b/doc/doc-docbook/spec.xfpt @@ -28712,13 +28712,18 @@ 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 +option. +.new +Logging may be stopped, and the file removed, with the &'kill'& option. +.wen +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 + control = debug/kill .endd diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff index 659c830bd..1a7ea70a0 100644 --- a/doc/doc-txt/NewStuff +++ b/doc/doc-txt/NewStuff @@ -14,6 +14,9 @@ Version 4.88 2. New log_selector: dnssec, adds a "DS" tag to acceptance and delivery lines. + 3. Speculative debugging, via a "kill" option to the "control=debug" ACL + modifier. + Version 4.87 ------------ diff --git a/src/src/acl.c b/src/src/acl.c index 474b0d181..dd59b4952 100644 --- a/src/src/acl.c +++ b/src/src/acl.c @@ -2976,8 +2976,6 @@ acl_check_condition(int verb, acl_condition_block *cb, int where, { uschar *user_message = NULL; uschar *log_message = NULL; -uschar *debug_tag = NULL; -uschar *debug_opts = NULL; int rc = OK; #ifdef WITH_CONTENT_SCAN int sep = -'/'; @@ -3329,24 +3327,39 @@ for (; cb != NULL; cb = cb->next) break; case CONTROL_DEBUG: - while (*p == '/') { - if (Ustrncmp(p, "/tag=", 5) == 0) - { - const 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 * debug_tag = NULL; + uschar * debug_opts = NULL; + BOOL kill = FALSE; + + while (*p == '/') { - const uschar *pp = p + 6; - while (*pp != '\0' && *pp != '/') pp++; - debug_opts = string_copyn(p+6, pp-p-6); + const uschar * pp = p+1; + if (Ustrncmp(pp, "tag=", 4) == 0) + { + for (pp += 4; *pp && *pp != '/';) pp++; + debug_tag = string_copyn(p+5, pp-p-5); + } + else if (Ustrncmp(pp, "opts=", 5) == 0) + { + for (pp += 5; *pp && *pp != '/';) pp++; + debug_opts = string_copyn(p+6, pp-p-6); + } + else if (Ustrncmp(pp, "kill", 4) == 0) + { + for (pp += 4; *pp && *pp != '/';) pp++; + kill = TRUE; + } + else + while (*pp && *pp != '/') pp++; p = pp; } + + if (kill) + debug_logging_stop(); + else + debug_logging_activate(debug_tag, debug_opts); } - debug_logging_activate(debug_tag, debug_opts); break; case CONTROL_SUPPRESS_LOCAL_FIXUPS: diff --git a/src/src/functions.h b/src/src/functions.h index f690e9fd9..ade557c2f 100644 --- a/src/src/functions.h +++ b/src/src/functions.h @@ -123,6 +123,7 @@ extern int dcc_process(uschar **); #endif extern void debug_logging_activate(uschar *, uschar *); +extern void debug_logging_stop(void); extern void debug_print_argv(const uschar **); extern void debug_print_ids(uschar *); extern void debug_print_string(uschar *); diff --git a/src/src/log.c b/src/src/log.c index 9e6809720..b01a179c0 100644 --- a/src/src/log.c +++ b/src/src/log.c @@ -503,6 +503,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 * @@ -1395,7 +1402,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; } @@ -1426,4 +1433,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 */ diff --git a/test/confs/0574 b/test/confs/0574 new file mode 100644 index 000000000..6b869514a --- /dev/null +++ b/test/confs/0574 @@ -0,0 +1,34 @@ +# Exim test configuration 0574 + +exim_path = EXIM_PATH +keep_environment = +host_lookup_order = bydns +primary_hostname = myhost.test.ex +spool_directory = DIR/spool +log_file_path = DIR/spool/log/SERVER%slog +gecos_pattern = "" +gecos_name = CALLER_NAME +tls_advertise_hosts = + +# ----- Main settings ----- + +acl_smtp_mail = chk_mail +acl_smtp_rcpt = chk_rcpt +acl_smtp_data = chk_data + +queue_only + +# ----- ACL ----- + +begin acl + +chk_mail: + accept control = debug/tag=_1 + +chk_rcpt: + accept control = debug/kill + +chk_data: + accept control = debug/tag=_2/opts=+all + +# End diff --git a/test/log/0574 b/test/log/0574 new file mode 100644 index 000000000..f26f757fc --- /dev/null +++ b/test/log/0574 @@ -0,0 +1,4 @@ + +******** SERVER ******** +1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port 1225 +1999-03-02 09:44:33 10HmaX-0005vi-00 <= tester@test.ex H=(test.ex) [127.0.0.1] P=esmtp S=sss diff --git a/test/runtest b/test/runtest index fa38ca019..2389efafe 100755 --- a/test/runtest +++ b/test/runtest @@ -1414,6 +1414,10 @@ $munges = { 'mainlog' => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1/', 'rejectlog' => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1/'}, + 'debuglog_stdout' => + { 'stdout' => 's/^\d\d:\d\d:\d\d* \d+ //; + s/Process \d+ is ready for new message/Process pppp is ready for new message/' + }, }; diff --git a/test/scripts/0000-Basic/0574 b/test/scripts/0000-Basic/0574 new file mode 100644 index 000000000..6784bde56 --- /dev/null +++ b/test/scripts/0000-Basic/0574 @@ -0,0 +1,37 @@ +# debug logging ACL modifier +munge debuglog_stdout +# +exim -DSERVER=server -bd -oX PORT_D +**** +# +client 127.0.0.1 PORT_D +??? 220 +EHLO test.ex +??? 250- +??? 250- +??? 250- +??? 250- +??? 250 +MAIL FROM: +??? 250 +RCPT TO: +??? 250 +DATA +??? 354 +Subject: test + +body +. +??? 250 +QUIT +??? 221 +**** +# +killdaemon +# +1 +cat DIR/spool/log/serverdebuglog_1 +# +cat DIR/spool/log/serverdebuglog_2 +# +no_msglog_check diff --git a/test/stderr/0574 b/test/stderr/0574 new file mode 100644 index 000000000..0d94be4e8 --- /dev/null +++ b/test/stderr/0574 @@ -0,0 +1,3 @@ +cat: TESTSUITE/spool/log/serverdebuglog_1: No such file or directory + +******** SERVER ******** diff --git a/test/stdout/0574 b/test/stdout/0574 new file mode 100644 index 000000000..8b960505d --- /dev/null +++ b/test/stdout/0574 @@ -0,0 +1,60 @@ +Connecting to 127.0.0.1 port 1225 ... connected +??? 220 +<<< 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000 +>>> EHLO test.ex +??? 250- +<<< 250-myhost.test.ex Hello test.ex [127.0.0.1] +??? 250- +<<< 250-SIZE 52428800 +??? 250- +<<< 250-8BITMIME +??? 250- +<<< 250-PIPELINING +??? 250 +<<< 250 HELP +>>> MAIL FROM: +??? 250 +<<< 250 OK +>>> RCPT TO: +??? 250 +<<< 250 Accepted +>>> DATA +??? 354 +<<< 354 Enter message, ending with "." on a line by itself +>>> Subject: test +>>> +>>> body +>>> . +??? 250 +<<< 250 OK id=10HmaX-0005vi-00 +>>> QUIT +??? 221 +<<< 221 myhost.test.ex closing connection +End of script +accept: condition test succeeded in ACL "chk_data" +end of ACL "chk_data": ACCEPT +calling local_scan(); timeout=300 +local_scan() returned 0 NULL +considering: ${tod_full} + expanding: ${tod_full} + result: Tue, 2 Mar 1999 09:44:33 +0000 +Writing spool header file +DSN: Write SPOOL :-dsn_envid NULL +DSN: Write SPOOL :-dsn_ret 0 +DSN: Flags :0 +DSN: **** SPOOL_OUT - address: |dest@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0 +Size of headers = sss +LOG: MAIN + <= tester@test.ex H=(test.ex) [127.0.0.1] P=esmtp S=sss +SMTP>> 250 OK id=10HmaX-0005vi-00 +search_tidyup called +Sender: tester@test.ex +Recipients: + dest@test.ex +Process pppp is ready for new message +smtp_setup_msg entered +SMTP<< QUIT +SMTP>> 221 myhost.test.ex closing connection +LOG: smtp_connection MAIN + SMTP connection from (test.ex) [127.0.0.1] closed by QUIT +search_tidyup called -- 2.30.2