From 8f6f8772553ebcc66418ac379d956d9af1abdc32 Mon Sep 17 00:00:00 2001 From: Jeremy Harris Date: Thu, 27 Jan 2022 17:04:05 +0000 Subject: [PATCH] Testsuite: move ACL-triggered debug output to stderr file, and munge Broken-by: 9dea8f12c7 --- test/runtest | 9 +- test/scripts/0000-Basic/0574 | 2 +- test/stderr/0574 | 112 ++++++++++++++++++++++++- test/stdout/0574 | 157 ----------------------------------- 4 files changed, 119 insertions(+), 161 deletions(-) diff --git a/test/runtest b/test/runtest index 6cc5b3bdb..89f734554 100755 --- a/test/runtest +++ b/test/runtest @@ -1408,8 +1408,13 @@ RESET_AFTER_EXTRA_LINE_READ: s/^errno = \d+$/errno = EEE/; s/^writing error \d+: /writing error EEE: /; - # Some platforms have to flip to slow-mode taint-checking - next if /switching to slow-mode taint checking/; + # Time-only, in debug output + # we have to handle double lines from the DBOPEN, hence placed down here and /mg + s/^\d\d:\d\d:\d\d\s/01:01:01 /mg; + + # pid in debug lines + s/^(\d\d:\d\d:\d\d)(\s\d+\s)/"$1 " . new_value($2, "%s", \$next_pid) . " "/mgxe; + s/(? errorsto: orcpt: dsn_flags: 0x0 +01:01:01 1234 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H +01:01:01 1234 Size of headers = sss +01:01:01 1234 LOG: MAIN +01:01:01 1234 <= tester@test.ex H=(test.ex) [127.0.0.1] P=esmtp S=sss +01:01:01 1234 SMTP>> 250 OK id=10HmaX-0005vi-00 +01:01:01 1234 search_tidyup called +01:01:01 1234 Sender: tester@test.ex +01:01:01 1234 Recipients: +01:01:01 1234 dest@test.ex +01:01:01 1234 forked delivery process1235 +01:01:01 1234 Process1236 is ready for new message +01:01:01 1234 smtp_setup_msg entered +01:01:01 1234 SMTP<< QUIT +01:01:01 1234 SMTP>> 221 myhost.test.ex closing connection +01:01:01 1234 LOG: smtp_connection MAIN +01:01:01 1234 SMTP connection from (test.ex) [127.0.0.1] closed by QUIT +01:01:01 1237 Exim version x.yz uid=EXIM_UID gid=EXIM_GID pid=pppp D=fff9ffff +01:01:01 1237 Total 25 lookups +01:01:01 1237 macros_trusted overridden to true by whitelisting +01:01:01 1237 changed uid/gid: forcing real = effective +01:01:01 1237 uid=uuuu gid=EXIM_GID pid=pppp +01:01:01 1237 adding SSLKEYLOGFILE=TESTSUITE/spool/sslkeys +01:01:01 1237 configuration file is TESTSUITE/test-config +01:01:01 1237 log selectors = 00000ffc 64205022 0000000c +01:01:01 1237 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 +01:01:01 1237 trusted user +01:01:01 1237 admin user +01:01:01 1237 dropping to exim gid; retaining priv uid +01:01:01 1237 set_process_info: pppp delivering specified messages +01:01:01 1237 set_process_info: pppp delivering 10HmaX-0005vi-00 +01:01:01 1237 Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D +01:01:01 1237 reading spool file 10HmaX-0005vi-00-H +01:01:01 1237 user=EXIMUSER uid=EXIM_UID gid=EXIM_GID sender=tester@test.ex +01:01:01 1237 sender_fullhost = (test.ex) [127.0.0.1] +01:01:01 1237 sender_rcvhost = [127.0.0.1] (helo=test.ex) +01:01:01 1237 sender_local=0 ident=unset +01:01:01 1237 Non-recipients: +01:01:01 1237 Empty Tree +01:01:01 1237 ---- End of tree ---- +01:01:01 1237 recipients_count=1 +01:01:01 1237 **** SPOOL_IN - No additional fields +01:01:01 1237 body_linecount=1 message_linecount=7 +01:01:01 1237 DSN: set orcpt: flags: 0x0 +01:01:01 1237 Delivery address list: +01:01:01 1237 dest@test.ex +01:01:01 1237 locking TESTSUITE/spool/db/retry.lockfile +01:01:01 1237 locked TESTSUITE/spool/db/retry.lockfile +01:01:01 1237 EXIM_DBOPEN: file dir flags=O_RDONLY +01:01:01 1237 returned from EXIM_DBOPEN: (nil) +01:01:01 1237 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory +01:01:01 1237 no retry data available +01:01:01 1237 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +01:01:01 1237 Considering: dest@test.ex +01:01:01 1237 unique = dest@test.ex +01:01:01 1237 no domain retry record +01:01:01 1237 no address retry record +01:01:01 1237 dest@test.ex: queued for routing +01:01:01 1237 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +01:01:01 1237 routing dest@test.ex +01:01:01 1237 --------> r1 router <-------- +01:01:01 1237 local_part=dest domain=test.ex +01:01:01 1237 calling r1 router +01:01:01 1237 rda_interpret (string): ':blackhole:' +01:01:01 1237 expanded: ':blackhole:' +01:01:01 1237 file is not a filter file +01:01:01 1237 parse_forward_list: :blackhole: +01:01:01 1237 extract item: :blackhole: +01:01:01 1237 address :blackhole:d +01:01:01 1237 LOG: MAIN +01:01:01 1237 => :blackhole: R=r1 +01:01:01 1237 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>> +01:01:01 1237 After routing: +01:01:01 1237 Local deliveries: +01:01:01 1237 Remote deliveries: +01:01:01 1237 Failed addresses: +01:01:01 1237 Deferred addresses: +01:01:01 1237 search_tidyup called +01:01:01 1237 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>> +01:01:01 1237 changed uid/gid: post-delivery tidying +01:01:01 1237 uid=EXIM_UID gid=EXIM_GID pid=pppp +01:01:01 1237 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00 +01:01:01 1237 Processing retry items +01:01:01 1237 Succeeded addresses: +01:01:01 1237 dest@test.ex: no retry items +01:01:01 1237 Failed addresses: +01:01:01 1237 Deferred addresses: +01:01:01 1237 end of retry processing +01:01:01 1237 DSN: processing router : r1 +01:01:01 1237 DSN: processing successful delivery address: dest@test.ex +01:01:01 1237 DSN: Sender_address: tester@test.ex +01:01:01 1237 DSN: orcpt: NULL flags: 0x0 +01:01:01 1237 DSN: envid: NULL ret: 0 +01:01:01 1237 DSN: Final recipient: dest@test.ex +01:01:01 1237 DSN: Remote SMTP server supports DSN: 0 +01:01:01 1237 DSN: not sending DSN success message +01:01:01 1237 LOG: MAIN +01:01:01 1237 Completed +01:01:01 1237 end delivery of 10HmaX-0005vi-00 +01:01:01 1237 search_tidyup called +01:01:01 1237 search_tidyup called +01:01:01 1237 >>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>> +01:01:01 1234 search_tidyup called +01:01:01 1234 SMTP>>(close on process exit) +01:01:01 1234 >>>>>>>>>>>>>>>> Exim pid=pppp (daemon-accept) terminating with rc=0 >>>>>>>>>>>>>>>> ******** SERVER ******** diff --git a/test/stdout/0574 b/test/stdout/0574 index f51ccd732..7311e2d77 100644 --- a/test/stdout/0574 +++ b/test/stdout/0574 @@ -31,160 +31,3 @@ Connecting to 127.0.0.1 port 1225 ... connected ??? 221 <<< 221 myhost.test.ex closing connection End of script -accept: condition test succeeded in ACL "chk_data" -end of ACL "chk_data": ACCEPT - ╭considering: ${tod_full} - ├──expanding: ${tod_full} - ╰─────result: Tue, 2 Mar 1999 09:44:33 +0000 -Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00 -DSN: **** SPOOL_OUT - address: errorsto: orcpt: dsn_flags: 0x0 -Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H -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 -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