Fix 2-phase, in-order queue run delivery order
[exim.git] / test / stderr / 2600
1 Exim version x.yz ....
2 Hints DB:
3 configuration file is TESTSUITE/test-config
4 admin user
5 dropping to exim gid; retaining priv uid
6  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
7  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
8    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
9  LRU list:
10  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
11    type=sqlite key="select name from them where id='userx';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
12  file lookup required for select name from them where id='userx';
13    in TESTSUITE/aux-fixed/sqlitedb
14  creating new cache entry
15  lookup yielded: Ayen░Other
16  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
17    cached open
18  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
19    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts=NULL
20  LRU list:
21  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
22    type=sqlite key="select name from them where id='userx';" opts=NULL
23  cached data found but wrong opts;  file lookup required for select name from them where id='userx';
24  c  in TESTSUITE/aux-fixed/sqlitedb
25  replacing old cache entry
26  lookup yielded: Ayen░Other
27  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
28    cached open
29  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
30    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
31  LRU list:
32  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
33    type=sqlite key="select name from them where id='userx';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
34  cached data found but wrong opts;  file lookup required for select name from them where id='userx';
35  c  in TESTSUITE/aux-fixed/sqlitedb
36  replacing old cache entry
37  lookup yielded: Ayen░Other
38  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
39    cached open
40  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
41    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
42  LRU list:
43  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
44    type=sqlite key="select name from them where id='userx';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
45  cached data used for lookup of select name from them where id='userx';
46    in TESTSUITE/aux-fixed/sqlitedb
47  lookup yielded: Ayen░Other
48  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
49    cached open
50  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
51    key="select name from them where id='xxxx';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
52  LRU list:
53  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
54    type=sqlite key="select name from them where id='xxxx';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
55  file lookup required for select name from them where id='xxxx';
56    in TESTSUITE/aux-fixed/sqlitedb
57  lookup forced cache cleanup
58  lookup failed
59  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
60    cached open
61  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
62    key="select name from them where id='nothing';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
63  LRU list:
64  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
65    type=sqlite key="select name from them where id='nothing';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
66  file lookup required for select name from them where id='nothing';
67    in TESTSUITE/aux-fixed/sqlitedb
68  creating new cache entry
69  lookup yielded: 
70  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
71    cached open
72  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
73    key="select id,name from them where id='nothing';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
74  LRU list:
75  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
76    type=sqlite key="select id,name from them where id='nothing';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
77  file lookup required for select id,name from them where id='nothing';
78    in TESTSUITE/aux-fixed/sqlitedb
79  creating new cache entry
80  lookup yielded: id=nothing░name=""░
81  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
82    cached open
83  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
84    key="select * from them where id='quote2';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
85  LRU list:
86  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
87    type=sqlite key="select * from them where id='quote2';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
88  file lookup required for select * from them where id='quote2';
89    in TESTSUITE/aux-fixed/sqlitedb
90  creating new cache entry
91  lookup yielded: name="\"stquot"░id=quote2░
92  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
93    cached open
94  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
95    key="select * from them where id='newline';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
96  LRU list:
97  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
98    type=sqlite key="select * from them where id='newline';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
99  file lookup required for select * from them where id='newline';
100    in TESTSUITE/aux-fixed/sqlitedb
101  creating new cache entry
102  lookup yielded: name="before↩
103  after"░id=newline░
104  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
105    cached open
106  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
107    key="select * from them where id='tab';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
108  LRU list:
109  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
110    type=sqlite key="select * from them where id='tab';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
111  file lookup required for select * from them where id='tab';
112    in TESTSUITE/aux-fixed/sqlitedb
113  creating new cache entry
114  lookup yielded: name="x␉x"░id=tab░
115  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
116    cached open
117  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
118    key="select * from them where id='its';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
119  LRU list:
120  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
121    type=sqlite key="select * from them where id='its';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
122  file lookup required for select * from them where id='its';
123    in TESTSUITE/aux-fixed/sqlitedb
124  creating new cache entry
125  lookup yielded: name=it's░id=its░
126  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
127    cached open
128  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
129    key="select * from them where name='it''s';" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
130  LRU list:
131  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
132    type=sqlite key="select * from them where name='it''s';" opts="file=TESTSUITE/aux-fixed/sqlitedb"
133  file lookup required for select * from them where name='it''s';
134    in TESTSUITE/aux-fixed/sqlitedb
135  creating new cache entry
136  lookup yielded: name=it's░id=its░
137 search_tidyup called
138 >>>>>>>>>>>>>>>> Exim pid=p1234 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
139 Exim version x.yz ....
140 Hints DB:
141 changed uid/gid: forcing real = effective
142   uid=uuuu gid=CALLER_GID pid=p1235
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=p1235
147 seeking password data for user "CALLER": cache not available
148 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
149 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
150 sender address = CALLER@myhost.test.ex
151 sender_fullhost = [10.0.0.0]
152 sender_rcvhost = [10.0.0.0]
153 host in hosts_connection_nolog? no (option unset)
154 LOG: smtp_connection MAIN
155   SMTP connection from [10.0.0.0]
156 host in host_lookup? no (option unset)
157 set_process_info: pppp handling incoming connection from [10.0.0.0]
158 host in host_reject_connection? no (option unset)
159 host in sender_unqualified_hosts? no (option unset)
160 host in recipient_unqualified_hosts? no (option unset)
161 host in helo_verify_hosts? no (option unset)
162 host in helo_try_verify_hosts? no (option unset)
163 host in helo_accept_junk_hosts? no (option unset)
164 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
165 smtp_setup_msg entered
166 SMTP<< helo test
167 test in helo_lookup_domains?
168  list element: @
169  list element: @[]
170 test in helo_lookup_domains? no (end of list)
171 sender_fullhost = (test) [10.0.0.0]
172 sender_rcvhost = [10.0.0.0] (helo=test)
173 set_process_info: pppp handling incoming connection from (test) [10.0.0.0]
174 SMTP>> 250 myhost.test.ex Hello test [10.0.0.0]
175 SMTP<< mail from:<a@b>
176 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
177 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
178 SMTP>> 250 OK
179 SMTP<< rcpt to:<c@d>
180 using ACL "check_recipient"
181 processing "accept" (TESTSUITE/test-config 32)
182 check domains = +local_domains
183 d in "+local_domains"?
184  list element: +local_domains
185   start sublist local_domains
186    d in "@"?
187    ╎list element: @
188    d in "@"? no (end of list)
189   end sublist local_domains
190 d in "+local_domains"? no (end of list)
191 accept: condition test failed in ACL "check_recipient"
192 processing "accept" (TESTSUITE/test-config 33)
193 check hosts = +relay_hosts
194 host in "+relay_hosts"?
195  list element: +relay_hosts
196   start sublist relay_hosts
197   host in "sqlite,file=TESTSUITE/aux-fixed/sqlitedb; select * from them where id='10.0.0.0'"?
198    ╎list element: sqlite,file=TESTSUITE/aux-fixed/sqlitedb;░select░*░from░them░where░id='10.0.0.0'
199    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
200    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
201    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
202    ╎LRU list:
203    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
204    ╎  type=sqlite key="select * from them where id='10.0.0.0'" opts="file=TESTSUITE/aux-fixed/sqlitedb"
205    ╎file lookup required for select * from them where id='10.0.0.0'
206    ╎  in TESTSUITE/aux-fixed/sqlitedb
207    ╎lookup forced cache cleanup
208    ╎lookup failed
209   host in "sqlite,file=TESTSUITE/aux-fixed/sqlitedb; select * from them where id='10.0.0.0'"? no (end of list)
210   end sublist relay_hosts
211 host in "+relay_hosts"? no (end of list)
212 accept: condition test failed in ACL "check_recipient"
213 processing "deny" (TESTSUITE/test-config 34)
214   message: relay not permitted
215 deny: condition test succeeded in ACL "check_recipient"
216 end of ACL "check_recipient": DENY
217 SMTP>> 550 relay not permitted
218 LOG: MAIN REJECT
219   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
220 SMTP<< rcpt to:<c@d>
221 using ACL "check_recipient"
222 processing "accept" (TESTSUITE/test-config 32)
223 check domains = +local_domains
224 d in "+local_domains"?
225  list element: +local_domains
226   start sublist local_domains
227    d in "@"?
228    ╎list element: @
229    d in "@"? no (end of list)
230   end sublist local_domains
231 d in "+local_domains"? no (end of list)
232 accept: condition test failed in ACL "check_recipient"
233 processing "accept" (TESTSUITE/test-config 33)
234 check hosts = +relay_hosts
235 host in "+relay_hosts"?
236  list element: +relay_hosts
237   start sublist relay_hosts
238   host in "sqlite,file=TESTSUITE/aux-fixed/sqlitedb; select * from them where id='10.0.0.0'"?
239    ╎list element: sqlite,file=TESTSUITE/aux-fixed/sqlitedb;░select░*░from░them░where░id='10.0.0.0'
240    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
241    ╎  cached open
242    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
243    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts="file=TESTSUITE/aux-fixed/sqlitedb"
244    ╎LRU list:
245    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
246    ╎  type=sqlite key="select * from them where id='10.0.0.0'" opts="file=TESTSUITE/aux-fixed/sqlitedb"
247    ╎file lookup required for select * from them where id='10.0.0.0'
248    ╎  in TESTSUITE/aux-fixed/sqlitedb
249    ╎lookup forced cache cleanup
250    ╎lookup failed
251   host in "sqlite,file=TESTSUITE/aux-fixed/sqlitedb; select * from them where id='10.0.0.0'"? no (end of list)
252   end sublist relay_hosts
253 host in "+relay_hosts"? no (end of list)
254 accept: condition test failed in ACL "check_recipient"
255 processing "deny" (TESTSUITE/test-config 34)
256   message: relay not permitted
257 deny: condition test succeeded in ACL "check_recipient"
258 end of ACL "check_recipient": DENY
259 SMTP>> 550 relay not permitted
260 LOG: MAIN REJECT
261   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
262 SMTP<< quit
263 SMTP>> 221 myhost.test.ex closing connection
264 LOG: smtp_connection MAIN
265   SMTP connection from (test) [10.0.0.0] D=qqs closed by QUIT
266 search_tidyup called
267 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
268 Exim version x.yz ....
269 Hints DB:
270 changed uid/gid: forcing real = effective
271   uid=uuuu gid=CALLER_GID pid=p1236
272 configuration file is TESTSUITE/test-config
273 admin user
274 changed uid/gid: privilege not needed
275   uid=EXIM_UID gid=EXIM_GID pid=p1236
276 seeking password data for user "CALLER": cache not available
277 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
278 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
279 sender address = CALLER@myhost.test.ex
280 sender_fullhost = [10.0.0.0]
281 sender_rcvhost = [10.0.0.0]
282 host in hosts_connection_nolog? no (option unset)
283 LOG: smtp_connection MAIN
284   SMTP connection from [10.0.0.0]
285 host in host_lookup? no (option unset)
286 set_process_info: pppp handling incoming connection from [10.0.0.0]
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 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
294 smtp_setup_msg entered
295 SMTP<< helo test
296 test in helo_lookup_domains?
297  list element: @
298  list element: @[]
299 test in helo_lookup_domains? no (end of list)
300 sender_fullhost = (test) [10.0.0.0]
301 sender_rcvhost = [10.0.0.0] (helo=test)
302 set_process_info: pppp handling incoming connection from (test) [10.0.0.0]
303 SMTP>> 250 myhost.test.ex Hello test [10.0.0.0]
304 SMTP<< mail from:<a@b>
305 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
306 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
307 SMTP>> 250 OK
308 SMTP<< rcpt to:<c@d>
309 using ACL "check_recipient"
310 processing "accept" (TESTSUITE/test-config 32)
311 check domains = +local_domains
312 d in "+local_domains"?
313  list element: +local_domains
314   start sublist local_domains
315    d in "@"?
316    ╎list element: @
317    d in "@"? no (end of list)
318   end sublist local_domains
319 d in "+local_domains"? no (end of list)
320 accept: condition test failed in ACL "check_recipient"
321 processing "accept" (TESTSUITE/test-config 33)
322 check hosts = +relay_hosts
323 host in "+relay_hosts"?
324  list element: +relay_hosts
325   start sublist relay_hosts
326   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"?
327    ╎list element: sqlite;TESTSUITE/aux-fixed/sqlitedb░select░*░from░them░where░id='10.0.0.0'
328    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
329    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
330    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
331    ╎LRU list:
332    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
333    ╎  type=sqlite key="select * from them where id='10.0.0.0'" opts=NULL
334    ╎file lookup required for select * from them where id='10.0.0.0'
335    ╎  in TESTSUITE/aux-fixed/sqlitedb
336    ╎lookup forced cache cleanup
337    ╎lookup failed
338   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"? no (end of list)
339   end sublist relay_hosts
340 host in "+relay_hosts"? no (end of list)
341 accept: condition test failed in ACL "check_recipient"
342 processing "deny" (TESTSUITE/test-config 34)
343   message: relay not permitted
344 deny: condition test succeeded in ACL "check_recipient"
345 end of ACL "check_recipient": DENY
346 SMTP>> 550 relay not permitted
347 LOG: MAIN REJECT
348   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
349 SMTP<< rcpt to:<c@d>
350 using ACL "check_recipient"
351 processing "accept" (TESTSUITE/test-config 32)
352 check domains = +local_domains
353 d in "+local_domains"?
354  list element: +local_domains
355   start sublist local_domains
356    d in "@"?
357    ╎list element: @
358    d in "@"? no (end of list)
359   end sublist local_domains
360 d in "+local_domains"? no (end of list)
361 accept: condition test failed in ACL "check_recipient"
362 processing "accept" (TESTSUITE/test-config 33)
363 check hosts = +relay_hosts
364 host in "+relay_hosts"?
365  list element: +relay_hosts
366   start sublist relay_hosts
367   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"?
368    ╎list element: sqlite;TESTSUITE/aux-fixed/sqlitedb░select░*░from░them░where░id='10.0.0.0'
369    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
370    ╎  cached open
371    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
372    ╎  key="select * from them where id='10.0.0.0'" partial=-1 affix=NULL starflags=0 opts=NULL
373    ╎LRU list:
374    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
375    ╎  type=sqlite key="select * from them where id='10.0.0.0'" opts=NULL
376    ╎file lookup required for select * from them where id='10.0.0.0'
377    ╎  in TESTSUITE/aux-fixed/sqlitedb
378    ╎lookup forced cache cleanup
379    ╎lookup failed
380   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.0.0.0'"? no (end of list)
381   end sublist relay_hosts
382 host in "+relay_hosts"? no (end of list)
383 accept: condition test failed in ACL "check_recipient"
384 processing "deny" (TESTSUITE/test-config 34)
385   message: relay not permitted
386 deny: condition test succeeded in ACL "check_recipient"
387 end of ACL "check_recipient": DENY
388 SMTP>> 550 relay not permitted
389 LOG: MAIN REJECT
390   H=(test) [10.0.0.0] F=<a@b> rejected RCPT <c@d>: relay not permitted
391 SMTP<< quit
392 SMTP>> 221 myhost.test.ex closing connection
393 LOG: smtp_connection MAIN
394   SMTP connection from (test) [10.0.0.0] D=qqs closed by QUIT
395 search_tidyup called
396 >>>>>>>>>>>>>>>> Exim pid=p1236 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
397 Exim version x.yz ....
398 Hints DB:
399 changed uid/gid: forcing real = effective
400   uid=uuuu gid=CALLER_GID pid=p1237
401 configuration file is TESTSUITE/test-config
402 admin user
403 changed uid/gid: privilege not needed
404   uid=EXIM_UID gid=EXIM_GID pid=p1237
405 seeking password data for user "CALLER": cache not available
406 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
407 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
408 sender address = CALLER@myhost.test.ex
409 sender_fullhost = [10.10.10.10]
410 sender_rcvhost = [10.10.10.10]
411 host in hosts_connection_nolog? no (option unset)
412 LOG: smtp_connection MAIN
413   SMTP connection from [10.10.10.10]
414 host in host_lookup? no (option unset)
415 set_process_info: pppp handling incoming connection from [10.10.10.10]
416 host in host_reject_connection? no (option unset)
417 host in sender_unqualified_hosts? no (option unset)
418 host in recipient_unqualified_hosts? no (option unset)
419 host in helo_verify_hosts? no (option unset)
420 host in helo_try_verify_hosts? no (option unset)
421 host in helo_accept_junk_hosts? no (option unset)
422 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
423 smtp_setup_msg entered
424 SMTP<< helo test
425 test in helo_lookup_domains?
426  list element: @
427  list element: @[]
428 test in helo_lookup_domains? no (end of list)
429 sender_fullhost = (test) [10.10.10.10]
430 sender_rcvhost = [10.10.10.10] (helo=test)
431 set_process_info: pppp handling incoming connection from (test) [10.10.10.10]
432 SMTP>> 250 myhost.test.ex Hello test [10.10.10.10]
433 SMTP<< mail from:<a@b>
434 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
435 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
436 SMTP>> 250 OK
437 SMTP<< rcpt to:<c@d>
438 using ACL "check_recipient"
439 processing "accept" (TESTSUITE/test-config 32)
440 check domains = +local_domains
441 d in "+local_domains"?
442  list element: +local_domains
443   start sublist local_domains
444    d in "@"?
445    ╎list element: @
446    d in "@"? no (end of list)
447   end sublist local_domains
448 d in "+local_domains"? no (end of list)
449 accept: condition test failed in ACL "check_recipient"
450 processing "accept" (TESTSUITE/test-config 33)
451 check hosts = +relay_hosts
452 host in "+relay_hosts"?
453  list element: +relay_hosts
454   start sublist relay_hosts
455   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'"?
456    ╎list element: sqlite;TESTSUITE/aux-fixed/sqlitedb░select░*░from░them░where░id='10.10.10.10'
457    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
458    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
459    ╎  key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0 opts=NULL
460    ╎LRU list:
461    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
462    ╎  type=sqlite key="select * from them where id='10.10.10.10'" opts=NULL
463    ╎file lookup required for select * from them where id='10.10.10.10'
464    ╎  in TESTSUITE/aux-fixed/sqlitedb
465    ╎creating new cache entry
466    ╎lookup yielded: name=ok░id=10.10.10.10░
467    ╎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'")
468   end sublist relay_hosts
469   host in "+relay_hosts"? yes (matched "+relay_hosts")
470 accept: condition test succeeded in ACL "check_recipient"
471 end of ACL "check_recipient": ACCEPT
472 SMTP>> 250 Accepted
473 SMTP<< rcpt to:<c@d>
474 using ACL "check_recipient"
475 processing "accept" (TESTSUITE/test-config 32)
476 check domains = +local_domains
477 d in "+local_domains"?
478  list element: +local_domains
479   start sublist local_domains
480    d in "@"?
481    ╎list element: @
482    d in "@"? no (end of list)
483   end sublist local_domains
484 d in "+local_domains"? no (end of list)
485 accept: condition test failed in ACL "check_recipient"
486 processing "accept" (TESTSUITE/test-config 33)
487 check hosts = +relay_hosts
488 host in "+relay_hosts"?
489  list element: +relay_hosts
490   start sublist relay_hosts
491   host in "sqlite;TESTSUITE/aux-fixed/sqlitedb select * from them where id='10.10.10.10'"?
492    ╎list element: sqlite;TESTSUITE/aux-fixed/sqlitedb░select░*░from░them░where░id='10.10.10.10'
493    ╎search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
494    ╎  cached open
495    ╎search_find: file="TESTSUITE/aux-fixed/sqlitedb"
496    ╎  key="select * from them where id='10.10.10.10'" partial=-1 affix=NULL starflags=0 opts=NULL
497    ╎LRU list:
498    ╎internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
499    ╎  type=sqlite key="select * from them where id='10.10.10.10'" opts=NULL
500    ╎cached data used for lookup of select * from them where id='10.10.10.10'
501    ╎  in TESTSUITE/aux-fixed/sqlitedb
502    ╎lookup yielded: name=ok░id=10.10.10.10░
503    ╎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'")
504   end sublist relay_hosts
505   host in "+relay_hosts"? yes (matched "+relay_hosts")
506 accept: condition test succeeded in ACL "check_recipient"
507 end of ACL "check_recipient": ACCEPT
508 SMTP>> 250 Accepted
509 SMTP<< quit
510 SMTP>> 221 myhost.test.ex closing connection
511 LOG: smtp_connection MAIN
512   SMTP connection from (test) [10.10.10.10] D=qqs closed by QUIT
513 search_tidyup called
514 >>>>>>>>>>>>>>>> Exim pid=p1237 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
515 Exim version x.yz ....
516 Hints DB:
517 changed uid/gid: forcing real = effective
518   uid=uuuu gid=CALLER_GID pid=p1238
519 configuration file is TESTSUITE/test-config
520 admin user
521 changed uid/gid: privilege not needed
522   uid=EXIM_UID gid=EXIM_GID pid=p1238
523 seeking password data for user "CALLER": cache not available
524 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
525 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
526 sender address = CALLER@myhost.test.ex
527 set_process_info: pppp accepting a local non-SMTP message from <CALLER@myhost.test.ex>
528 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
529 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
530 Sender: CALLER@myhost.test.ex
531 Recipients:
532   userx
533 search_tidyup called
534 >>Headers received:
535
536 qualify & rewrite recipients list
537 rewrite rules on sender address
538 qualify and rewrite headers
539  rewrite_one_header: type=F:
540    From: CALLER_NAME <CALLER@myhost.test.ex>
541 search_tidyup called
542 >>Headers after rewriting and local additions:
543  I Message-Id: <E10HmaX-000000005vi-0000@myhost.test.ex>
544  F From: CALLER_NAME <CALLER@myhost.test.ex>
545    Date: Tue, 2 Mar 1999 09:44:33 +0000
546
547 Data file name: TESTSUITE/spool//input//10HmaX-000000005vi-0000-D
548 Data file written for message 10HmaX-000000005vi-0000
549 >>Generated Received: header line
550 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
551         (envelope-from <CALLER@myhost.test.ex>)
552         id 10HmaX-000000005vi-0000
553         for userx@myhost.test.ex;
554         Tue, 2 Mar 1999 09:44:33 +0000
555 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-000000005vi-0000
556 DSN: **** SPOOL_OUT - address: <userx@myhost.test.ex> errorsto: <NULL> orcpt: <NULL> dsn_flags: 0x0
557 Renaming spool header file: TESTSUITE/spool//input//10HmaX-000000005vi-0000-H
558 Size of headers = sss
559 LOG: MAIN
560   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
561 created log directory TESTSUITE/spool/log
562 search_tidyup called
563 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -DOPT=y -C TESTSUITE/test-config -d=0xf7715cfd -MCd local-accept-delivery -odi -Mc 10HmaX-000000005vi-0000
564 Exim version x.yz ....
565 Hints DB:
566 changed uid/gid: forcing real = effective
567   uid=uuuu gid=EXIM_GID pid=p1239
568 configuration file is TESTSUITE/test-config
569 trusted user
570 admin user
571 dropping to exim gid; retaining priv uid
572 seeking password data for user "CALLER": cache not available
573 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
574 set_process_info: pppp delivering specified messages
575 set_process_info: pppp delivering 10HmaX-000000005vi-0000
576 Trying spool file TESTSUITE/spool//input//10HmaX-000000005vi-0000-D
577 reading spool file 10HmaX-000000005vi-0000-H
578 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@myhost.test.ex
579 sender_local=1 ident=CALLER
580 Non-recipients:
581  Empty Tree
582 ---- End of tree ----
583 recipients_count=1
584 **** SPOOL_IN - No additional fields
585 body_linecount=1 message_linecount=8
586 DSN: set orcpt:   flags: 0x0
587 Delivery address list:
588   userx@myhost.test.ex 
589  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
590  returned from EXIM_DBOPEN: (nil)
591  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
592 no retry data available
593 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
594 Considering: userx@myhost.test.ex
595 unique = userx@myhost.test.ex
596 no   domain  retry record
597 no   address retry record
598 userx@myhost.test.ex: queued for routing
599 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
600 routing userx@myhost.test.ex
601 --------> r1 router <--------
602 local_part=userx domain=myhost.test.ex
603 processing address_data
604  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
605  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
606    key="select name from them where id='userx'" partial=-1 affix=NULL starflags=0 opts=NULL
607  LRU list:
608  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
609    type=sqlite key="select name from them where id='userx'" opts=NULL
610  file lookup required for select name from them where id='userx'
611    in TESTSUITE/aux-fixed/sqlitedb
612  creating new cache entry
613  lookup yielded: Ayen░Other
614 calling r1 router
615 r1 router called for userx@myhost.test.ex
616   domain = myhost.test.ex
617 set transport t1
618 queued for t1 transport: local_part = userx
619 domain = myhost.test.ex
620   errors_to=NULL
621   domain_data=NULL local_part_data=NULL
622 routed by r1 router
623   envelope to: userx@myhost.test.ex
624   transport: t1
625 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
626 After routing:
627   Local deliveries:
628     userx@myhost.test.ex
629   Remote deliveries:
630   Failed addresses:
631   Deferred addresses:
632 search_tidyup called
633 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
634 --------> userx@myhost.test.ex <--------
635  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
636  returned from EXIM_DBOPEN: (nil)
637  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
638 no retry data available
639 search_tidyup called
640 changed uid/gid: local delivery to userx <userx@myhost.test.ex> transport=t1
641   uid=CALLER_UID gid=CALLER_GID pid=p1240
642   home=NULL current=/
643 set_process_info: pppp delivering 10HmaX-000000005vi-0000 to userx using t1
644 appendfile transport entered
645  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
646  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
647    key="select id from them where id='userx'" partial=-1 affix=NULL starflags=0 opts=NULL
648  LRU list:
649  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
650    type=sqlite key="select id from them where id='userx'" opts=NULL
651  file lookup required for select id from them where id='userx'
652    in TESTSUITE/aux-fixed/sqlitedb
653  creating new cache entry
654  lookup yielded: userx
655 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
656   file=TESTSUITE/test-mail/userx format=unix
657   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
658   message_suffix=\n
659   maildir_use_size_file=no
660   locking by lockfile fcntl 
661 lock name: TESTSUITE/test-mail/userx.lock
662 hitch name: TESTSUITE/test-mail/userx.lock.test.ex.dddddddd.pppppppp
663 lock file created
664 mailbox TESTSUITE/test-mail/userx is locked
665 writing to file TESTSUITE/test-mail/userx
666 writing data block fd=dddd size=sss timeout=0
667 cannot use sendfile for body: spoolfile not wireformat
668 writing data block fd=dddd size=sss timeout=0
669 writing data block fd=dddd size=sss timeout=0
670 appendfile yields 0 with errno=dd more_errno=dd
671 search_tidyup called
672 >>>>>>>>>>>>>>>> Exim pid=p1240 (delivery-local) terminating with rc=0 >>>>>>>>>>>>>>>>
673 journalling userx@myhost.test.ex
674 t1 transport returned OK for userx@myhost.test.ex
675 post-process userx@myhost.test.ex (0)
676 userx@myhost.test.ex delivered
677 LOG: MAIN
678   => userx <userx@myhost.test.ex> R=r1 T=t1
679 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
680 changed uid/gid: post-delivery tidying
681   uid=EXIM_UID gid=EXIM_GID pid=p1239
682 set_process_info: pppp tidying up after delivering 10HmaX-000000005vi-0000
683 Processing retry items
684 Succeeded addresses:
685  userx@myhost.test.ex: no retry items
686 Failed addresses:
687 Deferred addresses:
688 end of retry processing
689 DSN: processing router : r1
690 DSN: processing successful delivery address: userx@myhost.test.ex
691 DSN: Sender_address: CALLER@myhost.test.ex
692 DSN: orcpt: NULL  flags: 0x0
693 DSN: envid: NULL  ret: 0
694 DSN: Final recipient: userx@myhost.test.ex
695 DSN: Remote SMTP server supports DSN: 0
696 DSN: not sending DSN success message
697 LOG: MAIN
698   Completed
699 end delivery of 10HmaX-000000005vi-0000
700 search_tidyup called
701 search_tidyup called
702 >>>>>>>>>>>>>>>> Exim pid=p1239 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
703 search_tidyup called
704 >>>>>>>>>>>>>>>> Exim pid=p1238 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
705 Exim version x.yz ....
706 Hints DB:
707 configuration file is TESTSUITE/test-config
708 admin user
709 dropping to exim gid; retaining priv uid
710  search_open: sqlite "TESTSUITE/aux-fixed/sqlitedb"
711  search_find: file="TESTSUITE/aux-fixed/sqlitedb"
712    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts=NULL
713  LRU list:
714  internal_search_find: file="TESTSUITE/aux-fixed/sqlitedb"
715    type=sqlite key="select name from them where id='userx';" opts=NULL
716  file lookup required for select name from them where id='userx';
717    in TESTSUITE/aux-fixed/sqlitedb
718  creating new cache entry
719  lookup yielded: Ayen░Other
720 search_tidyup called
721 >>>>>>>>>>>>>>>> Exim pid=p1241 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
722 Exim version x.yz ....
723 Hints DB:
724 configuration file is TESTSUITE/test-config
725 admin user
726 dropping to exim gid; retaining priv uid
727  search_open: sqlite "NULL"
728  Using sqlite_dbfile: TESTSUITE/aux-fixed/sqlitedb
729  search_find: file="NULL"
730    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts=NULL
731  LRU list:
732  internal_search_find: file="NULL"
733    type=sqlite key="select name from them where id='userx';" opts=NULL
734  database lookup required for select name from them where id='userx';
735  creating new cache entry
736  lookup yielded: Ayen░Other
737 search_tidyup called
738 >>>>>>>>>>>>>>>> Exim pid=p1242 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
739 Exim version x.yz ....
740 Hints DB:
741 configuration file is TESTSUITE/test-config
742 admin user
743 dropping to exim gid; retaining priv uid
744  search_open: sqlite "NULL"
745  Using sqlite_dbfile: nonabsolute_filename
746 search_tidyup called
747 >>>>>>>>>>>>>>>> Exim pid=p1243 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
748 Exim version x.yz ....
749 Hints DB:
750 configuration file is TESTSUITE/test-config
751 admin user
752 dropping to exim gid; retaining priv uid
753  search_open: sqlite "NULL"
754  Using sqlite_dbfile: TESTSUITE/missingfile
755  search_find: file="NULL"
756    key="select name from them where id='userx';" partial=-1 affix=NULL starflags=0 opts=NULL
757  LRU list:
758  internal_search_find: file="NULL"
759    type=sqlite key="select name from them where id='userx';" opts=NULL
760  database lookup required for select name from them where id='userx';
761  sqlite3_exec failed: no such table: them
762  creating new cache entry
763  lookup failed
764 search_tidyup called
765 >>>>>>>>>>>>>>>> Exim pid=p1244 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>