Flush SMTP output buffer before "delay" in an ACL; add control =
[exim.git] / test / stderr / 2600
1 Exim version x.yz ....
2 configuration file is TESTSUITE/test-config
3 admin user
4 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
5 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
6   key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0
7 LRU list:
8 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
9   type=sqlite key="select name from them where id='userx';"
10 file lookup required for select name from them where id='userx';
11   in TESTSUITE/aux-fixed/sqlitedb
12 lookup yielded: Ayen Other
13 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
14   cached open
15 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
16   key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0
17 LRU list:
18 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
19   type=sqlite key="select name from them where id='userx';"
20 cached data used for lookup of select name from them where id='userx';
21   in TESTSUITE/aux-fixed/sqlitedb
22 lookup yielded: Ayen Other
23 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
24   cached open
25 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
26   key="select name from them where id='xxxx';" partial=-1 affix=NULL starflags=0
27 LRU list:
28 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
29   type=sqlite key="select name from them where id='xxxx';"
30 file lookup required for select name from them where id='xxxx';
31   in TESTSUITE/aux-fixed/sqlitedb
32 lookup forced cache cleanup
33 lookup failed
34 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
35   cached open
36 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
37   key="select name from them where id='nothing';" partial=-1 affix=NULL starflags=0
38 LRU list:
39 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
40   type=sqlite key="select name from them where id='nothing';"
41 file lookup required for select name from them where id='nothing';
42   in TESTSUITE/aux-fixed/sqlitedb
43 lookup yielded: 
44 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
45   cached open
46 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
47   key="select id,name from them where id='nothing';" partial=-1 affix=NULL starflags=0
48 LRU list:
49 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
50   type=sqlite key="select id,name from them where id='nothing';"
51 file lookup required for select id,name from them where id='nothing';
52   in TESTSUITE/aux-fixed/sqlitedb
53 lookup yielded: id=nothing name="" 
54 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
55   cached open
56 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
57   key="select * from them where id='quote2';" partial=-1 affix=NULL starflags=0
58 LRU list:
59 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
60   type=sqlite key="select * from them where id='quote2';"
61 file lookup required for select * from them where id='quote2';
62   in TESTSUITE/aux-fixed/sqlitedb
63 lookup yielded: name="\"stquot" id=quote2 
64 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
65   cached open
66 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
67   key="select * from them where id='newline';" partial=-1 affix=NULL starflags=0
68 LRU list:
69 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
70   type=sqlite key="select * from them where id='newline';"
71 file lookup required for select * from them where id='newline';
72   in TESTSUITE/aux-fixed/sqlitedb
73 lookup yielded: name="before
74 after" id=newline 
75 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
76   cached open
77 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
78   key="select * from them where id='tab';" partial=-1 affix=NULL starflags=0
79 LRU list:
80 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
81   type=sqlite key="select * from them where id='tab';"
82 file lookup required for select * from them where id='tab';
83   in TESTSUITE/aux-fixed/sqlitedb
84 lookup yielded: name="x x" id=tab 
85 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
86   cached open
87 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
88   key="select * from them where id='its';" partial=-1 affix=NULL starflags=0
89 LRU list:
90 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
91   type=sqlite key="select * from them where id='its';"
92 file lookup required for select * from them where id='its';
93   in TESTSUITE/aux-fixed/sqlitedb
94 lookup yielded: name=it's id=its 
95 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
96   cached open
97 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
98   key="select * from them where name='it''s';" partial=-1 affix=NULL starflags=0
99 LRU list:
100 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
101   type=sqlite key="select * from them where name='it''s';"
102 file lookup required for select * from them where name='it''s';
103   in TESTSUITE/aux-fixed/sqlitedb
104 lookup yielded: name=it's id=its 
105 search_tidyup called
106 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
107 Exim version x.yz ....
108 changed uid/gid: forcing real = effective
109   uid=uuuu gid=CALLER_GID pid=pppp
110 configuration file is TESTSUITE/test-config
111 admin user
112 changed uid/gid: privilege not needed
113   uid=EXIM_UID gid=EXIM_GID pid=pppp
114 seeking password data for user "CALLER": cache not available
115 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
116 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
117 sender address = CALLER@myhost.test.ex
118 sender_fullhost = [10.0.0.0]
119 sender_rcvhost = [10.0.0.0]
120 host in hosts_connection_nolog? no (option unset)
121 LOG: smtp_connection MAIN
122   SMTP connection from [10.0.0.0]
123 host in host_lookup? no (option unset)
124 set_process_info: pppp handling incoming connection from [10.0.0.0]
125 host in host_reject_connection? no (option unset)
126 host in sender_unqualified_hosts? no (option unset)
127 host in recipient_unqualified_hosts? no (option unset)
128 host in helo_verify_hosts? no (option unset)
129 host in helo_try_verify_hosts? no (option unset)
130 host in helo_accept_junk_hosts? no (option unset)
131 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
132 smtp_setup_msg entered
133 SMTP<< mail from:<a@b>
134 SMTP>> 250 OK
135 SMTP<< rcpt to:<c@d>
136 using ACL "check_recipient"
137 processing "accept"
138 check domains = +local_domains
139 d in "@"? no (end of list)
140 d in "+local_domains"? no (end of list)
141 accept: condition test failed
142 processing "accept"
143 check hosts = +relay_hosts
144 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
145 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
146   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0
147 LRU list:
148 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
149   type=sqlite key="select * from them where id='10.0.0.0'"
150 file lookup required for select * from them where id='10.0.0.0'
151   in TESTSUITE/aux-fixed/sqlitedb
152 lookup forced cache cleanup
153 lookup failed
154 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"? no (end of list)
155 host in "+relay_hosts"? no (end of list)
156 accept: condition test failed
157 processing "deny"
158 deny: condition test succeeded
159 SMTP>> 550 relay not permitted
160 LOG: MAIN REJECT
161   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
162 SMTP<< rcpt to:<c@d>
163 using ACL "check_recipient"
164 processing "accept"
165 check domains = +local_domains
166 d in "@"? no (end of list)
167 d in "+local_domains"? no (end of list)
168 accept: condition test failed
169 processing "accept"
170 check hosts = +relay_hosts
171 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
172   cached open
173 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
174   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0
175 LRU list:
176 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
177   type=sqlite key="select * from them where id='10.0.0.0'"
178 file lookup required for select * from them where id='10.0.0.0'
179   in TESTSUITE/aux-fixed/sqlitedb
180 lookup forced cache cleanup
181 lookup failed
182 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"? no (end of list)
183 host in "+relay_hosts"? no (end of list)
184 accept: condition test failed
185 processing "deny"
186 deny: condition test succeeded
187 SMTP>> 550 relay not permitted
188 LOG: MAIN REJECT
189   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
190 SMTP<< quit
191 SMTP>> 221 myhost.test.ex closing connection
192 LOG: smtp_connection MAIN
193   SMTP connection from [10.0.0.0] closed by QUIT
194 search_tidyup called
195 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
196 Exim version x.yz ....
197 changed uid/gid: forcing real = effective
198   uid=uuuu gid=CALLER_GID pid=pppp
199 configuration file is TESTSUITE/test-config
200 admin user
201 changed uid/gid: privilege not needed
202   uid=EXIM_UID gid=EXIM_GID pid=pppp
203 seeking password data for user "CALLER": cache not available
204 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
205 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
206 sender address = CALLER@myhost.test.ex
207 sender_fullhost = [10.10.10.10]
208 sender_rcvhost = [10.10.10.10]
209 host in hosts_connection_nolog? no (option unset)
210 LOG: smtp_connection MAIN
211   SMTP connection from [10.10.10.10]
212 host in host_lookup? no (option unset)
213 set_process_info: pppp handling incoming connection from [10.10.10.10]
214 host in host_reject_connection? no (option unset)
215 host in sender_unqualified_hosts? no (option unset)
216 host in recipient_unqualified_hosts? no (option unset)
217 host in helo_verify_hosts? no (option unset)
218 host in helo_try_verify_hosts? no (option unset)
219 host in helo_accept_junk_hosts? no (option unset)
220 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
221 smtp_setup_msg entered
222 SMTP<< mail from:<a@b>
223 SMTP>> 250 OK
224 SMTP<< rcpt to:<c@d>
225 using ACL "check_recipient"
226 processing "accept"
227 check domains = +local_domains
228 d in "@"? no (end of list)
229 d in "+local_domains"? no (end of list)
230 accept: condition test failed
231 processing "accept"
232 check hosts = +relay_hosts
233 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
234 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
235   key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0
236 LRU list:
237 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
238   type=sqlite key="select * from them where id='10.10.10.10'"
239 file lookup required for select * from them where id='10.10.10.10'
240   in TESTSUITE/aux-fixed/sqlitedb
241 lookup yielded: name=ok id=10.10.10.10 
242 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'"? yes (matched "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'")
243 host in "+relay_hosts"? yes (matched "+relay_hosts")
244 accept: condition test succeeded
245 SMTP>> 250 Accepted
246 SMTP<< rcpt to:<c@d>
247 using ACL "check_recipient"
248 processing "accept"
249 check domains = +local_domains
250 d in "@"? no (end of list)
251 d in "+local_domains"? no (end of list)
252 accept: condition test failed
253 processing "accept"
254 check hosts = +relay_hosts
255 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
256   cached open
257 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
258   key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0
259 LRU list:
260 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
261   type=sqlite key="select * from them where id='10.10.10.10'"
262 cached data used for lookup of select * from them where id='10.10.10.10'
263   in TESTSUITE/aux-fixed/sqlitedb
264 lookup yielded: name=ok id=10.10.10.10 
265 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'"? yes (matched "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'")
266 host in "+relay_hosts"? yes (matched "+relay_hosts")
267 accept: condition test succeeded
268 SMTP>> 250 Accepted
269 SMTP<< quit
270 SMTP>> 221 myhost.test.ex closing connection
271 LOG: smtp_connection MAIN
272   SMTP connection from [10.10.10.10] closed by QUIT
273 search_tidyup called
274 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
275 Exim version x.yz ....
276 changed uid/gid: forcing real = effective
277   uid=uuuu gid=CALLER_GID pid=pppp
278 configuration file is TESTSUITE/test-config
279 admin user
280 changed uid/gid: privilege not needed
281   uid=EXIM_UID gid=EXIM_GID pid=pppp
282 seeking password data for user "CALLER": cache not available
283 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
284 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
285 sender address = CALLER@myhost.test.ex
286 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
287 Sender: CALLER@myhost.test.ex
288 Recipients:
289   userx
290 search_tidyup called
291 >>Headers received:
292
293 rewrite_one_header: type=F:
294   From: CALLER_NAME <CALLER@myhost.test.ex>
295 search_tidyup called
296 >>Headers after rewriting and local additions:
297 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
298 F From: CALLER_NAME <CALLER@myhost.test.ex>
299   Date: Tue, 2 Mar 1999 09:44:33 +0000
300
301 Data file written for message 10HmaX-0005vi-00
302 >>Generated Received: header line
303 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
304         (envelope-from <CALLER@myhost.test.ex>)
305         id 10HmaX-0005vi-00
306         for userx@myhost.test.ex; Tue, 2 Mar 1999 09:44:33 +0000
307 calling local_scan(); timeout=300
308 local_scan() returned 0 NULL
309 Writing spool header file
310 Size of headers = sss
311 LOG: MAIN
312   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
313 created log directory TESTSUITE/spool/log
314 search_tidyup called
315 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
316 Exim version x.yz ....
317 changed uid/gid: forcing real = effective
318   uid=uuuu gid=EXIM_GID pid=pppp
319 configuration file is TESTSUITE/test-config
320 trusted user
321 admin user
322 skipping ACL configuration - not needed
323 seeking password data for user "CALLER": cache not available
324 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
325 set_process_info: pppp delivering specified messages
326 set_process_info: pppp delivering 10HmaX-0005vi-00
327 reading spool file 10HmaX-0005vi-00-H
328 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
329 sender_local=1 ident=CALLER
330 Non-recipients:
331 Empty Tree
332 ---- End of tree ----
333 recipients_count=1
334 body_linecount=1 message_linecount=7
335 Delivery address list:
336   userx@myhost.test.ex 
337 locking TESTSUITE/spool/db/retry.lockfile
338 locked TESTSUITE/spool/db/retry.lockfile
339 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
340 returned from EXIM_DBOPEN
341 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
342 no retry data available
343 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
344 Considering: userx@myhost.test.ex
345 unique = userx@myhost.test.ex
346 no domain retry record
347 no address retry record
348 userx@myhost.test.ex: queued for routing
349 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
350 routing userx@myhost.test.ex
351 --------> r1 router <--------
352 local_part=userx domain=myhost.test.ex
353 processing address_data
354 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
355 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
356   key="select name from them where id='userx'" partial=-1 affix=NULL starflags=0
357 LRU list:
358 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
359   type=sqlite key="select name from them where id='userx'"
360 file lookup required for select name from them where id='userx'
361   in TESTSUITE/aux-fixed/sqlitedb
362 lookup yielded: Ayen Other
363 calling r1 router
364 r1 router called for userx@myhost.test.ex
365   domain = myhost.test.ex
366 set transport t1
367 queued for t1 transport: local_part = userx
368 domain = myhost.test.ex
369   errors_to=NULL
370   domain_data=NULL localpart_data=NULL
371 routed by r1 router
372   envelope to: userx@myhost.test.ex
373   transport: t1
374 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
375 After routing:
376   Local deliveries:
377     userx@myhost.test.ex
378   Remote deliveries:
379   Failed addresses:
380   Deferred addresses:
381 search_tidyup called
382 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
383 --------> userx@myhost.test.ex <--------
384 locking TESTSUITE/spool/db/retry.lockfile
385 locked TESTSUITE/spool/db/retry.lockfile
386 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
387 returned from EXIM_DBOPEN
388 no retry data available
389 search_tidyup called
390 changed uid/gid: local delivery to userx <userx@myhost.test.ex> transport=t1
391   uid=CALLER_UID gid=CALLER_GID pid=pppp
392   home=NULL current=/
393 set_process_info: pppp delivering 10HmaX-0005vi-00 to userx using t1
394 appendfile transport entered
395 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
396 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
397   key="select id from them where id='userx'" partial=-1 affix=NULL starflags=0
398 LRU list:
399 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
400   type=sqlite key="select id from them where id='userx'"
401 file lookup required for select id from them where id='userx'
402   in TESTSUITE/aux-fixed/sqlitedb
403 lookup yielded: userx
404 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
405   file=TESTSUITE/test-mail/userx format=unix
406   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
407   message_suffix=\n
408   maildir_use_size_file=no
409   locking by lockfile fcntl 
410 lock name: TESTSUITE/test-mail/userx.lock
411 hitch name: TESTSUITE/test-mail/userx.lock.test.ex.dddddddd.pppppppp
412 lock file created
413 mailbox TESTSUITE/test-mail/userx is locked
414 writing to file TESTSUITE/test-mail/userx
415 writing data block fd=dddd size=sss timeout=0
416 writing data block fd=dddd size=sss timeout=0
417 writing data block fd=dddd size=sss timeout=0
418 appendfile yields 0 with errno=dd more_errno=dd
419 search_tidyup called
420 journalling userx@myhost.test.ex
421 t1 transport returned OK for userx@myhost.test.ex
422 post-process userx@myhost.test.ex (0)
423 userx@myhost.test.ex delivered
424 LOG: MAIN
425   => userx <userx@myhost.test.ex> R=r1 T=t1
426 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
427 changed uid/gid: post-delivery tidying
428   uid=EXIM_UID gid=EXIM_GID pid=pppp
429 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
430 Processing retry items
431 Succeeded addresses:
432 userx@myhost.test.ex: no retry items
433 Failed addresses:
434 Deferred addresses:
435 end of retry processing
436 LOG: MAIN
437   Completed
438 end delivery of 10HmaX-0005vi-00
439 search_tidyup called
440 search_tidyup called
441 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
442 search_tidyup called
443 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
444 Exim version x.yz ....
445 configuration file is TESTSUITE/test-config
446 admin user
447 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
448 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
449   key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0
450 LRU list:
451 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
452   type=sqlite key="select name from them where id='userx';"
453 file lookup required for select name from them where id='userx';
454   in TESTSUITE/aux-fixed/sqlitedb
455 lookup yielded: Ayen Other
456 search_tidyup called
457 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>