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