Debug: indent ACL and expreassion tracing by evaluation depth
[exim.git] / test / stderr / 0022
1 Exim version x.yz ....
2 changed uid/gid: forcing real = effective
3   uid=uuuu gid=CALLER_GID pid=pppp
4 configuration file is TESTSUITE/test-config
5 admin user
6 changed uid/gid: privilege not needed
7   uid=EXIM_UID gid=EXIM_GID pid=pppp
8 DSN: accept propagating DSN
9 seeking password data for user "CALLER": cache not available
10 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
11 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
12 sender address = CALLER@test.ex
13 sender_fullhost = [V4NET.9.8.7]
14 sender_rcvhost = [V4NET.9.8.7]
15 host in hosts_connection_nolog? no (end of list)
16 LOG: smtp_connection MAIN
17   SMTP connection from [V4NET.9.8.7]
18 host in host_lookup? no (option unset)
19 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
20 host in host_reject_connection? no (option unset)
21 host in sender_unqualified_hosts? no (option unset)
22 host in recipient_unqualified_hosts? no (option unset)
23 host in helo_verify_hosts? no (option unset)
24 host in helo_try_verify_hosts? no (option unset)
25 host in helo_accept_junk_hosts? no (option unset)
26 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
27 smtp_setup_msg entered
28 SMTP<< mail from:<x@y>
29 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
30 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
31 SMTP>> 250 OK
32 SMTP<< rcpt to:<warn_empty@test.ex>
33 using ACL "warn_empty"
34 processing "warn"
35 warn: condition test succeeded in ACL "warn_empty"
36 processing "accept"
37 accept: condition test succeeded in ACL "warn_empty"
38 end of ACL "warn_empty": ACCEPT
39 SMTP>> 250 Accepted
40 DSN: orcpt: NULL  flags: 0
41 SMTP<< data
42 SMTP>> 354 Enter message, ending with "." on a line by itself
43 search_tidyup called
44 >>Headers received:
45
46 search_tidyup called
47 >>Headers after rewriting and local additions:
48
49 Data file name: TESTSUITE/spool//input//10HmbF-0005vi-00-D
50 Data file written for message 10HmbF-0005vi-00
51 >>Generated Received: header line
52 P Received: from [V4NET.9.8.7]
53         by myhost.test.ex with smtp (Exim x.yz)
54         (envelope-from <x@y>)
55         id 10HmbF-0005vi-00
56         for warn_empty@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
57 calling local_scan(); timeout=300
58 local_scan() returned 0 NULL
59 LOG: MAIN
60   <= x@y H=[V4NET.9.8.7] P=smtp S=sss
61 SMTP>> 250 OK id=10HmbF-0005vi-00
62 smtp_setup_msg entered
63 SMTP<< quit
64 SMTP>> 221 myhost.test.ex closing connection
65 LOG: smtp_connection MAIN
66   SMTP connection from [V4NET.9.8.7] closed by QUIT
67 search_tidyup called
68 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
69 Exim version x.yz ....
70 changed uid/gid: forcing real = effective
71   uid=uuuu gid=CALLER_GID pid=pppp
72 configuration file is TESTSUITE/test-config
73 admin user
74 changed uid/gid: privilege not needed
75   uid=EXIM_UID gid=EXIM_GID pid=pppp
76 DSN: accept propagating DSN
77 seeking password data for user "CALLER": cache not available
78 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
79 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
80 sender address = CALLER@test.ex
81 sender_fullhost = [V4NET.9.8.7]
82 sender_rcvhost = [V4NET.9.8.7]
83 host in hosts_connection_nolog? no (end of list)
84 LOG: smtp_connection MAIN
85   SMTP connection from [V4NET.9.8.7]
86 host in host_lookup? no (option unset)
87 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
88 host in host_reject_connection? no (option unset)
89 host in sender_unqualified_hosts? no (option unset)
90 host in recipient_unqualified_hosts? no (option unset)
91 host in helo_verify_hosts? no (option unset)
92 host in helo_try_verify_hosts? no (option unset)
93 host in helo_accept_junk_hosts? no (option unset)
94 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
95 smtp_setup_msg entered
96 SMTP<< mail from:<x@y>
97 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
98 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
99 SMTP>> 250 OK
100 SMTP<< rcpt to:<warn_log@test.ex>
101 using ACL "warn_log"
102 processing "warn"
103 l_message: warn log message
104 warn: condition test succeeded in ACL "warn_log"
105 LOG: MAIN
106   H=[V4NET.9.8.7] Warning: warn log message
107 processing "accept"
108 accept: condition test succeeded in ACL "warn_log"
109 end of ACL "warn_log": ACCEPT
110 SMTP>> 250 Accepted
111 DSN: orcpt: NULL  flags: 0
112 SMTP<< data
113 SMTP>> 354 Enter message, ending with "." on a line by itself
114 search_tidyup called
115 >>Headers received:
116
117 search_tidyup called
118 >>Headers after rewriting and local additions:
119
120 Data file name: TESTSUITE/spool//input//10HmbG-0005vi-00-D
121 Data file written for message 10HmbG-0005vi-00
122 >>Generated Received: header line
123 P Received: from [V4NET.9.8.7]
124         by myhost.test.ex with smtp (Exim x.yz)
125         (envelope-from <x@y>)
126         id 10HmbG-0005vi-00
127         for warn_log@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
128 calling local_scan(); timeout=300
129 local_scan() returned 0 NULL
130 LOG: MAIN
131   <= x@y H=[V4NET.9.8.7] P=smtp S=sss
132 SMTP>> 250 OK id=10HmbG-0005vi-00
133 smtp_setup_msg entered
134 SMTP<< quit
135 SMTP>> 221 myhost.test.ex closing connection
136 LOG: smtp_connection MAIN
137   SMTP connection from [V4NET.9.8.7] closed by QUIT
138 search_tidyup called
139 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
140 Exim version x.yz ....
141 changed uid/gid: forcing real = effective
142   uid=uuuu gid=CALLER_GID pid=pppp
143 configuration file is TESTSUITE/test-config
144 admin user
145 changed uid/gid: privilege not needed
146   uid=EXIM_UID gid=EXIM_GID pid=pppp
147 DSN: accept propagating DSN
148 seeking password data for user "CALLER": cache not available
149 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
150 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
151 sender address = CALLER@test.ex
152 sender_fullhost = [V4NET.9.8.7]
153 sender_rcvhost = [V4NET.9.8.7]
154 host in hosts_connection_nolog? no (end of list)
155 LOG: smtp_connection MAIN
156   SMTP connection from [V4NET.9.8.7]
157 host in host_lookup? no (option unset)
158 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
159 host in host_reject_connection? no (option unset)
160 host in sender_unqualified_hosts? no (option unset)
161 host in recipient_unqualified_hosts? no (option unset)
162 host in helo_verify_hosts? no (option unset)
163 host in helo_try_verify_hosts? no (option unset)
164 host in helo_accept_junk_hosts? no (option unset)
165 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
166 smtp_setup_msg entered
167 SMTP<< mail from:<x@y>
168 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
169 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
170 SMTP>> 250 OK
171 SMTP<< rcpt to:<warn_user@test.ex>
172 using ACL "warn_user"
173 processing "warn"
174   message: warn user message
175 warn: condition test succeeded in ACL "warn_user"
176 processing "accept"
177 accept: condition test succeeded in ACL "warn_user"
178 end of ACL "warn_user": ACCEPT
179 SMTP>> 250 Accepted
180 DSN: orcpt: NULL  flags: 0
181 SMTP<< data
182 SMTP>> 354 Enter message, ending with "." on a line by itself
183 search_tidyup called
184 >>Headers received:
185
186 search_tidyup called
187 >>Headers after rewriting and local additions:
188
189 Data file name: TESTSUITE/spool//input//10HmbH-0005vi-00-D
190 Data file written for message 10HmbH-0005vi-00
191 >>Generated Received: header line
192 P Received: from [V4NET.9.8.7]
193         by myhost.test.ex with smtp (Exim x.yz)
194         (envelope-from <x@y>)
195         id 10HmbH-0005vi-00
196         for warn_user@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
197 >>Headers added by MAIL or RCPT ACL:
198   X-ACL-Warn: warn user message
199 >>
200 calling local_scan(); timeout=300
201 local_scan() returned 0 NULL
202 LOG: MAIN
203   <= x@y H=[V4NET.9.8.7] P=smtp S=sss
204 SMTP>> 250 OK id=10HmbH-0005vi-00
205 smtp_setup_msg entered
206 SMTP<< quit
207 SMTP>> 221 myhost.test.ex closing connection
208 LOG: smtp_connection MAIN
209   SMTP connection from [V4NET.9.8.7] closed by QUIT
210 search_tidyup called
211 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
212 >>> host in hosts_connection_nolog? no (end of list)
213 LOG: SMTP connection from [V4NET.9.8.7]
214 >>> host in host_lookup? no (option unset)
215 >>> host in host_reject_connection? no (option unset)
216 >>> host in sender_unqualified_hosts? no (option unset)
217 >>> host in recipient_unqualified_hosts? no (option unset)
218 >>> host in helo_verify_hosts? no (option unset)
219 >>> host in helo_try_verify_hosts? no (option unset)
220 >>> host in helo_accept_junk_hosts? no (option unset)
221 >>> using ACL "defer"
222 >>> processing "defer"
223 >>>   message: forcibly deferred
224 >>> defer: condition test succeeded in ACL "defer"
225 >>> end of ACL "defer": DEFER
226 LOG: H=[V4NET.9.8.7] F=<x@y> temporarily rejected RCPT <defer@y>: forcibly deferred
227 >>> using ACL "accept"
228 >>> processing "accept"
229 >>> accept: condition test succeeded in ACL "accept"
230 >>> end of ACL "accept": ACCEPT
231 >>> using ACL "drop"
232 >>> processing "drop"
233 >>>   message: forcibly dropped
234 >>> drop: condition test succeeded in ACL "drop"
235 >>> end of ACL "drop": DROP
236 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <drop@y>: forcibly dropped
237 LOG: SMTP connection from [V4NET.9.8.7] closed by DROP in ACL
238 >>> host in hosts_connection_nolog? no (end of list)
239 LOG: SMTP connection from [V4NET.9.8.7]
240 >>> host in host_lookup? no (option unset)
241 >>> host in host_reject_connection? no (option unset)
242 >>> host in sender_unqualified_hosts? no (option unset)
243 >>> host in recipient_unqualified_hosts? no (option unset)
244 >>> host in helo_verify_hosts? no (option unset)
245 >>> host in helo_try_verify_hosts? no (option unset)
246 >>> host in helo_accept_junk_hosts? no (option unset)
247 >>> using ACL "defer_senders"
248 >>> processing "defer"
249 >>> check senders = :
250 >>>  in ":"? yes (matched "")
251 >>> defer: condition test succeeded in ACL "defer_senders"
252 >>> end of ACL "defer_senders": DEFER
253 LOG: H=[V4NET.9.8.7] F=<> temporarily rejected RCPT <defer_senders@y>
254 LOG: SMTP connection from [V4NET.9.8.7] closed by QUIT
255 >>> host in hosts_connection_nolog? no (end of list)
256 LOG: SMTP connection from [V4NET.9.8.7]
257 >>> host in host_lookup? no (option unset)
258 >>> host in host_reject_connection? no (option unset)
259 >>> host in sender_unqualified_hosts? no (option unset)
260 >>> host in recipient_unqualified_hosts? no (option unset)
261 >>> host in helo_verify_hosts? no (option unset)
262 >>> host in helo_try_verify_hosts? no (option unset)
263 >>> host in helo_accept_junk_hosts? no (option unset)
264 >>> using ACL "delay_accept"
265 >>> processing "accept"
266 >>> check delay = 1s
267 >>> delay modifier requests 1-second delay
268 >>> delay skipped in -bh checking mode
269 >>> accept: condition test succeeded in ACL "delay_accept"
270 >>> end of ACL "delay_accept": ACCEPT
271 >>> using ACL "delay_warn"
272 >>> processing "warn"
273 >>> check delay = 1s
274 >>> delay modifier requests 1-second delay
275 >>> delay skipped in -bh checking mode
276 >>> warn: condition test succeeded in ACL "delay_warn"
277 >>> processing "accept"
278 >>> accept: condition test succeeded in ACL "delay_warn"
279 >>> end of ACL "delay_warn": ACCEPT
280 LOG: SMTP connection from [V4NET.9.8.7] closed by QUIT
281 >>> host in hosts_connection_nolog? no (end of list)
282 LOG: SMTP connection from [V4NET.9.8.7]
283 >>> host in host_lookup? no (option unset)
284 >>> host in host_reject_connection? no (option unset)
285 >>> host in sender_unqualified_hosts? no (option unset)
286 >>> host in recipient_unqualified_hosts? no (option unset)
287 >>> host in helo_verify_hosts? no (option unset)
288 >>> host in helo_try_verify_hosts? no (option unset)
289 >>> host in helo_accept_junk_hosts? no (option unset)
290 >>> using ACL "host_check"
291 >>> processing "deny"
292 >>> check hosts = net-lsearch;TESTSUITE/aux-var/0022.hosts
293 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
294 >>>   message: host data >$host_data<
295 >>> deny: condition test succeeded in ACL "host_check"
296 >>> end of ACL "host_check": DENY
297 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <host_check@y>: host data >A host-specific message<
298 >>> using ACL "host_check"
299 >>> processing "deny"
300 >>> check hosts = net-lsearch;TESTSUITE/aux-var/0022.hosts
301 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
302 >>>   message: host data >$host_data<
303 >>> deny: condition test succeeded in ACL "host_check"
304 >>> end of ACL "host_check": DENY
305 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <host_check@y>: host data >A host-specific message<
306 >>> using ACL "host_check2"
307 >>> processing "deny"
308 >>>   message: host data >$host_data<
309 >>> check hosts = +some_hosts
310 >>> host in "net-lsearch;TESTSUITE/aux-var/0022.hosts"? yes (matched "net-lsearch;TESTSUITE/aux-var/0022.hosts")
311 >>> host in "+some_hosts"? yes (matched "+some_hosts")
312 >>> deny: condition test succeeded in ACL "host_check2"
313 >>> end of ACL "host_check2": DENY
314 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <host_check2@y>: host data >A host-specific message<
315 >>> using ACL "host_check2"
316 >>> processing "deny"
317 >>>   message: host data >$host_data<
318 >>> check hosts = +some_hosts
319 >>> host in "+some_hosts"? yes (matched "+some_hosts" - cached)
320 >>> deny: condition test succeeded in ACL "host_check2"
321 >>> end of ACL "host_check2": DENY
322 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <host_check2@y>: host data >A host-specific message<
323 LOG: SMTP connection from [V4NET.9.8.7] closed by QUIT
324 LOG: smtp_connection MAIN
325   SMTP connection from CALLER
326 LOG: MAIN
327   Connections=0
328 LOG: MAIN
329   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
330 LOG: MAIN
331   frozen by ACL
332 LOG: MAIN
333   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
334 delivering 10HmaY-0005vi-00
335 LOG: MAIN
336   *> accept <accept@y> R=accept T=appendfile
337 LOG: MAIN
338   Completed
339 LOG: MAIN
340   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
341 LOG: delay_delivery MAIN
342   no immediate delivery: queued by ACL
343 LOG: MAIN
344   <= CALLER@test.ex U=CALLER P=local-smtp S=sss
345 delivering 10HmbA-0005vi-00
346 LOG: MAIN
347   *> accept <accept@y> R=accept T=appendfile
348 LOG: MAIN
349   Completed
350 LOG: smtp_connection MAIN
351   SMTP connection from CALLER closed by QUIT
352 >>> host in hosts_connection_nolog? no (end of list)
353 LOG: SMTP connection from [V4NET.9.8.7]
354 >>> host in host_lookup? no (option unset)
355 >>> host in host_reject_connection? no (option unset)
356 >>> host in sender_unqualified_hosts? no (option unset)
357 >>> host in recipient_unqualified_hosts? no (option unset)
358 >>> host in helo_verify_hosts? no (option unset)
359 >>> host in helo_try_verify_hosts? no (option unset)
360 >>> host in helo_accept_junk_hosts? no (option unset)
361 >>> using ACL "nested_drop"
362 >>> processing "accept"
363 >>> check acl = drop
364  >>> using ACL "drop"
365  >>> processing "drop"
366  >>>   message: forcibly dropped
367  >>> drop: condition test succeeded in ACL "drop"
368  >>> end of ACL "drop": DROP
369 >>> accept: condition test yielded "drop" in ACL "nested_drop"
370 >>> accept: endpass encountered - denying access
371 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <nested_drop@y>: forcibly dropped
372 LOG: SMTP connection from [V4NET.9.8.7] closed by DROP in ACL
373 >>> host in hosts_connection_nolog? no (end of list)
374 LOG: SMTP connection from [V4NET.9.8.7]
375 >>> host in host_lookup? no (option unset)
376 >>> host in host_reject_connection? no (option unset)
377 >>> host in sender_unqualified_hosts? no (option unset)
378 >>> host in recipient_unqualified_hosts? no (option unset)
379 >>> host in helo_verify_hosts? no (option unset)
380 >>> host in helo_try_verify_hosts? no (option unset)
381 >>> host in helo_accept_junk_hosts? no (option unset)
382 >>> using ACL "nested_drop_require"
383 >>> processing "require"
384 >>> check acl = drop
385  >>> using ACL "drop"
386  >>> processing "drop"
387  >>>   message: forcibly dropped
388  >>> drop: condition test succeeded in ACL "drop"
389  >>> end of ACL "drop": DROP
390 >>> require: condition test yielded "drop" in ACL "nested_drop_require"
391 >>> end of ACL "nested_drop_require": not OK
392 LOG: H=[V4NET.9.8.7] F=<x@y> rejected RCPT <nested_drop_require@y>: forcibly dropped
393 LOG: SMTP connection from [V4NET.9.8.7] closed by DROP in ACL
394
395 ******** SERVER ********