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