Move dkim-specific debug printf handlers to general string-services
[exim.git] / test / stderr / 0432
1 >>> host in hosts_connection_nolog? no (option unset)
2 >>> host in host_lookup? no (option unset)
3 >>> host in host_reject_connection? no (option unset)
4 >>> host in sender_unqualified_hosts? no (option unset)
5 >>> host in recipient_unqualified_hosts? no (option unset)
6 >>> host in helo_verify_hosts? no (option unset)
7 >>> host in helo_try_verify_hosts? no (option unset)
8 >>> host in helo_accept_junk_hosts? no (option unset)
9 >>> test in helo_lookup_domains?
10 >>>  list element: @
11 >>>  list element: @[]
12 >>> test in helo_lookup_domains? no (end of list)
13 >>> using ACL "mail"
14 >>> processing "accept" (TESTSUITE/test-config 20)
15 >>> check verify = sender/callout=1s,maxwait=1s
16 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
17 >>> routing x@y
18 >>> calling r1 router
19 >>> routed by r1 router
20 >>> local host found for non-MX address
21 MUNGED: ::1 will be omitted in what follows
22 >>> get[host|ipnode]byname[2] looked up these IP addresses:
23 >>>   name=127.0.0.1 address=127.0.0.1
24 >>> Attempting full verification using callout
25 >>> ... callout omitted by default when host testing
26 >>> (Use -bhc if you want the callouts to happen.)
27 >>> ----------- end verify ------------
28 >>> accept: condition test succeeded in ACL "mail"
29 >>> end of ACL "mail": ACCEPT
30 Exim version x.yz ....
31 Hints DB:
32 changed uid/gid: forcing real = effective
33   uid=uuuu gid=CALLER_GID pid=p1234
34 configuration file is TESTSUITE/test-config
35 admin user
36 changed uid/gid: privilege not needed
37   uid=EXIM_UID gid=EXIM_GID pid=p1234
38 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
39 sender address = CALLER@myhost.test.ex
40 sender_fullhost = [1.2.3.4]
41 sender_rcvhost = [1.2.3.4]
42 host in hosts_connection_nolog? no (option unset)
43 LOG: smtp_connection MAIN
44   SMTP connection from [1.2.3.4]
45 host in host_lookup? no (option unset)
46 set_process_info: pppp handling incoming connection from [1.2.3.4]
47 host in host_reject_connection? no (option unset)
48 host in sender_unqualified_hosts? no (option unset)
49 host in recipient_unqualified_hosts? no (option unset)
50 host in helo_verify_hosts? no (option unset)
51 host in helo_try_verify_hosts? no (option unset)
52 host in helo_accept_junk_hosts? no (option unset)
53 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
54 smtp_setup_msg entered
55 SMTP<< helo test
56 test in helo_lookup_domains?
57  list element: @
58  list element: @[]
59 test in helo_lookup_domains? no (end of list)
60 sender_fullhost = (test) [1.2.3.4]
61 sender_rcvhost = [1.2.3.4] (helo=test)
62 set_process_info: pppp handling incoming connection from (test) [1.2.3.4]
63 SMTP>> 250 myhost.test.ex Hello test [1.2.3.4]
64 SMTP<< mail from:<x@y>
65 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
66 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
67 using ACL "mail"
68 processing "accept" (TESTSUITE/test-config 20)
69 check verify = sender/callout=1s,maxwait=1s
70 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
71 Verifying x@y
72 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
73 Considering x@y
74 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
75 routing x@y
76 --------> r1 router <--------
77 local_part=x domain=y
78 calling r1 router
79 r1 router called for x@y
80   domain = y
81 set transport t1
82 queued for t1 transport: local_part = x
83 domain = y
84   errors_to=NULL
85   domain_data=NULL local_part_data=NULL
86 routed by r1 router
87   envelope to: x@y
88   transport: t1
89 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
90 local host found for non-MX address
91 MUNGED: ::1 will be omitted in what follows
92 get[host|ipnode]byname[2] looked up these IP addresses:
93   name=127.0.0.1 address=127.0.0.1
94 Attempting full verification using callout
95  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
96  hintsdb_open(flags 0x2 mode 0640) No such file or directory
97  returned from EXIM_DBOPEN: (nil)
98  TESTSUITE/spool/db/callout appears not to exist: trying to create
99  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR|O_CREAT
100  returned from EXIM_DBOPEN: 0xAAAAAAAA
101 dbfn_read: key=y
102 dbfn_read: null return
103 callout cache: no domain record found for y
104 dbfn_read: key=x@y
105 dbfn_read: null return
106 callout cache: no address record found for x@y
107 interface=NULL port=PORT_S
108 Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
109  127.0.0.1 in hosts_try_fastopen?
110   list element: 
111 connected
112   SMTP<< 220 server ready
113 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
114   SMTP>> EHLO myhost.test.ex
115 cmd buf flush ddd bytes
116   SMTP<< 250 OK
117 not using PIPELINING
118 not using DSN
119 127.0.0.1 in hosts_require_auth? no (option unset)
120   SMTP>> MAIL FROM:<>
121 cmd buf flush ddd bytes
122   SMTP<< 250 OK
123   SMTP>> RCPT TO:<x@y>
124 cmd buf flush ddd bytes
125 sync_responses expect rcpt for x@y
126   SMTP<< 250 OK
127   SMTP>> QUIT
128 cmd buf flush ddd bytes
129   SMTP<< 220 OK
130   SMTP(close)>>
131 cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
132  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
133  returned from EXIM_DBOPEN: 0xAAAAAAAA
134 dbfn_write: key=y datalen nn
135 wrote callout cache domain record for y:
136   result=1 postmaster=0 random=0
137 dbfn_write: key=x@y datalen nn
138 wrote positive callout cache address record for x@y
139 ----------- end verify ------------
140 sender x@y verified ok
141 accept: condition test succeeded in ACL "mail"
142 end of ACL "mail": ACCEPT
143 SMTP>> 250 OK
144 SMTP<< quit
145 SMTP>> 221 myhost.test.ex closing connection
146 LOG: smtp_connection MAIN
147   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
148 search_tidyup called
149 >>>>>>>>>>>>>>>> Exim pid=p1234 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
150 Exim version x.yz ....
151 Hints DB:
152 changed uid/gid: forcing real = effective
153   uid=uuuu gid=CALLER_GID pid=p1235
154 configuration file is TESTSUITE/test-config
155 admin user
156 changed uid/gid: privilege not needed
157   uid=EXIM_UID gid=EXIM_GID pid=p1235
158 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
159 sender address = CALLER@myhost.test.ex
160 sender_fullhost = [1.2.3.4]
161 sender_rcvhost = [1.2.3.4]
162 host in hosts_connection_nolog? no (option unset)
163 LOG: smtp_connection MAIN
164   SMTP connection from [1.2.3.4]
165 host in host_lookup? no (option unset)
166 set_process_info: pppp handling incoming connection from [1.2.3.4]
167 host in host_reject_connection? no (option unset)
168 host in sender_unqualified_hosts? no (option unset)
169 host in recipient_unqualified_hosts? no (option unset)
170 host in helo_verify_hosts? no (option unset)
171 host in helo_try_verify_hosts? no (option unset)
172 host in helo_accept_junk_hosts? no (option unset)
173 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
174 smtp_setup_msg entered
175 SMTP<< helo test
176 test in helo_lookup_domains?
177  list element: @
178  list element: @[]
179 test in helo_lookup_domains? no (end of list)
180 sender_fullhost = (test) [1.2.3.4]
181 sender_rcvhost = [1.2.3.4] (helo=test)
182 set_process_info: pppp handling incoming connection from (test) [1.2.3.4]
183 SMTP>> 250 myhost.test.ex Hello test [1.2.3.4]
184 SMTP<< mail from:<x@y>
185 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
186 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
187 using ACL "mail"
188 processing "accept" (TESTSUITE/test-config 20)
189 check verify = sender/callout=1s,maxwait=1s
190 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
191 Verifying x@y
192 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
193 Considering x@y
194 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
195 routing x@y
196 --------> r1 router <--------
197 local_part=x domain=y
198 calling r1 router
199 r1 router called for x@y
200   domain = y
201 set transport t1
202 queued for t1 transport: local_part = x
203 domain = y
204   errors_to=NULL
205   domain_data=NULL local_part_data=NULL
206 routed by r1 router
207   envelope to: x@y
208   transport: t1
209 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
210 local host found for non-MX address
211 MUNGED: ::1 will be omitted in what follows
212 get[host|ipnode]byname[2] looked up these IP addresses:
213   name=127.0.0.1 address=127.0.0.1
214 Attempting full verification using callout
215  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
216  returned from EXIM_DBOPEN: 0xAAAAAAAA
217 dbfn_read: key=y
218 dbfn_read: size nnn return
219 callout cache: found domain record for y
220 dbfn_read: key=x@y
221 dbfn_read: size nnn return
222 callout cache: found address record for x@y
223 callout cache: address record is positive
224 ----------- end verify ------------
225 sender x@y verified ok
226 accept: condition test succeeded in ACL "mail"
227 end of ACL "mail": ACCEPT
228 SMTP>> 250 OK
229 SMTP<< quit
230 SMTP>> 221 myhost.test.ex closing connection
231 LOG: smtp_connection MAIN
232   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
233 search_tidyup called
234 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
235 >>> host in hosts_connection_nolog? no (option unset)
236 >>> host in host_lookup? no (option unset)
237 >>> host in host_reject_connection? no (option unset)
238 >>> host in sender_unqualified_hosts? no (option unset)
239 >>> host in recipient_unqualified_hosts? no (option unset)
240 >>> host in helo_verify_hosts? no (option unset)
241 >>> host in helo_try_verify_hosts? no (option unset)
242 >>> host in helo_accept_junk_hosts? no (option unset)
243 >>> test in helo_lookup_domains?
244 >>>  list element: @
245 >>>  list element: @[]
246 >>> test in helo_lookup_domains? no (end of list)
247 >>> using ACL "mail"
248 >>> processing "accept" (TESTSUITE/test-config 20)
249 >>> check verify = sender/callout=1s,maxwait=1s
250 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
251 >>> routing x@y
252 >>> calling r1 router
253 >>> routed by r1 router
254 >>> local host found for non-MX address
255 MUNGED: ::1 will be omitted in what follows
256 >>> get[host|ipnode]byname[2] looked up these IP addresses:
257 >>>   name=127.0.0.1 address=127.0.0.1
258 >>> Attempting full verification using callout
259 >>> callout cache: found domain record for y
260 >>> callout cache: found address record for x@y
261 >>> callout cache: address record is positive
262 >>> ----------- end verify ------------
263 >>> accept: condition test succeeded in ACL "mail"
264 >>> end of ACL "mail": ACCEPT
265 >>> host in hosts_connection_nolog? no (option unset)
266 >>> host in host_lookup? no (option unset)
267 >>> host in host_reject_connection? no (option unset)
268 >>> host in sender_unqualified_hosts? no (option unset)
269 >>> host in recipient_unqualified_hosts? no (option unset)
270 >>> host in helo_verify_hosts? no (option unset)
271 >>> host in helo_try_verify_hosts? no (option unset)
272 >>> host in helo_accept_junk_hosts? no (option unset)
273 >>> test in helo_lookup_domains?
274 >>>  list element: @
275 >>>  list element: @[]
276 >>> test in helo_lookup_domains? no (end of list)
277 >>> using ACL "mail"
278 >>> processing "accept" (TESTSUITE/test-config 20)
279 >>> check verify = sender/callout=1s,maxwait=1s
280 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
281 >>> routing a@b
282 >>> calling r1 router
283 >>> routed by r1 router
284 >>> local host found for non-MX address
285 MUNGED: ::1 will be omitted in what follows
286 >>> get[host|ipnode]byname[2] looked up these IP addresses:
287 >>>   name=127.0.0.1 address=127.0.0.1
288 >>> Attempting full verification using callout
289 >>> callout cache: no domain record found for b
290 >>> callout cache: no address record found for a@b
291 >>> interface=NULL port=PORT_S
292 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
293 >>>  127.0.0.1 in hosts_try_fastopen?
294 >>>   list element: 
295 >>> connected
296 >>>   SMTP<< 220 server ready
297 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
298 >>>   SMTP>> EHLO myhost.test.ex
299 >>> cmd buf flush 21 bytes
300 >>>   SMTP<< 250 OK
301 >>> 127.0.0.1 in hosts_require_auth? no (option unset)
302 >>>   SMTP>> MAIL FROM:<>
303 >>> cmd buf flush 14 bytes
304 >>>   SMTP<< 250 OK
305 >>>   SMTP>> RCPT TO:<a@b>
306 >>> cmd buf flush 15 bytes
307 >>>   SMTP<< 250 OK
308 >>>   SMTP>> QUIT
309 >>> cmd buf flush 6 bytes
310 >>>   SMTP<< 220 OK
311 >>>   SMTP(close)>>
312 >>> cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
313 >>> wrote callout cache domain record for b:
314 >>>   result=1 postmaster=0 random=0
315 >>> wrote positive callout cache address record for a@b
316 >>> ----------- end verify ------------
317 >>> accept: condition test succeeded in ACL "mail"
318 >>> end of ACL "mail": ACCEPT
319 >>> host in hosts_connection_nolog? no (option unset)
320 >>> host in host_lookup? no (option unset)
321 >>> host in host_reject_connection? no (option unset)
322 >>> host in sender_unqualified_hosts? no (option unset)
323 >>> host in recipient_unqualified_hosts? no (option unset)
324 >>> host in helo_verify_hosts? no (option unset)
325 >>> host in helo_try_verify_hosts? no (option unset)
326 >>> host in helo_accept_junk_hosts? no (option unset)
327 >>> test in helo_lookup_domains?
328 >>>  list element: @
329 >>>  list element: @[]
330 >>> test in helo_lookup_domains? no (end of list)
331 >>> using ACL "mail"
332 >>> processing "accept" (TESTSUITE/test-config 20)
333 >>> check verify = sender/callout=1s,maxwait=1s
334 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
335 >>> routing p1@q
336 >>> calling r1 router
337 >>> routed by r1 router
338 >>> local host found for non-MX address
339 MUNGED: ::1 will be omitted in what follows
340 >>> get[host|ipnode]byname[2] looked up these IP addresses:
341 >>>   name=127.0.0.1 address=127.0.0.1
342 >>> Attempting full verification using callout
343 >>> callout cache: no domain record found for q
344 >>> callout cache: no address record found for p1@q
345 >>> interface=NULL port=PORT_S
346 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
347 >>>  127.0.0.1 in hosts_try_fastopen?
348 >>>   list element: 
349 >>> connected
350 >>>   SMTP<< 220 server ready
351 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
352 >>>   SMTP>> EHLO myhost.test.ex
353 >>> cmd buf flush 21 bytes
354 >>>   SMTP(close)>>
355 >>> cmdlog: '220:EHLO'
356 >>> SMTP timeout
357 >>> ----------- end verify ------------
358 >>> accept: condition test deferred in ACL "mail"
359 LOG: H=(test) [1.2.3.4] sender verify defer for <p1@q>: Could not complete sender verify callout: 127.0.0.1 [127.0.0.1] : SMTP timeout after EHLO myhost.test.ex
360 LOG: H=(test) [1.2.3.4] temporarily rejected MAIL <p1@q>: Could not complete sender verify callout