Remove ACL-config skip so that ${acl } expansions work from queue-runs.
[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 in ACL "check_recipient"
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 in ACL "check_recipient"
157 processing "deny"
158 deny: condition test succeeded in ACL "check_recipient"
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 in ACL "check_recipient"
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 in ACL "check_recipient"
185 processing "deny"
186 deny: condition test succeeded in ACL "check_recipient"
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 in ACL "check_recipient"
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 in ACL "check_recipient"
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 in ACL "check_recipient"
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 in ACL "check_recipient"
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 seeking password data for user "CALLER": cache not available
323 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
324 set_process_info: pppp delivering specified messages
325 set_process_info: pppp delivering 10HmaX-0005vi-00
326 reading spool file 10HmaX-0005vi-00-H
327 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
328 sender_local=1 ident=CALLER
329 Non-recipients:
330 Empty Tree
331 ---- End of tree ----
332 recipients_count=1
333 body_linecount=1 message_linecount=7
334 Delivery address list:
335   userx@myhost.test.ex 
336 locking TESTSUITE/spool/db/retry.lockfile
337 locked TESTSUITE/spool/db/retry.lockfile
338 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
339 returned from EXIM_DBOPEN
340 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
341 no retry data available
342 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
343 Considering: userx@myhost.test.ex
344 unique = userx@myhost.test.ex
345 no domain retry record
346 no address retry record
347 userx@myhost.test.ex: queued for routing
348 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
349 routing userx@myhost.test.ex
350 --------> r1 router <--------
351 local_part=userx domain=myhost.test.ex
352 processing address_data
353 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
354 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
355   key="select name from them where id='userx'" partial=-1 affix=NULL starflags=0
356 LRU list:
357 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
358   type=sqlite key="select name from them where id='userx'"
359 file lookup required for select name from them where id='userx'
360   in TESTSUITE/aux-fixed/sqlitedb
361 lookup yielded: Ayen Other
362 calling r1 router
363 r1 router called for userx@myhost.test.ex
364   domain = myhost.test.ex
365 set transport t1
366 queued for t1 transport: local_part = userx
367 domain = myhost.test.ex
368   errors_to=NULL
369   domain_data=NULL localpart_data=NULL
370 routed by r1 router
371   envelope to: userx@myhost.test.ex
372   transport: t1
373 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
374 After routing:
375   Local deliveries:
376     userx@myhost.test.ex
377   Remote deliveries:
378   Failed addresses:
379   Deferred addresses:
380 search_tidyup called
381 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
382 --------> userx@myhost.test.ex <--------
383 locking TESTSUITE/spool/db/retry.lockfile
384 locked TESTSUITE/spool/db/retry.lockfile
385 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
386 returned from EXIM_DBOPEN
387 no retry data available
388 search_tidyup called
389 changed uid/gid: local delivery to userx <userx@myhost.test.ex> transport=t1
390   uid=CALLER_UID gid=CALLER_GID pid=pppp
391   home=NULL current=/
392 set_process_info: pppp delivering 10HmaX-0005vi-00 to userx using t1
393 appendfile transport entered
394 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
395 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
396   key="select id from them where id='userx'" partial=-1 affix=NULL starflags=0
397 LRU list:
398 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
399   type=sqlite key="select id from them where id='userx'"
400 file lookup required for select id from them where id='userx'
401   in TESTSUITE/aux-fixed/sqlitedb
402 lookup yielded: userx
403 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
404   file=TESTSUITE/test-mail/userx format=unix
405   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
406   message_suffix=\n
407   maildir_use_size_file=no
408   locking by lockfile fcntl 
409 lock name: TESTSUITE/test-mail/userx.lock
410 hitch name: TESTSUITE/test-mail/userx.lock.test.ex.dddddddd.pppppppp
411 lock file created
412 mailbox TESTSUITE/test-mail/userx is locked
413 writing to file TESTSUITE/test-mail/userx
414 writing data block fd=dddd size=sss timeout=0
415 writing data block fd=dddd size=sss timeout=0
416 writing data block fd=dddd size=sss timeout=0
417 appendfile yields 0 with errno=dd more_errno=dd
418 search_tidyup called
419 journalling userx@myhost.test.ex
420 t1 transport returned OK for userx@myhost.test.ex
421 post-process userx@myhost.test.ex (0)
422 userx@myhost.test.ex delivered
423 LOG: MAIN
424   => userx <userx@myhost.test.ex> R=r1 T=t1
425 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
426 changed uid/gid: post-delivery tidying
427   uid=EXIM_UID gid=EXIM_GID pid=pppp
428 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
429 Processing retry items
430 Succeeded addresses:
431 userx@myhost.test.ex: no retry items
432 Failed addresses:
433 Deferred addresses:
434 end of retry processing
435 LOG: MAIN
436   Completed
437 end delivery of 10HmaX-0005vi-00
438 search_tidyup called
439 search_tidyup called
440 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
441 search_tidyup called
442 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
443 Exim version x.yz ....
444 configuration file is TESTSUITE/test-config
445 admin user
446 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
447 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
448   key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0
449 LRU list:
450 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
451   type=sqlite key="select name from them where id='userx';"
452 file lookup required for select name from them where id='userx';
453   in TESTSUITE/aux-fixed/sqlitedb
454 lookup yielded: Ayen Other
455 search_tidyup called
456 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>