More debug output

1 files changed, 60 insertions, 0 deletions

diff --git a/test/stderr/0023 b/test/stderr/0023
index b9894240b..01994efe6 100644
--- a/test/stderr/0023
+++ b/test/stderr/0023
@@ -12,10 +12,13 @@
 >>> test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> test.ex in "deny.test.ex"? no (end of list)
@@ -24,6 +27,7 @@
 >>> check domains = +local_domains
 >>> test.ex in "test.ex : *.test.ex"? yes (matched "test.ex")
 >>> test.ex in "+local_domains"? yes (matched "+local_domains")
+>>>   message: $domain gets refused
 >>> check domains = !refuse.test.ex
 >>> test.ex in "!refuse.test.ex"? yes (end of list)
 >>> accept: condition test succeeded in ACL "acl_1_2_3"
@@ -33,10 +37,13 @@
 >>> z in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> z in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> z in "deny.test.ex"? no (end of list)
@@ -63,10 +70,13 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> test.ex in "deny.test.ex"? no (end of list)
@@ -75,6 +85,7 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> check domains = +local_domains
 >>> test.ex in "test.ex : *.test.ex"? yes (matched "test.ex")
 >>> test.ex in "+local_domains"? yes (matched "+local_domains")
+>>>   message: $domain gets refused
 >>> check domains = !refuse.test.ex
 >>> test.ex in "!refuse.test.ex"? yes (end of list)
 >>> accept: condition test succeeded in ACL "acl_1_2_3"
@@ -84,10 +95,13 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> test.ex in "deny.test.ex"? no (end of list)
@@ -96,6 +110,7 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> check domains = +local_domains
 >>> test.ex in "test.ex : *.test.ex"? yes (matched "test.ex")
 >>> test.ex in "+local_domains"? yes (matched "+local_domains")
+>>>   message: $domain gets refused
 >>> check domains = !refuse.test.ex
 >>> test.ex in "!refuse.test.ex"? yes (end of list)
 >>> accept: condition test succeeded in ACL "acl_1_2_3"
@@ -105,10 +120,13 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> relay.test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> relay.test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> relay.test.ex in "deny.test.ex"? no (end of list)
@@ -117,6 +135,7 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> check domains = +local_domains
 >>> relay.test.ex in "test.ex : *.test.ex"? yes (matched "*.test.ex")
 >>> relay.test.ex in "+local_domains"? yes (matched "+local_domains")
+>>>   message: $domain gets refused
 >>> check domains = !refuse.test.ex
 >>> relay.test.ex in "!refuse.test.ex"? yes (end of list)
 >>> accept: condition test succeeded in ACL "acl_1_2_3"
@@ -126,10 +145,13 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <z@z>
 >>> deny.test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> deny.test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> deny.test.ex in "deny.test.ex"? yes (matched "deny.test.ex")
@@ -141,10 +163,13 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <x@deny.test.ex>: DOMAIN EXPLICITLY DENIE
 >>> refuse.test.ex in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> refuse.test.ex in "!wontpass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "deny"
+>>>   message: domain explicitly denied
+>>> l_message: DOMAIN EXPLICITLY DENIED
 >>> check continue = this value is not used
 >>> check domains = deny.test.ex
 >>> refuse.test.ex in "deny.test.ex"? no (end of list)
@@ -153,6 +178,7 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <x@deny.test.ex>: DOMAIN EXPLICITLY DENIE
 >>> check domains = +local_domains
 >>> refuse.test.ex in "test.ex : *.test.ex"? yes (matched "*.test.ex")
 >>> refuse.test.ex in "+local_domains"? yes (matched "+local_domains")
+>>>   message: $domain gets refused
 >>> check domains = !refuse.test.ex
 >>> refuse.test.ex in "!refuse.test.ex"? no (matched "!refuse.test.ex")
 >>> accept: condition test failed in ACL "acl_1_2_3"
@@ -170,6 +196,7 @@ LOG: H=[1.2.3.4] F=<x@y> rejected RCPT <x@nopass>
 >>> wontpass in "!nopass"? yes (end of list)
 >>> require: condition test succeeded in ACL "acl_1_2_3"
 >>> processing "require"
+>>>   message: $local_part@$domain shall not pass
 >>> check domains = !wontpass
 >>> wontpass in "!wontpass"? no (matched "!wontpass")
 >>> require: condition test failed in ACL "acl_1_2_3"
