Debug: pass ACL-initiated debug through execs
authorJeremy Harris <jgh146exb@wizmail.org>
Tue, 18 Jan 2022 00:50:47 +0000 (00:50 +0000)
committerJeremy Harris <jgh146exb@wizmail.org>
Tue, 18 Jan 2022 00:50:47 +0000 (00:50 +0000)
doc/doc-txt/ChangeLog
src/src/child.c
src/src/log.c
test/confs/0574
test/log/0574
test/runtest
test/stdout/0574

index 56739948318f7d761fbe5a13f8e656bf29854f80..20c6948ad72a208f822678835f572fab5aab23f8 100644 (file)
@@ -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
 -----------------
index 54583c3aeb1d9195963b3b9d930cba1a9c242126..4a262d623a2d19d40e3896561d22e421480a36ad 100644 (file)
@@ -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)
     {
index b085e9ee2ab39553ab4e9762386356e27439a4ce..2c82ee0a460a19c6d09b49c44a8f3e264b817a49 100644 (file)
@@ -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");
 }
index 9afc55247a072e7171bd994da5be874cc710ee12..8703c02192b5453db9937f6849368bc0241a6ab1 100644 (file)
@@ -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
index 2467a0a6762c41a28429cc11bd456abb4324fb12..1b544f9516a4e1ca7bad6fffd6030d1cf9323de3 100644 (file)
@@ -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: <dest@test.ex> R=r1
+1999-03-02 09:44:33 10HmaX-0005vi-00 Completed
index 3d5a975ff61419120442d1ab1b3df50e9ec5e625..cda11da9e0377d68a4c722989f904c585b2401fd 100755 (executable)
@@ -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
index 449fd4cfed2d1745e8abf65b3b4b574880b92601..f51ccd7329c61a1692940af835ee2dc80e6b5de7 100644 (file)
@@ -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: <none>
+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 <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> 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: <dest@test.ex> 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: <none>
+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 >>>>>>>>>>>>>>>>