Testsuite: fix munge around tpt connect time
[exim.git] / test / stderr / 0374
1 Exim version x.yz ....
2 configuration file is TESTSUITE/test-config
3 admin user
4 LOG: MAIN
5   <= CALLER@myhost.test.ex U=CALLER P=local S=sss
6 created log directory TESTSUITE/spool/log
7 Exim version x.yz ....
8 configuration file is TESTSUITE/test-config
9 trusted user
10 admin user
11 dropping to exim gid; retaining priv uid
12 locking TESTSUITE/spool/db/retry.lockfile
13 no retry data available
14 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
15 Considering: a1@myhost.test.ex
16 unique = a1@myhost.test.ex
17 a1@myhost.test.ex: queued for routing
18 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
19 Considering: b1@myhost.test.ex
20 unique = b1@myhost.test.ex
21 b1@myhost.test.ex: queued for routing
22 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
23 Considering: c1@myhost.test.ex
24 unique = c1@myhost.test.ex
25 c1@myhost.test.ex: queued for routing
26 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
27 Considering: d1@myhost.test.ex
28 unique = d1@myhost.test.ex
29 d1@myhost.test.ex: queued for routing
30 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
31 Considering: d2@myhost.test.ex
32 unique = d2@myhost.test.ex
33 d2@myhost.test.ex: queued for routing
34 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
35 Considering: d3@myhost.test.ex
36 unique = d3@myhost.test.ex
37 d3@myhost.test.ex: queued for routing
38 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
39 routing d3@myhost.test.ex
40 --------> u1 router <--------
41 local_part=d3 domain=myhost.test.ex
42 checking local_parts
43 d3 in local_parts? no (end of list)
44 u1 router skipped: local_parts mismatch
45 --------> ut2 router <--------
46 local_part=d3 domain=myhost.test.ex
47 checking local_parts
48 d3 in local_parts? no (end of list)
49 ut2 router skipped: local_parts mismatch
50 --------> ut3 router <--------
51 local_part=d3 domain=myhost.test.ex
52 checking local_parts
53 d3 in local_parts? no (end of list)
54 ut3 router skipped: local_parts mismatch
55 --------> ut4 router <--------
56 local_part=d3 domain=myhost.test.ex
57 checking local_parts
58 calling ut4 router
59 ut4 router called for d3@myhost.test.ex
60   domain = myhost.test.ex
61 set transport ut4
62 queued for ut4 transport: local_part = d3
63 domain = myhost.test.ex
64   errors_to=NULL
65   domain_data=NULL local_part_data=^d\d
66 routed by ut4 router (unseen)
67   envelope to: d3@myhost.test.ex
68   transport: ut4
69 "unseen" set: replicated d3@myhost.test.ex
70 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
71 routing d2@myhost.test.ex
72 --------> u1 router <--------
73 local_part=d2 domain=myhost.test.ex
74 checking local_parts
75 d2 in local_parts? no (end of list)
76 u1 router skipped: local_parts mismatch
77 --------> ut2 router <--------
78 local_part=d2 domain=myhost.test.ex
79 checking local_parts
80 d2 in local_parts? no (end of list)
81 ut2 router skipped: local_parts mismatch
82 --------> ut3 router <--------
83 local_part=d2 domain=myhost.test.ex
84 checking local_parts
85 d2 in local_parts? no (end of list)
86 ut3 router skipped: local_parts mismatch
87 --------> ut4 router <--------
88 local_part=d2 domain=myhost.test.ex
89 checking local_parts
90 calling ut4 router
91 ut4 router called for d2@myhost.test.ex
92   domain = myhost.test.ex
93 queued for ut4 transport: local_part = d2
94 domain = myhost.test.ex
95   errors_to=NULL
96   domain_data=NULL local_part_data=^d\d
97 routed by ut4 router (unseen)
98   envelope to: d2@myhost.test.ex
99   transport: ut4
100 "unseen" set: replicated d2@myhost.test.ex
101 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
102 routing d1@myhost.test.ex
103 --------> u1 router <--------
104 local_part=d1 domain=myhost.test.ex
105 checking local_parts
106 d1 in local_parts? no (end of list)
107 u1 router skipped: local_parts mismatch
108 --------> ut2 router <--------
109 local_part=d1 domain=myhost.test.ex
110 checking local_parts
111 d1 in local_parts? no (end of list)
112 ut2 router skipped: local_parts mismatch
113 --------> ut3 router <--------
114 local_part=d1 domain=myhost.test.ex
115 checking local_parts
116 d1 in local_parts? no (end of list)
117 ut3 router skipped: local_parts mismatch
118 --------> ut4 router <--------
119 local_part=d1 domain=myhost.test.ex
120 checking local_parts
121 calling ut4 router
122 ut4 router called for d1@myhost.test.ex
123   domain = myhost.test.ex
124 queued for ut4 transport: local_part = d1
125 domain = myhost.test.ex
126   errors_to=NULL
127   domain_data=NULL local_part_data=^d\d
128 routed by ut4 router (unseen)
129   envelope to: d1@myhost.test.ex
130   transport: ut4
131 "unseen" set: replicated d1@myhost.test.ex
132 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
133 routing c1@myhost.test.ex
134 --------> u1 router <--------
135 local_part=c1 domain=myhost.test.ex
136 checking local_parts
137 c1 in local_parts? no (end of list)
138 u1 router skipped: local_parts mismatch
139 --------> ut2 router <--------
140 local_part=c1 domain=myhost.test.ex
141 checking local_parts
142 c1 in local_parts? no (end of list)
143 ut2 router skipped: local_parts mismatch
144 --------> ut3 router <--------
145 local_part=c1 domain=myhost.test.ex
146 checking local_parts
147 calling ut3 router
148 ut3 router called for c1@myhost.test.ex
149   domain = myhost.test.ex
150 set transport ut3
151 queued for ut3 transport: local_part = c1
152 domain = myhost.test.ex
153   errors_to=NULL
154   domain_data=NULL local_part_data=^c\d
155 routed by ut3 router (unseen)
156   envelope to: c1@myhost.test.ex
157   transport: ut3
158 "unseen" set: replicated c1@myhost.test.ex
159 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
160 routing b1@myhost.test.ex
161 --------> u1 router <--------
162 local_part=b1 domain=myhost.test.ex
163 checking local_parts
164 b1 in local_parts? no (end of list)
165 u1 router skipped: local_parts mismatch
166 --------> ut2 router <--------
167 local_part=b1 domain=myhost.test.ex
168 checking local_parts
169 calling ut2 router
170 ut2 router called for b1@myhost.test.ex
171   domain = myhost.test.ex
172 set transport ut2
173 queued for ut2 transport: local_part = b1
174 domain = myhost.test.ex
175   errors_to=NULL
176   domain_data=NULL local_part_data=^b\d
177 routed by ut2 router (unseen)
178   envelope to: b1@myhost.test.ex
179   transport: ut2
180 "unseen" set: replicated b1@myhost.test.ex
181 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
182 routing a1@myhost.test.ex
183 --------> u1 router <--------
184 local_part=a1 domain=myhost.test.ex
185 checking local_parts
186 calling u1 router
187 u1 router called for a1@myhost.test.ex
188   domain = myhost.test.ex
189 set transport ut1
190 queued for ut1 transport: local_part = a1
191 domain = myhost.test.ex
192   errors_to=NULL
193   domain_data=NULL local_part_data=^a\d
194 routed by u1 router (unseen)
195   envelope to: a1@myhost.test.ex
196   transport: ut1
197 "unseen" set: replicated a1@myhost.test.ex
198 locking TESTSUITE/spool/db/retry.lockfile
199 no retry data available
200 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
201 Considering: a1@myhost.test.ex
202 unique = \0\a1@myhost.test.ex
203 a1@myhost.test.ex: queued for routing
204 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
205 Considering: b1@myhost.test.ex
206 unique = \0\b1@myhost.test.ex
207 b1@myhost.test.ex: queued for routing
208 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
209 Considering: c1@myhost.test.ex
210 unique = \0\c1@myhost.test.ex
211 c1@myhost.test.ex: queued for routing
212 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
213 Considering: d1@myhost.test.ex
214 unique = \0\d1@myhost.test.ex
215 d1@myhost.test.ex: queued for routing
216 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
217 Considering: d2@myhost.test.ex
218 unique = \0\d2@myhost.test.ex
219 d2@myhost.test.ex: queued for routing
220 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
221 Considering: d3@myhost.test.ex
222 unique = \0\d3@myhost.test.ex
223 d3@myhost.test.ex: queued for routing
224 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
225 routing d3@myhost.test.ex
226 --------> real router <--------
227 local_part=d3 domain=myhost.test.ex
228 calling real router
229 real router called for d3@myhost.test.ex
230   domain = myhost.test.ex
231 set transport real
232 queued for real transport: local_part = d3
233 domain = myhost.test.ex
234   errors_to=NULL
235   domain_data=NULL local_part_data=NULL
236 routed by real router
237   envelope to: d3@myhost.test.ex
238   transport: real
239 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
240 routing d2@myhost.test.ex
241 --------> real router <--------
242 local_part=d2 domain=myhost.test.ex
243 calling real router
244 real router called for d2@myhost.test.ex
245   domain = myhost.test.ex
246 queued for real transport: local_part = d2
247 domain = myhost.test.ex
248   errors_to=NULL
249   domain_data=NULL local_part_data=NULL
250 routed by real router
251   envelope to: d2@myhost.test.ex
252   transport: real
253 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
254 routing d1@myhost.test.ex
255 --------> real router <--------
256 local_part=d1 domain=myhost.test.ex
257 calling real router
258 real router called for d1@myhost.test.ex
259   domain = myhost.test.ex
260 queued for real transport: local_part = d1
261 domain = myhost.test.ex
262   errors_to=NULL
263   domain_data=NULL local_part_data=NULL
264 routed by real router
265   envelope to: d1@myhost.test.ex
266   transport: real
267 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
268 routing c1@myhost.test.ex
269 --------> ut4 router <--------
270 local_part=c1 domain=myhost.test.ex
271 checking local_parts
272 c1 in local_parts? no (end of list)
273 ut4 router skipped: local_parts mismatch
274 --------> real router <--------
275 local_part=c1 domain=myhost.test.ex
276 calling real router
277 real router called for c1@myhost.test.ex
278   domain = myhost.test.ex
279 queued for real transport: local_part = c1
280 domain = myhost.test.ex
281   errors_to=NULL
282   domain_data=NULL local_part_data=NULL
283 routed by real router
284   envelope to: c1@myhost.test.ex
285   transport: real
286 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
287 routing b1@myhost.test.ex
288 --------> ut3 router <--------
289 local_part=b1 domain=myhost.test.ex
290 checking local_parts
291 b1 in local_parts? no (end of list)
292 ut3 router skipped: local_parts mismatch
293 --------> ut4 router <--------
294 local_part=b1 domain=myhost.test.ex
295 checking local_parts
296 b1 in local_parts? no (end of list)
297 ut4 router skipped: local_parts mismatch
298 --------> real router <--------
299 local_part=b1 domain=myhost.test.ex
300 calling real router
301 real router called for b1@myhost.test.ex
302   domain = myhost.test.ex
303 queued for real transport: local_part = b1
304 domain = myhost.test.ex
305   errors_to=NULL
306   domain_data=NULL local_part_data=NULL
307 routed by real router
308   envelope to: b1@myhost.test.ex
309   transport: real
310 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
311 routing a1@myhost.test.ex
312 --------> ut2 router <--------
313 local_part=a1 domain=myhost.test.ex
314 checking local_parts
315 a1 in local_parts? no (end of list)
316 ut2 router skipped: local_parts mismatch
317 --------> ut3 router <--------
318 local_part=a1 domain=myhost.test.ex
319 checking local_parts
320 a1 in local_parts? no (end of list)
321 ut3 router skipped: local_parts mismatch
322 --------> ut4 router <--------
323 local_part=a1 domain=myhost.test.ex
324 checking local_parts
325 a1 in local_parts? no (end of list)
326 ut4 router skipped: local_parts mismatch
327 --------> real router <--------
328 local_part=a1 domain=myhost.test.ex
329 calling real router
330 real router called for a1@myhost.test.ex
331   domain = myhost.test.ex
332 queued for real transport: local_part = a1
333 domain = myhost.test.ex
334   errors_to=NULL
335   domain_data=NULL local_part_data=NULL
336 routed by real router
337   envelope to: a1@myhost.test.ex
338   transport: real
339 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
340 After routing:
341   Local deliveries:
342     a1@myhost.test.ex
343     b1@myhost.test.ex
344     c1@myhost.test.ex
345     d1@myhost.test.ex
346     d2@myhost.test.ex
347     d3@myhost.test.ex
348     a1@myhost.test.ex
349     b1@myhost.test.ex
350     c1@myhost.test.ex
351   Remote deliveries:
352     d1@myhost.test.ex
353     d2@myhost.test.ex
354     d3@myhost.test.ex
355   Failed addresses:
356   Deferred addresses:
357 locking TESTSUITE/spool/db/retry.lockfile
358 LOG: MAIN
359   => a1 <a1@myhost.test.ex> R=real T=real
360 locking TESTSUITE/spool/db/retry.lockfile
361 LOG: MAIN
362   => b1 <b1@myhost.test.ex> R=real T=real
363 locking TESTSUITE/spool/db/retry.lockfile
364 LOG: MAIN
365   => c1 <c1@myhost.test.ex> R=real T=real
366 locking TESTSUITE/spool/db/retry.lockfile
367 LOG: MAIN
368   => d1 <d1@myhost.test.ex> R=real T=real
369 locking TESTSUITE/spool/db/retry.lockfile
370 LOG: MAIN
371   => d2 <d2@myhost.test.ex> R=real T=real
372 locking TESTSUITE/spool/db/retry.lockfile
373 LOG: MAIN
374   => d3 <d3@myhost.test.ex> R=real T=real
375 locking TESTSUITE/spool/db/retry.lockfile
376 LOG: MAIN
377   => a1 <a1@myhost.test.ex> R=u1 T=ut1
378 locking TESTSUITE/spool/db/retry.lockfile
379 transport error EPIPE ignored
380 LOG: MAIN
381   ** b1@myhost.test.ex R=ut2 T=ut2: Child process of ut2 transport returned 127 (could mean unable to exec or command does not exist) from command: /non/existent/file
382 locking TESTSUITE/spool/db/retry.lockfile
383 transport error EPIPE ignored
384 LOG: MAIN
385   == c1@myhost.test.ex R=ut3 T=ut3 defer (0): Child process of ut3 transport returned 127 (could mean unable to exec or command does not exist) from command: /non/existent/file
386 locking TESTSUITE/spool/db/retry.lockfile
387 locking TESTSUITE/spool/db/wait-ut4.lockfile
388 cmdlog: '220'
389 LOG: MAIN
390   => d1@myhost.test.ex R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1] C="250 OK"
391 locking TESTSUITE/spool/db/retry.lockfile
392 cmdlog: '220'
393 LOG: MAIN
394   == d2@myhost.test.ex R=ut4 T=ut4 defer (-44) H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<d2@myhost.test.ex>: 450 soft error
395 locking TESTSUITE/spool/db/retry.lockfile
396 locking TESTSUITE/spool/db/wait-ut4.lockfile
397 cmdlog: '220'
398 LOG: MAIN
399   ** d3@myhost.test.ex R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1]: SMTP error from remote mail server after RCPT TO:<d3@myhost.test.ex>: 550 hard error
400 locking TESTSUITE/spool/db/retry.lockfile
401 Exim version x.yz ....
402 configuration file is TESTSUITE/test-config
403 trusted user
404 admin user
405 LOG: MAIN
406   <= <> R=10HmaX-000000005vi-0000 U=EXIMUSER P=local S=sss
407 Exim version x.yz ....
408 configuration file is TESTSUITE/test-config
409 trusted user
410 admin user
411 dropping to exim gid; retaining priv uid
412 locking TESTSUITE/spool/db/retry.lockfile
413 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
414 Considering: CALLER@myhost.test.ex
415 unique = CALLER@myhost.test.ex
416 CALLER@myhost.test.ex: queued for routing
417 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
418 routing CALLER@myhost.test.ex
419 --------> u1 router <--------
420 local_part=CALLER domain=myhost.test.ex
421 checking local_parts
422 CALLER in local_parts? no (end of list)
423 u1 router skipped: local_parts mismatch
424 --------> ut2 router <--------
425 local_part=CALLER domain=myhost.test.ex
426 checking local_parts
427 CALLER in local_parts? no (end of list)
428 ut2 router skipped: local_parts mismatch
429 --------> ut3 router <--------
430 local_part=CALLER domain=myhost.test.ex
431 checking local_parts
432 CALLER in local_parts? no (end of list)
433 ut3 router skipped: local_parts mismatch
434 --------> ut4 router <--------
435 local_part=CALLER domain=myhost.test.ex
436 checking local_parts
437 CALLER in local_parts? no (end of list)
438 ut4 router skipped: local_parts mismatch
439 --------> real router <--------
440 local_part=CALLER domain=myhost.test.ex
441 calling real router
442 real router called for CALLER@myhost.test.ex
443   domain = myhost.test.ex
444 set transport real
445 queued for real transport: local_part = CALLER
446 domain = myhost.test.ex
447   errors_to=NULL
448   domain_data=NULL local_part_data=NULL
449 routed by real router
450   envelope to: CALLER@myhost.test.ex
451   transport: real
452 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
453 After routing:
454   Local deliveries:
455     CALLER@myhost.test.ex
456   Remote deliveries:
457   Failed addresses:
458   Deferred addresses:
459 locking TESTSUITE/spool/db/retry.lockfile
460 LOG: MAIN
461   => CALLER <CALLER@myhost.test.ex> R=real T=real
462 LOG: MAIN
463   Completed
464 >>>>>>>>>>>>>>>> Exim pid=p1238 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
465 >>>>>>>>>>>>>>>> Exim pid=p1237 (bounce-message) terminating with rc=0 >>>>>>>>>>>>>>>>
466 >>>>>>>>>>>>>>>> Exim pid=p1236 (local-accept-delivery) terminating with rc=0 >>>>>>>>>>>>>>>>
467 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>