Debug: output priv-gid drop
[exim.git] / test / stderr / 0386
1 Exim version x.yz ....
2 changed uid/gid: forcing real = effective
3   uid=uuuu gid=CALLER_GID pid=pppp
4 seeking password data for user "CALLER": cache not available
5 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
6 configuration file is TESTSUITE/test-config
7 trusted user
8 admin user
9 changed uid/gid: privilege not needed
10   uid=EXIM_UID gid=EXIM_GID pid=pppp
11 seeking password data for user "CALLER": using cached result
12 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
13 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
14 sender address = CALLER@test.ex
15 sender_fullhost = [V4NET.9.8.7]
16 sender_rcvhost = [V4NET.9.8.7]
17 host in hosts_connection_nolog? no (option unset)
18 LOG: smtp_connection MAIN
19   SMTP connection from [V4NET.9.8.7]
20 host in host_lookup? no (option unset)
21 set_process_info: pppp handling incoming connection from [V4NET.9.8.7]
22 host in host_reject_connection? no (option unset)
23 host in sender_unqualified_hosts? no (option unset)
24 host in recipient_unqualified_hosts? no (option unset)
25 host in helo_verify_hosts? no (option unset)
26 host in helo_try_verify_hosts? no (option unset)
27 host in helo_accept_junk_hosts? no (option unset)
28 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
29 smtp_setup_msg entered
30 SMTP<< mail from:<x@y>
31 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
32 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
33 SMTP>> 250 OK
34 SMTP<< rcpt to:<1@b>
35 read ACL from file TESTSUITE/aux-fixed/0386.acl1
36 processing "accept" (TESTSUITE/test-config 32)
37 check hosts = :
38 host in ":"? no (end of list)
39 accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
40 processing "deny" (TESTSUITE/test-config 32)
41 check local_parts = ^.*[@%!/|]
42 1 in "^.*[@%!/|]"? no (end of list)
43 deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
44 processing "require" (TESTSUITE/test-config 32)
45 l_message: Invalid sender
46   message: Couldn't verify the sender
47 check verify = sender/defer_ok
48 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
49 Verifying x@y
50 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
51 Considering x@y
52 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
53 routing x@y
54 --------> r1 router <--------
55 local_part=x domain=y
56 calling r1 router
57 r1 router called for x@y
58   domain = y
59 set transport t1
60 queued for t1 transport: local_part = x
61 domain = y
62   errors_to=NULL
63   domain_data=NULL localpart_data=NULL
64 routed by r1 router
65   envelope to: x@y
66   transport: t1
67 ----------- end verify ------------
68 sender x@y verified ok
69 require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
70 processing "deny" (TESTSUITE/test-config 32)
71   message: No such user here
72 deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
73 end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
74 SMTP>> 550 No such user here
75 LOG: MAIN REJECT
76   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
77 SMTP<< rset
78 SMTP>> 250 Reset OK
79 SMTP<< mail from:<x@y>
80 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
81 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
82 SMTP>> 250 OK
83 SMTP<< rcpt to:<1@b>
84 using ACL "TESTSUITE/aux-fixed/0386.acl1"
85 processing "accept" (TESTSUITE/test-config 32)
86 check hosts = :
87 host in ":"? no (end of list)
88 accept: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
89 processing "deny" (TESTSUITE/test-config 32)
90 check local_parts = ^.*[@%!/|]
91 1 in "^.*[@%!/|]"? no (end of list)
92 deny: condition test failed in ACL "TESTSUITE/aux-fixed/0386.acl1"
93 processing "require" (TESTSUITE/test-config 32)
94 l_message: Invalid sender
95   message: Couldn't verify the sender
96 check verify = sender/defer_ok
97 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
98 Verifying x@y
99 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
100 Considering x@y
101 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
102 routing x@y
103 --------> r1 router <--------
104 local_part=x domain=y
105 calling r1 router
106 r1 router called for x@y
107   domain = y
108 queued for t1 transport: local_part = x
109 domain = y
110   errors_to=NULL
111   domain_data=NULL localpart_data=NULL
112 routed by r1 router
113   envelope to: x@y
114   transport: t1
115 ----------- end verify ------------
116 sender x@y verified ok
117 require: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
118 processing "deny" (TESTSUITE/test-config 32)
119   message: No such user here
120 deny: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl1"
121 end of ACL "TESTSUITE/aux-fixed/0386.acl1": DENY
122 SMTP>> 550 No such user here
123 LOG: MAIN REJECT
124   H=[V4NET.9.8.7] F=<x@y> rejected RCPT <1@b>: No such user here
125 SMTP<< quit
126 SMTP>> 221 myhost.test.ex closing connection
127 LOG: smtp_connection MAIN
128   SMTP connection from [V4NET.9.8.7] closed by QUIT
129 search_tidyup called
130 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
131 Exim version x.yz ....
132 changed uid/gid: forcing real = effective
133   uid=uuuu gid=CALLER_GID pid=pppp
134 seeking password data for user "CALLER": cache not available
135 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
136 configuration file is TESTSUITE/test-config
137 trusted user
138 admin user
139 changed uid/gid: privilege not needed
140   uid=EXIM_UID gid=EXIM_GID pid=pppp
141 seeking password data for user "CALLER": using cached result
142 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
143 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
144 sender address = NULL
145 sender_fullhost = [V4NET.11.12.13]
146 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
147 set_process_info: pppp handling incoming connection from [V4NET.11.12.13] via -oMa
148 set_process_info: pppp accepting a local SMTP message from <CALLER>
149 host in hosts_connection_nolog? no (option unset)
150 LOG: smtp_connection MAIN
151   SMTP connection from CALLER
152 host in host_lookup? no (option unset)
153 set_process_info: pppp handling incoming connection from [V4NET.11.12.13] U=CALLER
154 host in host_reject_connection? no (option unset)
155 host in sender_unqualified_hosts? no (option unset)
156 host in recipient_unqualified_hosts? no (option unset)
157 host in helo_verify_hosts? no (option unset)
158 host in helo_try_verify_hosts? no (option unset)
159 host in helo_accept_junk_hosts? no (option unset)
160 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
161 smtp_setup_msg entered
162 SMTP<< mail from:<x@y>
163 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
164 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
165 SMTP>> 250 OK
166 SMTP<< rcpt to:<2@b>
167 read ACL from file TESTSUITE/aux-fixed/0386.acl2
168 processing "warn" (TESTSUITE/test-config 32)
169   message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
170 l_message: found in $dnslist_domain: $dnslist_text
171 check dnslists = rbl.test.ex 
172 DNS list check: rbl.test.ex
173 new DNS lookup for 13.12.11.V4NET.rbl.test.ex
174 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) using fakens
175 DNS lookup of 13.12.11.V4NET.rbl.test.ex (A) succeeded
176 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
177 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) using fakens
178 DNS lookup of 13.12.11.V4NET.rbl.test.ex (TXT) succeeded
179 => that means V4NET.11.12.13 is listed at rbl.test.ex
180 warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
181 LOG: MAIN
182   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
183 created log directory TESTSUITE/spool/log
184 processing "accept" (TESTSUITE/test-config 32)
185 accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
186 end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
187 SMTP>> 250 Accepted
188 DSN: orcpt: NULL  flags: 0
189 SMTP<< data
190 SMTP>> 354 Enter message, ending with "." on a line by itself
191 search_tidyup called
192 >>Headers received:
193
194 search_tidyup called
195 >>Headers after rewriting and local additions:
196
197 Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
198 Data file written for message 10HmaX-0005vi-00
199 >>Generated Received: header line
200 P Received: from [V4NET.11.12.13] (ident=CALLER)
201         by myhost.test.ex with smtp (Exim x.yz)
202         (envelope-from <x@y>)
203         id 10HmaX-0005vi-00
204         for 2@b; Tue, 2 Mar 1999 09:44:33 +0000
205 >>Headers added by MAIL or RCPT ACL:
206   X-Warning: V4NET.11.12.13 is listed at rbl.test.ex
207   X-Warning: This is a test blacklisting message
208 >>
209 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaX-0005vi-00
210 DSN: Write SPOOL :-dsn_envid NULL
211 DSN: Write SPOOL :-dsn_ret 0
212 DSN: Flags :0
213 DSN: **** SPOOL_OUT - address: |2@b| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
214 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
215 Size of headers = sss
216 LOG: MAIN
217   <= x@y H=[V4NET.11.12.13] U=CALLER P=smtp S=sss
218 SMTP>> 250 OK id=10HmaX-0005vi-00
219 search_tidyup called
220 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -odi -Mc 10HmaX-0005vi-00
221 Exim version x.yz ....
222 changed uid/gid: forcing real = effective
223   uid=uuuu gid=EXIM_GID pid=pppp
224 seeking password data for user "CALLER": cache not available
225 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
226 configuration file is TESTSUITE/test-config
227 trusted user
228 admin user
229 dropping to exim gid; retaining priv uid
230 seeking password data for user "CALLER": using cached result
231 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
232 set_process_info: pppp delivering specified messages
233 set_process_info: pppp delivering 10HmaX-0005vi-00
234 Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D
235 reading spool file 10HmaX-0005vi-00-H
236 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
237 sender_fullhost = [V4NET.11.12.13]
238 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
239 sender_local=0 ident=CALLER
240 Non-recipients:
241 Empty Tree
242 ---- End of tree ----
243 recipients_count=1
244 **** SPOOL_IN - No additional fields
245 body_linecount=1 message_linecount=7
246 DSN: set orcpt:   flags: 0
247 Delivery address list:
248   2@b 
249  locking TESTSUITE/spool/db/retry.lockfile
250  locked  TESTSUITE/spool/db/retry.lockfile
251  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
252  returned from EXIM_DBOPEN: (nil)
253  ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
254  failed to open DB file TESTSUITE/spool/db/retry.lockfile: No such file or directory
255 no retry data available
256 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
257 Considering: 2@b
258 unique = 2@b
259 no   domain  retry record
260 no   address retry record
261 2@b: queued for routing
262 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
263 routing 2@b
264 --------> r1 router <--------
265 local_part=2 domain=b
266 calling r1 router
267 r1 router called for 2@b
268   domain = b
269 set transport t1
270 queued for t1 transport: local_part = 2
271 domain = b
272   errors_to=NULL
273   domain_data=NULL localpart_data=NULL
274 routed by r1 router
275   envelope to: 2@b
276   transport: t1
277 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
278 After routing:
279   Local deliveries:
280     2@b
281   Remote deliveries:
282   Failed addresses:
283   Deferred addresses:
284 search_tidyup called
285 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
286 --------> 2@b <--------
287  locking TESTSUITE/spool/db/retry.lockfile
288  locked  TESTSUITE/spool/db/retry.lockfile
289  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
290  returned from EXIM_DBOPEN: (nil)
291  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
292 no retry data available
293 search_tidyup called
294 changed uid/gid: local delivery to 2 <2@b> transport=t1
295   uid=CALLER_UID gid=CALLER_GID pid=pppp
296   home=NULL current=/
297 set_process_info: pppp delivering 10HmaX-0005vi-00 to 2 using t1
298 appendfile transport entered
299 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
300   file=TESTSUITE/test-mail/2 format=unix
301   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
302   message_suffix=\n
303   maildir_use_size_file=no
304   locking by lockfile fcntl 
305 lock name: TESTSUITE/test-mail/2.lock
306 hitch name: TESTSUITE/test-mail/2.lock.test.ex.dddddddd.pppppppp
307 lock file created
308 mailbox TESTSUITE/test-mail/2 is locked
309 writing to file TESTSUITE/test-mail/2
310 writing data block fd=dddd size=sss timeout=0
311 cannot use sendfile for body: spoolfile not wireformat
312 writing data block fd=dddd size=sss timeout=0
313 writing data block fd=dddd size=sss timeout=0
314 appendfile yields 0 with errno=dd more_errno=dd
315 search_tidyup called
316 journalling 2@b
317 t1 transport returned OK for 2@b
318 post-process 2@b (0)
319 2@b delivered
320 LOG: MAIN
321   => 2 <2@b> R=r1 T=t1
322 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
323 changed uid/gid: post-delivery tidying
324   uid=EXIM_UID gid=EXIM_GID pid=pppp
325 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
326 Processing retry items
327 Succeeded addresses:
328  2@b: no retry items
329 Failed addresses:
330 Deferred addresses:
331 end of retry processing
332 DSN: processing router : r1
333 DSN: processing successful delivery address: 2@b
334 DSN: Sender_address: x@y
335 DSN: orcpt: NULL  flags: 0
336 DSN: envid: NULL  ret: 0
337 DSN: Final recipient: 2@b
338 DSN: Remote SMTP server supports DSN: 0
339 DSN: not sending DSN success message
340 LOG: MAIN
341   Completed
342 end delivery of 10HmaX-0005vi-00
343 search_tidyup called
344 search_tidyup called
345 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
346 smtp_setup_msg entered
347 SMTP<< rset
348 SMTP>> 250 Reset OK
349 SMTP<< mail from:<x@y>
350 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
351 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
352 SMTP>> 250 OK
353 SMTP<< rcpt to:<2@b>
354 using ACL "TESTSUITE/aux-fixed/0386.acl2"
355 processing "warn" (TESTSUITE/test-config 32)
356   message: X-Warning: $sender_host_address is listed at $dnslist_domain\nX-Warning: $dnslist_text
357 l_message: found in $dnslist_domain: $dnslist_text
358 check dnslists = rbl.test.ex 
359 DNS list check: rbl.test.ex
360 using result of previous DNS lookup
361 DNS lookup for 13.12.11.V4NET.rbl.test.ex succeeded (yielding 127.0.0.2)
362 => that means V4NET.11.12.13 is listed at rbl.test.ex
363 warn: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
364 LOG: MAIN
365   H=[V4NET.11.12.13] U=CALLER Warning: found in rbl.test.ex: This is a test blacklisting message
366 processing "accept" (TESTSUITE/test-config 32)
367 accept: condition test succeeded in ACL "TESTSUITE/aux-fixed/0386.acl2"
368 end of ACL "TESTSUITE/aux-fixed/0386.acl2": ACCEPT
369 SMTP>> 250 Accepted
370 DSN: orcpt: NULL  flags: 0
371 SMTP<< data
372 SMTP>> 354 Enter message, ending with "." on a line by itself
373 search_tidyup called
374 >>Headers received:
375
376 search_tidyup called
377 >>Headers after rewriting and local additions:
378
379 Data file name: TESTSUITE/spool//input//10HmaY-0005vi-00-D
380 Data file written for message 10HmaY-0005vi-00
381 >>Generated Received: header line
382 P Received: from [V4NET.11.12.13] (ident=CALLER)
383         by myhost.test.ex with smtp (Exim x.yz)
384         (envelope-from <x@y>)
385         id 10HmaY-0005vi-00
386         for 2@b; Tue, 2 Mar 1999 09:44:33 +0000
387 >>Headers added by MAIL or RCPT ACL:
388   X-Warning: V4NET.11.12.13 is listed at rbl.test.ex
389   X-Warning: This is a test blacklisting message
390 >>
391 Writing spool header file: TESTSUITE/spool//input//hdr.10HmaY-0005vi-00
392 DSN: Write SPOOL :-dsn_envid NULL
393 DSN: Write SPOOL :-dsn_ret 0
394 DSN: Flags :0
395 DSN: **** SPOOL_OUT - address: |2@b| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
396 Renaming spool header file: TESTSUITE/spool//input//10HmaY-0005vi-00-H
397 Size of headers = sss
398 LOG: MAIN
399   <= x@y H=[V4NET.11.12.13] U=CALLER P=smtp S=sss
400 SMTP>> 250 OK id=10HmaY-0005vi-00
401 search_tidyup called
402 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xf7715cfd -odi -Mc 10HmaY-0005vi-00
403 Exim version x.yz ....
404 changed uid/gid: forcing real = effective
405   uid=uuuu gid=EXIM_GID pid=pppp
406 seeking password data for user "CALLER": cache not available
407 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
408 configuration file is TESTSUITE/test-config
409 trusted user
410 admin user
411 dropping to exim gid; retaining priv uid
412 seeking password data for user "CALLER": using cached result
413 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
414 set_process_info: pppp delivering specified messages
415 set_process_info: pppp delivering 10HmaY-0005vi-00
416 Trying spool file TESTSUITE/spool//input//10HmaY-0005vi-00-D
417 reading spool file 10HmaY-0005vi-00-H
418 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=x@y
419 sender_fullhost = [V4NET.11.12.13]
420 sender_rcvhost = [V4NET.11.12.13] (ident=CALLER)
421 sender_local=0 ident=CALLER
422 Non-recipients:
423 Empty Tree
424 ---- End of tree ----
425 recipients_count=1
426 **** SPOOL_IN - No additional fields
427 body_linecount=1 message_linecount=7
428 DSN: set orcpt:   flags: 0
429 Delivery address list:
430   2@b 
431  locking TESTSUITE/spool/db/retry.lockfile
432  locked  TESTSUITE/spool/db/retry.lockfile
433  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
434  returned from EXIM_DBOPEN: (nil)
435  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
436 no retry data available
437 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
438 Considering: 2@b
439 unique = 2@b
440 no   domain  retry record
441 no   address retry record
442 2@b: queued for routing
443 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
444 routing 2@b
445 --------> r1 router <--------
446 local_part=2 domain=b
447 calling r1 router
448 r1 router called for 2@b
449   domain = b
450 set transport t1
451 queued for t1 transport: local_part = 2
452 domain = b
453   errors_to=NULL
454   domain_data=NULL localpart_data=NULL
455 routed by r1 router
456   envelope to: 2@b
457   transport: t1
458 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
459 After routing:
460   Local deliveries:
461     2@b
462   Remote deliveries:
463   Failed addresses:
464   Deferred addresses:
465 search_tidyup called
466 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
467 --------> 2@b <--------
468  locking TESTSUITE/spool/db/retry.lockfile
469  locked  TESTSUITE/spool/db/retry.lockfile
470  EXIM_DBOPEN: file <TESTSUITE/spool/db/retry> dir <TESTSUITE/spool/db> flags=O_RDONLY
471  returned from EXIM_DBOPEN: (nil)
472  failed to open DB file TESTSUITE/spool/db/retry: No such file or directory
473 no retry data available
474 search_tidyup called
475 changed uid/gid: local delivery to 2 <2@b> transport=t1
476   uid=CALLER_UID gid=CALLER_GID pid=pppp
477   home=NULL current=/
478 set_process_info: pppp delivering 10HmaY-0005vi-00 to 2 using t1
479 appendfile transport entered
480 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
481   file=TESTSUITE/test-mail/2 format=unix
482   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
483   message_suffix=\n
484   maildir_use_size_file=no
485   locking by lockfile fcntl 
486 lock name: TESTSUITE/test-mail/2.lock
487 hitch name: TESTSUITE/test-mail/2.lock.test.ex.dddddddd.pppppppp
488 lock file created
489 mailbox TESTSUITE/test-mail/2 is locked
490 writing to file TESTSUITE/test-mail/2
491 writing data block fd=dddd size=sss timeout=0
492 cannot use sendfile for body: spoolfile not wireformat
493 writing data block fd=dddd size=sss timeout=0
494 writing data block fd=dddd size=sss timeout=0
495 appendfile yields 0 with errno=dd more_errno=dd
496 search_tidyup called
497 journalling 2@b
498 t1 transport returned OK for 2@b
499 post-process 2@b (0)
500 2@b delivered
501 LOG: MAIN
502   => 2 <2@b> R=r1 T=t1
503 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
504 changed uid/gid: post-delivery tidying
505   uid=EXIM_UID gid=EXIM_GID pid=pppp
506 set_process_info: pppp tidying up after delivering 10HmaY-0005vi-00
507 Processing retry items
508 Succeeded addresses:
509  2@b: no retry items
510 Failed addresses:
511 Deferred addresses:
512 end of retry processing
513 DSN: processing router : r1
514 DSN: processing successful delivery address: 2@b
515 DSN: Sender_address: x@y
516 DSN: orcpt: NULL  flags: 0
517 DSN: envid: NULL  ret: 0
518 DSN: Final recipient: 2@b
519 DSN: Remote SMTP server supports DSN: 0
520 DSN: not sending DSN success message
521 LOG: MAIN
522   Completed
523 end delivery of 10HmaY-0005vi-00
524 search_tidyup called
525 search_tidyup called
526 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
527 smtp_setup_msg entered
528 SMTP<< quit
529 SMTP>> 221 myhost.test.ex closing connection
530 LOG: smtp_connection MAIN
531   SMTP connection from CALLER closed by QUIT
532 search_tidyup called
533 >>>>>>>>>>>>>>>> Exim pid=pppp (msg setup toplevel) terminating with rc=0 >>>>>>>>>>>>>>>>