Testsuite: when generating a bounce message, allow time for exec to run before before...
[users/heiko/exim.git] / test / stderr / 0278
index 062aaaff60121c5e357c2c0bd5611e760294e0cd..634c3facc8df749716f179f89d7622de576c4913 100644 (file)
@@ -3,13 +3,9 @@ changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+dropping to exim gid; retaining priv uid
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
-DSN: r1 propagating DSN
-DSN: r2 propagating DSN
-DSN: r3 propagating DSN
-DSN: r4 propagating DSN
-DSN: r5 propagating DSN
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
@@ -25,6 +21,7 @@ checking local_parts
 CALLER in "never"? no (end of list)
 CALLER in "never1"? no (end of list)
 CALLER in "CALLER"? yes (matched "CALLER")
 CALLER in "never"? no (end of list)
 CALLER in "never1"? no (end of list)
 CALLER in "CALLER"? yes (matched "CALLER")
+data from lookup saved for cache for +local_localparts: key 'CALLER' value 'CALLER'
 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
 r1 router skipped: local_parts mismatch
 --------> r2 router <--------
 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
 r1 router skipped: local_parts mismatch
 --------> r2 router <--------
@@ -36,14 +33,14 @@ cached no match for +n1_localparts
 cached lookup data = NULL
 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
 cached yes match for +local_localparts
 cached lookup data = NULL
 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
 cached yes match for +local_localparts
-cached lookup data = NULL
+cached lookup data = CALLER
 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
 r2 router skipped: local_parts mismatch
 --------> r3 router <--------
 local_part=CALLER domain=test.ex
 checking local_parts
 cached yes match for +local_localparts
 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
 r2 router skipped: local_parts mismatch
 --------> r3 router <--------
 local_part=CALLER domain=test.ex
 checking local_parts
 cached yes match for +local_localparts
-cached lookup data = NULL
+cached lookup data = CALLER
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
 seeking password data for user "CALLER": using cached result
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
 seeking password data for user "CALLER": using cached result
@@ -55,12 +52,12 @@ set transport t1
 queued for t1 transport: local_part = CALLER
 domain = test.ex
   errors_to=NULL
 queued for t1 transport: local_part = CALLER
 domain = test.ex
   errors_to=NULL
-  domain_data=NULL localpart_data=NULL
+  domain_data=NULL local_part_data=CALLER
 routed by r3 router
   envelope to: CALLER@test.ex
   transport: t1
 search_tidyup called
 routed by r3 router
   envelope to: CALLER@test.ex
   transport: t1
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
@@ -70,14 +67,11 @@ changed uid/gid: privilege not needed
   uid=EXIM_UID gid=EXIM_GID pid=pppp
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
   uid=EXIM_UID gid=EXIM_GID pid=pppp
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
-DSN: r1 propagating DSN
-DSN: r2 propagating DSN
-DSN: r3 propagating DSN
-DSN: r4 propagating DSN
-DSN: r5 propagating DSN
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
+spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
+log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 Sender: CALLER@test.ex
 Recipients:
   CALLER@test.ex
 Sender: CALLER@test.ex
 Recipients:
   CALLER@test.ex
@@ -92,63 +86,58 @@ I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
 F From: CALLER_NAME <CALLER@test.ex>
   Date: Tue, 2 Mar 1999 09:44:33 +0000
 
 F From: CALLER_NAME <CALLER@test.ex>
   Date: Tue, 2 Mar 1999 09:44:33 +0000
 
+Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
 Data file written for message 10HmaX-0005vi-00
 >>Generated Received: header line
 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
        (envelope-from <CALLER@test.ex>)
        id 10HmaX-0005vi-00
        for CALLER@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
 Data file written for message 10HmaX-0005vi-00
 >>Generated Received: header line
 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
        (envelope-from <CALLER@test.ex>)
        id 10HmaX-0005vi-00
        for CALLER@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
-calling local_scan(); timeout=300
-local_scan() returned 0 NULL
-Writing spool header file
-DSN: Write SPOOL :-dsn_envid NULL
-DSN: Write SPOOL :-dsn_ret 0
-DSN: Flags :0
-DSN: **** SPOOL_OUT - address: |CALLER@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
+Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
+DSN: **** SPOOL_OUT - address: <CALLER@test.ex> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
+Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
   <= CALLER@test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 search_tidyup called
 Size of headers = sss
 LOG: MAIN
   <= CALLER@test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 search_tidyup called
-exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
+exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -MCd local-accept-delivery -odi -Mc 10HmaX-0005vi-00
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
 configuration file is TESTSUITE/test-config
 trusted user
 admin user
+dropping to exim gid; retaining priv uid
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
-DSN: r1 propagating DSN
-DSN: r2 propagating DSN
-DSN: r3 propagating DSN
-DSN: r4 propagating DSN
-DSN: r5 propagating DSN
 set_process_info: pppp delivering specified messages
 set_process_info: pppp delivering 10HmaX-0005vi-00
 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=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@test.ex
 sender_local=1 ident=CALLER
 Non-recipients:
 reading spool file 10HmaX-0005vi-00-H
 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@test.ex
 sender_local=1 ident=CALLER
 Non-recipients:
-Empty Tree
+ Empty Tree
 ---- End of tree ----
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=0 message_linecount=7
 ---- End of tree ----
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=0 message_linecount=7
-DSN: set orcpt: NULL  flags: 0
+DSN: set orcpt:   flags: 0x0
 Delivery address list:
   CALLER@test.ex 
 Delivery address list:
   CALLER@test.ex 
-locking TESTSUITE/spool/db/retry.lockfile
-locked TESTSUITE/spool/db/retry.lockfile
-EXIM_DBOPEN(TESTSUITE/spool/db/retry)
-returned from EXIM_DBOPEN
-ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
+ 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)
+ ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
+ failed to open DB file TESTSUITE/spool/db/retry.lockfile: No such file or directory
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: CALLER@test.ex
 unique = CALLER@test.ex
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: CALLER@test.ex
 unique = CALLER@test.ex
-no domain retry record
-no address retry record
+no   domain  retry record
+no   address retry record
 CALLER@test.ex: queued for routing
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 routing CALLER@test.ex
 CALLER@test.ex: queued for routing
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 routing CALLER@test.ex
@@ -158,6 +147,7 @@ checking local_parts
 CALLER in "never"? no (end of list)
 CALLER in "never1"? no (end of list)
 CALLER in "CALLER"? yes (matched "CALLER")
 CALLER in "never"? no (end of list)
 CALLER in "never1"? no (end of list)
 CALLER in "CALLER"? yes (matched "CALLER")
+data from lookup saved for cache for +local_localparts: key 'CALLER' value 'CALLER'
 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
 r1 router skipped: local_parts mismatch
 --------> r2 router <--------
 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
 r1 router skipped: local_parts mismatch
 --------> r2 router <--------
@@ -169,14 +159,14 @@ cached no match for +n1_localparts
 cached lookup data = NULL
 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
 cached yes match for +local_localparts
 cached lookup data = NULL
 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
 cached yes match for +local_localparts
-cached lookup data = NULL
+cached lookup data = CALLER
 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
 r2 router skipped: local_parts mismatch
 --------> r3 router <--------
 local_part=CALLER domain=test.ex
 checking local_parts
 cached yes match for +local_localparts
 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
 r2 router skipped: local_parts mismatch
 --------> r3 router <--------
 local_part=CALLER domain=test.ex
 checking local_parts
 cached yes match for +local_localparts
-cached lookup data = NULL
+cached lookup data = CALLER
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
 seeking password data for user "CALLER": using cached result
 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
 checking for local user
 seeking password data for user "CALLER": using cached result
@@ -188,7 +178,7 @@ set transport t1
 queued for t1 transport: local_part = CALLER
 domain = test.ex
   errors_to=NULL
 queued for t1 transport: local_part = CALLER
 domain = test.ex
   errors_to=NULL
-  domain_data=NULL localpart_data=NULL
+  domain_data=NULL local_part_data=CALLER
 routed by r3 router
   envelope to: CALLER@test.ex
   transport: t1
 routed by r3 router
   envelope to: CALLER@test.ex
   transport: t1
