Logging: avoid claiming a host was used for an addr, when conn refused under TFO
[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 u1 router skipped: local_parts mismatch
44 --------> ut2 router <--------
45 local_part=d3 domain=myhost.test.ex
46 checking local_parts
47 ut2 router skipped: local_parts mismatch
48 --------> ut3 router <--------
49 local_part=d3 domain=myhost.test.ex
50 checking local_parts
51 ut3 router skipped: local_parts mismatch
52 --------> ut4 router <--------
53 local_part=d3 domain=myhost.test.ex
54 checking local_parts
55 calling ut4 router
56 ut4 router called for d3@myhost.test.ex
57   domain = myhost.test.ex
58 set transport ut4
59 queued for ut4 transport: local_part = d3
60 domain = myhost.test.ex
61   errors_to=NULL
62   domain_data=NULL localpart_data=NULL
63 routed by ut4 router (unseen)
64   envelope to: d3@myhost.test.ex
65   transport: ut4
66 "unseen" set: replicated d3@myhost.test.ex
67 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
68 routing d2@myhost.test.ex
69 --------> u1 router <--------
70 local_part=d2 domain=myhost.test.ex
71 checking local_parts
72 u1 router skipped: local_parts mismatch
73 --------> ut2 router <--------
74 local_part=d2 domain=myhost.test.ex
75 checking local_parts
76 ut2 router skipped: local_parts mismatch
77 --------> ut3 router <--------
78 local_part=d2 domain=myhost.test.ex
79 checking local_parts
80 ut3 router skipped: local_parts mismatch
81 --------> ut4 router <--------
82 local_part=d2 domain=myhost.test.ex
83 checking local_parts
84 calling ut4 router
85 ut4 router called for d2@myhost.test.ex
86   domain = myhost.test.ex
87 queued for ut4 transport: local_part = d2
88 domain = myhost.test.ex
89   errors_to=NULL
90   domain_data=NULL localpart_data=NULL
91 routed by ut4 router (unseen)
92   envelope to: d2@myhost.test.ex
93   transport: ut4
94 "unseen" set: replicated d2@myhost.test.ex
95 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
96 routing d1@myhost.test.ex
97 --------> u1 router <--------
98 local_part=d1 domain=myhost.test.ex
99 checking local_parts
100 u1 router skipped: local_parts mismatch
101 --------> ut2 router <--------
102 local_part=d1 domain=myhost.test.ex
103 checking local_parts
104 ut2 router skipped: local_parts mismatch
105 --------> ut3 router <--------
106 local_part=d1 domain=myhost.test.ex
107 checking local_parts
108 ut3 router skipped: local_parts mismatch
109 --------> ut4 router <--------
110 local_part=d1 domain=myhost.test.ex
111 checking local_parts
112 calling ut4 router
113 ut4 router called for d1@myhost.test.ex
114   domain = myhost.test.ex
115 queued for ut4 transport: local_part = d1
116 domain = myhost.test.ex
117   errors_to=NULL
118   domain_data=NULL localpart_data=NULL
119 routed by ut4 router (unseen)
120   envelope to: d1@myhost.test.ex
121   transport: ut4
122 "unseen" set: replicated d1@myhost.test.ex
123 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
124 routing c1@myhost.test.ex
125 --------> u1 router <--------
126 local_part=c1 domain=myhost.test.ex
127 checking local_parts
128 u1 router skipped: local_parts mismatch
129 --------> ut2 router <--------
130 local_part=c1 domain=myhost.test.ex
131 checking local_parts
132 ut2 router skipped: local_parts mismatch
133 --------> ut3 router <--------
134 local_part=c1 domain=myhost.test.ex
135 checking local_parts
136 calling ut3 router
137 ut3 router called for c1@myhost.test.ex
138   domain = myhost.test.ex
139 set transport ut3
140 queued for ut3 transport: local_part = c1
141 domain = myhost.test.ex
142   errors_to=NULL
143   domain_data=NULL localpart_data=NULL
144 routed by ut3 router (unseen)
145   envelope to: c1@myhost.test.ex
146   transport: ut3
147 "unseen" set: replicated c1@myhost.test.ex
148 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
149 routing b1@myhost.test.ex
150 --------> u1 router <--------
151 local_part=b1 domain=myhost.test.ex
152 checking local_parts
153 u1 router skipped: local_parts mismatch
154 --------> ut2 router <--------
155 local_part=b1 domain=myhost.test.ex
156 checking local_parts
157 calling ut2 router
158 ut2 router called for b1@myhost.test.ex
159   domain = myhost.test.ex
160 set transport ut2
161 queued for ut2 transport: local_part = b1
162 domain = myhost.test.ex
163   errors_to=NULL
164   domain_data=NULL localpart_data=NULL
165 routed by ut2 router (unseen)
166   envelope to: b1@myhost.test.ex
167   transport: ut2
168 "unseen" set: replicated b1@myhost.test.ex
169 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
170 routing a1@myhost.test.ex
171 --------> u1 router <--------
172 local_part=a1 domain=myhost.test.ex
173 checking local_parts
174 calling u1 router
175 u1 router called for a1@myhost.test.ex
176   domain = myhost.test.ex
177 set transport ut1
178 queued for ut1 transport: local_part = a1
179 domain = myhost.test.ex
180   errors_to=NULL
181   domain_data=NULL localpart_data=NULL
182 routed by u1 router (unseen)
183   envelope to: a1@myhost.test.ex
184   transport: ut1
185 "unseen" set: replicated a1@myhost.test.ex
186 locking TESTSUITE/spool/db/retry.lockfile
187 no retry data available
188 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
189 Considering: a1@myhost.test.ex
190 unique = \0\a1@myhost.test.ex
191 a1@myhost.test.ex: queued for routing
192 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
193 Considering: b1@myhost.test.ex
194 unique = \0\b1@myhost.test.ex
195 b1@myhost.test.ex: queued for routing
196 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
197 Considering: c1@myhost.test.ex
198 unique = \0\c1@myhost.test.ex
199 c1@myhost.test.ex: queued for routing
200 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
201 Considering: d1@myhost.test.ex
202 unique = \0\d1@myhost.test.ex
203 d1@myhost.test.ex: queued for routing
204 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
205 Considering: d2@myhost.test.ex
206 unique = \0\d2@myhost.test.ex
207 d2@myhost.test.ex: queued for routing
208 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
209 Considering: d3@myhost.test.ex
210 unique = \0\d3@myhost.test.ex
211 d3@myhost.test.ex: queued for routing
212 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
213 routing d3@myhost.test.ex
214 --------> real router <--------
215 local_part=d3 domain=myhost.test.ex
216 calling real router
217 real router called for d3@myhost.test.ex
218   domain = myhost.test.ex
219 set transport real
220 queued for real transport: local_part = d3
221 domain = myhost.test.ex
222   errors_to=NULL
223   domain_data=NULL localpart_data=NULL
224 routed by real router
225   envelope to: d3@myhost.test.ex
226   transport: real
227 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
228 routing d2@myhost.test.ex
229 --------> real router <--------
230 local_part=d2 domain=myhost.test.ex
231 calling real router
232 real router called for d2@myhost.test.ex
233   domain = myhost.test.ex
234 queued for real transport: local_part = d2
235 domain = myhost.test.ex
236   errors_to=NULL
237   domain_data=NULL localpart_data=NULL
238 routed by real router
239   envelope to: d2@myhost.test.ex
240   transport: real
241 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
242 routing d1@myhost.test.ex
243 --------> real router <--------
244 local_part=d1 domain=myhost.test.ex
245 calling real router
246 real router called for d1@myhost.test.ex
247   domain = myhost.test.ex
248 queued for real transport: local_part = d1
249 domain = myhost.test.ex
250   errors_to=NULL
251   domain_data=NULL localpart_data=NULL
252 routed by real router
253   envelope to: d1@myhost.test.ex
254   transport: real
255 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
256 routing c1@myhost.test.ex
257 --------> ut4 router <--------
258 local_part=c1 domain=myhost.test.ex
259 checking local_parts
260 ut4 router skipped: local_parts mismatch
261 --------> real router <--------
262 local_part=c1 domain=myhost.test.ex
263 calling real router
264 real router called for c1@myhost.test.ex
265   domain = myhost.test.ex
266 queued for real transport: local_part = c1
267 domain = myhost.test.ex
268   errors_to=NULL
269   domain_data=NULL localpart_data=NULL
270 routed by real router
271   envelope to: c1@myhost.test.ex
272   transport: real
273 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
274 routing b1@myhost.test.ex
275 --------> ut3 router <--------
276 local_part=b1 domain=myhost.test.ex
277 checking local_parts
278 ut3 router skipped: local_parts mismatch
279 --------> ut4 router <--------
280 local_part=b1 domain=myhost.test.ex
281 checking local_parts
282 ut4 router skipped: local_parts mismatch
283 --------> real router <--------
284 local_part=b1 domain=myhost.test.ex
285 calling real router
286 real router called for b1@myhost.test.ex
287   domain = myhost.test.ex
288 queued for real transport: local_part = b1
289 domain = myhost.test.ex
290   errors_to=NULL
291   domain_data=NULL localpart_data=NULL
292 routed by real router
293   envelope to: b1@myhost.test.ex
294   transport: real
295 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
296 routing a1@myhost.test.ex
297 --------> ut2 router <--------
298 local_part=a1 domain=myhost.test.ex
299 checking local_parts
300 ut2 router skipped: local_parts mismatch
301 --------> ut3 router <--------
302 local_part=a1 domain=myhost.test.ex
303 checking local_parts
304 ut3 router skipped: local_parts mismatch
305 --------> ut4 router <--------
306 local_part=a1 domain=myhost.test.ex
307 checking local_parts
308 ut4 router skipped: local_parts mismatch
309 --------> real router <--------
310 local_part=a1 domain=myhost.test.ex
311 calling real router
312 real router called for a1@myhost.test.ex
313   domain = myhost.test.ex
314 queued for real transport: local_part = a1
315 domain = myhost.test.ex
316   errors_to=NULL
317   domain_data=NULL localpart_data=NULL
318 routed by real router
319   envelope to: a1@myhost.test.ex
320   transport: real
321 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
322 After routing:
323   Local deliveries:
324     a1@myhost.test.ex
325     b1@myhost.test.ex
326     c1@myhost.test.ex
327     d1@myhost.test.ex
328     d2@myhost.test.ex
329     d3@myhost.test.ex
330     a1@myhost.test.ex
331     b1@myhost.test.ex
332     c1@myhost.test.ex
333   Remote deliveries:
334     d1@myhost.test.ex
335     d2@myhost.test.ex
336     d3@myhost.test.ex
337   Failed addresses:
338   Deferred addresses:
339 locking TESTSUITE/spool/db/retry.lockfile
340 LOG: MAIN
341   => a1 <a1@myhost.test.ex> R=real T=real
342 locking TESTSUITE/spool/db/retry.lockfile
343 LOG: MAIN
344   => b1 <b1@myhost.test.ex> R=real T=real
345 locking TESTSUITE/spool/db/retry.lockfile
346 LOG: MAIN
347   => c1 <c1@myhost.test.ex> R=real T=real
348 locking TESTSUITE/spool/db/retry.lockfile
349 LOG: MAIN
350   => d1 <d1@myhost.test.ex> R=real T=real
351 locking TESTSUITE/spool/db/retry.lockfile
352 LOG: MAIN
353   => d2 <d2@myhost.test.ex> R=real T=real
354 locking TESTSUITE/spool/db/retry.lockfile
355 LOG: MAIN
356   => d3 <d3@myhost.test.ex> R=real T=real
357 locking TESTSUITE/spool/db/retry.lockfile
358 LOG: MAIN
359   => a1 <a1@myhost.test.ex> R=u1 T=ut1
360 locking TESTSUITE/spool/db/retry.lockfile
361 transport error EPIPE ignored
362 LOG: MAIN
363   ** 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
364 locking TESTSUITE/spool/db/retry.lockfile
365 transport error EPIPE ignored
366 LOG: MAIN
367   == 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
368 locking TESTSUITE/spool/db/retry.lockfile
369 locking TESTSUITE/spool/db/wait-ut4.lockfile
370 LOG: MAIN
371   => d1@myhost.test.ex R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1] C="250 OK"
372 locking TESTSUITE/spool/db/retry.lockfile
373 LOG: MAIN
374   == 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
375 locking TESTSUITE/spool/db/retry.lockfile
376 locking TESTSUITE/spool/db/wait-ut4.lockfile
377 LOG: MAIN
378   ** 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
379 locking TESTSUITE/spool/db/retry.lockfile
380 Exim version x.yz ....
381 configuration file is TESTSUITE/test-config
382 trusted user
383 admin user
384 LOG: MAIN
385   <= <> R=10HmaX-0005vi-00 U=EXIMUSER P=local S=sss
386 Exim version x.yz ....
387 configuration file is TESTSUITE/test-config
388 trusted user
389 admin user
390 dropping to exim gid; retaining priv uid
391 locking TESTSUITE/spool/db/retry.lockfile
392 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
393 Considering: CALLER@myhost.test.ex
394 unique = CALLER@myhost.test.ex
395 CALLER@myhost.test.ex: queued for routing
396 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
397 routing CALLER@myhost.test.ex
398 --------> u1 router <--------
399 local_part=CALLER domain=myhost.test.ex
400 checking local_parts
401 u1 router skipped: local_parts mismatch
402 --------> ut2 router <--------
403 local_part=CALLER domain=myhost.test.ex
404 checking local_parts
405 ut2 router skipped: local_parts mismatch
406 --------> ut3 router <--------
407 local_part=CALLER domain=myhost.test.ex
408 checking local_parts
409 ut3 router skipped: local_parts mismatch
410 --------> ut4 router <--------
411 local_part=CALLER domain=myhost.test.ex
412 checking local_parts
413 ut4 router skipped: local_parts mismatch
414 --------> real router <--------
415 local_part=CALLER domain=myhost.test.ex
416 calling real router
417 real router called for CALLER@myhost.test.ex
418   domain = myhost.test.ex
419 set transport real
420 queued for real transport: local_part = CALLER
421 domain = myhost.test.ex
422   errors_to=NULL
423   domain_data=NULL localpart_data=NULL
424 routed by real router
425   envelope to: CALLER@myhost.test.ex
426   transport: real
427 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
428 After routing:
429   Local deliveries:
430     CALLER@myhost.test.ex
431   Remote deliveries:
432   Failed addresses:
433   Deferred addresses:
434 locking TESTSUITE/spool/db/retry.lockfile
435 LOG: MAIN
436   => CALLER <CALLER@myhost.test.ex> R=real T=real
437 LOG: MAIN
438   Completed
439 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
440 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
441 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
442 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>