summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorJeremy Harris <jgh146exb@wizmail.org>2022-02-04 21:53:28 +0000
committerJeremy Harris <jgh146exb@wizmail.org>2022-02-05 19:34:43 +0000
commit19fdbfb4a2b6ca4a6a96ef52be848f0a23e2414f (patch)
tree0e11463bafd367fc15eb5451d9ba953821431650
parentacfde2172e82f6b776f16d78f789c6968b69b9f0 (diff)
Debug pretrigger capture facility
-rw-r--r--doc/doc-docbook/spec.xfpt43
-rw-r--r--doc/doc-txt/NewStuff2
-rw-r--r--src/src/acl.c34
-rw-r--r--src/src/child.c24
-rw-r--r--src/src/debug.c88
-rw-r--r--src/src/exim.c27
-rw-r--r--src/src/functions.h3
-rw-r--r--src/src/globals.c5
-rw-r--r--src/src/globals.h4
-rw-r--r--src/src/log.c15
-rw-r--r--src/src/macros.h9
-rw-r--r--test/confs/0628 (renamed from test/confs/0574)9
-rw-r--r--test/confs/062922
-rw-r--r--test/confs/063032
-rw-r--r--test/confs/063140
-rw-r--r--test/log/0628 (renamed from test/log/0574)0
-rw-r--r--test/log/06293
-rw-r--r--test/log/06306
-rw-r--r--test/log/06316
-rw-r--r--test/paniclog/06293
-rw-r--r--test/paniclog/06304
-rwxr-xr-xtest/runtest6
-rw-r--r--test/scripts/0000-Basic/0628 (renamed from test/scripts/0000-Basic/0574)0
-rw-r--r--test/scripts/0000-Basic/062926
-rw-r--r--test/scripts/0000-Basic/063030
-rw-r--r--test/scripts/0000-Basic/063130
-rw-r--r--test/stderr/0628 (renamed from test/stderr/0574)0
-rw-r--r--test/stderr/062922
-rw-r--r--test/stderr/063046
-rw-r--r--test/stderr/063116
-rw-r--r--test/stdout/0628 (renamed from test/stdout/0574)0
-rw-r--r--test/stdout/062924
-rw-r--r--test/stdout/063030
-rw-r--r--test/stdout/063130
34 files changed, 587 insertions, 52 deletions
diff --git a/doc/doc-docbook/spec.xfpt b/doc/doc-docbook/spec.xfpt
index 67d79aa7a..6acdc1a32 100644
--- a/doc/doc-docbook/spec.xfpt
+++ b/doc/doc-docbook/spec.xfpt
@@ -31600,14 +31600,43 @@ sender when the destination system is doing content-scan based rejection.
This control turns on debug logging, almost as though Exim had been invoked
with &`-d`&, with the output going to a new logfile in the usual logs directory,
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.
+
.new
-Logging started this way may be stopped by using the &'stop'& option.
-The &'kill'& option additionally removes the debug file.
+Options are a slash-separated list.
+If an option takes an argument, the option name and argument are separated by
+an equals character.
+Several options are supported:
.wen
+.display
+tag=<&'suffix'&> The filename can be adjusted with thise option.
+ The argument, which may access any variables already defined,
+ is appended to the default name.
+
+opts=<&'debug&~options'&> The argument specififes what is to be logged,
+ using the same values as the &`-d`& command-line option.
+
+stop Logging started with this control may be
+ stopped by using this option.
+
+kill Logging started with this control may be
+ stopped by using this option.
+ Additionally the debug file will be removed,
+ providing one means for speculative debug tracing.
+
+pretrigger=<&'size'&> This option specifies a memory buffuer to be used
+ for pre-trigger debug capture.
+ Debug lines are recorded in the buffer until
+ and if) a trigger occurs; at which time they are
+ dumped to the debug file. Newer lines displace the
+ oldest if the buffer is full. After a trigger,
+ immediate writes to file are done as normal.
+
+trigger=<&'reason'&> This option selects cause for the pretrigger buffer
+ see above) to be copied to file. A reason of $*now*
+ take effect immediately; one of &*paniclog*& triggers
+ on a write to the panic log.
+.endd
+
Some examples (which depend on variables that don't exist in all
contexts):
.code
@@ -31616,6 +31645,8 @@ contexts):
control = debug/opts=+expand+acl
control = debug/tag=.$message_exim_id/opts=+expand
control = debug/kill
+ control = debug/opts=+all/pretrigger=1024/trigger=paniclog
+ control = debug/trigger=now
.endd
diff --git a/doc/doc-txt/NewStuff b/doc/doc-txt/NewStuff
index 46e6254bb..3555d8c12 100644
--- a/doc/doc-txt/NewStuff
+++ b/doc/doc-txt/NewStuff
@@ -22,7 +22,7 @@ Version 4.96
the main and panic logs. A future release will enforce this by failing
the lookup.
- 6. The ACL "debug" control gains a "stop" option.
+ 6. The ACL "debug" control gains options "stop", "pretrigger" and "trigger".
Version 4.95
diff --git a/src/src/acl.c b/src/src/acl.c
index 19c1bbbd9..fa1172331 100644
--- a/src/src/acl.c
+++ b/src/src/acl.c
@@ -3498,25 +3498,39 @@ for (; cb; cb = cb->next)
}
else if (Ustrncmp(pp, "kill", 4) == 0)
{
- for (pp += 4; *pp && *pp != '/';) pp++;
+ pp += 4;
kill = TRUE;
}
else if (Ustrncmp(pp, "stop", 4) == 0)
{
- for (pp += 4; *pp && *pp != '/';) pp++;
+ pp += 4;
stop = TRUE;
}
- else
- while (*pp && *pp != '/') pp++;
+ else if (Ustrncmp(pp, "pretrigger=", 11) == 0)
+ debug_pretrigger_setup(pp+11);
+ else if (Ustrncmp(pp, "trigger=", 8) == 0)
+ {
+ if (Ustrncmp(pp += 8, "now", 3) == 0)
+ {
+ pp += 3;
+ debug_trigger_fire();
+ }
+ else if (Ustrncmp(pp, "paniclog", 8) == 0)
+ {
+ pp += 8;
+ dtrigger_selector |= BIT(DTi_panictrigger);
+ }
+ }
+ while (*pp && *pp != '/') pp++;
p = pp;
}
- if (kill)
- debug_logging_stop(TRUE);
- else if (stop)
- debug_logging_stop(FALSE);
- else
- debug_logging_activate(debug_tag, debug_opts);
+ if (kill)
+ debug_logging_stop(TRUE);
+ else if (stop)
+ debug_logging_stop(FALSE);
+ else if (debug_tag || debug_opts)
+ debug_logging_activate(debug_tag, debug_opts);
break;
}
diff --git a/src/src/child.c b/src/src/child.c
index 4a262d623..07115bee4 100644
--- a/src/src/child.c
+++ b/src/src/child.c
@@ -76,7 +76,7 @@ int n = 0;
int extra = pcount ? *pcount : 0;
uschar **argv;
-argv = store_get((extra + acount + MAX_CLMACROS + 21) * sizeof(char *), FALSE);
+argv = store_get((extra + acount + MAX_CLMACROS + 24) * sizeof(char *), FALSE);
/* In all case, the list starts out with the path, any macros, and a changed
config file. */
@@ -88,10 +88,7 @@ if (clmacro_count > 0)
n += clmacro_count;
}
if (f.config_changed)
- {
- argv[n++] = US"-C";
- argv[n++] = config_main_filename;
- }
+ { argv[n++] = US"-C"; argv[n++] = config_main_filename; }
/* These values are added only for non-minimal cases. If debug_selector is
precisely D_v, we have to assume this was started by a non-admin user, and
@@ -120,22 +117,23 @@ if (!minimal)
}
}
}
+ if (debug_pretrigger_buf)
+ { argv[n++] = US"-dp"; argv[n++] = string_sprintf("0x%x", debug_pretrigger_bsize); }
+ if (dtrigger_selector != 0)
+ argv[n++] = string_sprintf("-dt=0x%x", dtrigger_selector);
DEBUG(D_any)
{
argv[n++] = US"-MCd";
argv[n++] = US process_purpose;
}
- if (!f.testsuite_delays) argv[n++] = US"-odd";
- if (f.dont_deliver) argv[n++] = US"-N";
- if (f.queue_smtp) argv[n++] = US"-odqs";
- if (f.synchronous_delivery) argv[n++] = US"-odi";
+ if (!f.testsuite_delays) argv[n++] = US"-odd";
+ if (f.dont_deliver) argv[n++] = US"-N";
+ if (f.queue_smtp) argv[n++] = US"-odqs";
+ if (f.synchronous_delivery) argv[n++] = US"-odi";
if (connection_max_messages >= 0)
argv[n++] = string_sprintf("-oB%d", connection_max_messages);
if (*queue_name)
- {
- argv[n++] = US"-MCG";
- argv[n++] = queue_name;
- }
+ { argv[n++] = US"-MCG"; argv[n++] = queue_name; }
}
/* Now add in any others that are in the call. Remember which they were,
diff --git a/src/src/debug.c b/src/src/debug.c
index 92cad6d48..7b9be057b 100644
--- a/src/src/debug.c
+++ b/src/src/debug.c
@@ -13,6 +13,8 @@ static uschar debug_buffer[2048];
static uschar *debug_ptr = debug_buffer;
static int debug_prefix_length = 0;
+static unsigned pretrigger_writeoff;
+static unsigned pretrigger_readoff;
const uschar * rc_names[] = { /* Mostly for debug output */
@@ -318,8 +320,40 @@ if (debug_ptr[-1] == '\n')
}
}
- fprintf(debug_file, "%s", CS debug_buffer);
- fflush(debug_file);
+ if (debug_pretrigger_buf)
+ {
+ int needed = Ustrlen(debug_buffer), avail;
+ char c;
+
+ if (needed > debug_pretrigger_bsize)
+ needed = debug_pretrigger_bsize;
+ if ((avail = pretrigger_readoff - pretrigger_writeoff) <= 0)
+ avail += debug_pretrigger_bsize;
+
+ /* We have a pretrigger set up, trigger not yet hit. Copy the line(s) to the
+ pretrig buffer, dropping earlier lines if needed but truncating this line if
+ the pbuf is maxed out. In the PTB the lines are NOT nul-terminated. */
+
+ while (avail < needed)
+ do
+ {
+ avail++;
+ c = debug_pretrigger_buf[pretrigger_readoff];
+ if (++pretrigger_readoff >= debug_pretrigger_bsize) pretrigger_readoff = 0;
+ }
+ while (c && c != '\n' && pretrigger_readoff != pretrigger_writeoff);
+
+ for (int i = 0; needed; i++, needed--)
+ {
+ debug_pretrigger_buf[pretrigger_writeoff] = debug_buffer[i];
+ if (++pretrigger_writeoff >= debug_pretrigger_bsize) pretrigger_writeoff = 0;
+ }
+ }
+ else
+ {
+ fprintf(debug_file, "%s", CS debug_buffer);
+ fflush(debug_file);
+ }
debug_ptr = debug_buffer;
debug_prefix_length = 0;
}
@@ -410,4 +444,54 @@ else
}
+/**************************************************************/
+/* Pretrigger handling for debug. The debug_printf implementation
+diverts output to a circular buffer if the buffer is set up.
+The routines here set up the buffer, and unload it to file (and release it).
+What ends up in the buffer is subject to the usual debug_selector. */
+
+void
+debug_pretrigger_setup(const uschar * size_string)
+{
+long size = Ustrtol(size_string, NULL, 0);
+if (size > 0)
+ {
+ unsigned bufsize = MIN(size, 16384);
+
+ dtrigger_selector |= BIT(DTi_pretrigger);
+ if (debug_pretrigger_buf) store_free(debug_pretrigger_buf);
+ debug_pretrigger_buf = store_malloc((size_t)(debug_pretrigger_bsize = bufsize));
+ pretrigger_readoff = pretrigger_writeoff = 0;
+ }
+}
+
+void
+debug_trigger_fire(void)
+{
+int nbytes;
+
+if (!debug_pretrigger_buf) return;
+
+if (debug_file && (nbytes = pretrigger_writeoff - pretrigger_readoff) != 0)
+ if (nbytes > 0)
+ fwrite(debug_pretrigger_buf + pretrigger_readoff, 1, nbytes, debug_file);
+ else
+ {
+ fwrite(debug_pretrigger_buf + pretrigger_readoff, 1,
+ debug_pretrigger_bsize - pretrigger_readoff, debug_file);
+ fwrite(debug_pretrigger_buf, 1, pretrigger_writeoff, debug_file);
+ }
+
+debug_pretrigger_discard();
+}
+
+void
+debug_pretrigger_discard(void)
+{
+if (debug_pretrigger_buf) store_free(debug_pretrigger_buf);
+debug_pretrigger_buf = NULL;
+dtrigger_selector = 0;
+}
+
+
/* End of debug.c */
diff --git a/src/src/exim.c b/src/src/exim.c
index 664d5d7f1..b59157286 100644
--- a/src/src/exim.c
+++ b/src/src/exim.c
@@ -2655,21 +2655,36 @@ on the second character (the one after '-'), to save some effort. */
#endif
break;
- /* -d: Set debug level (see also -v below) or set the drop_cr option.
- The latter is now a no-op, retained for compatibility only. If -dd is used,
- debugging subprocesses of the daemon is disabled. */
-
case 'd':
+
+ /* -dropcr: Set this option. Now a no-op, retained for compatibility only. */
+
if (Ustrcmp(argrest, "ropcr") == 0)
{
/* drop_cr = TRUE; */
}
- /* Use an intermediate variable so that we don't set debugging while
- decoding the debugging bits. */
+ /* -dp: Set up a debug pretrigger buffer with given size. */
+
+ else if (Ustrcmp(argrest, "p") == 0)
+ if (++i >= argc)
+ badarg = TRUE;
+ else
+ debug_pretrigger_setup(argv[i]);
+
+ /* -dt: Set a debug trigger selector */
+
+ else if (Ustrncmp(argrest, "t=", 2) == 0)
+ dtrigger_selector = (unsigned int) Ustrtol(argrest + 2, NULL, 0);
+
+ /* -d: Set debug level (see also -v below).
+ If -dd is used, debugging subprocesses of the daemon is disabled. */
else
{
+ /* Use an intermediate variable so that we don't set debugging while
+ decoding the debugging bits. */
+
unsigned int selector = D_default;
debug_selector = 0;
debug_file = NULL;
diff --git a/src/src/functions.h b/src/src/functions.h
index d27c23baa..4b4ff5e14 100644
--- a/src/src/functions.h
+++ b/src/src/functions.h
@@ -193,7 +193,10 @@ extern void debug_printf_indent(const char *, ...) PRINTF_FUNCTION(1,2);
extern void debug_print_string(uschar *);
extern void debug_print_tree(const char *, tree_node *);
extern void debug_vprintf(int, const char *, va_list);
+extern void debug_pretrigger_setup(const uschar *);
+extern void debug_pretrigger_discard(void);
extern void debug_print_socket(int);
+extern void debug_trigger_fire(void);
extern void decode_bits(unsigned int *, size_t, int *,
uschar *, bit_table *, int, uschar *, int);
diff --git a/src/src/globals.c b/src/src/globals.c
index 7f7ceac00..7e50867b2 100644
--- a/src/src/globals.c
+++ b/src/src/globals.c
@@ -815,8 +815,10 @@ bit_table debug_options[] = { /* must be in alphabetical order and use
BIT_TABLE(D, verify),
};
int debug_options_count = nelem(debug_options);
-
+unsigned debug_pretrigger_bsize= 0;
+uschar * debug_pretrigger_buf = NULL;
unsigned int debug_selector = 0;
+
int delay_warning[DELAY_WARNING_SIZE] = { DELAY_WARNING_SIZE, 1, 24*60*60 };
uschar *delay_warning_condition=
US"${if or {"
@@ -897,6 +899,7 @@ uschar *dnslist_value = NULL;
tree_node *domainlist_anchor = NULL;
int domainlist_count = 0;
uschar *dsn_from = US DEFAULT_DSN_FROM;
+unsigned int dtrigger_selector = 0;
int errno_quota = ERRNO_QUOTA;
uschar *errors_copy = NULL;
diff --git a/src/src/globals.h b/src/src/globals.h
index 10dd3effc..de4670a81 100644
--- a/src/src/globals.h
+++ b/src/src/globals.h
@@ -487,6 +487,8 @@ extern FILE *debug_file; /* Where to write debugging info */
extern int debug_notall[]; /* Debug options excluded from +all */
extern bit_table debug_options[]; /* Table of debug options */
extern int debug_options_count; /* Size of table */
+extern unsigned debug_pretrigger_bsize;
+extern uschar *debug_pretrigger_buf; /* circular buffer for precapture */
extern BOOL debug_store; /* Do extra checks on store_reset */
extern int delay_warning[]; /* Times between warnings */
extern uschar *delay_warning_condition; /* Condition string for warnings */
@@ -576,6 +578,8 @@ extern int domainlist_count; /* Number defined */
/* This option is now a no-opt, retained for compatibility */
extern BOOL drop_cr; /* For broken local MUAs */
+extern unsigned int dtrigger_selector; /* when to start debug */
+
extern uschar *dsn_from; /* From: string for DSNs */
extern BOOL envelope_to_remove; /* Remove envelope_to_headers */
diff --git a/src/src/log.c b/src/src/log.c
index fe9bd0c9f..8bdb244bd 100644
--- a/src/src/log.c
+++ b/src/src/log.c
@@ -905,6 +905,11 @@ if (!path_inspected)
"More than one path given in log_file_path: using %s", file_path);
}
+/* Optionally trigger debug */
+
+if (flags & LOG_PANIC && dtrigger_selector & BIT(DTi_panictrigger))
+ debug_trigger_fire();
+
/* If debugging, show all log entries, but don't show headers. Do it all
in one go so that it doesn't get split when multi-processing. */
@@ -1470,7 +1475,11 @@ 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. The second use is inetd wait mode debug preservation. */
+for certain sources. The second use is inetd wait mode debug preservation.
+
+It might be nice, in ACL-initiated pretrigger mode, to not create the file
+immediately but only upon a trigger - but we'd need another cmdline option
+to pass the name through child_exxec_exim(). */
void
debug_logging_activate(uschar *tag_name, uschar *opts)
@@ -1482,7 +1491,7 @@ if (debug_file)
return;
}
-if (tag_name != NULL && (Ustrchr(tag_name, '/') != NULL))
+if (tag_name && (Ustrchr(tag_name, '/') != NULL))
{
log_write(0, LOG_MAIN|LOG_PANIC, "debug tag may not contain a '/' in: %s",
tag_name);
@@ -1512,11 +1521,13 @@ else
void
debug_logging_stop(BOOL kill)
{
+debug_pretrigger_discard();
if (!debug_file || !debuglog_name[0]) return;
debug_selector = 0;
fclose(debug_file);
debug_file = NULL;
+debug_fd = -1;
if (kill) unlink_log(lt_debug);
}
diff --git a/src/src/macros.h b/src/src/macros.h
index 80e0ecbe1..5e26a7bce 100644
--- a/src/src/macros.h
+++ b/src/src/macros.h
@@ -106,7 +106,7 @@ don't make the file descriptors two-way. */
/* Debugging control */
#define DEBUG(x) if (debug_selector & (x))
-#define HDEBUG(x) if (host_checking || (debug_selector & (x)))
+#define HDEBUG(x) if (host_checking || debug_selector & (x))
/* The default From: text for DSNs */
@@ -422,6 +422,13 @@ enum {
D_timestamp | \
D_resolver))
+/* Bits for debug triggers */
+
+enum {
+ DTi_panictrigger,
+ DTi_pretrigger,
+};
+
/* Options bits for logging. Those that have values < BITWORDSIZE can be used
in calls to log_write(). The others are put into later words in log_selector
and are only ever tested independently, so they do not need bit mask
diff --git a/test/confs/0574 b/test/confs/0628
index 8703c0219..4369f5a99 100644
--- a/test/confs/0574
+++ b/test/confs/0628
@@ -1,4 +1,4 @@
-# Exim test configuration 0574
+# Exim test configuration 0628
.include DIR/aux-var/std_conf_prefix
@@ -15,13 +15,14 @@ acl_smtp_data = chk_data
begin acl
chk_mail:
- accept control = debug/tag=_1
+ accept control = debug/tag=_1
chk_rcpt:
- accept control = debug/kill
+ accept control = debug/kill
chk_data:
- accept control = debug/tag=_2/opts=+all
+ accept control = debug/tag=_2/opts=+all
+
# ----- Routers -----
diff --git a/test/confs/0629 b/test/confs/0629
new file mode 100644
index 000000000..15ae731ae
--- /dev/null
+++ b/test/confs/0629
@@ -0,0 +1,22 @@
+# Exim test configuration 0629
+
+.include DIR/aux-var/std_conf_prefix
+
+primary_hostname = myhost.test.ex
+
+# ----- Main settings -----
+
+acl_smtp_mail = chk_mail
+acl_smtp_rcpt = chk_rcpt
+
+# ----- ACL -----
+
+begin acl
+
+chk_mail:
+ accept control = debug/tag=_rcpt/pretrigger=1024/trigger=paniclog
+
+chk_rcpt:
+ deny log_reject_target = panic
+
+# End
diff --git a/test/confs/0630 b/test/confs/0630
new file mode 100644
index 000000000..b83790f19
--- /dev/null
+++ b/test/confs/0630
@@ -0,0 +1,32 @@
+# Exim test configuration 0630
+
+.include DIR/aux-var/std_conf_prefix
+
+primary_hostname = myhost.test.ex
+
+# ----- Main settings -----
+
+acl_smtp_mail = chk_mail
+acl_smtp_rcpt = chk_rcpt
+
+# ----- ACL -----
+
+begin acl
+
+chk_mail:
+ accept control = debug/tag=_router/opts=+all/pretrigger=2040/trigger=paniclog
+
+chk_rcpt:
+ accept
+
+# ----- Routers -----
+
+begin routers
+
+r0:
+ # cause paniclog write (by using a tainted filename)
+ driver = redirect
+ local_parts = $spool_directory/$local_part
+ data = :blackhole:
+#
+# End
diff --git a/test/confs/0631 b/test/confs/0631
new file mode 100644
index 000000000..89f282703
--- /dev/null
+++ b/test/confs/0631
@@ -0,0 +1,40 @@
+# Exim test configuration 0631
+
+.include DIR/aux-var/std_conf_prefix
+
+primary_hostname = myhost.test.ex
+
+# ----- Main settings -----
+
+acl_smtp_mail = chk_mail
+acl_smtp_rcpt = chk_rcpt
+acl_smtp_data = chk_data
+
+# ----- ACL -----
+
+begin acl
+
+chk_mail:
+ accept control = debug/tag=_acl/opts=-all+acl/pretrigger=270
+ message = yes1
+ message = yes2
+ message = yes3
+ message = yes4
+ message = yes5
+ message = yes6
+
+chk_rcpt:
+ accept control = debug/trigger=now
+
+chk_data:
+ accept control = debug/stop
+
+# ----- Routers -----
+
+begin routers
+
+r0:
+ driver = redirect
+ data = :blackhole:
+#
+# End
diff --git a/test/log/0574 b/test/log/0628
index 1b544f951..1b544f951 100644
--- a/test/log/0574
+++ b/test/log/0628
diff --git a/test/log/0629 b/test/log/0629
new file mode 100644
index 000000000..6161c31ba
--- /dev/null
+++ b/test/log/0629
@@ -0,0 +1,3 @@
+
+******** SERVER ********
+1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
diff --git a/test/log/0630 b/test/log/0630
new file mode 100644
index 000000000..86dfe447e
--- /dev/null
+++ b/test/log/0630
@@ -0,0 +1,6 @@
+
+******** SERVER ********
+1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= test_3@paniclogrouter H=(test.ex) [127.0.0.1] P=esmtp S=sss
+1999-03-02 09:44:33 10HmaX-0005vi-00 Tainted filename 'TESTSUITE/spool/dest3'
+1999-03-02 09:44:33 10HmaX-0005vi-00 failed to open TESTSUITE/spool/dest3 when checking "$spool_directory/$local_part": Permission denied (euid=uuuu egid=EXIM_GID)
diff --git a/test/log/0631 b/test/log/0631
new file mode 100644
index 000000000..d7e5e70fc
--- /dev/null
+++ b/test/log/0631
@@ -0,0 +1,6 @@
+
+******** SERVER ********
+1999-03-02 09:44:33 exim x.yz daemon started: pid=pppp, no queue runs, listening for SMTP on port PORT_D
+1999-03-02 09:44:33 10HmaX-0005vi-00 <= test_3@paniclogrouter H=(test.ex) [127.0.0.1] P=esmtp S=sss
+1999-03-02 09:44:33 10HmaX-0005vi-00 => :blackhole: <dest3@test.ex> R=r0
+1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
diff --git a/test/paniclog/0629 b/test/paniclog/0629
new file mode 100644
index 000000000..b51843e1c
--- /dev/null
+++ b/test/paniclog/0629
@@ -0,0 +1,3 @@
+
+******** SERVER ********
+1999-03-02 09:44:33 H=(test.ex) [127.0.0.1] F=<test_2@paniclogrcpt> rejected RCPT <dest2@test.ex>
diff --git a/test/paniclog/0630 b/test/paniclog/0630
new file mode 100644
index 000000000..6e72b86ed
--- /dev/null
+++ b/test/paniclog/0630
@@ -0,0 +1,4 @@
+
+******** SERVER ********
+1999-03-02 09:44:33 10HmaX-0005vi-00 Tainted filename 'TESTSUITE/spool/dest3'
+1999-03-02 09:44:33 10HmaX-0005vi-00 failed to open TESTSUITE/spool/dest3 when checking "$spool_directory/$local_part": Permission denied (euid=uuuu egid=EXIM_GID)
diff --git a/test/runtest b/test/runtest
index 8e3a1f42c..051508eca 100755
--- a/test/runtest
+++ b/test/runtest
@@ -1929,12 +1929,6 @@ $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\s+\d+ //;
- s/Process \d+ is ready for new message/Process pppp is ready for new message/;
- s/^(?:daemon-accept forked for daemon-accept-delivery:|forked delivery process) \K\d+$/pppp/;'
- },
-
'timeout_errno' => # actual errno differs Solaris vs. Linux
{ 'mainlog' => 's/((?:host|message) deferral .* errno) <\d+> /$1 <EEE> /' },
diff --git a/test/scripts/0000-Basic/0574 b/test/scripts/0000-Basic/0628
index d227b5acc..d227b5acc 100644
--- a/test/scripts/0000-Basic/0574
+++ b/test/scripts/0000-Basic/0628
diff --git a/test/scripts/0000-Basic/0629 b/test/scripts/0000-Basic/0629
new file mode 100644
index 000000000..758b7b1a6
--- /dev/null
+++ b/test/scripts/0000-Basic/0629
@@ -0,0 +1,26 @@
+# debug logging ACL modifier, pretrigger
+#
+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:<test_2@paniclogrcpt>
+??? 250
+RCPT TO:<dest2@test.ex>
+??? 550
+QUIT
+??? 221
+****
+#
+killdaemon
+#
+cp DIR/spool/log/serverdebuglog_rcpt /dev/stderr
+#
+no_msglog_check
diff --git a/test/scripts/0000-Basic/0630 b/test/scripts/0000-Basic/0630
new file mode 100644
index 000000000..55a5290ba
--- /dev/null
+++ b/test/scripts/0000-Basic/0630
@@ -0,0 +1,30 @@
+# debug logging ACL modifier, trigger in router
+#
+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:<test_3@paniclogrouter>
+??? 250
+RCPT TO:<dest3@test.ex>
+??? 250
+DATA
+??? 354
+.
+??? 250
+QUIT
+??? 221
+****
+#
+killdaemon
+#
+cp DIR/spool/log/serverdebuglog_router /dev/stderr
+#
+no_msglog_check
diff --git a/test/scripts/0000-Basic/0631 b/test/scripts/0000-Basic/0631
new file mode 100644
index 000000000..75cf31f35
--- /dev/null
+++ b/test/scripts/0000-Basic/0631
@@ -0,0 +1,30 @@
+# debug logging ACL modifier, pretrigger, trigger by ACL command
+#
+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:<test_3@paniclogrouter>
+??? 250
+RCPT TO:<dest3@test.ex>
+??? 250
+DATA
+??? 354
+.
+??? 250
+QUIT
+??? 221
+****
+#
+killdaemon
+#
+cp DIR/spool/log/serverdebuglog_acl /dev/stderr
+#
+no_msglog_check
diff --git a/test/stderr/0574 b/test/stderr/0628
index ab3ddcb3b..ab3ddcb3b 100644
--- a/test/stderr/0574
+++ b/test/stderr/0628
diff --git a/test/stderr/0629 b/test/stderr/0629
new file mode 100644
index 000000000..ad96aa70e
--- /dev/null
+++ b/test/stderr/0629
@@ -0,0 +1,22 @@
+accept: condition test succeeded in ACL "chk_mail"
+end of ACL "chk_mail": ACCEPT
+SMTP>> 250 OK
+SMTP<< RCPT TO:<dest2@test.ex>
+using ACL "chk_rcpt"
+processing "deny" (TESTSUITE/test-config 20)
+check log_reject_target = panic
+deny: condition test succeeded in ACL "chk_rcpt"
+end of ACL "chk_rcpt": DENY
+SMTP>> 550 Administrative prohibition
+LOG: PANIC
+ H=(test.ex) [127.0.0.1] F=<test_2@paniclogrcpt> rejected RCPT <dest2@test.ex>
+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
+SMTP>>(close on process exit)
+>>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept) terminating with rc=0 >>>>>>>>>>>>>>>>
+
+******** SERVER ********
+1999-03-02 09:44:33 H=(test.ex) [127.0.0.1] F=<test_2@paniclogrcpt> rejected RCPT <dest2@test.ex>
diff --git a/test/stderr/0630 b/test/stderr/0630
new file mode 100644
index 000000000..271f4499b
--- /dev/null
+++ b/test/stderr/0630
@@ -0,0 +1,46 @@
+01:01:01 1234 reading spool file 10HmaX-0005vi-00-H
+01:01:01 1234 user=EXIMUSER uid=EXIM_UID gid=EXIM_GID sender=test_3@paniclogrouter
+01:01:01 1234 sender_fullhost = (test.ex) [127.0.0.1]
+01:01:01 1234 sender_rcvhost = [127.0.0.1] (helo=test.ex)
+01:01:01 1234 sender_local=0 ident=unset
+01:01:01 1234 Non-recipients:
+01:01:01 1234 Empty Tree
+01:01:01 1234 ---- End of tree ----
+01:01:01 1234 recipients_count=1
+01:01:01 1234 **** SPOOL_IN - No additional fields
+01:01:01 1234 body_linecount=0 message_linecount=6
+01:01:01 1234 DSN: set orcpt: flags: 0x0
+01:01:01 1234 Delivery address list:
+01:01:01 1234 dest3@test.ex
+01:01:01 1234 locking TESTSUITE/spool/db/retry.lockfile
+01:01:01 1234 locked TESTSUITE/spool/db/retry.lockfile
+01:01:01 1234 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
+01:01:01 1234 returned from EXIM_DBOPEN: (nil)
+01:01:01 1234 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
+01:01:01 1234 no retry data available
+01:01:01 1234 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+01:01:01 1234 Considering: dest3@test.ex
+01:01:01 1234 unique = dest3@test.ex
+01:01:01 1234 no domain retry record
+01:01:01 1234 no address retry record
+01:01:01 1234 dest3@test.ex: queued for routing
+01:01:01 1234 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
+01:01:01 1234 routing dest3@test.ex
+01:01:01 1234 --------> r0 router <--------
+01:01:01 1234 local_part=dest3 domain=test.ex
+01:01:01 1234 checking local_parts
+01:01:01 1234 ╭considering: $spool_directory/$local_part
+01:01:01 1234 ├considering: /$local_part
+01:01:01 1234 ├───────text: /
+01:01:01 1234 ├considering: $local_part
+01:01:01 1234 ├──expanding: $spool_directory/$local_part
+01:01:01 1234 ╰─────result: TESTSUITE/spool/dest3
+01:01:01 1234 ╰──(tainted)
+01:01:01 1234 LOG: MAIN PANIC
+01:01:01 1234 Tainted filename 'TESTSUITE/spool/dest3'
+01:01:01 1234 LOG: MAIN PANIC DIE
+01:01:01 1234 failed to open TESTSUITE/spool/dest3 when checking "$spool_directory/$local_part": Permission denied (euid=uuuu egid=EXIM_GID)
+01:01:01 1234 search_tidyup called
+01:01:01 1234 >>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept-delivery) terminating with rc=1 >>>>>>>>>>>>>>>>
+
+******** SERVER ********
diff --git a/test/stderr/0631 b/test/stderr/0631
new file mode 100644
index 000000000..f0dc9300e
--- /dev/null
+++ b/test/stderr/0631
@@ -0,0 +1,16 @@
+ message: yes3
+ message: yes4
+ message: yes5
+ message: yes6
+accept: condition test succeeded in ACL "chk_mail"
+end of ACL "chk_mail": ACCEPT
+using ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 27)
+check control = debug/trigger=now
+accept: condition test succeeded in ACL "chk_rcpt"
+end of ACL "chk_rcpt": ACCEPT
+using ACL "chk_data"
+processing "accept" (TESTSUITE/test-config 30)
+check control = debug/stop
+
+******** SERVER ********
diff --git a/test/stdout/0574 b/test/stdout/0628
index 7311e2d77..7311e2d77 100644
--- a/test/stdout/0574
+++ b/test/stdout/0628
diff --git a/test/stdout/0629 b/test/stdout/0629
new file mode 100644
index 000000000..eaa8463ce
--- /dev/null
+++ b/test/stdout/0629
@@ -0,0 +1,24 @@
+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:<test_2@paniclogrcpt>
+??? 250
+<<< 250 OK
+>>> RCPT TO:<dest2@test.ex>
+??? 550
+<<< 550 Administrative prohibition
+>>> QUIT
+??? 221
+<<< 221 myhost.test.ex closing connection
+End of script
diff --git a/test/stdout/0630 b/test/stdout/0630
new file mode 100644
index 000000000..8aec05945
--- /dev/null
+++ b/test/stdout/0630
@@ -0,0 +1,30 @@
+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:<test_3@paniclogrouter>
+??? 250
+<<< 250 OK
+>>> RCPT TO:<dest3@test.ex>
+??? 250
+<<< 250 Accepted
+>>> DATA
+??? 354
+<<< 354 Enter message, ending with "." on a line by itself
+>>> .
+??? 250
+<<< 250 OK id=10HmaX-0005vi-00
+>>> QUIT
+??? 221
+<<< 221 myhost.test.ex closing connection
+End of script
diff --git a/test/stdout/0631 b/test/stdout/0631
new file mode 100644
index 000000000..5ca8747c8
--- /dev/null
+++ b/test/stdout/0631
@@ -0,0 +1,30 @@
+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:<test_3@paniclogrouter>
+??? 250
+<<< 250 yes6
+>>> RCPT TO:<dest3@test.ex>
+??? 250
+<<< 250 Accepted
+>>> DATA
+??? 354
+<<< 354 Enter message, ending with "." on a line by itself
+>>> .
+??? 250
+<<< 250 OK id=10HmaX-0005vi-00
+>>> QUIT
+??? 221
+<<< 221 myhost.test.ex closing connection
+End of script