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