Logging: millisecond time on 'no MAIL' lines. Bug 2102
[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 DSN: r1 propagating DSN
9 DSN: r2 propagating DSN
10 DSN: r3 propagating DSN
11 DSN: r4 propagating DSN
12 DSN: r5 propagating DSN
13 seeking password data for user "CALLER": cache not available
14 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
15 seeking password data for user "CALLER": using cached result
16 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
17 seeking password data for user "CALLER": using cached result
18 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
19 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
20 sender address = CALLER@test.ex
21 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
22 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
23 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
24 Sender: CALLER@test.ex
25 Recipients:
26   CALLER@test.ex
27   usery@test.ex
28   userz
29   rd+CALLER
30   rd+usery
31 search_tidyup called
32 >>Headers received:
33
34 rewrite_one_header: type=F:
35   From: CALLER_NAME <CALLER@test.ex>
36 search_tidyup called
37 >>Headers after rewriting and local additions:
38 I Message-Id: <E10HmaX-0005vi-00@mail.test.ex>
39 F From: CALLER_NAME <CALLER@test.ex>
40   Date: Tue, 2 Mar 1999 09:44:33 +0000
41
42 Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
43 Data file written for message 10HmaX-0005vi-00
44  ┌considering: ${tod_full}
45  ├──expanding: ${tod_full}
46  └─────result: Tue, 2 Mar 1999 09:44:33 +0000
47  ┌considering: Received: ${if def:sender_rcvhost {from $sender_rcvhost
48         }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
49         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
50         ${if def:sender_address {(envelope-from <$sender_address>)
51         }}id $message_exim_id${if def:received_for {
52         for $received_for}}
53  ├──condition: def:sender_rcvhost
54  ├─────result: false
55   ┌───scanning: from $sender_rcvhost
56         }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
57         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
58         ${if def:sender_address {(envelope-from <$sender_address>)
59         }}id $message_exim_id${if def:received_for {
60         for $received_for}}
61   ├──expanding: from $sender_rcvhost
62         
63   ├─────result: from 
64         
65   └───skipping: result is not used
66   ┌considering: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
67         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
68         ${if def:sender_address {(envelope-from <$sender_address>)
69         }}id $message_exim_id${if def:received_for {
70         for $received_for}}
71   ├──condition: def:sender_ident
72   ├─────result: true
73    ┌considering: from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
74         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
75         ${if def:sender_address {(envelope-from <$sender_address>)
76         }}id $message_exim_id${if def:received_for {
77         for $received_for}}
78    ╎┌considering: $sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
79    ╎  }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol   ╎}} (Exim $version_number)
80    ╎  ${if def:sender_address {(envelope-from <$sender_address>)
81    ╎  }}id $message_exim_id${if def:received_for {
82    ╎  for $received_for}}
83    ╎├──expanding: $sender_ident
84    ╎└─────result: CALLER
85    ├──expanding: from ${quote_local_part:$sender_ident} 
86    └─────result: from CALLER 
87   ├──condition: def:sender_helo_name
88   ├─────result: false
89    ┌───scanning: (helo=$sender_helo_name)
90         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
91         ${if def:sender_address {(envelope-from <$sender_address>)
92         }}id $message_exim_id${if def:received_for {
93         for $received_for}}
94    ├──expanding: (helo=$sender_helo_name)
95         
96    ├─────result: (helo=)
97         
98    └───skipping: result is not used
99   ├──expanding: ${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
100         }}
101   └─────result: from CALLER 
102  ├──condition: def:received_protocol
103  ├─────result: true
104   ┌considering: with $received_protocol}} (Exim $version_number)
105         ${if def:sender_address {(envelope-from <$sender_address>)
106         }}id $message_exim_id${if def:received_for {
107         for $received_for}}
108   ├──expanding: with $received_protocol
109   └─────result: with local
110  ├──condition: def:tls_cipher
111  ├─────result: false
112   ┌───scanning: ($tls_cipher)
113         }}(Exim $version_number)
114         ${if def:sender_address {(envelope-from <$sender_address>)
115         }}id $message_exim_id${if def:received_for {
116         for $received_for}}
117   ├──expanding: ($tls_cipher)
118         
119   ├─────result: ()
120         
121   └───skipping: result is not used
122  ├──condition: def:sender_address
123  ├─────result: true
124   ┌considering: (envelope-from <$sender_address>)
125         }}id $message_exim_id${if def:received_for {
126         for $received_for}}
127   ├──expanding: (envelope-from <$sender_address>)
128         
129   └─────result: (envelope-from <CALLER@test.ex>)
130         
131  ├──condition: def:received_for
132  ├─────result: false
133   ┌───scanning: 
134         for $received_for}}
135   ├──expanding: 
136         for $received_for
137   ├─────result: 
138         for 
139   └───skipping: result is not used
140  ├──expanding: Received: ${if def:sender_rcvhost {from $sender_rcvhost
141         }{${if def:sender_ident {from ${quote_local_part:$sender_ident} }}${if def:sender_helo_name {(helo=$sender_helo_name)
142         }}}}by $primary_hostname ${if def:received_protocol {with $received_protocol}} (Exim $version_number)
143         ${if def:sender_address {(envelope-from <$sender_address>)
144         }}id $message_exim_id${if def:received_for {
145         for $received_for}}
146  └─────result: Received: from CALLER by mail.test.ex with local (Exim x.yz)
147         (envelope-from <CALLER@test.ex>)
148         id 10HmaX-0005vi-00
149 >>Generated Received: header line
150 P Received: from CALLER by mail.test.ex with local (Exim x.yz)
151         (envelope-from <CALLER@test.ex>)
152         id 10HmaX-0005vi-00; Tue, 2 Mar 1999 09:44:33 +0000
153 calling local_scan(); timeout=300
154 local_scan() returned 0 NULL
155  ┌considering: ${tod_full}
156  ├──expanding: ${tod_full}
157  └─────result: Tue, 2 Mar 1999 09:44:33 +0000
158 Writing spool header file: TESTSUITE/spool//input//hdr.pppp
159 DSN: Write SPOOL :-dsn_envid NULL
160 DSN: Write SPOOL :-dsn_ret 0
161 DSN: Flags :0
162 DSN: **** SPOOL_OUT - address: |CALLER@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
163 DSN: Flags :0
164 DSN: **** SPOOL_OUT - address: |usery@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
165 DSN: Flags :0
166 DSN: **** SPOOL_OUT - address: |userz@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
167 DSN: Flags :0
168 DSN: **** SPOOL_OUT - address: |rd+CALLER@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
169 DSN: Flags :0
170 DSN: **** SPOOL_OUT - address: |rd+usery@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
171 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
172 Size of headers = sss
173 LOG: MAIN
174   <= CALLER@test.ex U=CALLER P=local S=sss
175 created log directory TESTSUITE/spool/log
176 search_tidyup called
177 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95dfd -odi -Mc 10HmaX-0005vi-00
178 Exim version x.yz ....
179 changed uid/gid: forcing real = effective
180   uid=uuuu gid=EXIM_GID pid=pppp
181 configuration file is TESTSUITE/test-config
182 trusted user
183 admin user
184 DSN: r1 propagating DSN
185 DSN: r2 propagating DSN
186 DSN: r3 propagating DSN
187 DSN: r4 propagating DSN
188 DSN: r5 propagating DSN
189 seeking password data for user "CALLER": cache not available
190 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
191 seeking password data for user "CALLER": using cached result
192 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
193 seeking password data for user "CALLER": using cached result
194 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
195 set_process_info: pppp delivering specified messages
196 set_process_info: pppp delivering 10HmaX-0005vi-00
197 Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D
198 reading spool file 10HmaX-0005vi-00-H
199 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@test.ex
200 sender_local=1 ident=CALLER
201 Non-recipients:
202 Empty Tree
203 ---- End of tree ----
204 recipients_count=5
205 **** SPOOL_IN - No additional fields
206 **** SPOOL_IN - No additional fields
207 **** SPOOL_IN - No additional fields
208 **** SPOOL_IN - No additional fields
209 **** SPOOL_IN - No additional fields
210 body_linecount=0 message_linecount=6
211 DSN: set orcpt: NULL  flags: 0
212 DSN: set orcpt: NULL  flags: 0
213 DSN: set orcpt: NULL  flags: 0
214 DSN: set orcpt: NULL  flags: 0
215 DSN: set orcpt: NULL  flags: 0
216 Delivery address list:
217   CALLER@test.ex 
218   usery@test.ex 
219   userz@test.ex 
220   rd+CALLER@test.ex 
221   rd+usery@test.ex 
222 locking TESTSUITE/spool/db/retry.lockfile
223 locked  TESTSUITE/spool/db/retry.lockfile
224 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
225 returned from EXIM_DBOPEN: (nil)
226 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
227 failed to open DB file TESTSUITE/spool/db/retry.lockfile: No such file or directory
228 no retry data available
229 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
230 Considering: CALLER@test.ex
231 unique = CALLER@test.ex
232 no domain retry record
233 no address retry record
234 CALLER@test.ex: queued for routing
235 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
236 Considering: usery@test.ex
237 unique = usery@test.ex
238 no domain retry record
239 no address retry record
240 usery@test.ex: queued for routing
241 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
242 Considering: userz@test.ex
243 unique = userz@test.ex
244 no domain retry record
245 no address retry record
246 userz@test.ex: queued for routing
247 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
248 Considering: rd+CALLER@test.ex
249 unique = rd+CALLER@test.ex
250 no domain retry record
251 no address retry record
252 rd+CALLER@test.ex: queued for routing
253 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
254 Considering: rd+usery@test.ex
255 unique = rd+usery@test.ex
256 no domain retry record
257 no address retry record
258 rd+usery@test.ex: queued for routing
259 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
260 routing rd+usery@test.ex
261 --------> r1 router <--------
262 local_part=rd+usery domain=test.ex
263 checking local_parts
264 rd+usery in "CALLER"? no (end of list)
265 r1 router skipped: local_parts mismatch
266 --------> r2 router <--------
267 local_part=rd+usery domain=test.ex
268 checking local_parts
269 rd+usery in "usery"? no (end of list)
270 r2 router skipped: local_parts mismatch
271 --------> r3 router <--------
272 local_part=rd+usery domain=test.ex
273 checking local_parts
274 rd+usery in "userz"? no (end of list)
275 r3 router skipped: local_parts mismatch
276 --------> r4 router <--------
277 local_part=rd+usery domain=test.ex
278 stripped prefix rd+
279 checking local_parts
280 usery in "CALLER"? no (end of list)
281 r4 router skipped: local_parts mismatch
282 --------> r5 router <--------
283 local_part=rd+usery domain=test.ex
284 stripped prefix rd+
285 checking local_parts
286 usery in "usery"? yes (matched "usery")
287  ┌considering: /non-exist/$domain
288  ├──expanding: /non-exist/$domain
289  └─────result: /non-exist/test.ex
290 calling r5 router
291 rda_interpret (string): TESTSUITE/test-mail/junk
292 expanded: TESTSUITE/test-mail/junk
293 file is not a filter file
294 parse_forward_list: TESTSUITE/test-mail/junk
295 extract item: TESTSUITE/test-mail/junk
296 set transport ft1
297 r5 router generated TESTSUITE/test-mail/junk
298   pipe, file, or autoreply
299   errors_to=NULL transport=ft1
300   uid=unset gid=unset home=/non-exist/$local_part
301 routed by r5 router
302   envelope to: rd+usery@test.ex
303   transport: <none>
304 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
305 routing rd+CALLER@test.ex
306 --------> r1 router <--------
307 local_part=rd+CALLER domain=test.ex
308 checking local_parts
309 rd+CALLER in "CALLER"? no (end of list)
310 r1 router skipped: local_parts mismatch
311 --------> r2 router <--------
312 local_part=rd+CALLER domain=test.ex
313 checking local_parts
314 rd+CALLER in "usery"? no (end of list)
315 r2 router skipped: local_parts mismatch
316 --------> r3 router <--------
317 local_part=rd+CALLER domain=test.ex
318 checking local_parts
319 rd+CALLER in "userz"? no (end of list)
320 r3 router skipped: local_parts mismatch
321 --------> r4 router <--------
322 local_part=rd+CALLER domain=test.ex
323 stripped prefix rd+
324 checking local_parts
325 CALLER in "CALLER"? yes (matched "CALLER")
326  ┌considering: /non-exist/$local_part
327  ├──expanding: /non-exist/$local_part
328  └─────result: /non-exist/CALLER
329 calling r4 router
330 rda_interpret (string): TESTSUITE/test-mail/junk
331 expanded: TESTSUITE/test-mail/junk
332 file is not a filter file
333 parse_forward_list: TESTSUITE/test-mail/junk
334 extract item: TESTSUITE/test-mail/junk
335 set transport ft1
336 r4 router generated TESTSUITE/test-mail/junk
337   pipe, file, or autoreply
338   errors_to=NULL transport=ft1
339   uid=unset gid=unset home=/non-exist/CALLER
340 routed by r4 router
341   envelope to: rd+CALLER@test.ex
342   transport: <none>
343 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
344 routing userz@test.ex
345 --------> r1 router <--------
346 local_part=userz domain=test.ex
347 checking local_parts
348 userz in "CALLER"? no (end of list)
349 r1 router skipped: local_parts mismatch
350 --------> r2 router <--------
351 local_part=userz domain=test.ex
352 checking local_parts
353 userz in "usery"? no (end of list)
354 r2 router skipped: local_parts mismatch
355 --------> r3 router <--------
356 local_part=userz domain=test.ex
357 checking local_parts
358 userz in "userz"? yes (matched "userz")
359  ┌considering: /non-exist/$domain
360  ├──expanding: /non-exist/$domain
361  └─────result: /non-exist/test.ex
362 calling r3 router
363 r3 router called for userz@test.ex
364   domain = test.ex
365 set transport t2
366 queued for t2 transport: local_part = userz
367 domain = test.ex
368   errors_to=NULL
369   domain_data=NULL localpart_data=NULL
370 routed by r3 router
371   envelope to: userz@test.ex
372   transport: t2
373 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
374 routing usery@test.ex
375 --------> r1 router <--------
376 local_part=usery domain=test.ex
377 checking local_parts
378 usery in "CALLER"? no (end of list)
379 r1 router skipped: local_parts mismatch
380 --------> r2 router <--------
381 local_part=usery domain=test.ex
382 checking local_parts
383 usery in "usery"? yes (matched "usery")
384  ┌considering: /non-exist/$domain
385  ├──expanding: /non-exist/$domain
386  └─────result: /non-exist/test.ex
387 calling r2 router
388 r2 router called for usery@test.ex
389   domain = test.ex
390 set transport t1
391 queued for t1 transport: local_part = usery
392 domain = test.ex
393   errors_to=NULL
394   domain_data=NULL localpart_data=NULL
395 routed by r2 router
396   envelope to: usery@test.ex
397   transport: t1
398 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
399 routing CALLER@test.ex
400 --------> r1 router <--------
401 local_part=CALLER domain=test.ex
402 checking local_parts
403 CALLER in "CALLER"? yes (matched "CALLER")
404  ┌considering: /non-exist/$local_part
405  ├──expanding: /non-exist/$local_part
406  └─────result: /non-exist/CALLER
407 calling r1 router
408 r1 router called for CALLER@test.ex
409   domain = test.ex
410 set transport t1
411 queued for t1 transport: local_part = CALLER
412 domain = test.ex
413   errors_to=NULL
414   domain_data=NULL localpart_data=NULL
415 routed by r1 router
416   envelope to: CALLER@test.ex
417   transport: t1
418 locking TESTSUITE/spool/db/retry.lockfile
419 locked  TESTSUITE/spool/db/retry.lockfile
420 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
421 returned from EXIM_DBOPEN: (nil)
422 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
423 no retry data available
424 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
425 Considering: TESTSUITE/test-mail/junk
426 unique = TESTSUITE/test-mail/junk:rd+CALLER@test.ex
427 queued for ft1 transport
428 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
429 Considering: TESTSUITE/test-mail/junk
430 unique = TESTSUITE/test-mail/junk:rd+usery@test.ex
431 queued for ft1 transport
432 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
433 After routing:
434   Local deliveries:
435     TESTSUITE/test-mail/junk
436     TESTSUITE/test-mail/junk
437     CALLER@test.ex
438     usery@test.ex
439     userz@test.ex
440   Remote deliveries:
441   Failed addresses:
442   Deferred addresses:
443 search_tidyup called
444 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
445 --------> TESTSUITE/test-mail/junk <--------
446 locking TESTSUITE/spool/db/retry.lockfile
447 locked  TESTSUITE/spool/db/retry.lockfile
448 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
449 returned from EXIM_DBOPEN: (nil)
450 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
451 no retry data available
452  ┌considering: /non-exist/$local_part
453  ├──expanding: /non-exist/$local_part
454  └─────result: /non-exist/usery
455 search_tidyup called
456 changed uid/gid: local delivery to TESTSUITE/test-mail/junk <TESTSUITE/test-mail/junk> transport=ft1
457   uid=CALLER_UID gid=CALLER_GID pid=pppp
458   home=/non-exist/usery current=/
459 set_process_info: pppp delivering 10HmaX-0005vi-00 to TESTSUITE/test-mail/junk using ft1
460 appendfile transport entered
461  ┌considering: $address_file
462  ├──expanding: $address_file
463  └─────result: TESTSUITE/test-mail/junk
464 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
465   file=TESTSUITE/test-mail/junk format=unix
466   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
467   message_suffix=\n
468   maildir_use_size_file=no
469   locking by lockfile fcntl 
470 lock name: TESTSUITE/test-mail/junk.lock
471 hitch name: TESTSUITE/test-mail/junk.lock.test.ex.dddddddd.pppppppp
472 lock file created
473 mailbox TESTSUITE/test-mail/junk is locked
474 writing to file TESTSUITE/test-mail/junk
475  ┌considering: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
476  
477  ├──condition: def:return_path
478  ├─────result: true
479   ┌considering: $return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
480   
481   ├──expanding: $return_path
482   └─────result: CALLER@test.ex
483   ┌───scanning: MAILER-DAEMON}} ${tod_bsdinbox}
484   
485   ├──expanding: MAILER-DAEMON
486   ├─────result: MAILER-DAEMON
487   └───skipping: result is not used
488  ├──expanding: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
489  
490  └─────result: From CALLER@test.ex Tue Mar 02 09:44:33 1999
491  
492 writing data block fd=dddd size=sss timeout=0
493 cannot use sendfile for body: spoolfile not wireformat
494 writing data block fd=dddd size=sss timeout=0
495 writing data block fd=dddd size=sss timeout=0
496 appendfile yields 0 with errno=dd more_errno=dd
497 search_tidyup called
498 journalling TESTSUITE/test-mail/junk:rd+usery@test.ex
499 ft1 transport returned OK for TESTSUITE/test-mail/junk
500 post-process TESTSUITE/test-mail/junk (0)
501 TESTSUITE/test-mail/junk delivered
502 rd+usery@test.ex: children all complete
503 LOG: MAIN
504   => TESTSUITE/test-mail/junk <rd+usery@test.ex> R=r5 T=ft1
505 --------> TESTSUITE/test-mail/junk <--------
506 locking TESTSUITE/spool/db/retry.lockfile
507 locked  TESTSUITE/spool/db/retry.lockfile
508 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
509 returned from EXIM_DBOPEN: (nil)
510 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
511 no retry data available
512 search_tidyup called
513 changed uid/gid: local delivery to TESTSUITE/test-mail/junk <TESTSUITE/test-mail/junk> transport=ft1
514   uid=CALLER_UID gid=CALLER_GID pid=pppp
515   home=/non-exist/CALLER current=/
516 set_process_info: pppp delivering 10HmaX-0005vi-00 to TESTSUITE/test-mail/junk using ft1
517 appendfile transport entered
518  ┌considering: $address_file
519  ├──expanding: $address_file
520  └─────result: TESTSUITE/test-mail/junk
521 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
522   file=TESTSUITE/test-mail/junk format=unix
523   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
524   message_suffix=\n
525   maildir_use_size_file=no
526   locking by lockfile fcntl 
527 lock name: TESTSUITE/test-mail/junk.lock
528 hitch name: TESTSUITE/test-mail/junk.lock.test.ex.dddddddd.pppppppp
529 lock file created
530 mailbox TESTSUITE/test-mail/junk is locked
531 writing to file TESTSUITE/test-mail/junk
532  ┌considering: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
533  
534  ├──condition: def:return_path
535  ├─────result: true
536   ┌considering: $return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
537   
538   ├──expanding: $return_path
539   └─────result: CALLER@test.ex
540   ┌───scanning: MAILER-DAEMON}} ${tod_bsdinbox}
541   
542   ├──expanding: MAILER-DAEMON
543   ├─────result: MAILER-DAEMON
544   └───skipping: result is not used
545  ├──expanding: From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}
546  
547  └─────result: From CALLER@test.ex Tue Mar 02 09:44:33 1999
548  
549 writing data block fd=dddd size=sss timeout=0
550 cannot use sendfile for body: spoolfile not wireformat
551 writing data block fd=dddd size=sss timeout=0
552 writing data block fd=dddd size=sss timeout=0
553 appendfile yields 0 with errno=dd more_errno=dd
554 search_tidyup called
555 journalling TESTSUITE/test-mail/junk:rd+CALLER@test.ex
556 ft1 transport returned OK for TESTSUITE/test-mail/junk
557 post-process TESTSUITE/test-mail/junk (0)
558 TESTSUITE/test-mail/junk delivered
559 rd+CALLER@test.ex: children all complete
560 LOG: MAIN
561   => TESTSUITE/test-mail/junk <rd+CALLER@test.ex> R=r4 T=ft1
562 --------> CALLER@test.ex <--------
563 locking TESTSUITE/spool/db/retry.lockfile
564 locked  TESTSUITE/spool/db/retry.lockfile
565 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
566 returned from EXIM_DBOPEN: (nil)
567 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
568 no retry data available
569 search_tidyup called
570 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
571   uid=CALLER_UID gid=CALLER_GID pid=pppp
572   home=/non-exist/CALLER current=/
573 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
574 appendfile transport entered
575 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
576   file=/dev/null format=unix
577   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
578   message_suffix=\n
579   maildir_use_size_file=no
580   locking by lockfile fcntl 
581 search_tidyup called
582 journalling CALLER@test.ex
583 t1 transport returned OK for CALLER@test.ex
584 post-process CALLER@test.ex (0)
585 CALLER@test.ex delivered
586 LOG: MAIN
587   => CALLER <CALLER@test.ex> R=r1 T=t1
588 --------> usery@test.ex <--------
589 locking TESTSUITE/spool/db/retry.lockfile
590 locked  TESTSUITE/spool/db/retry.lockfile
591 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
592 returned from EXIM_DBOPEN: (nil)
593 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
594 no retry data available
595  ┌considering: /non-exist/$local_part
596  ├──expanding: /non-exist/$local_part
597  └─────result: /non-exist/usery
598 search_tidyup called
599 changed uid/gid: local delivery to usery <usery@test.ex> transport=t1
600   uid=CALLER_UID gid=CALLER_GID pid=pppp
601   home=/non-exist/usery current=/
602 set_process_info: pppp delivering 10HmaX-0005vi-00 to usery using t1
603 appendfile transport entered
604 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
605   file=/dev/null format=unix
606   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
607   message_suffix=\n
608   maildir_use_size_file=no
609   locking by lockfile fcntl 
610 search_tidyup called
611 journalling usery@test.ex
612 t1 transport returned OK for usery@test.ex
613 post-process usery@test.ex (0)
614 usery@test.ex delivered
615 LOG: MAIN
616   => usery <usery@test.ex> R=r2 T=t1
617 --------> userz@test.ex <--------
618 locking TESTSUITE/spool/db/retry.lockfile
619 locked  TESTSUITE/spool/db/retry.lockfile
620 EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags 0x0
621 returned from EXIM_DBOPEN: (nil)
622 failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
623 no retry data available
624  ┌considering: /$local_part
625  ├──expanding: /$local_part
626  └─────result: /userz
627 search_tidyup called
628 changed uid/gid: local delivery to userz <userz@test.ex> transport=t2
629   uid=CALLER_UID gid=CALLER_GID pid=pppp
630   home=/userz current=/
631 set_process_info: pppp delivering 10HmaX-0005vi-00 to userz using t2
632 appendfile transport entered
633 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
634   file=/dev/null format=unix
635   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
636   message_suffix=\n
637   maildir_use_size_file=no
638   locking by lockfile fcntl 
639 search_tidyup called
640 journalling userz@test.ex
641 t2 transport returned OK for userz@test.ex
642 post-process userz@test.ex (0)
643 userz@test.ex delivered
644 LOG: MAIN
645   => userz <userz@test.ex> R=r3 T=t2
646 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
647 changed uid/gid: post-delivery tidying
648   uid=EXIM_UID gid=EXIM_GID pid=pppp
649 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
650 Processing retry items
651 Succeeded addresses:
652  userz@test.ex: no retry items
653  usery@test.ex: no retry items
654  CALLER@test.ex: no retry items
655  TESTSUITE/test-mail/junk: no retry items
656  rd+CALLER@test.ex: no retry items
657  TESTSUITE/test-mail/junk: no retry items
658  rd+usery@test.ex: no retry items
659  rd+CALLER@test.ex: no retry items
660  rd+usery@test.ex: no retry items
661 Failed addresses:
662 Deferred addresses:
663 end of retry processing
664 DSN: processing router : r3
665 DSN: processing successful delivery address: userz@test.ex
666 DSN: Sender_address: CALLER@test.ex
667 DSN: orcpt: NULL  flags: 0
668 DSN: envid: NULL  ret: 0
669 DSN: Final recipient: userz@test.ex
670 DSN: Remote SMTP server supports DSN: 0
671 DSN: not sending DSN success message
672 DSN: processing router : r2
673 DSN: processing successful delivery address: usery@test.ex
674 DSN: Sender_address: CALLER@test.ex
675 DSN: orcpt: NULL  flags: 0
676 DSN: envid: NULL  ret: 0
677 DSN: Final recipient: usery@test.ex
678 DSN: Remote SMTP server supports DSN: 0
679 DSN: not sending DSN success message
680 DSN: processing router : r1
681 DSN: processing successful delivery address: CALLER@test.ex
682 DSN: Sender_address: CALLER@test.ex
683 DSN: orcpt: NULL  flags: 0
684 DSN: envid: NULL  ret: 0
685 DSN: Final recipient: CALLER@test.ex
686 DSN: Remote SMTP server supports DSN: 0
687 DSN: not sending DSN success message
688 DSN: processing router : r4
689 DSN: processing successful delivery address: TESTSUITE/test-mail/junk
690 DSN: Sender_address: CALLER@test.ex
691 DSN: orcpt: NULL  flags: 0
692 DSN: envid: NULL  ret: 0
693 DSN: Final recipient: TESTSUITE/test-mail/junk
694 DSN: Remote SMTP server supports DSN: 0
695 DSN: not sending DSN success message
696 DSN: processing router : r5
697 DSN: processing successful delivery address: TESTSUITE/test-mail/junk
698 DSN: Sender_address: CALLER@test.ex
699 DSN: orcpt: NULL  flags: 0
700 DSN: envid: NULL  ret: 0
701 DSN: Final recipient: TESTSUITE/test-mail/junk
702 DSN: Remote SMTP server supports DSN: 0
703 DSN: not sending DSN success message
704 DSN: processing router : r4
705 DSN: processing successful delivery address: rd+CALLER@test.ex
706 DSN: Sender_address: CALLER@test.ex
707 DSN: orcpt: NULL  flags: 0
708 DSN: envid: NULL  ret: 0
709 DSN: Final recipient: rd+CALLER@test.ex
710 DSN: Remote SMTP server supports DSN: 0
711 DSN: not sending DSN success message
712 DSN: processing router : r5
713 DSN: processing successful delivery address: rd+usery@test.ex
714 DSN: Sender_address: CALLER@test.ex
715 DSN: orcpt: NULL  flags: 0
716 DSN: envid: NULL  ret: 0
717 DSN: Final recipient: rd+usery@test.ex
718 DSN: Remote SMTP server supports DSN: 0
719 DSN: not sending DSN success message
720 LOG: MAIN
721   Completed
722 end delivery of 10HmaX-0005vi-00
723 search_tidyup called
724 search_tidyup called
725 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
726 search_tidyup called
727 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>