consistent fork-time debug
[users/heiko/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 fresh-exec forking for local-accept delivery
8 postfork: local-accept delivery
9 fresh-exec forked for local-accept delivery: npppp
10 Exim version x.yz ....
11 configuration file is TESTSUITE/test-config
12 trusted user
13 admin user
14 dropping to exim gid; retaining priv uid
15 locking TESTSUITE/spool/db/retry.lockfile
16 no retry data available
17 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
18 Considering: a1@myhost.test.ex
19 unique = a1@myhost.test.ex
20 a1@myhost.test.ex: queued for routing
21 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
22 Considering: b1@myhost.test.ex
23 unique = b1@myhost.test.ex
24 b1@myhost.test.ex: queued for routing
25 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
26 Considering: c1@myhost.test.ex
27 unique = c1@myhost.test.ex
28 c1@myhost.test.ex: queued for routing
29 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
30 Considering: d1@myhost.test.ex
31 unique = d1@myhost.test.ex
32 d1@myhost.test.ex: queued for routing
33 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
34 Considering: d2@myhost.test.ex
35 unique = d2@myhost.test.ex
36 d2@myhost.test.ex: queued for routing
37 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
38 Considering: d3@myhost.test.ex
39 unique = d3@myhost.test.ex
40 d3@myhost.test.ex: queued for routing
41 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
42 routing d3@myhost.test.ex
43 --------> u1 router <--------
44 local_part=d3 domain=myhost.test.ex
45 checking local_parts
46 u1 router skipped: local_parts mismatch
47 --------> ut2 router <--------
48 local_part=d3 domain=myhost.test.ex
49 checking local_parts
50 ut2 router skipped: local_parts mismatch
51 --------> ut3 router <--------
52 local_part=d3 domain=myhost.test.ex
53 checking local_parts
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 localpart_data=NULL
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 u1 router skipped: local_parts mismatch
76 --------> ut2 router <--------
77 local_part=d2 domain=myhost.test.ex
78 checking local_parts
79 ut2 router skipped: local_parts mismatch
80 --------> ut3 router <--------
81 local_part=d2 domain=myhost.test.ex
82 checking local_parts
83 ut3 router skipped: local_parts mismatch
84 --------> ut4 router <--------
85 local_part=d2 domain=myhost.test.ex
86 checking local_parts
87 calling ut4 router
88 ut4 router called for d2@myhost.test.ex
89   domain = myhost.test.ex
90 queued for ut4 transport: local_part = d2
91 domain = myhost.test.ex
92   errors_to=NULL
93   domain_data=NULL localpart_data=NULL
94 routed by ut4 router (unseen)
95   envelope to: d2@myhost.test.ex
96   transport: ut4
97 "unseen" set: replicated d2@myhost.test.ex
98 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
99 routing d1@myhost.test.ex
100 --------> u1 router <--------
101 local_part=d1 domain=myhost.test.ex
102 checking local_parts
103 u1 router skipped: local_parts mismatch
104 --------> ut2 router <--------
105 local_part=d1 domain=myhost.test.ex
106 checking local_parts
107 ut2 router skipped: local_parts mismatch
108 --------> ut3 router <--------
109 local_part=d1 domain=myhost.test.ex
110 checking local_parts
111 ut3 router skipped: local_parts mismatch
112 --------> ut4 router <--------
113 local_part=d1 domain=myhost.test.ex
114 checking local_parts
115 calling ut4 router
116 ut4 router called for d1@myhost.test.ex
117   domain = myhost.test.ex
118 queued for ut4 transport: local_part = d1
119 domain = myhost.test.ex
120   errors_to=NULL
121   domain_data=NULL localpart_data=NULL
122 routed by ut4 router (unseen)
123   envelope to: d1@myhost.test.ex
124   transport: ut4
125 "unseen" set: replicated d1@myhost.test.ex
126 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
127 routing c1@myhost.test.ex
128 --------> u1 router <--------
129 local_part=c1 domain=myhost.test.ex
130 checking local_parts
131 u1 router skipped: local_parts mismatch
132 --------> ut2 router <--------
133 local_part=c1 domain=myhost.test.ex
134 checking local_parts
135 ut2 router skipped: local_parts mismatch
136 --------> ut3 router <--------
137 local_part=c1 domain=myhost.test.ex
138 checking local_parts
139 calling ut3 router
140 ut3 router called for c1@myhost.test.ex
141   domain = myhost.test.ex
142 set transport ut3
143 queued for ut3 transport: local_part = c1
144 domain = myhost.test.ex
145   errors_to=NULL
146   domain_data=NULL localpart_data=NULL
147 routed by ut3 router (unseen)
148   envelope to: c1@myhost.test.ex
149   transport: ut3
150 "unseen" set: replicated c1@myhost.test.ex
151 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
152 routing b1@myhost.test.ex
153 --------> u1 router <--------
154 local_part=b1 domain=myhost.test.ex
155 checking local_parts
156 u1 router skipped: local_parts mismatch
157 --------> ut2 router <--------
158 local_part=b1 domain=myhost.test.ex
159 checking local_parts
160 calling ut2 router
161 ut2 router called for b1@myhost.test.ex
162   domain = myhost.test.ex
163 set transport ut2
164 queued for ut2 transport: local_part = b1
165 domain = myhost.test.ex
166   errors_to=NULL
167   domain_data=NULL localpart_data=NULL
168 routed by ut2 router (unseen)
169   envelope to: b1@myhost.test.ex
170   transport: ut2
171 "unseen" set: replicated b1@myhost.test.ex
172 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
173 routing a1@myhost.test.ex
174 --------> u1 router <--------
175 local_part=a1 domain=myhost.test.ex
176 checking local_parts
177 calling u1 router
178 u1 router called for a1@myhost.test.ex
179   domain = myhost.test.ex
180 set transport ut1
181 queued for ut1 transport: local_part = a1
182 domain = myhost.test.ex
183   errors_to=NULL
184   domain_data=NULL localpart_data=NULL
185 routed by u1 router (unseen)
186   envelope to: a1@myhost.test.ex
187   transport: ut1
188 "unseen" set: replicated a1@myhost.test.ex
189 locking TESTSUITE/spool/db/retry.lockfile
190 no retry data available
191 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
192 Considering: a1@myhost.test.ex
193 unique = \0\a1@myhost.test.ex
194 a1@myhost.test.ex: queued for routing
195 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
196 Considering: b1@myhost.test.ex
197 unique = \0\b1@myhost.test.ex
198 b1@myhost.test.ex: queued for routing
199 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
200 Considering: c1@myhost.test.ex
201 unique = \0\c1@myhost.test.ex
202 c1@myhost.test.ex: queued for routing
203 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
204 Considering: d1@myhost.test.ex
205 unique = \0\d1@myhost.test.ex
206 d1@myhost.test.ex: queued for routing
207 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
208 Considering: d2@myhost.test.ex
209 unique = \0\d2@myhost.test.ex
210 d2@myhost.test.ex: queued for routing
211 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
212 Considering: d3@myhost.test.ex
213 unique = \0\d3@myhost.test.ex
214 d3@myhost.test.ex: queued for routing
215 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
216 routing d3@myhost.test.ex
217 --------> real router <--------
218 local_part=d3 domain=myhost.test.ex
219 calling real router
220 real router called for d3@myhost.test.ex
221   domain = myhost.test.ex
222 set transport real
223 queued for real transport: local_part = d3
224 domain = myhost.test.ex
225   errors_to=NULL
226   domain_data=NULL localpart_data=NULL
227 routed by real router
228   envelope to: d3@myhost.test.ex
229   transport: real
230 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
231 routing d2@myhost.test.ex
232 --------> real router <--------
233 local_part=d2 domain=myhost.test.ex
234 calling real router
235 real router called for d2@myhost.test.ex
236   domain = myhost.test.ex
237 queued for real transport: local_part = d2
238 domain = myhost.test.ex
239   errors_to=NULL
240   domain_data=NULL localpart_data=NULL
241 routed by real router
242   envelope to: d2@myhost.test.ex
243   transport: real
244 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
245 routing d1@myhost.test.ex
246 --------> real router <--------
247 local_part=d1 domain=myhost.test.ex
248 calling real router
249 real router called for d1@myhost.test.ex
250   domain = myhost.test.ex
251 queued for real transport: local_part = d1
252 domain = myhost.test.ex
253   errors_to=NULL
254   domain_data=NULL localpart_data=NULL
255 routed by real router
256   envelope to: d1@myhost.test.ex
257   transport: real
258 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
259 routing c1@myhost.test.ex
260 --------> ut4 router <--------
261 local_part=c1 domain=myhost.test.ex
262 checking local_parts
263 ut4 router skipped: local_parts mismatch
264 --------> real router <--------
265 local_part=c1 domain=myhost.test.ex
266 calling real router
267 real router called for c1@myhost.test.ex
268   domain = myhost.test.ex
269 queued for real transport: local_part = c1
270 domain = myhost.test.ex
271   errors_to=NULL
272   domain_data=NULL localpart_data=NULL
273 routed by real router
274   envelope to: c1@myhost.test.ex
275   transport: real
276 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
277 routing b1@myhost.test.ex
278 --------> ut3 router <--------
279 local_part=b1 domain=myhost.test.ex
280 checking local_parts
281 ut3 router skipped: local_parts mismatch
282 --------> ut4 router <--------
283 local_part=b1 domain=myhost.test.ex
284 checking local_parts
285 ut4 router skipped: local_parts mismatch
286 --------> real router <--------
287 local_part=b1 domain=myhost.test.ex
288 calling real router
289 real router called for b1@myhost.test.ex
290   domain = myhost.test.ex
291 queued for real transport: local_part = b1
292 domain = myhost.test.ex
293   errors_to=NULL
294   domain_data=NULL localpart_data=NULL
295 routed by real router
296   envelope to: b1@myhost.test.ex
297   transport: real
298 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
299 routing a1@myhost.test.ex
300 --------> ut2 router <--------
301 local_part=a1 domain=myhost.test.ex
302 checking local_parts
303 ut2 router skipped: local_parts mismatch
304 --------> ut3 router <--------
305 local_part=a1 domain=myhost.test.ex
306 checking local_parts
307 ut3 router skipped: local_parts mismatch
308 --------> ut4 router <--------
309 local_part=a1 domain=myhost.test.ex
310 checking local_parts
311 ut4 router skipped: local_parts mismatch
312 --------> real router <--------
313 local_part=a1 domain=myhost.test.ex
314 calling real router
315 real router called for a1@myhost.test.ex
316   domain = myhost.test.ex
317 queued for real transport: local_part = a1
318 domain = myhost.test.ex
319   errors_to=NULL
320   domain_data=NULL localpart_data=NULL
321 routed by real router
322   envelope to: a1@myhost.test.ex
323   transport: real
324 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
325 After routing:
326   Local deliveries:
327     a1@myhost.test.ex
328     b1@myhost.test.ex
329     c1@myhost.test.ex
330     d1@myhost.test.ex
331     d2@myhost.test.ex
332     d3@myhost.test.ex
333     a1@myhost.test.ex
334     b1@myhost.test.ex
335     c1@myhost.test.ex
336   Remote deliveries:
337     d1@myhost.test.ex
338     d2@myhost.test.ex
339     d3@myhost.test.ex
340   Failed addresses:
341   Deferred addresses:
342 locking TESTSUITE/spool/db/retry.lockfile
343 fresh-exec forking for delivery (local)
344 postfork: delivery (local)
345 fresh-exec forked for delivery (local): npppp
346 LOG: MAIN
347   => a1 <a1@myhost.test.ex> R=real T=real
348 locking TESTSUITE/spool/db/retry.lockfile
349 fresh-exec forking for delivery (local)
350 postfork: delivery (local)
351 fresh-exec forked for delivery (local): npppp
352 LOG: MAIN
353   => b1 <b1@myhost.test.ex> R=real T=real
354 locking TESTSUITE/spool/db/retry.lockfile
355 fresh-exec forking for delivery (local)
356 postfork: delivery (local)
357 fresh-exec forked for delivery (local): npppp
358 LOG: MAIN
359   => c1 <c1@myhost.test.ex> R=real T=real
360 locking TESTSUITE/spool/db/retry.lockfile
361 fresh-exec forking for delivery (local)
362 postfork: delivery (local)
363 fresh-exec forked for delivery (local): npppp
364 LOG: MAIN
365   => d1 <d1@myhost.test.ex> R=real T=real
366 locking TESTSUITE/spool/db/retry.lockfile
367 fresh-exec forking for delivery (local)
368 postfork: delivery (local)
369 fresh-exec forked for delivery (local): npppp
370 LOG: MAIN
371   => d2 <d2@myhost.test.ex> R=real T=real
372 locking TESTSUITE/spool/db/retry.lockfile
373 fresh-exec forking for delivery (local)
374 postfork: delivery (local)
375 fresh-exec forked for delivery (local): npppp
376 LOG: MAIN
377   => d3 <d3@myhost.test.ex> R=real T=real
378 locking TESTSUITE/spool/db/retry.lockfile
379 fresh-exec forking for delivery (local)
380 postfork: delivery (local)
381 fresh-exec forked for delivery (local): npppp
382 LOG: MAIN
383   => a1 <a1@myhost.test.ex> R=u1 T=ut1
384 locking TESTSUITE/spool/db/retry.lockfile
385 fresh-exec forking for delivery (local)
386 postfork: delivery (local)
387 delivery (local) forking for child-open
388 postfork: child-open
389 fresh-exec forked for delivery (local): npppp
390 delivery (local) forked for child-open: npppp
391 delivery (local) forking for pipe-transport output
392 postfork: pipe-transport output
393 delivery (local) forked for pipe-transport output: npppp
394 transport error EPIPE ignored
395 LOG: MAIN
396   ** 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
397 locking TESTSUITE/spool/db/retry.lockfile
398 fresh-exec forking for delivery (local)
399 postfork: delivery (local)
400 delivery (local) forking for child-open
401 postfork: child-open
402 fresh-exec forked for delivery (local): npppp
403 delivery (local) forked for child-open: npppp
404 delivery (local) forking for pipe-transport output
405 postfork: pipe-transport output
406 delivery (local) forked for pipe-transport output: npppp
407 transport error EPIPE ignored
408 LOG: MAIN
409   == 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
410 fresh-exec forking for transport
411 postfork: transport
412 locking TESTSUITE/spool/db/retry.lockfile
413 locking TESTSUITE/spool/db/wait-ut4.lockfile
414 fresh-exec forked for transport: npppp
415 LOG: MAIN
416   => d1@myhost.test.ex R=ut4 T=ut4 H=127.0.0.1 [127.0.0.1] C="250 OK"
417 fresh-exec forking for transport
418 postfork: transport
419 locking TESTSUITE/spool/db/retry.lockfile
420 fresh-exec forked for transport: npppp
421 LOG: MAIN
422   == 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
423 fresh-exec forking for transport
424 postfork: transport
425 locking TESTSUITE/spool/db/retry.lockfile
426 locking TESTSUITE/spool/db/wait-ut4.lockfile
427 fresh-exec forked for transport: npppp
428 LOG: MAIN
429   ** 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
430 locking TESTSUITE/spool/db/retry.lockfile
431 fresh-exec forking for bounce message
432 postfork: bounce message
433 fresh-exec forked for bounce message: npppp
434 Exim version x.yz ....
435 configuration file is TESTSUITE/test-config
436 trusted user
437 admin user
438 LOG: MAIN
439   <= <> R=10HmaX-0005vi-00 U=EXIMUSER P=local S=sss
440 fresh-exec forking for local-accept delivery
441 postfork: local-accept delivery
442 fresh-exec forked for local-accept delivery: npppp
443 Exim version x.yz ....
444 configuration file is TESTSUITE/test-config
445 trusted user
446 admin user
447 dropping to exim gid; retaining priv uid
448 locking TESTSUITE/spool/db/retry.lockfile
449 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
450 Considering: CALLER@myhost.test.ex
451 unique = CALLER@myhost.test.ex
452 CALLER@myhost.test.ex: queued for routing
453 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
454 routing CALLER@myhost.test.ex
455 --------> u1 router <--------
456 local_part=CALLER domain=myhost.test.ex
457 checking local_parts
458 u1 router skipped: local_parts mismatch
459 --------> ut2 router <--------
460 local_part=CALLER domain=myhost.test.ex
461 checking local_parts
462 ut2 router skipped: local_parts mismatch
463 --------> ut3 router <--------
464 local_part=CALLER domain=myhost.test.ex
465 checking local_parts
466 ut3 router skipped: local_parts mismatch
467 --------> ut4 router <--------
468 local_part=CALLER domain=myhost.test.ex
469 checking local_parts
470 ut4 router skipped: local_parts mismatch
471 --------> real router <--------
472 local_part=CALLER domain=myhost.test.ex
473 calling real router
474 real router called for CALLER@myhost.test.ex
475   domain = myhost.test.ex
476 set transport real
477 queued for real transport: local_part = CALLER
478 domain = myhost.test.ex
479   errors_to=NULL
480   domain_data=NULL localpart_data=NULL
481 routed by real router
482   envelope to: CALLER@myhost.test.ex
483   transport: real
484 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
485 After routing:
486   Local deliveries:
487     CALLER@myhost.test.ex
488   Remote deliveries:
489   Failed addresses:
490   Deferred addresses:
491 locking TESTSUITE/spool/db/retry.lockfile
492 fresh-exec forking for delivery (local)
493 postfork: delivery (local)
494 fresh-exec forked for delivery (local): npppp
495 LOG: MAIN
496   => CALLER <CALLER@myhost.test.ex> R=real T=real
497 LOG: MAIN
498   Completed
499 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
500 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
501 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>
502 >>>>>>>>>>>>>>>> Exim pid=pppp (main) terminating with rc=0 >>>>>>>>>>>>>>>>