From 9dea8f12c7617bcee02319adbb51353b6b35b2f8 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Tue, 18 Jan 2022 00:50:47 +0000 Subject: [PATCH] Debug: pass ACL-initiated debug through execs --- doc/doc-txt/ChangeLog | 4 ++ src/src/child.c | 10 ++++ src/src/log.c | 8 +-- test/confs/0574 | 9 ++- test/log/0574 | 2 + test/runtest | 5 +- test/stdout/0574 | 132 ++++++++++++++++++++++++++++++++++++++++++ 7 files changed, 161 insertions(+), 9 deletions(-) diff --git a/doc/doc-txt/ChangeLog b/doc/doc-txt/ChangeLog index 567399483..20c6948ad 100644 --- a/doc/doc-txt/ChangeLog +++ b/doc/doc-txt/ChangeLog @@ -69,6 +69,10 @@ JH/15 Fix a resource leak in *BSD. An off-by-one error resulted in the daemon failing to close the certificates directory, every hour or any time it was touched. +JH/16 Debugging initiated by an ACL control now continues through into routing + and transport processes, when delivery is immediate. Previously debugging + stopped any time Exim re-execs. + Exim version 4.95 ----------------- diff --git a/src/src/child.c b/src/src/child.c index 54583c3ae..4a262d623 100644 --- a/src/src/child.c +++ b/src/src/child.c @@ -108,7 +108,17 @@ if (!minimal) else { if (debug_selector != 0) + { argv[n++] = string_sprintf("-d=0x%x", debug_selector); + if (debug_fd > 2) + { + int flags = fcntl(debug_fd, F_GETFD); + if (flags != -1) (void)fcntl(debug_fd, F_SETFD, flags & ~FD_CLOEXEC); + close(2); + dup2(debug_fd, 2); + close(debug_fd); + } + } } DEBUG(D_any) { diff --git a/src/src/log.c b/src/src/log.c index b085e9ee2..2c82ee0a4 100644 --- a/src/src/log.c +++ b/src/src/log.c @@ -1475,8 +1475,6 @@ for certain sources. The second use is inetd wait mode debug preservation. */ void debug_logging_activate(uschar *tag_name, uschar *opts) { -int fd = -1; - if (debug_file) { debug_printf("DEBUGGING ACTIVATED FROM WITHIN CONFIG.\n" @@ -1502,10 +1500,10 @@ do not segfault; note that nondefault log locations will not work */ if (!*file_path) set_file_path(NULL); -open_log(&fd, lt_debug, tag_name); +open_log(&debug_fd, lt_debug, tag_name); -if (fd != -1) - debug_file = fdopen(fd, "w"); +if (debug_fd != -1) + debug_file = fdopen(debug_fd, "w"); else log_write(0, LOG_MAIN|LOG_PANIC, "unable to open debug log"); } diff --git a/test/confs/0574 b/test/confs/0574 index 9afc55247..8703c0219 100644 --- a/test/confs/0574 +++ b/test/confs/0574 @@ -10,8 +10,6 @@ acl_smtp_mail = chk_mail acl_smtp_rcpt = chk_rcpt acl_smtp_data = chk_data -queue_only - # ----- ACL ----- begin acl @@ -25,4 +23,11 @@ chk_rcpt: chk_data: accept control = debug/tag=_2/opts=+all +# ----- Routers ----- + +begin routers + +r1: + driver = redirect + data = :blackhole: # End diff --git a/test/log/0574 b/test/log/0574 index 2467a0a67..1b544f951 100644 --- a/test/log/0574 +++ b/test/log/0574 @@ -2,3 +2,5 @@ ******** 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 <= tester@test.ex H=(test.ex) [127.0.0.1] P=esmtp S=sss +1999-03-02 09:44:33 10HmaX-0005vi-00 => :blackhole: R=r1 +1999-03-02 09:44:33 10HmaX-0005vi-00 Completed diff --git a/test/runtest b/test/runtest index 3d5a975ff..cda11da9e 100755 --- a/test/runtest +++ b/test/runtest @@ -408,7 +408,7 @@ RESET_AFTER_EXTRA_LINE_READ: #s/Exim \K\d+[._]\d+[\w_-]*/x.yz/i; # Replace Exim message ids by a unique series - s/((?:[^\W_]{6}-){2}[^\W_]{2}) + s/(\d[^\W_]{5}-[^\W_]{6}-[^\W_]{2}) /new_value($1, "10Hm%s-0005vi-00", \$next_msgid)/egx; # The names of lock files appear in some error and debug messages @@ -1920,7 +1920,8 @@ $munges = '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/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 diff --git a/test/stdout/0574 b/test/stdout/0574 index 449fd4cfe..f51ccd732 100644 --- a/test/stdout/0574 +++ b/test/stdout/0574 @@ -47,12 +47,144 @@ search_tidyup called Sender: tester@test.ex Recipients: dest@test.ex +daemon-accept forking for daemon-accept-delivery +postfork: daemon-accept-delivery +daemon-accept forked for daemon-accept-delivery: pppp +forked delivery process pppp 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 +Exim version x.yz uid=EXIM_UID gid=EXIM_GID pid=pppp D=fff9ffff +Support for: crypteq iconv() IPv6 PAM Perl Expand_dlfunc OpenSSL TLS_resume move_frozen_messages Content_Scanning DANE DKIM DNSSEC Event I18N OCSP PIPECONNECT PRDR PROXY Queue_Ramp SOCKS SPF SRS TCP_Fast_Open Experimental_ARC Experimental_DCC Experimental_DSN_info Experimental_ESMTP_Limits Experimental_QUEUEFILE +Lookups (built-in): lsearch wildlsearch nwildlsearch iplsearch cdb dbm dbmjz dbmnz dnsdb dsearch json ldap ldapdn ldapm lmdb mysql nis nis0 passwd pgsql redis sqlite testdb +Authenticators: cram_md5 cyrus_sasl dovecot external gsasl plaintext spa tls +Routers: accept dnslookup ipliteral manualroute queryprogram redirect +Transports: appendfile/maildir/mailstore/mbx autoreply lmtp pipe queuefile smtp +Malware: sophie clamd sock cmdline +Fixed never_users: 0 +Configure owner: 1002:1002 +Size of off_t: 8 +Compiler: GCC [11.2.1 20210728 (Red Hat 11.2.1-1)] +Library version: Glibc: Compile: 2.33 + Runtime: 2.33 +Library version: BDB: Compile: Berkeley DB 5.3.28: (September 9, 2013) + Runtime: Berkeley DB 5.3.28: (September 9, 2013) +Library version: OpenSSL: Compile: OpenSSL 1.1.1l FIPS 24 Aug 2021 + Runtime: OpenSSL 1.1.1l FIPS 24 Aug 2021 + : built on: Tue Mar 02 09:44:33 1999 UTC +Library version: IDN2: Compile: 2.3.2 + Runtime: 2.3.2 +Library version: Stringprep: Compile: 1.36 + Runtime: 1.36 +Library version: spf2: Compile: 1.2.11 + Runtime: 1.2.11 +Library version: Cyrus SASL: Compile: 2.1.27 + Runtime: 2.1.27 [Cyrus SASL] +Library version: GNU SASL: Compile: 1.8.1 + Runtime: 1.8.1 +Library version: PCRE2: Compile: 10.36 + Runtime: 10.36 2020-12-04 +Total 25 lookups +Library version: json: Jansonn version 2.13.1 +Library version: LMDB: Compile: 0.9.29 +Library version: MySQL: Compile: 100505 10.5.5 [mariadb-10.5] + Runtime: 100505 10.5.5 +Library version: REDIS: Compile: 0 [13] +Library version: SQLite: Compile: 3.34.1 + Runtime: 3.34.1 +WHITELIST_D_MACROS: "DIR:EXIM_PATH:AA:ACL:ACLRCPT:ACL_MAIL:ACL_PREDATA:ACL_RCPT:AFFIX:ALLOW:ARG1:ARG2:AUTHF:AUTHS:AUTH_ID_DOMAIN:BAD:BANNER:BB:BR:BRB:CERT:COM:COMMAND_USER:CONNECTCOND:CONTROL:CREQCIP:CREQMAC:CRL:CSS:D6:DATA:DCF:DDF:DEFAULTDWC:DELAY:DETAILS:DRATELIMIT:DYNAMIC_OPTION:ELI:ERROR_DETAILS:ERT:FAKE:FALLBACK:FILTER:FILTER_PREPEND_HOME:FORBID:FORBID_SMTP_CODE:FUSER:HAI:HAP:HARDLIMIT:HEADER_LINE_MAXSIZE:HEADER_MAXSIZE:HELO_MSG:HL:HOSTS:HOSTS_AVOID_TLS:HOSTS_MAX_TRY:HVH:IFACE:IGNORE_QUOTA:INC:INSERT:IP1:IP2:LAST:LDAPSERVERS:LENCHECK:LIMIT:LIST:LOG_SELECTOR:LS:MAXNM:MESSAGE_LOGS:MSIZE:NOTDAEMON:ONCE:ONLY:OPT:OPTION:ORDER:PAH:PEX:PORT:PTBC:QDG:QOLL:QUOTA:QUOTA_FILECOUNT:QWM:RCPT_MSG:REMEMBER:REQUIRE:RETRY:RETRY1:RETRY2:RETURN:RETURN_ERROR_DETAILS:REWRITE:ROUTE_DATA:RRATELIMIT:RT:S:SELECTOR:SELF:SERVER:SERVERS:SREQCIP:SREQMAC:SRV:STD:STRICT:SUB:SUBMISSION_OPTIONS:TIMEOUTDEFER:TIMES:TRUSTED:TRYCLEAR:UL:USE_SENDER:UTF8:VALUE:WMF:X:Y" +TRUSTED_CONFIG_LIST: "TESTSUITE/trusted_configs" +macros_trusted overridden to true by whitelisting +changed uid/gid: forcing real = effective + uid=uuuu gid=EXIM_GID pid=pppp + auxiliary group list: +PATH in keep_environment? yes (matched "PATH") +SSLKEYLOGFILE in keep_environment? no (end of list) +PATH in keep_environment? yes (matched "PATH") +adding SSLKEYLOGFILE=TESTSUITE/spool/sslkeys +configuration file is TESTSUITE/test-config +log selectors = 00000ffc 64205022 0000000c +cwd=TESTSUITE/spool 10 args: TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -DSERVER=server -C TESTSUITE/test-config -d=0xfff9ffff -MCd daemon-accept-delivery -Mc 10HmaX-0005vi-00 +trusted user +admin user +dropping to exim gid; retaining priv uid +set_process_info: pppp delivering specified messages +set_process_info: pppp delivering 10HmaX-0005vi-00 +Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D +reading spool file 10HmaX-0005vi-00-H +user=EXIMUSER uid=EXIM_UID gid=EXIM_GID sender=tester@test.ex +sender_fullhost = (test.ex) [127.0.0.1] +sender_rcvhost = [127.0.0.1] (helo=test.ex) +sender_local=0 ident=unset +Non-recipients: + Empty Tree +---- End of tree ---- +recipients_count=1 +**** SPOOL_IN - No additional fields +body_linecount=1 message_linecount=7 +DSN: set orcpt: flags: 0x0 +Delivery address list: + dest@test.ex + locking TESTSUITE/spool/db/retry.lockfile + locked TESTSUITE/spool/db/retry.lockfile + EXIM_DBOPEN: file dir flags=O_RDONLY + returned from EXIM_DBOPEN: (nil) + failed to open DB file TESTSUITE/spool/db/retry: No such file or directory +no retry data available +>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +Considering: dest@test.ex +unique = dest@test.ex +no domain retry record +no address retry record +dest@test.ex: queued for routing +>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +routing dest@test.ex +--------> r1 router <-------- +local_part=dest domain=test.ex +calling r1 router +rda_interpret (string): ':blackhole:' +expanded: ':blackhole:' +file is not a filter file +parse_forward_list: :blackhole: +extract item: :blackhole: +address :blackhole:d +LOG: MAIN + => :blackhole: R=r1 +>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +After routing: + Local deliveries: + Remote deliveries: + Failed addresses: + Deferred addresses: +search_tidyup called +>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>> +changed uid/gid: post-delivery tidying + uid=EXIM_UID gid=EXIM_GID pid=pppp + auxiliary group list: +set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00 +Processing retry items +Succeeded addresses: + dest@test.ex: no retry items +Failed addresses: +Deferred addresses: +end of retry processing +DSN: processing router : r1 +DSN: processing successful delivery address: dest@test.ex +DSN: Sender_address: tester@test.ex +DSN: orcpt: NULL flags: 0x0 +DSN: envid: NULL ret: 0 +DSN: Final recipient: dest@test.ex +DSN: Remote SMTP server supports DSN: 0 +DSN: not sending DSN success message +LOG: MAIN + Completed +end delivery of 10HmaX-0005vi-00 +search_tidyup called +search_tidyup called +>>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>> search_tidyup called SMTP>>(close on process exit) >>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept) terminating with rc=0 >>>>>>>>>>>>>>>> -- 2.30.2