On a host lookup name->MX->A->ip sequence, require both stages to
[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   message: relay not permitted
159 deny: condition test succeeded in ACL "check_recipient"
160 SMTP>> 550 relay not permitted
161 LOG: MAIN REJECT
162   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
163 SMTP<< rcpt to:<c@d>
164 using ACL "check_recipient"
165 processing "accept"
166 check domains = +local_domains
167 d in "@"? no (end of list)
168 d in "+local_domains"? no (end of list)
169 accept: condition test failed in ACL "check_recipient"
170 processing "accept"
171 check hosts = +relay_hosts
172 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
173   cached open
174 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
175   key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0
176 LRU list:
177 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
178   type=sqlite key="select * from them where id='10.0.0.0'"
179 file lookup required for select * from them where id='10.0.0.0'
180   in TESTSUITE/aux-fixed/sqlitedb
181 lookup forced cache cleanup
182 lookup failed
183 host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"? no (end of list)
184 host in "+relay_hosts"? no (end of list)
185 accept: condition test failed in ACL "check_recipient"
186 processing "deny"
187   message: relay not permitted
188 deny: condition test succeeded in ACL "check_recipient"
189 SMTP>> 550 relay not permitted
190 LOG: MAIN REJECT
191   H=[10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
192 SMTP<< quit
193 SMTP>> 221 myhost.test.ex closing connection
194 LOG: smtp_connection MAIN
195   SMTP connection from [10.0.0.0] closed by QUIT
196 search_tidyup called
197 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
198 Exim version x.yz ....
199 changed uid/gid: forcing real = effective
200   uid=uuuu gid=CALLER_GID pid=pppp
201 configuration file is TESTSUITE/test-config
202 admin user
203 changed uid/gid: privilege not needed
204   uid=EXIM_UID gid=EXIM_GID pid=pppp
205 seeking password data for user "CALLER": cache not available
206 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
207 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
208 sender address = CALLER@myhost.test.ex
209 sender_fullhost = [10.10.10.10]
210 sender_rcvhost = [10.10.10.10]
211 host in hosts_connection_nolog? no (option unset)
212 LOG: smtp_connection MAIN
213   SMTP connection from [10.10.10.10]
214 host in host_lookup? no (option unset)
215 set_process_info: pppp handling incoming connection from [10.10.10.10]
216 host in host_reject_connection? no (option unset)
217 host in sender_unqualified_hosts? no (option unset)
218 host in recipient_unqualified_hosts? no (option unset)
219 host in helo_verify_hosts? no (option unset)
220 host in helo_try_verify_hosts? no (option unset)
221 host in helo_accept_junk_hosts? no (option unset)
222 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
223 smtp_setup_msg entered
224 SMTP<< mail from:<a@b>
225 SMTP>> 250 OK
226 SMTP<< rcpt to:<c@d>
227 using ACL "check_recipient"
228 processing "accept"
229 check domains = +local_domains
230 d in "@"? no (end of list)
231 d in "+local_domains"? no (end of list)
232 accept: condition test failed in ACL "check_recipient"
233 processing "accept"
234 check hosts = +relay_hosts
235 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
236 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
237   key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0
238 LRU list:
239 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
240   type=sqlite key="select * from them where id='10.10.10.10'"
241 file lookup required for select * from them where id='10.10.10.10'
242   in TESTSUITE/aux-fixed/sqlitedb
243 lookup yielded: name=ok id=10.10.10.10 
244 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'")
245 host in "+relay_hosts"? yes (matched "+relay_hosts")
246 accept: condition test succeeded in ACL "check_recipient"
247 SMTP>> 250 Accepted
248 SMTP<< rcpt to:<c@d>
249 using ACL "check_recipient"
250 processing "accept"
251 check domains = +local_domains
252 d in "@"? no (end of list)
253 d in "+local_domains"? no (end of list)
254 accept: condition test failed in ACL "check_recipient"
255 processing "accept"
256 check hosts = +relay_hosts
257 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
258   cached open
259 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
260   key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0
261 LRU list:
262 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
263   type=sqlite key="select * from them where id='10.10.10.10'"
264 cached data used for lookup of select * from them where id='10.10.10.10'
265   in TESTSUITE/aux-fixed/sqlitedb
266 lookup yielded: name=ok id=10.10.10.10 
267 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'")
268 host in "+relay_hosts"? yes (matched "+relay_hosts")
269 accept: condition test succeeded in ACL "check_recipient"
270 SMTP>> 250 Accepted
271 SMTP<< quit
272 SMTP>> 221 myhost.test.ex closing connection
273 LOG: smtp_connection MAIN
274   SMTP connection from [10.10.10.10] closed by QUIT
275 search_tidyup called
276 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
277 Exim version x.yz ....
278 changed uid/gid: forcing real = effective
279   uid=uuuu gid=CALLER_GID pid=pppp
280 configuration file is TESTSUITE/test-config
281 admin user
282 changed uid/gid: privilege not needed
283   uid=EXIM_UID gid=EXIM_GID pid=pppp
284 seeking password data for user "CALLER": cache not available
285 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
286 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
287 sender address = CALLER@myhost.test.ex
288 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
289 Sender: CALLER@myhost.test.ex
290 Recipients:
291   userx
292 search_tidyup called
293 >>Headers received:
294
295 rewrite_one_header: type=F:
296   From: CALLER_NAME <CALLER@myhost.test.ex>
297 search_tidyup called
298 >>Headers after rewriting and local additions:
299 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
300 F From: CALLER_NAME <CALLER@myhost.test.ex>
301   Date: Tue, 2 Mar 1999 09:44:33 +0000
302
303 Data file written for message 10HmaX-0005vi-00
304 >>Generated Received: header line
305 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
306         (envelope-from <CALLER@myhost.test.ex>)
307         id 10HmaX-0005vi-00
308         for userx@myhost.test.ex; Tue, 2 Mar 1999 09:44:33 +0000
309 calling local_scan(); timeout=300
310 local_scan() returned 0 NULL
311 Writing spool header file
312 Size of headers = sss
313 LOG: MAIN
314   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
315 created log directory TESTSUITE/spool/log
316 search_tidyup called
317 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
318 Exim version x.yz ....
319 changed uid/gid: forcing real = effective
320   uid=uuuu gid=EXIM_GID pid=pppp
321 configuration file is TESTSUITE/test-config
322 trusted user
323 admin user
324 seeking password data for user "CALLER": cache not available
325 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
326 set_process_info: pppp delivering specified messages
327 set_process_info: pppp delivering 10HmaX-0005vi-00
328 reading spool file 10HmaX-0005vi-00-H
329 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
330 sender_local=1 ident=CALLER
331 Non-recipients:
332 Empty Tree
333 ---- End of tree ----
334 recipients_count=1
335 body_linecount=1 message_linecount=7
336 Delivery address list:
337   userx@myhost.test.ex 
338 locking TESTSUITE/spool/db/retry.lockfile
339 locked TESTSUITE/spool/db/retry.lockfile
340 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
341 returned from EXIM_DBOPEN
342 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
343 no retry data available
344 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
345 Considering: userx@myhost.test.ex
346 unique = userx@myhost.test.ex
347 no domain retry record
348 no address retry record
349 userx@myhost.test.ex: queued for routing
350 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
351 routing userx@myhost.test.ex
352 --------> r1 router <--------
353 local_part=userx domain=myhost.test.ex
354 processing address_data
355 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
356 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
357   key="select name from them where id='userx'" partial=-1 affix=NULL starflags=0
358 LRU list:
359 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
360   type=sqlite key="select name from them where id='userx'"
361 file lookup required for select name from them where id='userx'
362   in TESTSUITE/aux-fixed/sqlitedb
363 lookup yielded: Ayen Other
364 calling r1 router
365 r1 router called for userx@myhost.test.ex
366   domain = myhost.test.ex
367 set transport t1
368 queued for t1 transport: local_part = userx
369 domain = myhost.test.ex
370   errors_to=NULL
371   domain_data=NULL localpart_data=NULL
372 routed by r1 router
373   envelope to: userx@myhost.test.ex
374   transport: t1
375 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
376 After routing:
377   Local deliveries:
378     userx@myhost.test.ex
379   Remote deliveries:
380   Failed addresses:
381   Deferred addresses:
382 search_tidyup called
383 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
384 --------> userx@myhost.test.ex <--------
385 locking TESTSUITE/spool/db/retry.lockfile
386 locked TESTSUITE/spool/db/retry.lockfile
387 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
388 returned from EXIM_DBOPEN
389 no retry data available
390 search_tidyup called
391 changed uid/gid: local delivery to userx <userx@myhost.test.ex> transport=t1
392   uid=CALLER_UID gid=CALLER_GID pid=pppp
393   home=NULL current=/
394 set_process_info: pppp delivering 10HmaX-0005vi-00 to userx using t1
395 appendfile transport entered
396 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
397 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
398   key="select id from them where id='userx'" partial=-1 affix=NULL starflags=0
399 LRU list:
400 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
401   type=sqlite key="select id from them where id='userx'"
402 file lookup required for select id from them where id='userx'
403   in TESTSUITE/aux-fixed/sqlitedb
404 lookup yielded: userx
405 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
406   file=TESTSUITE/test-mail/userx format=unix
407   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
408   message_suffix=\n
409   maildir_use_size_file=no
410   locking by lockfile fcntl 
411 lock name: TESTSUITE/test-mail/userx.lock
412 hitch name: TESTSUITE/test-mail/userx.lock.test.ex.dddddddd.pppppppp
413 lock file created
414 mailbox TESTSUITE/test-mail/userx is locked
415 writing to file TESTSUITE/test-mail/userx
416 writing data block fd=dddd size=sss timeout=0
417 writing data block fd=dddd size=sss timeout=0
418 writing data block fd=dddd size=sss timeout=0
419 appendfile yields 0 with errno=dd more_errno=dd
420 search_tidyup called
421 journalling userx@myhost.test.ex
422 t1 transport returned OK for userx@myhost.test.ex
423 post-process userx@myhost.test.ex (0)
424 userx@myhost.test.ex delivered
425 LOG: MAIN
426   => userx <userx@myhost.test.ex> R=r1 T=t1
427 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
428 changed uid/gid: post-delivery tidying
429   uid=EXIM_UID gid=EXIM_GID pid=pppp
430 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
431 Processing retry items
432 Succeeded addresses:
433 userx@myhost.test.ex: no retry items
434 Failed addresses:
435 Deferred addresses:
436 end of retry processing
437 LOG: MAIN
438   Completed
439 end delivery of 10HmaX-0005vi-00
440 search_tidyup called
441 search_tidyup called
442 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
443 search_tidyup called
444 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
445 Exim version x.yz ....
446 configuration file is TESTSUITE/test-config
447 admin user
448 search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
449 search_find: file="TESTSUITE/aux-fixed/sqlitedb"
450   key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0
451 LRU list:
452 internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
453   type=sqlite key="select name from them where id='userx';"
454 file lookup required for select name from them where id='userx';
455   in TESTSUITE/aux-fixed/sqlitedb
456 lookup yielded: Ayen Other
457 search_tidyup called
458 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>