Consistent logging, always use DKIM instead of mixed DKIM/PDKIM
[exim.git] / test / stderr / 0386
index 046393456c61c26a88153d8fbd06666b3bda5fb7..80de7da898a1a74d374775a7aaa388b9be8cea0b 100644 (file)
@@ -32,19 +32,24 @@ spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<1@b>
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<1@b>
-read ACL from file TESTSUITE/aux-fixed/0386.acl1
-processing "accept" (TESTSUITE/test-config 32)
-check hosts = :
+using ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 18)
+check local_parts = 1
+1 in "1"? yes (matched "1")
+check acl = TESTSUITE/aux-fixed/0386.acl1
+ read ACL from file TESTSUITE/aux-fixed/0386.acl1
+ processing "accept" (TESTSUITE/test-config 43)
+ check hosts = :
 host in ":"? no (end of list)
 host in ":"? no (end of list)
-accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "deny" (TESTSUITE/test-config 32)
-check local_parts = ^.*[@%!/|]
+ accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "deny" (TESTSUITE/test-config 43)
+ check local_parts = ^.*[@%!/|]
 1 in "^.*[@%!/|]"? no (end of list)
 1 in "^.*[@%!/|]"? no (end of list)
-deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "require" (TESTSUITE/test-config 32)
-l_message: Invalid sender
-  message: Couldn't verify the sender
-check verify = sender/defer_ok
+ deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "require" (TESTSUITE/test-config 43)
+ l_message: Invalid sender
+   message: Couldn't verify the sender
+ check verify = sender/defer_ok
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Verifying x@y
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Verifying x@y
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
@@ -64,13 +69,15 @@ domain = y
 routed by r1 router
   envelope to: x@y
   transport: t1
 routed by r1 router
   envelope to: x@y
   transport: t1
------------ end verify ------------
-sender x@y verified ok
-require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "deny" (TESTSUITE/test-config 32)
-  message: No such user here
-deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
-end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
+ ----------- end verify ------------
+ sender x@y verified ok
+ require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "deny" (TESTSUITE/test-config 43)
+   message: No such user here
+ deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
+accept: condition test failed in ACL "chk_rcpt"
+accept: endpass encountered - denying access
 SMTP>> 550 No such user here
 LOG: MAIN REJECT
   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
 SMTP>> 550 No such user here
 LOG: MAIN REJECT
   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
@@ -81,19 +88,24 @@ spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<1@b>
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<1@b>
-using ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "accept" (TESTSUITE/test-config 32)
-check hosts = :
+using ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 18)
+check local_parts = 1
+1 in "1"? yes (matched "1")
+check acl = TESTSUITE/aux-fixed/0386.acl1
+ using ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "accept" (TESTSUITE/test-config 43)
+ check hosts = :
 host in ":"? no (end of list)
 host in ":"? no (end of list)
-accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "deny" (TESTSUITE/test-config 32)
-check local_parts = ^.*[@%!/|]
+ accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "deny" (TESTSUITE/test-config 43)
+ check local_parts = ^.*[@%!/|]
 1 in "^.*[@%!/|]"? no (end of list)
 1 in "^.*[@%!/|]"? no (end of list)
-deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "require" (TESTSUITE/test-config 32)
-l_message: Invalid sender
-  message: Couldn't verify the sender
-check verify = sender/defer_ok
+ deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "require" (TESTSUITE/test-config 43)
+ l_message: Invalid sender
+   message: Couldn't verify the sender
+ check verify = sender/defer_ok
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Verifying x@y
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 Verifying x@y
 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
@@ -112,13 +124,15 @@ domain = y
 routed by r1 router
   envelope to: x@y
   transport: t1
 routed by r1 router
   envelope to: x@y
   transport: t1
