Logging: Fix logging of errors under PIPELINING
[users/jgh/exim.git] / test / stderr / 0278
1 Exim version x.yz ....
2 changed uid/gid: forcing real = effective
3   uid=uuuu gid=CALLER_GID pid=pppp
4 configuration file is TESTSUITE/test-config
5 admin user
6 seeking password data for user "CALLER": cache not available
7 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
8 DSN: r1 propagating DSN
9 DSN: r2 propagating DSN
10 DSN: r3 propagating DSN
11 DSN: r4 propagating DSN
12 DSN: r5 propagating DSN
13 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
14 sender address = CALLER@test.ex
15 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
16 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
17 Testing CALLER@test.ex
18 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
19 Considering CALLER@test.ex
20 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
21 routing CALLER@test.ex
22 --------> r1 router <--------
23 local_part=CALLER domain=test.ex
24 checking local_parts
25 CALLER in "never"? no (end of list)
26 CALLER in "never1"? no (end of list)
27 CALLER in "CALLER"? yes (matched "CALLER")
28 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
29 r1 router skipped: local_parts mismatch
30 --------> r2 router <--------
31 local_part=CALLER domain=test.ex
32 checking local_parts
33 cached no match for +never_localparts
34 cached lookup data = NULL
35 cached no match for +n1_localparts
36 cached lookup data = NULL
37 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
38 cached yes match for +local_localparts
39 cached lookup data = NULL
40 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
41 r2 router skipped: local_parts mismatch
42 --------> r3 router <--------
43 local_part=CALLER domain=test.ex
44 checking local_parts
45 cached yes match for +local_localparts
46 cached lookup data = NULL
47 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
48 checking for local user
49 seeking password data for user "CALLER": using cached result
50 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
51 calling r3 router
52 r3 router called for CALLER@test.ex
53   domain = test.ex
54 set transport t1
55 queued for t1 transport: local_part = CALLER
56 domain = test.ex
57   errors_to=NULL
58   domain_data=NULL localpart_data=NULL
59 routed by r3 router
60   envelope to: CALLER@test.ex
61   transport: t1
62 search_tidyup called
63 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
64 Exim version x.yz ....
65 changed uid/gid: forcing real = effective
66   uid=uuuu gid=CALLER_GID pid=pppp
67 configuration file is TESTSUITE/test-config
68 admin user
69 changed uid/gid: privilege not needed
70   uid=EXIM_UID gid=EXIM_GID pid=pppp
71 seeking password data for user "CALLER": cache not available
72 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
73 DSN: r1 propagating DSN
74 DSN: r2 propagating DSN
75 DSN: r3 propagating DSN
76 DSN: r4 propagating DSN
77 DSN: r5 propagating DSN
78 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
79 sender address = CALLER@test.ex
80 set_process_info: pppp accepting a local non-SMTP message from <CALLER@test.ex>
81 Sender: CALLER@test.ex
82 Recipients:
83   CALLER@test.ex
84 search_tidyup called
85 >>Headers received:
86
87 rewrite_one_header: type=F:
88   From: CALLER_NAME <CALLER@test.ex>
89 search_tidyup called
90 >>Headers after rewriting and local additions:
91 I Message-Id: <E10HmaX-0005vi-00@myhost.test.ex>
92 F From: CALLER_NAME <CALLER@test.ex>
93   Date: Tue, 2 Mar 1999 09:44:33 +0000
94
95 Data file name: TESTSUITE/spool//input//10HmaX-0005vi-00-D
96 Data file written for message 10HmaX-0005vi-00
97 >>Generated Received: header line
98 P Received: from CALLER by myhost.test.ex with local (Exim x.yz)
99         (envelope-from <CALLER@test.ex>)
100         id 10HmaX-0005vi-00
101         for CALLER@test.ex; Tue, 2 Mar 1999 09:44:33 +0000
102 calling local_scan(); timeout=300
103 local_scan() returned 0 NULL
104 Writing spool header file: TESTSUITE/spool//input//hdr.pppp
105 DSN: Write SPOOL :-dsn_envid NULL
106 DSN: Write SPOOL :-dsn_ret 0
107 DSN: Flags :0
108 DSN: **** SPOOL_OUT - address: |CALLER@test.ex| errorsto: |NULL| orcpt: |NULL| dsn_flags: 0
109 Renaming spool header file: TESTSUITE/spool//input//10HmaX-0005vi-00-H
110 Size of headers = sss
111 LOG: MAIN
112   <= CALLER@test.ex U=CALLER P=local S=sss
113 created log directory TESTSUITE/spool/log
114 search_tidyup called
115 exec TESTSUITE/eximdir/exim -DEXIM_PATH=TESTSUITE/eximdir/exim -C TESTSUITE/test-config -d=0xfbb95cfd -odi -Mc 10HmaX-0005vi-00
116 Exim version x.yz ....
117 changed uid/gid: forcing real = effective
118   uid=uuuu gid=EXIM_GID pid=pppp
119 configuration file is TESTSUITE/test-config
120 trusted user
121 admin user
122 seeking password data for user "CALLER": cache not available
123 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
124 DSN: r1 propagating DSN
125 DSN: r2 propagating DSN
126 DSN: r3 propagating DSN
127 DSN: r4 propagating DSN
128 DSN: r5 propagating DSN
129 set_process_info: pppp delivering specified messages
130 set_process_info: pppp delivering 10HmaX-0005vi-00
131 Trying spool file TESTSUITE/spool//input//10HmaX-0005vi-00-D
132 reading spool file 10HmaX-0005vi-00-H
133 user=CALLER uid=CALLER_UID gid=CALLER_GID sender=CALLER@test.ex
134 sender_local=1 ident=CALLER
135 Non-recipients:
136 Empty Tree
137 ---- End of tree ----
138 recipients_count=1
139 **** SPOOL_IN - No additional fields
140 body_linecount=0 message_linecount=7
141 DSN: set orcpt: NULL  flags: 0
142 Delivery address list:
143   CALLER@test.ex 
144 locking TESTSUITE/spool/db/retry.lockfile
145 locked TESTSUITE/spool/db/retry.lockfile
146 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
147 returned from EXIM_DBOPEN
148 ensuring TESTSUITE/spool/db/retry.lockfile is owned by exim
149 no retry data available
150 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
151 Considering: CALLER@test.ex
152 unique = CALLER@test.ex
153 no domain retry record
154 no address retry record
155 CALLER@test.ex: queued for routing
156 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
157 routing CALLER@test.ex
158 --------> r1 router <--------
159 local_part=CALLER domain=test.ex
160 checking local_parts
161 CALLER in "never"? no (end of list)
162 CALLER in "never1"? no (end of list)
163 CALLER in "CALLER"? yes (matched "CALLER")
164 CALLER in "+never_localparts : +n1_localparts : ! +local_localparts"? no (matched "! +local_localparts")
165 r1 router skipped: local_parts mismatch
166 --------> r2 router <--------
167 local_part=CALLER domain=test.ex
168 checking local_parts
169 cached no match for +never_localparts
170 cached lookup data = NULL
171 cached no match for +n1_localparts
172 cached lookup data = NULL
173 CALLER in "<; never2 ; +n1_localparts"? no (end of list)
174 cached yes match for +local_localparts
175 cached lookup data = NULL
176 CALLER in "+never_localparts : +n2_localparts : !+local_localparts"? no (matched "!+local_localparts" - cached)
177 r2 router skipped: local_parts mismatch
178 --------> r3 router <--------
179 local_part=CALLER domain=test.ex
180 checking local_parts
181 cached yes match for +local_localparts
182 cached lookup data = NULL
183 CALLER in "+local_localparts"? yes (matched "+local_localparts" - cached)
184 checking for local user
185 seeking password data for user "CALLER": using cached result
186 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
187 calling r3 router
188 r3 router called for CALLER@test.ex
189   domain = test.ex
190 set transport t1
191 queued for t1 transport: local_part = CALLER
192 domain = test.ex
193   errors_to=NULL
194   domain_data=NULL localpart_data=NULL
195 routed by r3 router
196   envelope to: CALLER@test.ex
197   transport: t1
198 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
199 After routing:
200   Local deliveries:
201     CALLER@test.ex
202   Remote deliveries:
203   Failed addresses:
204   Deferred addresses:
205 search_tidyup called
206 >>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
207 --------> CALLER@test.ex <--------
208 locking TESTSUITE/spool/db/retry.lockfile
209 locked TESTSUITE/spool/db/retry.lockfile
210 EXIM_DBOPEN(TESTSUITE/spool/db/retry)
211 returned from EXIM_DBOPEN
212 no retry data available
213 search_tidyup called
214 changed uid/gid: local delivery to CALLER <CALLER@test.ex> transport=t1
215   uid=CALLER_UID gid=CALLER_GID pid=pppp
216   home=CALLER_HOME current=CALLER_HOME
217 set_process_info: pppp delivering 10HmaX-0005vi-00 to CALLER using t1
218 appendfile transport entered
219 appendfile: mode=600 notify_comsat=0 quota=0 warning=0
220   file=/dev/null format=unix
221   message_prefix=From ${if def:return_path{$return_path}{MAILER-DAEMON}} ${tod_bsdinbox}\n
222   message_suffix=\n
223   maildir_use_size_file=no
224   locking by lockfile fcntl 
225 search_tidyup called
226 journalling CALLER@test.ex
227 t1 transport returned OK for CALLER@test.ex
228 post-process CALLER@test.ex (0)
229 CALLER@test.ex delivered
230 LOG: MAIN
231   => CALLER <CALLER@test.ex> R=r3 T=t1
232 >>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
233 changed uid/gid: post-delivery tidying
234   uid=EXIM_UID gid=EXIM_GID pid=pppp
235 set_process_info: pppp tidying up after delivering 10HmaX-0005vi-00
236 Processing retry items
237 Succeeded addresses:
238 CALLER@test.ex: no retry items
239 Failed addresses:
240 Deferred addresses:
241 end of retry processing
242 DSN: processing router : r3
243 DSN: processing successful delivery address: CALLER@test.ex
244 DSN: Sender_address: CALLER@test.ex
245 DSN: orcpt: NULL  flags: 0
246 DSN: envid: NULL  ret: 0
247 DSN: Final recipient: CALLER@test.ex
248 DSN: Remote SMTP server supports DSN: 0
249 DSN: not sending DSN success message
250 LOG: MAIN
251   Completed
252 end delivery of 10HmaX-0005vi-00
253 search_tidyup called
254 search_tidyup called
255 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
256 search_tidyup called
257 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=0 >>>>>>>>>>>>>>>>
258 Exim version x.yz ....
259 changed uid/gid: forcing real = effective
260   uid=uuuu gid=CALLER_GID pid=pppp
261 configuration file is TESTSUITE/test-config
262 admin user
263 seeking password data for user "CALLER": cache not available
264 getpwnam() succeeded uid=CALLER_UID gid=CALLER_GID
265 DSN: r1 propagating DSN
266 DSN: r2 propagating DSN
267 DSN: r3 propagating DSN
268 DSN: r4 propagating DSN
269 DSN: r5 propagating DSN
270 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
271 sender address = CALLER@test.ex
272 Address testing: uid=uuuu gid=EXIM_GID euid=uuuu egid=EXIM_GID
273 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
274 Testing unknown@test.ex
275 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
276 Considering unknown@test.ex
277 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
278 routing unknown@test.ex
279 --------> r1 router <--------
280 local_part=unknown domain=test.ex
281 checking local_parts
282 unknown in "never"? no (end of list)
283 unknown in "never1"? no (end of list)
284 unknown in "CALLER"? no (end of list)
285 unknown in "+never_localparts : +n1_localparts : ! +local_localparts"? yes (end of list)
286 calling r1 router
287 r1 router called for unknown@test.ex
288   domain = test.ex
289 route_item = never
290 test.ex in "never"? no (end of list)
291 r1 router declined for unknown@test.ex
292 --------> r2 router <--------
293 local_part=unknown domain=test.ex
294 checking local_parts
295 cached no match for +never_localparts
296 cached lookup data = NULL
297 cached no match for +n1_localparts
298 cached lookup data = NULL
299 unknown in "<; never2 ; +n1_localparts"? no (end of list)
300 cached no match for +local_localparts
301 cached lookup data = NULL
302 unknown in "+never_localparts : +n2_localparts : !+local_localparts"? yes (end of list)
303 calling r2 router
304 r2 router called for unknown@test.ex
305   domain = test.ex
306 DNS lookup of test.ex (MX) using fakens
307 DNS lookup of test.ex (MX) gave NO_DATA
308 returning DNS_NODATA
309 DNS lookup of test.ex (A) using fakens
310 DNS lookup of test.ex (A) gave NO_DATA
311 returning DNS_NODATA
312 r2 router declined for unknown@test.ex
313 --------> r3 router <--------
314 local_part=unknown domain=test.ex
315 checking local_parts
316 cached no match for +local_localparts
317 cached lookup data = NULL
318 unknown in "+local_localparts"? no (end of list)
319 r3 router skipped: local_parts mismatch
320 --------> r4 router <--------
321 local_part=unknown domain=test.ex
322 checking local_parts
323 cached no match for +local_localparts
324 cached lookup data = NULL
325 unknown in "test.ex"? no (end of list)
326 unknown in "unexpanded"? no (end of list)
327 unknown in "+local_localparts : +expanded : +unexpanded"? no (end of list)
328 r4 router skipped: local_parts mismatch
329 --------> r5 router <--------
330 local_part=unknown domain=test.ex
331 checking local_parts
332 cached no match for +local_localparts
333 cached lookup data = NULL
334 unknown in "test.ex"? no (end of list)
335 cached no match for +unexpanded
336 cached lookup data = NULL
337 unknown in "+local_localparts : +expanded : +unexpanded"? no (end of list)
338 r5 router skipped: local_parts mismatch
339 no more routers
340 search_tidyup called
341 >>>>>>>>>>>>>>>> Exim pid=pppp terminating with rc=2 >>>>>>>>>>>>>>>>