TLS: rework error logging to pass more string back to caller for logging
[users/jgh/exim.git] / test / stderr / 0038
1 >>> host in hosts_connection_nolog? no (option unset)
2 >>> host in host_lookup? no (option unset)
3 >>> host in host_reject_connection? no (option unset)
4 >>> host in sender_unqualified_hosts? no (option unset)
5 >>> host in recipient_unqualified_hosts? no (option unset)
6 >>> host in helo_verify_hosts? no (option unset)
7 >>> host in helo_try_verify_hosts? no (option unset)
8 >>> host in helo_accept_junk_hosts? no (option unset)
9 >>> test.ex in helo_lookup_domains? no (end of list)
10 >>> host in dsn_advertise_hosts? no (option unset)
11 >>> host in pipelining_advertise_hosts? yes (matched "*")
12 >>> host in chunking_advertise_hosts? no (end of list)
13 >>> using ACL "check_rcpt"
14 >>> processing "warn"
15 >>> check ratelimit = 0/1h/strict
16 >>> ratelimit condition count=1 0.0/1h/per_mail/V4NET.9.8.7
17 >>> ratelimit creating new rate data block
18 >>> ratelimit initializing new key's rate data
19 >>> ratelimit db updated
20 >>> ratelimit computed rate 1.0
21 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
22 >>> warn: condition test succeeded in ACL "check_rcpt"
23 LOG: H=(test.ex) [V4NET.9.8.7] Warning: RCPT: sender_rate=1.0 sender_rate_limit=0 sender_rate_period=1h
24 >>> processing "accept"
25 >>> accept: condition test succeeded in ACL "check_rcpt"
26 >>> end of ACL "check_rcpt": ACCEPT
27 >>> host in ignore_fromline_hosts? no (option unset)
28 >>> using ACL "check_data"
29 >>> processing "warn"
30 >>> check ratelimit = 0/1h/per_byte/strict
31 >>> ratelimit condition count=19 0.0/1h/per_mail/V4NET.9.8.7
32 >>> ratelimit found pre-computed rate 1.0
33 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
34 >>> warn: condition test succeeded in ACL "check_data"
35 LOG: 10HmaX-0005vi-00 H=(test.ex) [V4NET.9.8.7] Warning: DATA: sender_rate=1.0 sender_rate_limit=0 sender_rate_period=1h
36 >>> processing "deny"
37 >>> deny: condition test succeeded in ACL "check_data"
38 >>> end of ACL "check_data": DENY
39 LOG: 10HmaX-0005vi-00 H=(test.ex) [V4NET.9.8.7] F=<> rejected after DATA
40 >>> host in hosts_connection_nolog? no (option unset)
41 >>> host in host_lookup? no (option unset)
42 >>> host in host_reject_connection? no (option unset)
43 >>> host in sender_unqualified_hosts? no (option unset)
44 >>> host in recipient_unqualified_hosts? no (option unset)
45 >>> host in helo_verify_hosts? no (option unset)
46 >>> host in helo_try_verify_hosts? no (option unset)
47 >>> host in helo_accept_junk_hosts? no (option unset)
48 >>> test.ex in helo_lookup_domains? no (end of list)
49 >>> host in dsn_advertise_hosts? no (option unset)
50 >>> host in pipelining_advertise_hosts? yes (matched "*")
51 >>> host in chunking_advertise_hosts? no (end of list)
52 >>> using ACL "check_rcpt"
53 >>> processing "warn"
54 >>> check ratelimit = 0/1h/strict
55 >>> ratelimit condition count=1 0.0/1h/per_mail/V4NET.9.8.7
56 >>> ratelimit found key in database
57 >>> ratelimit db updated
58 >>> ratelimit computed rate 2.0
59 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
60 >>> warn: condition test succeeded in ACL "check_rcpt"
61 LOG: H=(test.ex) [V4NET.9.8.7] Warning: RCPT: sender_rate=2.0 sender_rate_limit=0 sender_rate_period=1h
62 >>> processing "accept"
63 >>> accept: condition test succeeded in ACL "check_rcpt"
64 >>> end of ACL "check_rcpt": ACCEPT
65 >>> host in ignore_fromline_hosts? no (option unset)
66 >>> using ACL "check_data"
67 >>> processing "warn"
68 >>> check ratelimit = 0/1h/per_byte/strict
69 >>> ratelimit condition count=19 0.0/1h/per_mail/V4NET.9.8.7
70 >>> ratelimit found pre-computed rate 2.0
71 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
72 >>> warn: condition test succeeded in ACL "check_data"
73 LOG: 10HmaY-0005vi-00 H=(test.ex) [V4NET.9.8.7] Warning: DATA: sender_rate=2.0 sender_rate_limit=0 sender_rate_period=1h
74 >>> processing "deny"
75 >>> deny: condition test succeeded in ACL "check_data"
76 >>> end of ACL "check_data": DENY
77 LOG: 10HmaY-0005vi-00 H=(test.ex) [V4NET.9.8.7] F=<> rejected after DATA
78 >>> host in hosts_connection_nolog? no (option unset)
79 >>> host in host_lookup? no (option unset)
80 >>> host in host_reject_connection? no (option unset)
81 >>> host in sender_unqualified_hosts? no (option unset)
82 >>> host in recipient_unqualified_hosts? no (option unset)
83 >>> host in helo_verify_hosts? no (option unset)
84 >>> host in helo_try_verify_hosts? no (option unset)
85 >>> host in helo_accept_junk_hosts? no (option unset)
86 >>> test.ex in helo_lookup_domains? no (end of list)
87 >>> host in dsn_advertise_hosts? no (option unset)
88 >>> host in pipelining_advertise_hosts? yes (matched "*")
89 >>> host in chunking_advertise_hosts? no (end of list)
90 >>> using ACL "check_rcpt"
91 >>> processing "warn"
92 >>> check ratelimit = 0/1h/per_conn/strict
93 >>> ratelimit condition count=1 0.0/1h/per_conn/V4NET.9.8.7
94 >>> ratelimit creating new rate data block
95 >>> ratelimit initializing new key's rate data
96 >>> ratelimit db updated
97 >>> ratelimit computed rate 1.0
98 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
99 >>> warn: condition test succeeded in ACL "check_rcpt"
100 LOG: H=(test.ex) [V4NET.9.8.7] Warning: RCPT: sender_rate=1.0 sender_rate_limit=0 sender_rate_period=1h
101 >>> processing "accept"
102 >>> accept: condition test succeeded in ACL "check_rcpt"
103 >>> end of ACL "check_rcpt": ACCEPT
104 >>> host in ignore_fromline_hosts? no (option unset)
105 >>> using ACL "check_data"
106 >>> processing "warn"
107 >>> check ratelimit = 0/1h/per_conn/strict
108 >>> ratelimit condition count=1 0.0/1h/per_conn/V4NET.9.8.7
109 >>> ratelimit found pre-computed rate 1.0
110 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
111 >>> warn: condition test succeeded in ACL "check_data"
112 LOG: 10HmaZ-0005vi-00 H=(test.ex) [V4NET.9.8.7] Warning: DATA: sender_rate=1.0 sender_rate_limit=0 sender_rate_period=1h
113 >>> processing "deny"
114 >>> deny: condition test succeeded in ACL "check_data"
115 >>> end of ACL "check_data": DENY
116 LOG: 10HmaZ-0005vi-00 H=(test.ex) [V4NET.9.8.7] F=<> rejected after DATA
117 >>> host in hosts_connection_nolog? no (option unset)
118 >>> host in host_lookup? no (option unset)
119 >>> host in host_reject_connection? no (option unset)
120 >>> host in sender_unqualified_hosts? no (option unset)
121 >>> host in recipient_unqualified_hosts? no (option unset)
122 >>> host in helo_verify_hosts? no (option unset)
123 >>> host in helo_try_verify_hosts? no (option unset)
124 >>> host in helo_accept_junk_hosts? no (option unset)
125 >>> test.ex in helo_lookup_domains? no (end of list)
126 >>> host in dsn_advertise_hosts? no (option unset)
127 >>> host in pipelining_advertise_hosts? yes (matched "*")
128 >>> host in chunking_advertise_hosts? no (end of list)
129 >>> using ACL "check_rcpt"
130 >>> processing "warn"
131 >>> check ratelimit = 0/1h/per_conn/strict
132 >>> ratelimit condition count=1 0.0/1h/per_conn/V4NET.9.8.7
133 >>> ratelimit found key in database
134 >>> ratelimit db updated
135 >>> ratelimit computed rate 2.0
136 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
137 >>> warn: condition test succeeded in ACL "check_rcpt"
138 LOG: H=(test.ex) [V4NET.9.8.7] Warning: RCPT: sender_rate=2.0 sender_rate_limit=0 sender_rate_period=1h
139 >>> processing "accept"
140 >>> accept: condition test succeeded in ACL "check_rcpt"
141 >>> end of ACL "check_rcpt": ACCEPT
142 >>> host in ignore_fromline_hosts? no (option unset)
143 >>> using ACL "check_data"
144 >>> processing "warn"
145 >>> check ratelimit = 0/1h/per_conn/strict
146 >>> ratelimit condition count=1 0.0/1h/per_conn/V4NET.9.8.7
147 >>> ratelimit found pre-computed rate 2.0
148 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
149 >>> warn: condition test succeeded in ACL "check_data"
150 LOG: 10HmbA-0005vi-00 H=(test.ex) [V4NET.9.8.7] Warning: DATA: sender_rate=2.0 sender_rate_limit=0 sender_rate_period=1h
151 >>> processing "deny"
152 >>> deny: condition test succeeded in ACL "check_data"
153 >>> end of ACL "check_data": DENY
154 LOG: 10HmbA-0005vi-00 H=(test.ex) [V4NET.9.8.7] F=<> rejected after DATA
155 >>> host in hosts_connection_nolog? no (option unset)
156 >>> host in host_lookup? no (option unset)
157 >>> host in host_reject_connection? no (option unset)
158 >>> host in sender_unqualified_hosts? no (option unset)
159 >>> host in recipient_unqualified_hosts? no (option unset)
160 >>> host in helo_verify_hosts? no (option unset)
161 >>> host in helo_try_verify_hosts? no (option unset)
162 >>> host in helo_accept_junk_hosts? no (option unset)
163 >>> test.ex in helo_lookup_domains? no (end of list)
164 >>> host in dsn_advertise_hosts? no (option unset)
165 >>> host in pipelining_advertise_hosts? yes (matched "*")
166 >>> host in chunking_advertise_hosts? no (end of list)
167 >>> using ACL "check_rcpt"
168 >>> processing "warn"
169 >>> check ratelimit = 0/1h/per_rcpt
170 >>> ratelimit condition count=1 0.0/1h/per_rcpt/V4NET.9.8.7
171 >>> ratelimit creating new rate data block
172 >>> ratelimit initializing new key's rate data
173 >>> ratelimit db not updated: over the limit, but leaky
174 >>> ratelimit computed rate 1.0
175 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
176 >>> warn: condition test succeeded in ACL "check_rcpt"
177 LOG: H=(test.ex) [V4NET.9.8.7] Warning: RCPT: sender_rate=1.0 sender_rate_limit=0 sender_rate_period=1h
178 >>> processing "accept"
179 >>> accept: condition test succeeded in ACL "check_rcpt"
180 >>> end of ACL "check_rcpt": ACCEPT
181 >>> using ACL "check_rcpt"
182 >>> processing "warn"
183 >>> check ratelimit = 0/1h/per_rcpt
184 >>> ratelimit condition count=1 0.0/1h/per_rcpt/V4NET.9.8.7
185 >>> ratelimit creating new rate data block
186 >>> ratelimit initializing new key's rate data
187 >>> ratelimit db not updated: over the limit, but leaky
188 >>> ratelimit computed rate 1.0
189 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
190 >>> warn: condition test succeeded in ACL "check_rcpt"
191 >>> processing "accept"
192 >>> accept: condition test succeeded in ACL "check_rcpt"
193 >>> end of ACL "check_rcpt": ACCEPT
194 >>> using ACL "check_rcpt"
195 >>> processing "warn"
196 >>> check ratelimit = 0/1h/per_rcpt
197 >>> ratelimit condition count=1 0.0/1h/per_rcpt/V4NET.9.8.7
198 >>> ratelimit creating new rate data block
199 >>> ratelimit initializing new key's rate data
200 >>> ratelimit db not updated: over the limit, but leaky
201 >>> ratelimit computed rate 1.0
202 >>> l_message: RCPT: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
203 >>> warn: condition test succeeded in ACL "check_rcpt"
204 >>> processing "accept"
205 >>> accept: condition test succeeded in ACL "check_rcpt"
206 >>> end of ACL "check_rcpt": ACCEPT
207 >>> host in ignore_fromline_hosts? no (option unset)
208 >>> using ACL "check_data"
209 >>> processing "warn"
210 >>> check ratelimit = 0/1h/per_conn
211 >>> ratelimit condition count=1 0.0/1h/per_conn/V4NET.9.8.7
212 >>> ratelimit found key in database
213 >>> ratelimit db not updated: over the limit, but leaky
214 >>> ratelimit computed rate 3.0
215 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
216 >>> warn: condition test succeeded in ACL "check_data"
217 LOG: 10HmbB-0005vi-00 H=(test.ex) [V4NET.9.8.7] Warning: DATA: sender_rate=3.0 sender_rate_limit=0 sender_rate_period=1h
218 >>> processing "deny"
219 >>> deny: condition test succeeded in ACL "check_data"
220 >>> end of ACL "check_data": DENY
221 LOG: 10HmbB-0005vi-00 H=(test.ex) [V4NET.9.8.7] F=<> rejected after DATA
222 >>> host in hosts_connection_nolog? no (option unset)
223 >>> host in host_lookup? no (option unset)
224 >>> host in host_reject_connection? no (option unset)
225 >>> host in sender_unqualified_hosts? no (option unset)
226 >>> host in recipient_unqualified_hosts? no (option unset)
227 >>> host in helo_verify_hosts? no (option unset)
228 >>> host in helo_try_verify_hosts? no (option unset)
229 >>> host in helo_accept_junk_hosts? no (option unset)
230 >>> test.ex in helo_lookup_domains? no (end of list)
231 >>> host in dsn_advertise_hosts? no (option unset)
232 >>> host in pipelining_advertise_hosts? yes (matched "*")
233 >>> host in chunking_advertise_hosts? no (end of list)
234 >>> using ACL "check_rcpt2"
235 >>> processing "warn"
236 >>> check ratelimit = 1/1m/per_rcpt/noupdate
237 >>> ratelimit condition count=0 1.0/1m/per_rcpt/V4NET.9.8.6
238 >>> ratelimit creating new rate data block
239 >>> ratelimit initializing new key's rate data
240 >>> ratelimit db not updated: readonly mode
241 >>> ratelimit computed rate 0.0
242 >>> warn: condition test failed in ACL "check_rcpt2"
243 >>> processing "warn"
244 >>> check ratelimit = 1/1m/per_rcpt
245 >>> ratelimit condition count=1 1.0/1m/per_rcpt/V4NET.9.8.6
246 >>> ratelimit found pre-computed rate 0.0
247 >>> warn: condition test failed in ACL "check_rcpt2"
248 >>> processing "accept"
249 >>> accept: condition test succeeded in ACL "check_rcpt2"
250 >>> end of ACL "check_rcpt2": ACCEPT
251 >>> using ACL "check_rcpt2"
252 >>> processing "warn"
253 >>> check ratelimit = 1/1m/per_rcpt/noupdate
254 >>> ratelimit condition count=0 1.0/1m/per_rcpt/V4NET.9.8.6
255 >>> ratelimit creating new rate data block
256 >>> ratelimit initializing new key's rate data
257 >>> ratelimit db not updated: readonly mode
258 >>> ratelimit computed rate 0.0
259 >>> warn: condition test failed in ACL "check_rcpt2"
260 >>> processing "warn"
261 >>> check ratelimit = 1/1m/per_rcpt
262 >>> ratelimit condition count=1 1.0/1m/per_rcpt/V4NET.9.8.6
263 >>> ratelimit found pre-computed rate 0.0
264 >>> warn: condition test failed in ACL "check_rcpt2"
265 >>> processing "accept"
266 >>> accept: condition test succeeded in ACL "check_rcpt2"
267 >>> end of ACL "check_rcpt2": ACCEPT
268 >>> host in ignore_fromline_hosts? no (option unset)
269 >>> using ACL "check_data"
270 >>> processing "warn"
271 >>> check ratelimit = 0/1h/per_byte/strict
272 >>> ratelimit condition count=19 0.0/1h/per_mail/V4NET.9.8.6
273 >>> ratelimit creating new rate data block
274 >>> ratelimit initializing new key's rate data
275 >>> ratelimit db updated
276 >>> ratelimit computed rate 19.0
277 >>> l_message: DATA: sender_rate=$sender_rate sender_rate_limit=$sender_rate_limit sender_rate_period=$sender_rate_period
278 >>> warn: condition test succeeded in ACL "check_data"
279 LOG: 10HmbC-0005vi-00 H=(test.ex) [V4NET.9.8.6] Warning: DATA: sender_rate=19.0 sender_rate_limit=0 sender_rate_period=1h
280 >>> processing "deny"
281 >>> deny: condition test succeeded in ACL "check_data"
282 >>> end of ACL "check_data": DENY
283 LOG: 10HmbC-0005vi-00 H=(test.ex) [V4NET.9.8.6] F=<> rejected after DATA