------------ end verify ------------
-sender x@y verified ok
-require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
-processing "deny" (TESTSUITE/test-config 32)
-  message: No such user here
-deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
-end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
+ ----------- end verify ------------
+ sender x@y verified ok
+ require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ processing "deny" (TESTSUITE/test-config 43)
+   message: No such user here
+ deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
+ end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
+accept: condition test failed in ACL "chk_rcpt"
+accept: endpass encountered - denying access
 SMTP>> 550 No such user here
 LOG: MAIN REJECT
   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
 SMTP>> 550 No such user here
 LOG: MAIN REJECT
   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
@@ -164,26 +178,38 @@ spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<2@b>
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<2@b>
-read ACL from file TESTSUITE/aux-fixed/0386.acl2
-processing "warn" (TESTSUITE/test-config 32)
-  message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
-l_message: found in $dnslist_domain: $dnslist_text
-check dnslists = rbl.test.ex 
-DNS list check: rbl.test.ex
+using ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 18)
+check local_parts = 1
+2 in "1"? no (end of list)
+accept: condition test failed in ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 21)
+check local_parts = 2
+2 in "2"? yes (matched "2")
+check acl = TESTSUITE/aux-fixed/0386.acl2
+ read ACL from file TESTSUITE/aux-fixed/0386.acl2
+ processing "warn" (TESTSUITE/test-config 43)
+   message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
+ l_message: found in $dnslist_domain: $dnslist_text
+ check dnslists = rbl.test.ex 
+dnslists check: rbl.test.ex
 new DNS lookup for 13.12.11.V4NET.rbl.test.ex
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) using fakens
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) succeeded
 new DNS lookup for 13.12.11.V4NET.rbl.test.ex
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) using fakens
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) succeeded
+dnslists: wrote cache entry, ttl=3
 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) using fakens
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) succeeded
 => that means V4NET.11.12.13 is listed at rbl.test.ex
 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) using fakens
 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) succeeded
 => that means V4NET.11.12.13 is listed at rbl.test.ex
-warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
+ warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 LOG: MAIN
   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
 created log directory TESTSUITE/spool/log
 LOG: MAIN
   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
 created log directory TESTSUITE/spool/log
-processing "accept" (TESTSUITE/test-config 32)
-accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
-end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
+ processing "accept" (TESTSUITE/test-config 43)
+ accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
+ end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
+accept: condition test succeeded in ACL "chk_rcpt"
+end of ACL "chk_rcpt": ACCEPT
 SMTP>> 250 Accepted
 DSN: orcpt: NULL  flags: 0
 SMTP<< data
 SMTP>> 250 Accepted
 DSN: orcpt: NULL  flags: 0
 SMTP<< data
@@ -207,10 +233,10 @@ P Received: from [V4NET.11.12.13] (ident=CALLER)
   X-Warning: This is a test blacklisting message
 >>
 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
   X-Warning: This is a test blacklisting message
 >>
 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 :0
-DSN: **** SPOOL_OUT - address: |2@b| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
+DSN: Write SPOOL-dsn_envid NULL
+DSN: Write SPOOL  :-dsn_ret 0
+DSN: Flags: 0x0
+DSN: **** SPOOL_OUT - address: <2@b> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
@@ -243,7 +269,7 @@ Empty Tree
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=1 message_linecount=7
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=1 message_linecount=7
-DSN: set orcpt:   flags: 0
+DSN: set orcpt:   flags: 0x0
 Delivery address list:
   2@b 
  locking TESTSUITE/spool/db/retry.lockfile
 Delivery address list:
   2@b 
  locking TESTSUITE/spool/db/retry.lockfile
@@ -332,7 +358,7 @@ end of retry processing
 DSN: processing router : r1
 DSN: processing successful delivery address: 2@b
 DSN: Sender_address: x@y
 DSN: processing router : r1
 DSN: processing successful delivery address: 2@b
 DSN: Sender_address: x@y
-DSN: orcpt: NULL  flags: 0
+DSN: orcpt: NULL  flags: 0x0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: 2@b
 DSN: Remote SMTP server supports DSN: 0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: 2@b
 DSN: Remote SMTP server supports DSN: 0
