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