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