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