Hintsbd: fix locking
[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  locking TESTSUITE/spool/db/callout.lockfile
96  locked  TESTSUITE/spool/db/callout.lockfile
97  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
98  returned from EXIM_DBOPEN: 0xAAAAAAAA
99  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
100  dbfn_read: key=y
101  dbfn_read: null return
102  callout cache: no domain record found for y
103  dbfn_read: key=x@y
104  dbfn_read: null return
105  callout cache: no address record found for x@y
106  EXIM_DBCLOSE(0xAAAAAAAA)
107  closed hints database and lockfile
108 interface=NULL port=PORT_S
109 Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
110  127.0.0.1 in hosts_try_fastopen?
111   list element: 
112 connected
113   SMTP<< 220 server ready
114 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
115   SMTP>> EHLO myhost.test.ex
116 cmd buf flush ddd bytes
117   SMTP<< 250 OK
118 not using PIPELINING
119 not using DSN
120 127.0.0.1 in hosts_require_auth? no (option unset)
121   SMTP>> MAIL FROM:<>
122 cmd buf flush ddd bytes
123   SMTP<< 250 OK
124   SMTP>> RCPT TO:<x@y>
125 cmd buf flush ddd bytes
126 sync_responses expect rcpt for x@y
127   SMTP<< 250 OK
128   SMTP>> QUIT
129 cmd buf flush ddd bytes
130   SMTP<< 220 OK
131   SMTP(close)>>
132 cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
133  locking TESTSUITE/spool/db/callout.lockfile
134  locked  TESTSUITE/spool/db/callout.lockfile
135  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
136  returned from EXIM_DBOPEN: 0xAAAAAAAA
137  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
138  dbfn_write: key=y datalen NNN
139  wrote callout cache domain record for y:
140    result=1 postmaster=0 random=0
141  dbfn_write: key=x@y datalen NNN
142  wrote positive callout cache address record for x@y
143  EXIM_DBCLOSE(0xAAAAAAAA)
144  closed hints database and lockfile
145 ----------- end verify ------------
146 sender x@y verified ok
147 accept: condition test succeeded in ACL "mail"
148 end of ACL "mail": ACCEPT
149 SMTP>> 250 OK
150 SMTP<< quit
151 SMTP>> 221 myhost.test.ex closing connection
152 LOG: smtp_connection MAIN
153   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
154 search_tidyup called
155 >>>>>>>>>>>>>>>> Exim pid=p1234 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
156 Exim version x.yz ....
157 Hints DB:
158 changed uid/gid: forcing real = effective
159   uid=uuuu gid=CALLER_GID pid=p1235
160 configuration file is TESTSUITE/test-config
161 admin user
162 changed uid/gid: privilege not needed
163   uid=EXIM_UID gid=EXIM_GID pid=p1235
164 originator: uid=CALLER_UID gid=CALLER_GID login=CALLER name=CALLER_NAME
165 sender address = CALLER@myhost.test.ex
166 sender_fullhost = [1.2.3.4]
167 sender_rcvhost = [1.2.3.4]
168 host in hosts_connection_nolog? no (option unset)
169 LOG: smtp_connection MAIN
170   SMTP connection from [1.2.3.4]
171 host in host_lookup? no (option unset)
172 set_process_info: pppp handling incoming connection from [1.2.3.4]
173 host in host_reject_connection? no (option unset)
174 host in sender_unqualified_hosts? no (option unset)
175 host in recipient_unqualified_hosts? no (option unset)
176 host in helo_verify_hosts? no (option unset)
177 host in helo_try_verify_hosts? no (option unset)
178 host in helo_accept_junk_hosts? no (option unset)
179 SMTP>> 220 myhost.test.ex ESMTP Exim x.yz Tue, 2 Mar 1999 09:44:33 +0000
180 smtp_setup_msg entered
181 SMTP<< helo test
182 test in helo_lookup_domains?
183  list element: @
184  list element: @[]
185 test in helo_lookup_domains? no (end of list)
186 sender_fullhost = (test) [1.2.3.4]
187 sender_rcvhost = [1.2.3.4] (helo=test)
188 set_process_info: pppp handling incoming connection from (test) [1.2.3.4]
189 SMTP>> 250 myhost.test.ex Hello test [1.2.3.4]
190 SMTP<< mail from:<x@y>
191 spool directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100 msg_size = 0
192 log directory space = nnnnnK inodes = nnnnn check_space = 10240K inodes = 100
193 using ACL "mail"
194 processing "accept" (TESTSUITE/test-config 20)
195 check verify = sender/callout=1s,maxwait=1s
196 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
197 Verifying x@y
198 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
199 Considering x@y
200 >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
201 routing x@y
202 --------> r1 router <--------
203 local_part=x domain=y
204 calling r1 router
205 r1 router called for x@y
206   domain = y
207 set transport t1
208 queued for t1 transport: local_part = x
209 domain = y
210   errors_to=NULL
211   domain_data=NULL local_part_data=NULL
212 routed by r1 router
213   envelope to: x@y
214   transport: t1
215 using host_fake_gethostbyname for 127.0.0.1 (IPv4)
216 local host found for non-MX address
217 MUNGED: ::1 will be omitted in what follows
218 get[host|ipnode]byname[2] looked up these IP addresses:
219   name=127.0.0.1 address=127.0.0.1
220 Attempting full verification using callout
221  locking TESTSUITE/spool/db/callout.lockfile
222  locked  TESTSUITE/spool/db/callout.lockfile
223  EXIM_DBOPEN: file <TESTSUITE/spool/db/callout> dir <TESTSUITE/spool/db> flags=O_RDWR
224  returned from EXIM_DBOPEN: 0xAAAAAAAA
225  opened hints database TESTSUITE/spool/db/callout: flags=O_RDWR
226  dbfn_read: key=y
227  dbfn_read: size 40 return
228  callout cache: found domain record for y
229  dbfn_read: key=x@y
230  dbfn_read: size 16 return
231  callout cache: found address record for x@y
232  callout cache: address record is positive
233  EXIM_DBCLOSE(0xAAAAAAAA)
234  closed hints database and lockfile
235 ----------- end verify ------------
236 sender x@y verified ok
237 accept: condition test succeeded in ACL "mail"
238 end of ACL "mail": ACCEPT
239 SMTP>> 250 OK
240 SMTP<< quit
241 SMTP>> 221 myhost.test.ex closing connection
242 LOG: smtp_connection MAIN
243   SMTP connection from (test) [1.2.3.4] D=qqs closed by QUIT
244 search_tidyup called
245 >>>>>>>>>>>>>>>> Exim pid=p1235 (fresh-exec) terminating with rc=0 >>>>>>>>>>>>>>>>
246 >>> host in hosts_connection_nolog? no (option unset)
247 >>> host in host_lookup? no (option unset)
248 >>> host in host_reject_connection? no (option unset)
249 >>> host in sender_unqualified_hosts? no (option unset)
250 >>> host in recipient_unqualified_hosts? no (option unset)
251 >>> host in helo_verify_hosts? no (option unset)
252 >>> host in helo_try_verify_hosts? no (option unset)
253 >>> host in helo_accept_junk_hosts? no (option unset)
254 >>> test in helo_lookup_domains?
255 >>>  list element: @
256 >>>  list element: @[]
257 >>> test in helo_lookup_domains? no (end of list)
258 >>> using ACL "mail"
259 >>> processing "accept" (TESTSUITE/test-config 20)
260 >>> check verify = sender/callout=1s,maxwait=1s
261 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
262 >>> routing x@y
263 >>> calling r1 router
264 >>> routed by r1 router
265 >>> local host found for non-MX address
266 MUNGED: ::1 will be omitted in what follows
267 >>> get[host|ipnode]byname[2] looked up these IP addresses:
268 >>>   name=127.0.0.1 address=127.0.0.1
269 >>> Attempting full verification using callout
270 >>> callout cache: found domain record for y
271 >>> callout cache: found address record for x@y
272 >>> callout cache: address record is positive
273 >>> ----------- end verify ------------
274 >>> accept: condition test succeeded in ACL "mail"
275 >>> end of ACL "mail": ACCEPT
276 >>> host in hosts_connection_nolog? no (option unset)
277 >>> host in host_lookup? no (option unset)
278 >>> host in host_reject_connection? no (option unset)
279 >>> host in sender_unqualified_hosts? no (option unset)
280 >>> host in recipient_unqualified_hosts? no (option unset)
281 >>> host in helo_verify_hosts? no (option unset)
282 >>> host in helo_try_verify_hosts? no (option unset)
283 >>> host in helo_accept_junk_hosts? no (option unset)
284 >>> test in helo_lookup_domains?
285 >>>  list element: @
286 >>>  list element: @[]
287 >>> test in helo_lookup_domains? no (end of list)
288 >>> using ACL "mail"
289 >>> processing "accept" (TESTSUITE/test-config 20)
290 >>> check verify = sender/callout=1s,maxwait=1s
291 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
292 >>> routing a@b
293 >>> calling r1 router
294 >>> routed by r1 router
295 >>> local host found for non-MX address
296 MUNGED: ::1 will be omitted in what follows
297 >>> get[host|ipnode]byname[2] looked up these IP addresses:
298 >>>   name=127.0.0.1 address=127.0.0.1
299 >>> Attempting full verification using callout
300 >>> callout cache: no domain record found for b
301 >>> callout cache: no address record found for a@b
302 >>> interface=NULL port=PORT_S
303 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
304 >>>  127.0.0.1 in hosts_try_fastopen?
305 >>>   list element: 
306 >>> connected
307 >>>   SMTP<< 220 server ready
308 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
309 >>>   SMTP>> EHLO myhost.test.ex
310 >>> cmd buf flush 21 bytes
311 >>>   SMTP<< 250 OK
312 >>> 127.0.0.1 in hosts_require_auth? no (option unset)
313 >>>   SMTP>> MAIL FROM:<>
314 >>> cmd buf flush 14 bytes
315 >>>   SMTP<< 250 OK
316 >>>   SMTP>> RCPT TO:<a@b>
317 >>> cmd buf flush 15 bytes
318 >>>   SMTP<< 250 OK
319 >>>   SMTP>> QUIT
320 >>> cmd buf flush 6 bytes
321 >>>   SMTP<< 220 OK
322 >>>   SMTP(close)>>
323 >>> cmdlog: '220:EHLO:250:MAIL:250:RCPT:250:QUIT:220'
324 >>> wrote callout cache domain record for b:
325 >>>   result=1 postmaster=0 random=0
326 >>> wrote positive callout cache address record for a@b
327 >>> ----------- end verify ------------
328 >>> accept: condition test succeeded in ACL "mail"
329 >>> end of ACL "mail": ACCEPT
330 >>> host in hosts_connection_nolog? no (option unset)
331 >>> host in host_lookup? no (option unset)
332 >>> host in host_reject_connection? no (option unset)
333 >>> host in sender_unqualified_hosts? no (option unset)
334 >>> host in recipient_unqualified_hosts? no (option unset)
335 >>> host in helo_verify_hosts? no (option unset)
336 >>> host in helo_try_verify_hosts? no (option unset)
337 >>> host in helo_accept_junk_hosts? no (option unset)
338 >>> test in helo_lookup_domains?
339 >>>  list element: @
340 >>>  list element: @[]
341 >>> test in helo_lookup_domains? no (end of list)
342 >>> using ACL "mail"
343 >>> processing "accept" (TESTSUITE/test-config 20)
344 >>> check verify = sender/callout=1s,maxwait=1s
345 >>> >>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
346 >>> routing p1@q
347 >>> calling r1 router
348 >>> routed by r1 router
349 >>> local host found for non-MX address
350 MUNGED: ::1 will be omitted in what follows
351 >>> get[host|ipnode]byname[2] looked up these IP addresses:
352 >>>   name=127.0.0.1 address=127.0.0.1
353 >>> Attempting full verification using callout
354 >>> callout cache: no domain record found for q
355 >>> callout cache: no address record found for p1@q
356 >>> interface=NULL port=PORT_S
357 >>> Connecting to 127.0.0.1 [127.0.0.1]:PORT_S ...
358 >>>  127.0.0.1 in hosts_try_fastopen?
359 >>>   list element: 
360 >>> connected
361 >>>   SMTP<< 220 server ready
362 >>> 127.0.0.1 in hosts_avoid_esmtp? no (option unset)
363 >>>   SMTP>> EHLO myhost.test.ex
364 >>> cmd buf flush 21 bytes
365 >>>   SMTP(close)>>
366 >>> cmdlog: '220:EHLO'
367 >>> SMTP timeout
368 >>> ----------- end verify ------------
369 >>> accept: condition test deferred in ACL "mail"
370 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
371 LOG: H=(test) [1.2.3.4] temporarily rejected MAIL <p1@q>: Could not complete sender verify callout