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