Merge branch 'master' into transp_logging_1031
[users/jgh/exim.git] / test / stderr / 0402
1 Exim version x.yz ....
2 changed uid/gid: forcing real = effective
3   uid=uuuu gid=CALLER_GID pid=pppp
4 configuration file is TESTSUITE/test-config
5 admin user
6 changed uid/gid: privilege not needed
7   uid=EXIM_UID gid=EXIM_GID pid=pppp
8 seeking password data for user "CALLER": cache not available
9 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
10 seeking password data for user "CALLER": using cached result
11 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
12 seeking password data for user "CALLER": using cached result
13 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
14 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
15 sender address = CALLER@test.ex
16 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
17 Sender: CALLER@test.ex
18 Recipients:
19   CALLER@test.ex
20   usery@test.ex
21   userz
22   rd+CALLER
23   rd+usery
24 search_tidyup called
25 >>Headers received:
26
27 rewrite_one_header: type=F:
28   From: CALLER_NAME <CALLER@test.ex>
29 search_tidyup called
30 >>Headers after rewriting and local additions:
31 I Message-Id: <E10HmaX-0005vi-00@mail.test.ex>
32 F From: CALLER_NAME <CALLER@test.ex>
33   Date: Tue, 2 Mar 1999 09:44:33 +0000
34
35 Data file written for message 10HmaX-0005vi-00
36 expanding: ${tod_full}
37    result: Tue, 2 Mar 1999 09:44:33 +0000
38 condition: def:sender_rcvhost
39    result: false
40 expanding: from $sender_rcvhost
41         
42    result: from 
43         
44 skipping: result is not used
45 condition: def:sender_ident
46    result: true
47 expanding: $sender_ident
48    result: CALLER
49 expanding: from ${quote_local_part:$sender_ident} 
50    result: from CALLER 
51 condition: def:sender_helo_name
52    result: false
53 expanding: (helo=$sender_helo_name)
54         
55    result: (helo=)
56         
57 skipping: result is not used
58 expanding: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
59         }}
60    result: from CALLER 
61 condition: def:received_protocol
62    result: true
63 expanding: with $received_protocol
64    result: with local
65 condition: def:sender_address
66    result: true
67 expanding: (envelope-from <$sender_address>)
68         
69    result: (envelope-from <CALLER@test.ex>)
70         
71 condition: def:received_for
72    result: false
73 expanding: 
74         for $received_for
75    result: 
76         for 
77 skipping: result is not used
78 >>Generated Received: header line
79 P Received: from CALLER by mail.test.ex with local (Exim x.yz)
80         (envelope-from <CALLER@test.ex>)
81         id 10HmaX-0005vi-00; Tue, 2 Mar 1999 09:44:33 +0000
82 calling local_scan(); timeout=300
83 local_scan() returned 0 NULL
84 expanding: ${tod_full}
85    result: Tue, 2 Mar 1999 09:44:33 +0000
86 Writing spool header file
87 Size of headers = sss
88 LOG: MAIN
89   <= CALLER@test.ex U=CALLER P=local S=sss
90 created log directory TESTSUITE/spool/log
91 search_tidyup called
92 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95dfd -odi -Mc 10HmaX-0005vi-00
93 Exim version x.yz ....
94 changed uid/gid: forcing real = effective
95   uid=uuuu gid=EXIM_GID pid=pppp
96 configuration file is TESTSUITE/test-config
97 trusted user
98 admin user
99 seeking password data for user "CALLER": cache not available
100 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
101 seeking password data for user "CALLER": using cached result
102 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
103 seeking password data for user "CALLER": using cached result
104 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
105 set_process_info: pppp delivering specified messages
106 set_process_info: pppp delivering 10HmaX-0005vi-00
107 reading spool file 10HmaX-0005vi-00-H
108 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@test.ex
109 sender_local=1 ident=CALLER
110 Non-recipients:
111 Empty Tree
112 ---- End of tree ----
113 recipients_count=5
114 body_linecount=0 message_linecount=6
115 Delivery address list:
116   CALLER@test.ex 
117   usery@test.ex 
118   userz@test.ex 
119   rd+CALLER@test.ex 
120   rd+usery@test.ex 
121 locking TESTSUITE/spool/db/retry.lockfile
122 locked TESTSUITE/spool/db/retry.lockfile
123 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
124 returned from EXIM_DBOPEN
125 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
126 no retry data available
127 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
128 Considering: CALLER@test.ex
129 unique = CALLER@test.ex
130 no domain retry record
131 no address retry record
132 CALLER@test.ex: queued for routing
133 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
134 Considering: usery@test.ex
135 unique = usery@test.ex
136 no domain retry record
137 no address retry record
138 usery@test.ex: queued for routing
139 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
140 Considering: userz@test.ex
141 unique = userz@test.ex
142 no domain retry record
143 no address retry record
144 userz@test.ex: queued for routing
145 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
146 Considering: rd+CALLER@test.ex
147 unique = rd+CALLER@test.ex
148 no domain retry record
149 no address retry record
150 rd+CALLER@test.ex: queued for routing
151 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
152 Considering: rd+usery@test.ex
153 unique = rd+usery@test.ex
154 no domain retry record
155 no address retry record
156 rd+usery@test.ex: queued for routing
157 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
158 routing rd+usery@test.ex
159 --------> r1 router <--------
160 local_part=rd+usery domain=test.ex
161 checking local_parts
162 rd+usery in "CALLER"? no (end of list)
163 r1 router skipped: local_parts mismatch
164 --------> r2 router <--------
165 local_part=rd+usery domain=test.ex
166 checking local_parts
167 rd+usery in "usery"? no (end of list)
168 r2 router skipped: local_parts mismatch
169 --------> r3 router <--------
170 local_part=rd+usery domain=test.ex
171 checking local_parts
172 rd+usery in "userz"? no (end of list)
173 r3 router skipped: local_parts mismatch
174 --------> r4 router <--------
175 local_part=rd+usery domain=test.ex
176 stripped prefix rd+
177 checking local_parts
178 usery in "CALLER"? no (end of list)
179 r4 router skipped: local_parts mismatch
180 --------> r5 router <--------
181 local_part=rd+usery domain=test.ex
182 stripped prefix rd+
183 checking local_parts
184 usery in "usery"? yes (matched "usery")
185 expanding: /non-exist/$domain
186    result: /non-exist/test.ex
187 calling r5 router
188 rda_interpret (string): TESTSUITE/test-mail/junk
189 expanded: TESTSUITE/test-mail/junk
190 file is not a filter file
191 parse_forward_list: TESTSUITE/test-mail/junk
192 extract item: TESTSUITE/test-mail/junk
193 set transport ft1
194 r5 router generated TESTSUITE/test-mail/junk
195   pipe, file, or autoreply
196   errors_to=NULL transport=ft1
197   uid=unset gid=unset home=/non-exist/$local_part
198 routed by r5 router
199   envelope to: rd+usery@test.ex
200   transport: <none>
201 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
202 routing rd+CALLER@test.ex
203 --------> r1 router <--------
204 local_part=rd+CALLER domain=test.ex
205 checking local_parts
206 rd+CALLER in "CALLER"? no (end of list)
207 r1 router skipped: local_parts mismatch
208 --------> r2 router <--------
209 local_part=rd+CALLER domain=test.ex
210 checking local_parts
211 rd+CALLER in "usery"? no (end of list)
212 r2 router skipped: local_parts mismatch
213 --------> r3 router <--------
214 local_part=rd+CALLER domain=test.ex
215 checking local_parts
216 rd+CALLER in "userz"? no (end of list)
217 r3 router skipped: local_parts mismatch
218 --------> r4 router <--------
219 local_part=rd+CALLER domain=test.ex
220 stripped prefix rd+
221 checking local_parts
222 CALLER in "CALLER"? yes (matched "CALLER")
223 expanding: /non-exist/$local_part
224    result: /non-exist/CALLER
225 calling r4 router
226 rda_interpret (string): TESTSUITE/test-mail/junk
227 expanded: TESTSUITE/test-mail/junk
228 file is not a filter file
229 parse_forward_list: TESTSUITE/test-mail/junk
230 extract item: TESTSUITE/test-mail/junk
231 set transport ft1
232 r4 router generated TESTSUITE/test-mail/junk
233   pipe, file, or autoreply
234   errors_to=NULL transport=ft1
235   uid=unset gid=unset home=/non-exist/CALLER
236 routed by r4 router
237   envelope to: rd+CALLER@test.ex
238   transport: <none>
239 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
240 routing userz@test.ex
241 --------> r1 router <--------
242 local_part=userz domain=test.ex
243 checking local_parts
244 userz in "CALLER"? no (end of list)
245 r1 router skipped: local_parts mismatch
246 --------> r2 router <--------
247 local_part=userz domain=test.ex
248 checking local_parts
249 userz in "usery"? no (end of list)
250 r2 router skipped: local_parts mismatch
251 --------> r3 router <--------
252 local_part=userz domain=test.ex
253 checking local_parts
254 userz in "userz"? yes (matched "userz")
255 expanding: /non-exist/$domain
256    result: /non-exist/test.ex
257 calling r3 router
258 r3 router called for userz@test.ex
259   domain = test.ex
260 set transport t2
261 queued for t2 transport: local_part = userz
262 domain = test.ex
263   errors_to=NULL
264   domain_data=NULL localpart_data=NULL
265 routed by r3 router
266   envelope to: userz@test.ex
267   transport: t2
268 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
269 routing usery@test.ex
270 --------> r1 router <--------
271 local_part=usery domain=test.ex
272 checking local_parts
273 usery in "CALLER"? no (end of list)
274 r1 router skipped: local_parts mismatch
275 --------> r2 router <--------
276 local_part=usery domain=test.ex
277 checking local_parts
278 usery in "usery"? yes (matched "usery")
279 expanding: /non-exist/$domain
280    result: /non-exist/test.ex
281 calling r2 router
282 r2 router called for usery@test.ex
283   domain = test.ex
284 set transport t1
285 queued for t1 transport: local_part = usery
286 domain = test.ex
287   errors_to=NULL
288   domain_data=NULL localpart_data=NULL
289 routed by r2 router
290   envelope to: usery@test.ex
291   transport: t1
292 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
293 routing CALLER@test.ex
294 --------> r1 router <--------
295 local_part=CALLER domain=test.ex
296 checking local_parts
297 CALLER in "CALLER"? yes (matched "CALLER")
298 expanding: /non-exist/$local_part
299    result: /non-exist/CALLER
300 calling r1 router
301 r1 router called for CALLER@test.ex
302   domain = test.ex
303 set transport t1
304 queued for t1 transport: local_part = CALLER
305 domain = test.ex
306   errors_to=NULL
307   domain_data=NULL localpart_data=NULL
308 routed by r1 router
309   envelope to: CALLER@test.ex
310   transport: t1
311 locking TESTSUITE/spool/db/retry.lockfile
312 locked TESTSUITE/spool/db/retry.lockfile
313 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
314 returned from EXIM_DBOPEN
315 no retry data available
316 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
317 Considering: TESTSUITE/test-mail/junk
318 unique = TESTSUITE/test-mail/junk:rd+CALLER@test.ex
319 queued for ft1 transport
320 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
321 Considering: TESTSUITE/test-mail/junk
322 unique = TESTSUITE/test-mail/junk:rd+usery@test.ex
323 queued for ft1 transport
324 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
325 After routing:
326   Local deliveries:
327     TESTSUITE/test-mail/junk
328     TESTSUITE/test-mail/junk
329     CALLER@test.ex
330     usery@test.ex
331     userz@test.ex
332   Remote deliveries:
333   Failed addresses:
334   Deferred addresses:
335 search_tidyup called
336 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
337 --------> TESTSUITE/test-mail/junk <--------
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 no retry data available
343 expanding: /non-exist/$local_part
344    result: /non-exist/usery
345 search_tidyup called
346 changed uid/gid: local delivery to TESTSUITE/test-mail/junk <TESTSUITE/test-mail/junk> transport=ft1
347   uid=CALLER_UID gid=CALLER_GID pid=pppp
348   home=/non-exist/usery current=/
349 set_process_info: pppp delivering 10HmaX-0005vi-00 to TESTSUITE/test-mail/junk using ft1
350 appendfile transport entered
351 expanding: $address_file
352    result: TESTSUITE/test-mail/junk
353 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
354   file=TESTSUITE/test-mail/junk format=unix
355   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
356   message_suffix=\n
357   maildir_use_size_file=no
358   locking by lockfile fcntl 
359 lock name: TESTSUITE/test-mail/junk.lock
360 hitch name: TESTSUITE/test-mail/junk.lock.test.ex.dddddddd.pppppppp
361 lock file created
362 mailbox TESTSUITE/test-mail/junk is locked
363 writing to file TESTSUITE/test-mail/junk
364 condition: def:return_path
365    result: true
366 expanding: $return_path
367    result: CALLER@test.ex
368 expanding: MAILER-DAEMON
369    result: MAILER-DAEMON
370 skipping: result is not used
371 expanding: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
372
373    result: From CALLER@test.ex Tue Mar 02 09:44:33 1999
374
375 writing data block fd=dddd size=sss timeout=0
376 writing data block fd=dddd size=sss timeout=0
377 writing data block fd=dddd size=sss timeout=0
378 appendfile yields 0 with errno=dd more_errno=dd
379 search_tidyup called
380 journalling TESTSUITE/test-mail/junk:rd+usery@test.ex
381 ft1 transport returned OK for TESTSUITE/test-mail/junk
382 post-process TESTSUITE/test-mail/junk (0)
383 TESTSUITE/test-mail/junk delivered
384 rd+usery@test.ex: children all complete
385 LOG: MAIN
386   => TESTSUITE/test-mail/junk <rd+usery@test.ex> R=r5 T=ft1
387 --------> TESTSUITE/test-mail/junk <--------
388 locking TESTSUITE/spool/db/retry.lockfile
389 locked TESTSUITE/spool/db/retry.lockfile
390 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
391 returned from EXIM_DBOPEN
392 no retry data available
393 search_tidyup called
394 changed uid/gid: local delivery to TESTSUITE/test-mail/junk <TESTSUITE/test-mail/junk> transport=ft1
395   uid=CALLER_UID gid=CALLER_GID pid=pppp
396   home=/non-exist/CALLER current=/
397 set_process_info: pppp delivering 10HmaX-0005vi-00 to TESTSUITE/test-mail/junk using ft1
398 appendfile transport entered
399 expanding: $address_file
400    result: TESTSUITE/test-mail/junk
401 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
402   file=TESTSUITE/test-mail/junk format=unix
403   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
404   message_suffix=\n
405   maildir_use_size_file=no
406   locking by lockfile fcntl 
407 lock name: TESTSUITE/test-mail/junk.lock
408 hitch name: TESTSUITE/test-mail/junk.lock.test.ex.dddddddd.pppppppp
409 lock file created
410 mailbox TESTSUITE/test-mail/junk is locked
411 writing to file TESTSUITE/test-mail/junk
412 condition: def:return_path
413    result: true
414 expanding: $return_path
415    result: CALLER@test.ex
416 expanding: MAILER-DAEMON
417    result: MAILER-DAEMON
418 skipping: result is not used
419 expanding: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
420
421    result: From CALLER@test.ex Tue Mar 02 09:44:33 1999
422
423 writing data block fd=dddd size=sss timeout=0
424 writing data block fd=dddd size=sss timeout=0
425 writing data block fd=dddd size=sss timeout=0
426 appendfile yields 0 with errno=dd more_errno=dd
427 search_tidyup called
428 journalling TESTSUITE/test-mail/junk:rd+CALLER@test.ex
429 ft1 transport returned OK for TESTSUITE/test-mail/junk
430 post-process TESTSUITE/test-mail/junk (0)
431 TESTSUITE/test-mail/junk delivered
432 rd+CALLER@test.ex: children all complete
433 LOG: MAIN
434   => TESTSUITE/test-mail/junk <rd+CALLER@test.ex> R=r4 T=ft1
435 --------> CALLER@test.ex <--------
436 locking TESTSUITE/spool/db/retry.lockfile
437 locked TESTSUITE/spool/db/retry.lockfile
438 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
439 returned from EXIM_DBOPEN
440 no retry data available
441 search_tidyup called
442 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
443   uid=CALLER_UID gid=CALLER_GID pid=pppp
444   home=/non-exist/CALLER current=/
445 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
446 appendfile transport entered
447 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
448   file=/dev/null format=unix
449   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
450   message_suffix=\n
451   maildir_use_size_file=no
452   locking by lockfile fcntl 
453 search_tidyup called
454 journalling CALLER@test.ex
455 t1 transport returned OK for CALLER@test.ex
456 post-process CALLER@test.ex (0)
457 CALLER@test.ex delivered
458 LOG: MAIN
459   => CALLER <CALLER@test.ex> R=r1 T=t1
460 --------> usery@test.ex <--------
461 locking TESTSUITE/spool/db/retry.lockfile
462 locked TESTSUITE/spool/db/retry.lockfile
463 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
464 returned from EXIM_DBOPEN
465 no retry data available
466 expanding: /non-exist/$local_part
467    result: /non-exist/usery
468 search_tidyup called
469 changed uid/gid: local delivery to usery <usery@test.ex> transport=t1
470   uid=CALLER_UID gid=CALLER_GID pid=pppp
471   home=/non-exist/usery current=/
472 set_process_info: pppp delivering 10HmaX-0005vi-00 to usery using t1
473 appendfile transport entered
474 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
475   file=/dev/null format=unix
476   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
477   message_suffix=\n
478   maildir_use_size_file=no
479   locking by lockfile fcntl 
480 search_tidyup called
481 journalling usery@test.ex
482 t1 transport returned OK for usery@test.ex
483 post-process usery@test.ex (0)
484 usery@test.ex delivered
485 LOG: MAIN
486   => usery <usery@test.ex> R=r2 T=t1
487 --------> userz@test.ex <--------
488 locking TESTSUITE/spool/db/retry.lockfile
489 locked TESTSUITE/spool/db/retry.lockfile
490 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
491 returned from EXIM_DBOPEN
492 no retry data available
493 expanding: /$local_part
494    result: /userz
495 search_tidyup called
496 changed uid/gid: local delivery to userz <userz@test.ex> transport=t2
497   uid=CALLER_UID gid=CALLER_GID pid=pppp
498   home=/userz current=/
499 set_process_info: pppp delivering 10HmaX-0005vi-00 to userz using t2
500 appendfile transport entered
501 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
502   file=/dev/null format=unix
503   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
504   message_suffix=\n
505   maildir_use_size_file=no
506   locking by lockfile fcntl 
507 search_tidyup called
508 journalling userz@test.ex
509 t2 transport returned OK for userz@test.ex
510 post-process userz@test.ex (0)
511 userz@test.ex delivered
512 LOG: MAIN
513   => userz <userz@test.ex> R=r3 T=t2
514 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
515 changed uid/gid: post-delivery tidying
516   uid=EXIM_UID gid=EXIM_GID pid=pppp
517 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
518 Processing retry items
519 Succeeded addresses:
520 userz@test.ex: no retry items
521 usery@test.ex: no retry items
522 CALLER@test.ex: no retry items
523 TESTSUITE/test-mail/junk: no retry items
524 rd+CALLER@test.ex: no retry items
525 TESTSUITE/test-mail/junk: no retry items
526 rd+usery@test.ex: no retry items
527 rd+CALLER@test.ex: no retry items
528 rd+usery@test.ex: no retry items
529 Failed addresses:
530 Deferred addresses:
531 end of retry processing
532 LOG: MAIN
533   Completed
534 end delivery of 10HmaX-0005vi-00
535 search_tidyup called
536 search_tidyup called
537 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
538 search_tidyup called
539 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>