Debug: "kill" option on ACL control=debug. Bug 1831
authorJeremy Harris <jgh146exb@wizmail.org>
Sat, 21 May 2016 20:14:05 +0000 (21:14 +0100)
committerJeremy Harris <jgh146exb@wizmail.org>
Sat, 21 May 2016 20:14:05 +0000 (21:14 +0100)
doc/doc-docbook/spec.xfpt
doc/doc-txt/NewStuff
src/src/acl.c
src/src/functions.h
src/src/log.c
test/confs/0574 [new file with mode: 0644]
test/log/0574 [new file with mode: 0644]
test/runtest
test/scripts/0000-Basic/0574 [new file with mode: 0644]
test/stderr/0574 [new file with mode: 0644]
test/stdout/0574 [new file with mode: 0644]

index 736a458..d625d88 100644 (file)
@@ -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
 
 
index 659c830..1a7ea70 100644 (file)
@@ -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
 ------------
index 474b0d1..dd59b49 100644 (file)
@@ -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:
index f690e9f..ade557c 100644 (file)
@@ -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 *);
index 9e68097..b01a179 100644 (file)
@@ -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 (file)
index 0000000..6b86951
--- /dev/null
@@ -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 (file)
index 0000000..f26f757
--- /dev/null
@@ -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
index fa38ca0..2389efa 100755 (executable)
@@ -1414,6 +1414,10 @@ $munges =
     { 'mainlog'   => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1<suppressed>/',
       'rejectlog' => 's/^(.* SMTP protocol synchronization error .* next input=.{8}).*$/$1<suppressed>/'},
 
+    '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 (file)
index 0000000..6784bde
--- /dev/null
@@ -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:<tester@test.ex>
+??? 250
+RCPT TO:<dest@test.ex>
+??? 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 (file)
index 0000000..0d94be4
--- /dev/null
@@ -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 (file)
index 0000000..8b96050
--- /dev/null
@@ -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:<tester@test.ex>
+??? 250
+<<< 250 OK
+>>> RCPT TO:<dest@test.ex>
+??? 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