Debug: build a summary string tracking transport SMTP commands & responses
[exim.git] / test / stderr / 0278
index bea5f6422a34b10b68e35d1b02ea8bfc83bcbe8d..bc36cfb03d43c0615732db31363c4f58ce6a549d 100644 (file)
@@ -21,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 <--------
@@ -32,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
@@ -51,7 +52,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
@@ -77,8 +78,11 @@ Recipients:
 search_tidyup called
 >>Headers received:
 
 search_tidyup called
 >>Headers received:
 
-rewrite_one_header: type=F:
-  From: CALLER_NAME <CALLER@test.ex>
+qualify & rewrite recipients list
+global rewrite rules
+rewrite headers
+ rewrite_one_header: type=F:
+   From: CALLER_NAME <CALLER@test.ex>
 search_tidyup called
 >>Headers after rewriting and local additions:
 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
 search_tidyup called
 >>Headers after rewriting and local additions:
 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
@@ -91,11 +95,9 @@ Data file written for message 10HmaX-0005vi-00
 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
        (envelope-from <CALLER@test.ex>)
        id 10HmaX-0005vi-00
 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
+       for CALLER@test.ex;
+       Tue, 2 Mar 1999 09:44:33 +0000
 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
-DSN: Write SPOOL: -dsn_envid NULL
-DSN: Write SPOOL  :-dsn_ret 0
-DSN: Flags: 0x0
 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
 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
@@ -103,10 +105,7 @@ LOG: MAIN
   <= CALLER@test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 search_tidyup called
   <= CALLER@test.ex U=CALLER P=local S=sss
 created log directory TESTSUITE/spool/log
 search_tidyup called
-fresh-exec forking for local-accept-delivery
-postfork: local-accept-delivery
 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -MCd local-accept-delivery -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
-fresh-exec forked for local-accept-delivery: npppp
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
 Exim version x.yz ....
 changed uid/gid: forcing real = effective
   uid=uuuu gid=EXIM_GID pid=pppp
@@ -123,11 +122,11 @@ 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:
 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
 ---- End of tree ----
 recipients_count=1
 **** SPOOL_IN - No additional fields
-body_linecount=0 message_linecount=7
+body_linecount=0 message_linecount=8
 DSN: set orcpt:   flags: 0x0
 Delivery address list:
   CALLER@test.ex 
 DSN: set orcpt:   flags: 0x0
 Delivery address list:
   CALLER@test.ex 
@@ -135,8 +134,7 @@ Delivery address list:
  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)
  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
+ failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: CALLER@test.ex
 no retry data available
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Considering: CALLER@test.ex
@@ -152,6 +150,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 <--------
@@ -163,14 +162,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
@@ -182,7 +181,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
@@ -203,8 +202,6 @@ search_tidyup called
  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
 no retry data available
 search_tidyup called
  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
 no retry data available
 search_tidyup called
-local-accept-delivery forking for delivery-local
-postfork: delivery-local
 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
   uid=CALLER_UID gid=CALLER_GID pid=pppp
   home=CALLER_HOME current=CALLER_HOME
 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
   uid=CALLER_UID gid=CALLER_GID pid=pppp
   home=CALLER_HOME current=CALLER_HOME
@@ -217,7 +214,6 @@ appendfile: mode=600 notify_comsat=0 quota=0 warning=0
   maildir_use_size_file=no
   locking by lockfile fcntl 
 search_tidyup called
   maildir_use_size_file=no
   locking by lockfile fcntl 
 search_tidyup called
-local-accept-delivery forked for delivery-local: npppp
 journalling CALLER@test.ex
 t1 transport returned OK for CALLER@test.ex
 post-process CALLER@test.ex (0)
 journalling CALLER@test.ex
 t1 transport returned OK for CALLER@test.ex
 post-process CALLER@test.ex (0)
@@ -296,21 +292,12 @@ r2 router called for unknown@test.ex
   domain = test.ex
 test.ex in "*"? yes (matched "*")
 DNS lookup of test.ex (MX) using fakens
   domain = test.ex
 test.ex in "*"? yes (matched "*")
 DNS lookup of test.ex (MX) using fakens
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 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 (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
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 DNS lookup of test.ex (A) using fakens
 DNS lookup of test.ex (A) using fakens
-fresh-exec forking for fakens-search
-postfork: fakens-search
-fresh-exec forked for fakens-search: npppp
 DNS lookup of test.ex (A) gave NO_DATA
 returning DNS_NODATA
 faking res_search(A) response length as 65535
 DNS lookup of test.ex (A) gave NO_DATA
 returning DNS_NODATA
 faking res_search(A) response length as 65535