@@ -246,6 +273,7 @@ LOG: H=[5.6.7.8] F=<x@y> rejected RCPT <x@test.ex>
 >>> host in "+ok9_hosts"? no (end of list)
 >>> accept: condition test failed in ACL "acl_9_9_9"
 >>> processing "deny"
+>>>   message: don't like this host
 >>> check hosts = 9.9.9.0/26
 >>> host in "9.9.9.0/26"? yes (matched "9.9.9.0/26")
 >>> deny: condition test succeeded in ACL "acl_9_9_9"
@@ -256,6 +284,7 @@ LOG: H=[9.9.9.8] F=<x@y> rejected RCPT <x@y>: don't like this host
 >>> host in "+ok9_hosts"? no (end of list)
 >>> accept: condition test failed in ACL "acl_9_9_9"
 >>> processing "deny"
+>>>   message: don't like this host
 >>> check hosts = 9.9.9.0/26
 >>> host in "9.9.9.0/26"? yes (matched "9.9.9.0/26")
 >>> deny: condition test succeeded in ACL "acl_9_9_9"
@@ -275,6 +304,7 @@ LOG: H=[9.9.9.8] F=<x@y> rejected RCPT <a@b>: don't like this host
 >>> host in "+ok9_hosts"? no (end of list)
 >>> accept: condition test failed in ACL "acl_9_9_9"
 >>> processing "deny"
+>>>   message: don't like this host
 >>> check hosts = 9.9.9.0/26
 >>> host in "9.9.9.0/26"? no (end of list)
 >>> deny: condition test failed in ACL "acl_9_9_9"
@@ -288,6 +318,7 @@ LOG: H=[9.9.9.8] F=<x@y> rejected RCPT <a@b>: don't like this host
 >>> host in "+ok9_hosts"? no (end of list)
 >>> accept: condition test failed in ACL "acl_9_9_9"
 >>> processing "deny"
+>>>   message: don't like this host
 >>> check hosts = 9.9.9.0/26
 >>> host in "9.9.9.0/26"? no (end of list)
 >>> deny: condition test failed in ACL "acl_9_9_9"
@@ -381,6 +412,7 @@ LOG: H=[5.6.8.1] F=<user2@domain1> rejected RCPT <x@y>
 >>>                 = no
 >>> accept: condition test failed in ACL "acl_5_6_11"
 >>> processing "deny"
+>>>   message: "local part of wrong type\n(quotes are literal)
 >>> deny: condition test succeeded in ACL "acl_5_6_11"
 LOG: H=[5.6.11.1] F=<x@y> rejected RCPT <y2@y>: "local part of wrong type
 >>> host in hosts_connection_nolog? no (option unset)
@@ -395,6 +427,7 @@ LOG: H=[5.6.11.1] F=<x@y> rejected RCPT <y2@y>: "local part of wrong type
 >>> processing "accept"
 >>> check hosts = 5.6.12.1
 >>> host in "5.6.12.1"? yes (matched "5.6.12.1")
+>>>   message: failed nested acl
 >>> check acl = acl_5_6_12A
 >>> using ACL "acl_5_6_12A"
 >>> processing "accept"
@@ -406,6 +439,7 @@ LOG: H=[5.6.11.1] F=<x@y> rejected RCPT <y2@y>: "local part of wrong type
 >>> processing "accept"
 >>> check hosts = 5.6.12.1
 >>> host in "5.6.12.1"? yes (matched "5.6.12.1")
+>>>   message: failed nested acl
 >>> check acl = acl_5_6_12A
 >>> using ACL "acl_5_6_12A"
 >>> processing "accept"
@@ -588,6 +622,8 @@ LOG: H=[5.6.13.1] F=<x@y> rejected RCPT <x2@y>
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_V4NET_11_12"
 >>> processing "deny"
+>>>   message: host in DNS list $dnslist_domain: $dnslist_text
+>>> l_message: DNSLIST ($dnslist_domain: $dnslist_text)
 >>> check dnslists = rbl.test.ex
 >>> DNS list check: rbl.test.ex
 >>> new DNS lookup for 13.12.11.V4NET.rbl.test.ex
@@ -597,6 +633,8 @@ LOG: H=[5.6.13.1] F=<x@y> rejected RCPT <x2@y>
 LOG: H=[V4NET.11.12.13] F=<x@y> rejected RCPT <x@y>: DNSLIST (rbl.test.ex: This is a test blacklisting message)
 >>> using ACL "acl_V4NET_11_12"
 >>> processing "deny"