@@ -351,21 +377,32 @@ spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<2@b>
 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
 SMTP>> 250 OK
 SMTP<< rcpt to:<2@b>
-using ACL "TESTSUITE/aux-fixed/0386.acl2"
-processing "warn" (TESTSUITE/test-config 32)
-  message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
-l_message: found in $dnslist_domain: $dnslist_text
-check dnslists = rbl.test.ex 
-DNS list check: rbl.test.ex
-using result of previous DNS lookup
+using ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 18)
+check local_parts = 1
+2 in "1"? no (end of list)
+accept: condition test failed in ACL "chk_rcpt"
+processing "accept" (TESTSUITE/test-config 21)
+check local_parts = 2
+2 in "2"? yes (matched "2")
+check acl = TESTSUITE/aux-fixed/0386.acl2
+ using ACL "TESTSUITE/aux-fixed/0386.acl2"
+ processing "warn" (TESTSUITE/test-config 43)
+   message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
+ l_message: found in $dnslist_domain: $dnslist_text
+ check dnslists = rbl.test.ex 
+dnslists check: rbl.test.ex
+dnslists: using result of previous lookup
 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 => that means V4NET.11.12.13 is listed at rbl.test.ex
 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
 => that means V4NET.11.12.13 is listed at rbl.test.ex
-warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
+ warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
 LOG: MAIN
   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
 LOG: MAIN
   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
-processing "accept" (TESTSUITE/test-config 32)
-accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
-end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
+ processing "accept" (TESTSUITE/test-config 43)
+ accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
+ end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
+accept: condition test succeeded in ACL "chk_rcpt"
+end of ACL "chk_rcpt": ACCEPT
 SMTP>> 250 Accepted
 DSN: orcpt: NULL  flags: 0
 SMTP<< data
 SMTP>> 250 Accepted
 DSN: orcpt: NULL  flags: 0
 SMTP<< data
@@ -389,10 +426,10 @@ P Received: from [V4NET.11.12.13] (ident=CALLER)
   X-Warning: This is a test blacklisting message
 >>
 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaY-0005vi-00
   X-Warning: This is a test blacklisting message
 >>
 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaY-0005vi-00
-DSN: Write SPOOL :-dsn_envid NULL
-DSN: Write SPOOL :-dsn_ret 0
-DSN: Flags :0
-DSN: **** SPOOL_OUT - address: |2@b| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
+DSN: Write SPOOL-dsn_envid NULL
+DSN: Write SPOOL  :-dsn_ret 0
+DSN: Flags: 0x0
+DSN: **** SPOOL_OUT - address: <2@b> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
 Renaming spool header file: TESTSUITE/spool//input//10HmaY-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
 Renaming spool header file: TESTSUITE/spool//input//10HmaY-0005vi-00-H
 Size of headers = sss
 LOG: MAIN
@@ -425,7 +462,7 @@ Empty Tree
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=1 message_linecount=7
 recipients_count=1
 **** SPOOL_IN - No additional fields
 body_linecount=1 message_linecount=7
-DSN: set orcpt:   flags: 0
+DSN: set orcpt:   flags: 0x0
 Delivery address list:
   2@b 
  locking TESTSUITE/spool/db/retry.lockfile
 Delivery address list:
   2@b 
  locking TESTSUITE/spool/db/retry.lockfile
@@ -513,7 +550,7 @@ end of retry processing
 DSN: processing router : r1
 DSN: processing successful delivery address: 2@b
 DSN: Sender_address: x@y
 DSN: processing router : r1
 DSN: processing successful delivery address: 2@b
 DSN: Sender_address: x@y
-DSN: orcpt: NULL  flags: 0
+DSN: orcpt: NULL  flags: 0x0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: 2@b
 DSN: Remote SMTP server supports DSN: 0
 DSN: envid: NULL  ret: 0
 DSN: Final recipient: 2@b
 DSN: Remote SMTP server supports DSN: 0