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