+>>>   message: host in DNS list $dnslist_domain: $dnslist_text
+>>> l_message: DNSLIST ($dnslist_domain: $dnslist_text)
 >>> check dnslists = rbl.test.ex
 >>> DNS list check: rbl.test.ex
 >>> using result of previous DNS lookup
@@ -614,6 +652,8 @@ LOG: H=[V4NET.11.12.13] F=<x@y> rejected RCPT <x1@y>: DNSLIST (rbl.test.ex: This
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_V4NET_11_12"
 >>> processing "deny"
+>>>   message: host in DNS list $dnslist_domain: $dnslist_text
+>>> l_message: DNSLIST ($dnslist_domain: $dnslist_text)
 >>> check dnslists = rbl.test.ex
 >>> DNS list check: rbl.test.ex
 >>> new DNS lookup for 12.12.11.V4NET.rbl.test.ex
@@ -624,6 +664,8 @@ LOG: H=[V4NET.11.12.13] F=<x@y> rejected RCPT <x1@y>: DNSLIST (rbl.test.ex: This
 >>> accept: condition test succeeded in ACL "acl_V4NET_11_12"
 >>> using ACL "acl_V4NET_11_12"
 >>> processing "deny"
+>>>   message: host in DNS list $dnslist_domain: $dnslist_text
+>>> l_message: DNSLIST ($dnslist_domain: $dnslist_text)
 >>> check dnslists = rbl.test.ex
 >>> DNS list check: rbl.test.ex
 >>> using result of previous DNS lookup
@@ -642,6 +684,7 @@ LOG: H=[V4NET.11.12.13] F=<x@y> rejected RCPT <x1@y>: DNSLIST (rbl.test.ex: This
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_20_20_20"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing x@y
@@ -656,6 +699,7 @@ LOG: H=[20.20.20.20] sender verify fail for <x@y>: Unrouteable address
 LOG: H=[20.20.20.20] F=<x@y> rejected RCPT <x1@y>: Sender verify failed
 >>> using ACL "acl_20_20_20"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender
 >>> using cached sender verify result
 >>> accept: condition test failed in ACL "acl_20_20_20"
@@ -671,6 +715,7 @@ LOG: H=[20.20.20.20] F=<x@y> rejected RCPT <x2@y>: Sender verify failed
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_20_20_20"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing userx@y
@@ -679,6 +724,7 @@ LOG: H=[20.20.20.20] F=<x@y> rejected RCPT <x2@y>: Sender verify failed
 >>> calling r1 router
 >>> routed by r1 router
 >>> ----------- end verify ------------
+>>>   message: recipient verify failure
 >>> check verify = recipient
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing x1@y
@@ -692,8 +738,10 @@ LOG: H=[20.20.20.20] F=<x@y> rejected RCPT <x2@y>: Sender verify failed
 LOG: H=[20.20.20.20] F=<userx@y> rejected RCPT <x1@y>: Unrouteable address
 >>> using ACL "acl_20_20_20"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender
 >>> using cached sender verify result
+>>>   message: recipient verify failure
 >>> check verify = recipient
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing userx@y
@@ -831,6 +879,7 @@ LOG: H=[22.22.22.22] F=<userx@y> rejected RCPT <userx@y>
 >>> processing "deny"
 >>> check hosts = 23.23.23.0
 >>> host in "23.23.23.0"? yes (matched "23.23.23.0")
+>>>   message: sender must verify
 >>> check !verify = sender
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing x@y
@@ -846,6 +895,7 @@ LOG: H=[23.23.23.0] F=<x@y> rejected RCPT <userx@y>: Sender verify failed
 >>> processing "deny"
 >>> check hosts = 23.23.23.0
 >>> host in "23.23.23.0"? yes (matched "23.23.23.0")
+>>>   message: sender must verify
 >>> check !verify = sender
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing userx@y
@@ -882,6 +932,7 @@ LOG: H=[23.23.23.0] F=<x@y> rejected RCPT <userx@y>: Sender verify failed
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_24_24_24"
 >>> processing "warn"
+>>>   message: X-Warn: sender didn't verify
 >>> check condition = yes
 >>> warn: condition test succeeded in ACL "acl_24_24_24"
 >>> end of ACL "acl_24_24_24": implicit DENY
@@ -896,6 +947,7 @@ LOG: H=[24.24.24.24] F=<x@y> rejected RCPT <userx@y>
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_25_25_25"
 >>> processing "deny"
+>>>   message: denying domains=x
 >>> check domains = x
 >>> y in "x"? no (end of list)
 >>> deny: condition test failed in ACL "acl_25_25_25"
@@ -913,6 +965,7 @@ LOG: H=[25.25.25.25] F=<x@y> rejected RCPT <x@y>
 >>> processing "deny"
 >>> check senders = :
 >>>  in ":"? yes (matched "")
+>>>   message: bounce messages can have only one recipient
 >>> check condition = ${if > {$recipients_count}{0}{yes}{no}}
 >>>                 = no
 >>> deny: condition test failed in ACL "acl_26_26_26"
@@ -922,6 +975,7 @@ LOG: H=[25.25.25.25] F=<x@y> rejected RCPT <x@y>
 >>> processing "deny"
 >>> check senders = :
 >>>  in ":"? yes (matched "")
+>>>   message: bounce messages can have only one recipient
 >>> check condition = ${if > {$recipients_count}{0}{yes}{no}}
 >>>                 = yes
 >>> deny: condition test succeeded in ACL "acl_26_26_26"
@@ -930,6 +984,7 @@ LOG: H=[26.26.26.26] F=<> rejected RCPT <y@y>: bounce messages can have only one
 >>> processing "deny"
 >>> check senders = :
 >>>  in ":"? yes (matched "")
+>>>   message: bounce messages can have only one recipient
 >>> check condition = ${if > {$recipients_count}{0}{yes}{no}}
 >>>                 = yes
 >>> deny: condition test succeeded in ACL "acl_26_26_26"
@@ -1058,6 +1113,7 @@ LOG: H=[29.29.29.29] F=<a@localhost> rejected RCPT <x@y>
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_30_30_30"
 >>> processing "deny"
+>>>   message: domain=$dnslist_domain\nvalue=$dnslist_value\nmatched=$dnslist_matched\ntext="$dnslist_text"
 >>> check dnslists = test.ex=V4NET.0.0.1,127.0.0.2/$sender_address_domain
 >>>                = test.ex=V4NET.0.0.1,127.0.0.2/ten-1
 >>> DNS list check: test.ex=V4NET.0.0.1,127.0.0.2/ten-1
@@ -1068,6 +1124,7 @@ LOG: H=[29.29.29.29] F=<a@localhost> rejected RCPT <x@y>
 LOG: H=[30.30.30.30] F=<a@ten-1> rejected RCPT <x@y>: domain=test.ex
 >>> using ACL "acl_30_30_30"
 >>> processing "deny"
+>>>   message: domain=$dnslist_domain\nvalue=$dnslist_value\nmatched=$dnslist_matched\ntext="$dnslist_text"
 >>> check dnslists = test.ex=V4NET.0.0.1,127.0.0.2/$sender_address_domain
 >>>                = test.ex=V4NET.0.0.1,127.0.0.2/ten-2
 >>> DNS list check: test.ex=V4NET.0.0.1,127.0.0.2/ten-2
@@ -1081,6 +1138,7 @@ LOG: H=[30.30.30.30] F=<a@ten-1> rejected RCPT <x@y>: domain=test.ex
 >>> host in smtp_accept_max_nonmail_hosts? yes (matched "*")
 >>> using ACL "acl_30_30_30"
 >>> processing "deny"
+>>>   message: domain=$dnslist_domain\nvalue=$dnslist_value\nmatched=$dnslist_matched\ntext="$dnslist_text"
 >>> check dnslists = test.ex=V4NET.0.0.1,127.0.0.2/$sender_address_domain
 >>>                = test.ex=V4NET.0.0.1,127.0.0.2/13.12.11.V4NET.rbl
 >>> DNS list check: test.ex=V4NET.0.0.1,127.0.0.2/13.12.11.V4NET.rbl
@@ -1116,6 +1174,7 @@ LOG: dnslist query is too long (ignored): y+extra+extra+extra+extra+extra+extra+
 >>> host in helo_accept_junk_hosts? no (option unset)
 >>> using ACL "acl_33_33_33"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender/no_details
 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
 >>> routing x@y
@@ -1129,6 +1188,7 @@ LOG: dnslist query is too long (ignored): y+extra+extra+extra+extra+extra+extra+
 LOG: H=[33.33.33.33] F=<x@y> rejected RCPT <x1@y>: Sender verify failed
 >>> using ACL "acl_33_33_33"
 >>> processing "accept"
+>>>   message: sender verify failure
 >>> check verify = sender/no_details
 >>> using cached sender verify result
 >>> accept: condition test failed in ACL "acl_33_33_33"