@@ -202,10 +192,11 @@ After routing:
 search_tidyup called
 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 --------> CALLER@test.ex <--------
 search_tidyup called
 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
 --------> CALLER@test.ex <--------
-locking TESTSUITE/spool/db/retry.lockfile
-locked TESTSUITE/spool/db/retry.lockfile
-EXIM_DBOPEN(TESTSUITE/spool/db/retry)
-returned from EXIM_DBOPEN
+ 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
 search_tidyup called
 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
 no retry data available
 search_tidyup called
 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
@@ -232,38 +223,34 @@ changed uid/gid: post-delivery tidying
 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
 Processing retry items
 Succeeded addresses:
 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
 Processing retry items
 Succeeded addresses:
-CALLER@test.ex: no retry items
+ CALLER@test.ex: no retry items
 Failed addresses:
 Deferred addresses:
 end of retry processing
 DSN: processing router : r3
 DSN: processing successful delivery address: CALLER@test.ex
 DSN: Sender_address: CALLER@test.ex
 Failed addresses:
 Deferred addresses:
 end of retry processing
 DSN: processing router : r3
 DSN: processing successful delivery address: CALLER@test.ex
 DSN: Sender_address: CALLER@test.ex
-DSN: orcpt: NULL  flags: 0
+DSN: orcpt: NULL  flags: 0x0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: CALLER@test.ex
 DSN: Remote SMTP server supports DSN: 0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: CALLER@test.ex
 DSN: Remote SMTP server supports DSN: 0
-DSN: *** NOT SENDING DSN SUCCESS Message ***
+DSN: not sending DSN success message
 LOG: MAIN
   Completed
 end delivery of 10HmaX-0005vi-00
 search_tidyup called
 search_tidyup called
 LOG: MAIN
   Completed
 end delivery of 10HmaX-0005vi-00
 search_tidyup called
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=pppp (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
 search_tidyup called
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=CALLER_GID pid=pppp
 configuration file is TESTSUITE/test-config
 admin user
+dropping to exim gid; retaining priv uid
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
 seeking password data for user "CALLER": cache not available
 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
-DSN: r1 propagating DSN
-DSN: r2 propagating DSN
-DSN: r3 propagating DSN
-DSN: r4 propagating DSN
-DSN: r5 propagating DSN
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
 sender address = CALLER@test.ex
 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
@@ -300,12 +287,18 @@ unknown in "+never_localparts : +n2_localparts : !+local_localparts"? yes (end o
 calling r2 router
 r2 router called for unknown@test.ex
   domain = test.ex
 calling r2 router
 r2 router called for unknown@test.ex
   domain = test.ex
+test.ex in "*"? yes (matched "*")
 DNS lookup of test.ex (MX) using fakens
 DNS lookup of test.ex (MX) gave NO_DATA
 returning DNS_NODATA
 DNS lookup of test.ex (MX) using fakens
 DNS lookup of test.ex (MX) gave NO_DATA
 returning DNS_NODATA
+faking res_search(MX) response length as 65535
+ writing neg-cache entry for test.ex-MX-xxxx, ttl 3000
+test.ex (MX resp) DNSSEC
 DNS lookup of test.ex (A) using fakens
 DNS lookup of test.ex (A) gave NO_DATA
 returning DNS_NODATA
 DNS lookup of test.ex (A) using fakens
 DNS lookup of test.ex (A) gave NO_DATA
 returning DNS_NODATA
+faking res_search(A) response length as 65535
+ writing neg-cache entry for test.ex-A-xxxx, ttl 3000
 r2 router declined for unknown@test.ex
 --------> r3 router <--------
 local_part=unknown domain=test.ex
 r2 router declined for unknown@test.ex
 --------> r3 router <--------
 local_part=unknown domain=test.ex
@@ -335,4 +328,4 @@ unknown in "+local_localparts : +expanded : +unexpanded"? no (end of list)
 r5 router skipped: local_parts mismatch
 no more routers
 search_tidyup called
 r5 router skipped: local_parts mismatch
 no more routers
 search_tidyup called
->>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=2 >>>>>>>>>>>>>>>>
+>>>>>>>>>>>>>>>> Exim pid=pppp (fresh-exec) terminating with rc=2 >>>>>>>>>>>>>>>>